April 21, 2016 at 9:32 am
We are receiving deadlocks in our Update Statistics job while inserting a record into a history table. The deadlocks are being caused by a Microsoft Service Manager process. We're trying to determine where within the INSERT statement sys.sysschobjs is being locked. Any ideas?
Here is the resource info from the log
keylock hobtid=281474978938880
dbid=10
objectname=OMDWDataMart.sys.sysschobjs
indexname=clst
id=lock8723d1200
mode=U
associatedObjectId=281474978938880
Below is the INSERT statement.
Insert Into DBA_HOME.dbo.Table_Statistics
(
ExecutionId,
DBName,
SchemaName,
ObjectName,
Objecttype,
StatsName,
StatsType,
StatsDesc,
StatsId,
CreateDate,
Duration,
Elapsed_Time,
RecordCount,
ScanSample
)
SELECT@ExecutionId,
@DBName,
LEFT(sch.name,50),-- Schema Name
obj.name,-- Object Name
obj.type,-- Object Type
LEFT(st.name,150),
CASE
WHEN ind.type is NULLThen 0
Else ind.type
END,-- Stats Type
CASE
WHEN ind.type IS NOT NULLTHEN LEFT(ind.type_desc,30)
WHEN ind.type IS NULL AND auto_created = 1THEN 'STATISTIC - AUTO CREATED'
WHEN ind.type IS NULL AND user_created = 1THEN 'STATISTIC - USER CREATED'
ELSE '*** UNKNOWN ***'
END,
stats_id,
STATS_DATE(obj.object_id, stats_id),
CASE
WHEN STATS_DATE(obj.object_id, stats_id) IS NOT NULL
THEN CASE
WHEN (select min(stats_id) from sys.stats where object_id = obj.object_id) = st.stats_id
THEN CONVERT(varchar(12),STATS_DATE(obj.object_id, stats_id) - @StartTime, 114)
ELSE CONVERT(varchar(12),STATS_DATE(obj.object_id, stats_id) - (select STATS_DATE(obj.object_Id, (select max(stats_id) from sys.stats where object_id = obj.object_id and stats_id < st.stats_id))), 114)
END
ELSE -- No Stats Date, which means statistcs were not updated. Only store the overall duration in the last stats_id
CASE
When st.stats_id= (select max(stats_id) from sys.stats where object_id = obj.object_id)
THEN CONVERT(varchar(12),@EndTime - @StartTime, 114)-- Only save duration for the last stats_id since no stats were updated
ELSE ''
END
END as Duration,
CASE
WHEN STATS_DATE(obj.object_id, stats_id) IS NOT NULL
THEN CONVERT(varchar(12),STATS_DATE(obj.object_id, stats_id) - @StartTime, 114)
ELSE
CASE
When st.stats_id= (select max(stats_id) from sys.stats where object_id = obj.object_id)
THEN CONVERT(varchar(12),@EndTime - @StartTime, 114)-- Only save duration for the last stats_id since no stats were updated
ELSE ''
END
END as Elapsed_Time,
(Select sum(row_count) From sys.dm_db_partition_stats Where object_id = obj.object_id and index_id in (0,1)),
@Sample
FROM sys.objects obj
JOIN sys.stats st
ON obj.object_id = st.object_id
LEFT JOIN sys.indexes ind
ON obj.object_id = ind.object_id
AND st.name = ind.name
LEFT JOIN sys.schemas sch
ON obj.schema_id = sch.schema_id
WHERE Object_Name(obj.object_id) = @ObjectName
And sch.name = @SchemaName
Service Manager has all sorts of deadlock issues, constantly deadlocking its own processing.
April 21, 2016 at 9:48 am
sysschobjs is a base table that lies behind sys.objects, sys.indexes, and a bunch of other system views, so all the references to sys.objects, sys.indexes and such are why that INSERT would take out locks on sysschobjs.
However, I'm not sure why that query would be taking any U locks.
Is it possible for you to post the full deadlock xml?
Cheers!
April 21, 2016 at 10:11 am
That's the part that confuses me. The deadlock graph shows MODE: U for the victim, but the Service Manager process is MODE: X. Not sure why my insert would be an Update lock.
April 21, 2016 at 10:51 am
That's why I'd like to see the full deadlock graph, if possible. Just from this information the only thing I could guess is that it's run in a transaction and a previous statement had taken the U locks.
Cheers!
April 21, 2016 at 12:00 pm
<TextData>
<deadlock-list>
<deadlock victim="process3482188">
<process-list>
<process id="process3482188" taskpriority="0" logused="0" waitresource="OBJECT: 10:1163151189:0 " waittime="3710" ownerId="5047445652" transactionname="WstrObjnameI4I4" lasttranstarted="2016-04-21T10:08:19.440" XDES="0x1dd3c5f740" lockMode="Sch-S" schedulerid="7" kpid="6536" status="suspended" spid="174" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2016-04-21T09:56:29.750" lastbatchcompleted="2016-04-21T09:56:29.750" lastattention="1900-01-01T00:00:00.750" clientapp="SQLAgent - TSQL JobStep (Job 0xB5F26A398617634EABB901786809BE73 : Step 1)" hostname="XX-XXXXV12" hostpid="6136" loginname="Domain1\SQL" isolationlevel="read committed (2)" xactid="5047442605" currentdb="10" lockTimeout="4294967295" clientoption1="538968096" clientoption2="128056">
<executionStack>
<frame procname="master.dbo.sp_wb_Run_Update_Statistics" line="246" stmtstart="19222" stmtend="25732" sqlhandle="0x03000100f4a45555e1cda300efa5000001000000000000000000000000000000000000000000000000000000">
Insert Into DBA_HOME.dbo.Table_Statistics
(
ExecutionId,
DBName,
SchemaName,
ObjectName,
Objecttype,
StatsName,
StatsType,
StatsDesc,
StatsId,
CreateDate,
Duration,
Elapsed_Time,
RecordCount,
ScanSample
)
SELECT@ExecutionId,
@DBName,
LEFT(sch.name,50),-- Schema Name
obj.name,-- Object Name
obj.type,-- Object Type
LEFT(st.name,150),
CASE
WHEN ind.type is NULLThen 0
Else ind.type
END,-- Stats Type
CASE
WHEN ind.type IS NOT NULLTHEN LEFT(ind.type_desc,30)
WHEN ind.type IS NULL AND auto_created = 1THEN 'STATISTIC - AUTO CREATED'
WHEN ind.type IS NULL AND user_created = 1THEN 'STATISTIC - USER CREATED'
ELSE '*** UNKNOWN ***'
END,
stats_id,
STATS_DATE(obj.object_id, stats_id),
-- If processing the first stats_id for the current object, subtract from the start time
-- For all other stats_id subtract the current STATS_DATE from the STATS_DATE of the previo </frame>
<frame procname="unknown" line="1" sqlhandle="0x01000500474bfc1e209eaa250a00000000000000000000000000000000000000000000000000000000000000">
unknown </frame>
<frame procname="mssqlsystemresource.sys.sp_executesql" line="1" stmtstart="-1" sqlhandle="0x0400ff7f427f99d9010000000000000000000000000000000000000000000000000000000000000000000000">
sp_executesql </frame>
<frame procname="DBA_HOME.dbo.usp_wb_Update_Statistics" line="120" stmtstart="8000" stmtend="8090" sqlhandle="0x03000500d4ab884e51fad100e6a5000001000000000000000000000000000000000000000000000000000000">
EXECUTE @Return_Status=sp_executesql @sql </frame>
<frame procname="adhoc" line="3" stmtstart="154" sqlhandle="0x01000500e1e2a817903fd63e0300000000000000000000000000000000000000000000000000000000000000">
EXEC DBA_HOME.dbo.usp_wb_Update_Statistics </frame>
</executionStack>
<inputbuf>
Print 'Starting Update Statistics: ' + Convert(varchar(23),getdate(),121)
EXEC DBA_HOME.dbo.usp_wb_Update_Statistics </inputbuf>
</process>
<process id="process189714928" taskpriority="-10" logused="10304" waitresource="KEY: 10:281474978938880 (de97a1e670d5)" waittime="3688" ownerId="5047421713" transactionname="ALTER INDEX" lasttranstarted="2016-04-21T10:08:19.253" XDES="0xa00672d28" lockMode="X" schedulerid="1" kpid="7848" status="suspended" spid="121" sbid="0" ecid="0" priority="0" trancount="1" lastbatchstarted="2016-04-21T10:08:19.213" lastbatchcompleted="2016-04-21T10:08:19.213" lastattention="1900-01-01T00:00:00.213" clientapp="SC DAL--DWMaintenance" hostname="XXXXX01" hostpid="2940" loginname="DOMAIN1\XXXX" isolationlevel="read committed (2)" xactid="5047421713" currentdb="10" lockTimeout="4294967295" clientoption1="673185824" clientoption2="128056">
<executionStack>
<frame procname="adhoc" line="1" sqlhandle="0x01000a00dcdeb73a501e47960200000000000000000000000000000000000000000000000000000000000000">
ALTER INDEX [UniqueIndex] ON [dbo].[ActivityDim] REBUILD WITH (ONLINE=ON, FILLFACTOR=100) </frame>
<frame procname="OMDWDataMart.dbo.DomainTableIndexOptimize" line="193" stmtstart="15198" stmtend="15304" sqlhandle="0x03000a00f4320d6dbd0afc007ba4000001000000000000000000000000000000000000000000000000000000">
EXECUTE (@OnlineStatement) </frame>
<frame procname="OMDWDataMart.dbo.StandardDatasetOptimize" line="103" stmtstart="5980" stmtend="6732" sqlhandle="0x03000a00d8c3dd70ee0afc007ba4000001000000000000000000000000000000000000000000000000000000">
EXEC DomainTableIndexOptimize
@DatasetId = @DatasetId
,@BlockingMaintenanceStartTime = @BlockingMaintenanceStartTime
,@BlockingMaintenanceDurationMinutes = @BlockingMaintenanceDurationMinutes
--********************************************************
-- Insert new optimization work items
-- groom optimization history </frame>
</executionStack>
<inputbuf>
Proc [Database Id = 10 Object Id = 1893581784] </inputbuf>
</process>
</process-list>
<resource-list>
<objectlock lockPartition="0" objid="1163151189" subresource="FULL" dbid="10" objectname="OMDWDataMart.dbo.ActivityDim" id="lockafce05a80" mode="Sch-M" associatedObjectId="1163151189">
<owner-list>
<owner id="process189714928" mode="Sch-M" />
</owner-list>
<waiter-list>
<waiter id="process3482188" mode="Sch-S" requestType="wait" />
</waiter-list>
</objectlock>
<keylock hobtid="281474978938880" dbid="10" objectname="OMDWDataMart.sys.sysschobjs" indexname="clst" id="lock8723d1200" mode="U" associatedObjectId="281474978938880">
<owner-list>
<owner id="process3482188" mode="S" />
</owner-list>
<waiter-list>
<waiter id="process189714928" mode="X" requestType="convert" />
</waiter-list>
</keylock>
</resource-list>
</deadlock>
</deadlock-list>
</TextData>)
April 21, 2016 at 12:02 pm
Here is the deadlock graph from our most recent deadlock. The log information from my earlier post is for the same type of deadlock, but at a different time of day.
April 21, 2016 at 12:05 pm
Ah, ok, as I read it that makes more sense.
The INSERT only has an S lock.
The REBUILD has the U lock and is trying to convert it to an X lock.
Cheers!
EDIT: That graph in the jpg seems to be a different sort of deadlock. It's on a user table, not sys.sysschobjs.
It also has two held X locks blocking two requests for S locks. The one with the INSERT and REBUILD had the REBUILD's Sch-M lock blocking the INSERT...SELECT's Sch-S on ActivityDim (the table being REBUILT; the Sch-S taken by the INSERT...SELECT is from STATS_DATE()), and the INSERT...SELECT's S lock blocking the REBUILD's U-to-X conversion.
It's a different object and a different locking pattern.
April 21, 2016 at 1:10 pm
I completely missed the REBUILD. Now it makes sense. It didn't show up in previous deadlocks, but I enabled a couple TRACE flags today for more details so apparently that helped. We'll check with our System Center team to see why it's generating so many REBUILDs. Sounds like an incorrect configuration.
Thanks again
Viewing 8 posts - 1 through 7 (of 7 total)
You must be logged in to reply to this topic. Login to reply