Stored Procedure suppressing errors?

SQL Server Administration
1

So, I started to tune a piece of sql code that had a high number of waits - a stored procedure that takes 6 parameters and inserts their values into a table. I am running SQL Server 2016 Enterprise CU5, DB Compatibility Mode is SQL Server 2016(130).

This is where it gets interesting - I captured an actual command from a trace and plugged those values into the stored procedure and attempted to get an estimated execution plan. I get this error in SSMS:

Msg 2739, Level 16, State 1, Line 20
The text, ntext, and image data types are invalid for local variables.

My question is, why would the stored procedure continue to execute without issue VS a manual run by SSMS using the same values? Further inspection does indeed show that there is an NTEXT datatype defined in the table involved in the INSERT...

I believe that there is something going on with this scenario that is causing excessive waits...

Any ideas?

Regards

2

please post the problematic script. otherwise it would only be guesses

3

It's failing when it calls the stored procedure. The procedure isn't running. Run this and you'll see what I mean.

declare @T ntext

1 Like
4

Here is the redacted stored procedure:

USE [database_01]
GO

SET ANSI_NULLS ON
GO
SET QUOTED_IDENTIFIER ON
GO

ALTER PROCEDURE [dbo].[questionable_Stored_Procedure]
@param01 bigint = null,
@param02 varchar(50),
@param03 varchar(50),
@param04 ntext,
@param05 datetime,
@param06 varchar(max)
AS

BEGIN

SET NOCOUNT ON;

	INSERT INTO table01
	(col01, col02, col03, col04, col05, col06)
	VALUES
	(@param01, @param02, @param03, @param04, @param05, @param06)

END

Also, yes the stored procedure is definitely running about 1000 times a minute... I verified this by commenting out all of the code and then things started to break on the application. I did a rollback to the original code and things went back to normal...
Thanks

5

please post schema for table01 and any indices you might have on it. Is this table a staging table or a working table?

6

Here is the table schema - thanks... Also, this is a working, transactional table...

USE [database_01]
GO

SET ANSI_NULLS ON
GO

SET QUOTED_IDENTIFIER ON
GO

CREATE TABLE [dbo].[table01](
[id] [bigint] IDENTITY(1,1) NOT NULL,
[col01] [bigint] NULL,
[col02] varchar NOT NULL,
[col03] varchar NOT NULL,
[col04] [ntext] NOT NULL,
[col05] [datetime] NOT NULL,
[col06] varchar NULL,
CONSTRAINT [PK_Reporting_Queue] PRIMARY KEY CLUSTERED
(
[id] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON, FILLFACTOR = 80) ON [PRIMARY]
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]

GO

--Indexes
USE [database_01]
GO

ALTER TABLE [dbo].[table01] ADD CONSTRAINT [PK_table01] PRIMARY KEY CLUSTERED
(
[id] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, IGNORE_DUP_KEY = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON, FILLFACTOR = 80) ON [PRIMARY]
GO

USE [database_01]
GO

CREATE NONCLUSTERED INDEX [IDX_TimeStamp] ON [dbo].[table01]
(
[time_stamp] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, SORT_IN_TEMPDB = OFF, DROP_EXISTING = OFF, ONLINE = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON, FILLFACTOR = 80) ON [PRIMARY]
GO

7

is your table table01 being actually populated now? since you do not have error logging in it, I think it is failing 1000x times .

CREATE TABLE [dbo].[table01](
[id] [bigint] IDENTITY(1,1) NOT NULL,
[col01] [bigint] NULL,
[col02] varchar NOT NULL,
[col03] varchar NOT NULL,
[col04] [ntext] NOT NULL,
[col05] [datetime] NOT NULL,
[col06] varchar NULL,
CONSTRAINT [PK_Reporting_Queue] PRIMARY KEY CLUSTERED
(
[id] ASC
)WITH (PAD_INDEX = OFF, STATISTICS_NORECOMPUTE = OFF, 
IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, 
ALLOW_PAGE_LOCKS = ON, FILLFACTOR = 80) ON [PRIMARY]
) ON [PRIMARY] TEXTIMAGE_ON [PRIMARY]

GO

declare @param01 bigint = 0, 
  @param02	varchar(50), 
@param03	varchar(50),
@param05	datetime,
@param06	varchar(max);

WHILE (SELECT count(1) FROM table01) < 2000
BEGIN  
	select @param01 = @param01 + 100, 
	       @param02	= CAST(@param01 as varchar(50)) , 
		   @param03= CAST(@param01 as varchar(50)) ,
		   @param05	= GETDATE(),
		   @param06	= CAST(@param01 as varchar(max));

	exec [questionable_Stored_Procedure] @param01, @param02, @param03, @param03, @param05, @param06

   IF (SELECT count(1) FROM table01) > 2000  
      BREAK  
   ELSE  
      CONTINUE  
END
8

The table is definitely being populated by the INSERT statement in the stored procedure. I just verified again by sql trace. I can see the stored procedure name in the captured ObjectName and I see the INSERT statemen tin the TextData. Also, I see the rowcounts going up on the table.
I decided to take the test a little further by creating the following procs - one with NTEXT as a parameter and the other with NTEXT as a local variable.
It appears that the proc with the local NTEXT variable fails, but the proc with the NTEXT parameter does create - see the sample code below... still a head-scratcher...

--Fails
create procedure dbo.[NTEXT_Wrapper01]
AS
BEGIN
declare @T ntext
SELECT @T
END
go

--succeeds
create procedure dbo.[NTEXT_Wrapper02]
@T ntext
AS
BEGIN

SELECT @T

END
go
EXEC [NTEXT_Wrapper02] 'test'

9

yes that is @mike01 mentioned to you. so getting back to your original problem, performance. why do you have a identity column on this table and where is timestamp coming from?

do you do any type of query on this table using where clause?

10

It does not appear that the timestamp index is getting used according to the index stats dmv... Now, it looks like we're getting somewhere... Looks like the ntext error was nothing and now the unused index may be contributing to the excessive waits...

Thoughts ?

OBJECT NAME INDEX NAME USER_SEEKS USER_SCANS USER_LOOKUPS USER_UPDATES
table01 PK_table01 47049205 208216 0 94098478
table01 IDX_TimeStamp 0 0 0 94098475
11

is the primary key being accessed by anything else?

[id] [bigint] IDENTITY(1,1) NOT NULL,

if you are writing to it 1K times a minute any index will affect performance. heap tables are well suited for those kinds of inserts but will come to bite you when want to query the table. Are you somehow querying this table with or without where clauses?

12

This looks to be the only query using the PK -

DELETE FROM table01
WHERE id = @id

13

where is @id coming from. any other tables joining to this table?
might it be worth using
[id] UNIQUEIDENTIFIER PRIMARY KEY default NEWID(),

with no clustered index on that column, that could speed things up? basically you would have a heap table with no clustered index but nicely improves your performance?

14

The @id is coming from a parameter in a similar store procedure. I am thinking that I may starting with disabling/dropping 'IDX_TimeStamp', since it is not used. I guess that I could consider dropping the clustered index, but not just yet...
Thanks for your input!

ALTER PROCEDURE [dbo].[Delete_ID]
@id bigint
AS
BEGIN
-- SET NOCOUNT ON added to prevent extra result sets from
-- interfering with SELECT statements.
SET NOCOUNT ON;

DELETE FROM table01
WHERE id = @id;

END

15

please explain to me why you would use a clustered index?

16

Ok - I am going to talk with the developers and ask the same question. It appears that the dev composed the schema and everything associated with the process that is generating the high waits... I find that the table is transient (table01) - meaning that the table fills up with a few rows, then all of the rows are deleted. It looks like the table never gets over 200 rows, before a DELETE happens. I would agree that a clustered index may not be needed.

I will have to touch base with the devs first to understand why they put it in place - more to come

Regards

17

Be careful with this type of process and using a HEAP because you may find that the space utilized just continues increasing leaving a lot of unused space allocated to the HEAP. To recover that unused space you would then need to run an ALTER TABLE ... REBUILD.

Before moving forward - what are the actual waits that you are seeing related to this process and what are the stats for those waits? If you have a total of 10,000,000 waits - but the average wait time is 2ms - then is there really an issue?

18

I did more inspection and found that this the waits are HADR_SYNC_COMMIT waits... Which is strange... This may not actually be a perf prob - maybe an network infra issue ?

Thoughts ?

19

This would indicate that you have AlwaysOn - with a synchronous availability group setup. In this scenario - the commits on the primary cannot be completed until the commit on the secondary has been hardened.

The question still remains - what is the average/min/max wait times associated with this wait stat? What are the wait stats specifically related to this query?

Again - you can have a high number of waits but if the wait time is small then it really isn't a problem.

1 Like
20

You should unquestionably keep the existing clustered index.

Look for searches by other column values on the table. Not by time_stamp, since there's no uses of that index. The best way to check is to look at SQL's missing index stats for that table.

DECLARE @table_name_pattern nvarchar(128)
SET @table_name_pattern = 'table_01%'
    SELECT
        DB_NAME(mid.database_id) AS Db_Name,
        CONVERT(varchar(10), GETDATE(), 120) AS capture_date,
        dps.row_count,
        OBJECT_NAME(mid.object_id) AS Table_Name,
        mid.equality_columns, mid.inequality_columns, mid.included_columns,        
        user_seeks, user_scans, cj1.max_days_active, unique_compiles, 
        last_user_seek, last_user_scan, 
        CAST(avg_total_user_cost AS decimal(9, 2)) AS avg_total_user_cost,
        CAST(avg_user_impact AS decimal(9, 2)) AS [avg_user_impact%],
        system_seeks, system_scans, last_system_seek, last_system_scan,
        CAST(avg_total_system_cost AS decimal(9, 2)) AS avg_total_system_cost,
        CAST(avg_system_impact AS decimal(9, 2)) AS [avg_system_impact%],
        mid.statement, mid.object_id, mid.index_handle
    FROM sys.dm_db_missing_index_details mid WITH (NOLOCK)
    CROSS JOIN (
        SELECT DATEDIFF(DAY, create_date, GETDATE()) AS max_days_active FROM sys.databases WITH (NOLOCK) WHERE name = 'tempdb'
    ) AS cj1
    LEFT OUTER JOIN sys.dm_db_missing_index_groups mig WITH (NOLOCK) ON
        mig.index_handle = mid.index_handle
    LEFT OUTER JOIN sys.dm_db_missing_index_group_stats migs WITH (NOLOCK) ON
        migs.group_handle = mig.index_group_handle
    LEFT OUTER JOIN sys.dm_db_partition_stats dps WITH (NOLOCK) ON
        dps.object_id = mid.object_id AND
        dps.index_id IN (0, 1)
    CROSS APPLY (
        SELECT CASE WHEN dps.row_count >= 1000000 THEN 'M' WHEN dps.row_count >= 1000 THEN 'K' ELSE '' END AS row_count_suffix
    ) AS ca1
    WHERE
        1 = 1 
        AND mid.database_id = DB_ID()
        AND OBJECT_NAME(mid.object_id) LIKE @table_name_pattern
    ORDER BY
        --avg_total_user_cost * (user_seeks + user_scans) DESC,
        Table_Name,
        equality_columns, inequality_columns,
        user_seeks DESC