Why does only one version of these procedures get blocked under moderate load?

Question

The table:

CREATE TABLE [dbo].[Session] (
    [SessionId]          UNIQUEIDENTIFIER NOT NULL,
    [CID]                INT              NULL,
    [DEST]               VARCHAR (50)     NOT NULL,
    [EndUser]            VARCHAR (50)     NULL,
    [Platform]           VARCHAR (5)      CONSTRAINT [DF_Session_Platform] DEFAULT ('WEB') NOT NULL,
    [SessionState]       VARCHAR (50)     NOT NULL,
    [ServerName]         VARCHAR (180)    NOT NULL,
    [StartDate]          DATETIME         CONSTRAINT [DF_Session_StartDate] DEFAULT (getutcdate()) NOT NULL,
    [UpdateDate]         DATETIME         NULL,
    [EndDate]            DATETIME         NULL,
    [SessionData]        XML              NULL,
    [StartMinute]        AS               (dateadd(minute,datediff(minute,(0),[StartDate]),(0))) PERSISTED,
    [ActivityBreadcrumb] NVARCHAR (MAX)   NULL,
    CONSTRAINT [PK_Session] PRIMARY KEY CLUSTERED ([StartDate] ASC, [SessionId] ASC)
);
GO

CREATE NONCLUSTERED INDEX [IX_Session_StartDate_EndDate]
    ON [dbo].[Session]([StartDate] ASC, [EndDate] ASC);
GO

CREATE NONCLUSTERED INDEX [IX_Session_CID_DEST]
    ON [dbo].[Session]([CID] ASC, [DEST] ASC, [StartDate] ASC, [SessionId] ASC)
    INCLUDE([Platform]);
GO

CREATE PRIMARY XML INDEX [IX_Session_SessionData]
    ON [dbo].[Session]([SessionData])
    WITH (PAD_INDEX = OFF);
GO

CREATE XML INDEX [IX_Session_SessionData_PROPERTY]
    ON [dbo].[Session]([SessionData])
    USING XML INDEX [IX_Session_SessionData] FOR PROPERTY
    WITH (PAD_INDEX = OFF);
GO

CREATE NONCLUSTERED INDEX [IX_StartMinute]
    ON [dbo].[Session]([StartMinute] DESC, [EndDate] ASC);
GO

CREATE NONCLUSTERED INDEX [IX_Session_CID_SessionId]
    ON [dbo].[Session]([CID] ASC, [SessionId] ASC);
GO

CREATE STATISTICS [ST_Session_StartDate_SessionId_CID]
    ON [dbo].[Session]([StartDate], [SessionId], [CID]);
GO

CREATE STATISTICS [ST_Session_SessionId_CID_DEST]
    ON [dbo].[Session]([SessionId], [CID], [DEST]);

The procedure that caused problems:

CREATE PROCEDURE [dbo].[SessionUpdate] 
    @SessionId uniqueidentifier, 
    @CID int,
    @DEST varchar(50),
    @EndUser varchar(50) = NULL,
    @Platform varchar(5) = NULL,
    @SessionState varchar(50),
    @ServerName varchar(180) ,
    @StatusDtm datetime,
    @EndDtm datetime,
    @Data xml,
    @ActivityBreadcrumb nvarchar(max) = NULL
AS
BEGIN

    SET NOCOUNT ON;

    MERGE AppLog.dbo.[Session] as target
    USING (Select @SessionId, @CID, @DEST, @EndUser, @Platform, @SessionState, @ServerName, @StatusDtm, @EndDtm, @Data, @ActivityBreadcrumb) as source (SessionId, CID, DEST, EndUser, [Platform], SessionState, ServerName, StatusDtm, EndDtm, Data, ActivityBreadcrumb)
    ON (target.SessionID = source.SessionId)
    WHEN MATCHED THEN
        Update Set target.UpdateDate = Source.StatusDtm,
            target.CID = coalesce(Source.CID, target.CID),
            target.Platform = coalesce(Source.Platform, target.Platform),
            target.SessionState = coalesce(Source.SessionState,Target.SessionState),
            target.SessionData = source.Data,
            target.ActivityBreadcrumb = source.ActivityBreadcrumb
    WHEN NOT MATCHED THEN
        Insert Values(Source.SessionId, Source.CID, Source.DEST, Source.EndUser, Source.[Platform], Source.SessionState, Source.ServerName, Source.StatusDtm, null, Source.EndDtm, source.Data, source.ActivityBreadcrumb);

END

The above procedure seemed to run fine for years. Scheduled queries remove year old data nightly. The application experienced a large amount of volume for a few days and we started seeing some blocking during that time. The issue persisted after the volume receded to normal levels and even below normal levels.

Rows were not getting inserted into the table for 10 to 20 minutes. This is what we see when we looked at blocking queries during that time:

We made changes to indexes, the procedure and changed the how the application updates the table. The problem no longer happens. The proc now just inserts a row without updating:

CREATE PROCEDURE [dbo].[SessionUpdate] 
    @SessionId uniqueidentifier, 
    @CID int,
    @DEST varchar(50),
    @EndUser varchar(50) = NULL,
    @Platform varchar(5) = NULL,
    @SessionState varchar(50),
    @ServerName varchar(180) ,
    @StatusDtm datetime,
    @EndDtm datetime,
    @Data xml,
    @ActivityBreadcrumb nvarchar(max) = NULL
AS
BEGIN
    SET NOCOUNT ON;

    INSERT INTO Session (SessionId, CID, DEST, EndUser, [Platform], SessionState, ServerName, StartDate, EndDate, SessionData, ActivityBreadcrumb)
    VALUES (@SessionId, @CID, @DEST, @EndUser, @Platform, @SessionState, @ServerName, @StatusDtm, @EndDtm, @Data, @ActivityBreadcrumb)
END

We suspect the reason the blocking was happening was due to statistics becoming old and the procedure recompiling. It looked like all of the procedure calls were waiting on one procedure to finish compiling. Here is the lock data:

<Database name="AppLog">
<Locks>
   <Lock request_mode="S" request_status="GRANT" request_count="1" />
</Locks>
<Objects>
   <Object name="SessionUpdate" schema_name="dbo">
      <Locks>
         <Lock resource_type="OBJECT" request_mode="Sch-S" request_status="GRANT" request_count="1" />
         <Lock resource_type="OBJECT.COMPILE" request_mode="X" request_status="WAIT" request_count="1" />
      </Locks>
   </Object>
</Objects>
</Database>

Does that sound correct?

I would like to understand better what was happening to avoid this situation again.

For example, does the new procedure no longer recompile, or if it does, why does it no longer block other calls?

If a call to the new procedure does cause it to recompile, and it takes 10-20 minutes to finish, does the insert still happen after the application has closed the connection due to a timeout?

Should we worry about other queries that use this table? Could they timeout due to statistics being updated?

Answer 1

Not a full answer, but with information presented it's impossible to answer definetly.

I doubt this is a problem with statistics update and recompile. At least this wouldn't be my first guess. First thing I notice is that the MERGE joins on target.SessionID = source.SessionId This means you need to have an index on SessionID to do a effective seek. The DDL provided contains no index where first column is SessionID. The best thing SQL Server can do in this situation is to scan an index. Index scan is horrible for concurrency. It will block others from accessing the table. It can also go parallel, if the index is sufficently big. In this case we can see both: plenty of long lock waits and the blocking session has latch ACCESS_METHODS_DATASET_PARENT indicating parallel work. Now statistics update can go parallel too, but only since SQL Server 2016 and for databases in compatibility level 130. Source

Starting with SQL Server 2016 (13.x), sampling of data to build statistics is done in parallel, when using compatibility level 130, to improve the performance of statistics collection. The query optimizer will use parallel sample statistics, whenever a table size exceeds a certain threshold.

You should definetly check what compatibility level your database is on. Secondly: by default statistics are sampled, unless you force a full scan. Given that the MERGE does probably index scan already, I would be surprised, if additional table sampling added significant amount to query runtime. Not stating that this cannot happen. Just with given information, I would expect the missing index on SessionID to cause the problems.