sql-server – 阻塞进程报告中的空阻塞进程

我正在使用扩展事件收集阻止的进程报告,并且由于某些原因,在某些报告中阻塞进程节点为空.这是完整的xml：

<blocked-process-report monitorLoop="383674">
 <blocked-process>
  <process id="processa7bd5b868" taskpriority="0" logused="106108620" waitresource="KEY: 6:72057613454278656 (8a2f7bc2cd41)" waittime="25343" ownerId="1051989016" transactionname="user_transaction" lasttranstarted="2017-03-20T09:30:38.657" XDES="0x21f382d9c8" lockMode="X" schedulerid="7" kpid="15316" status="suspended" spid="252" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2017-03-20T09:39:15.853" lastbatchcompleted="2017-03-20T09:39:15.850" lastattention="1900-01-01T00:00:00.850" clientapp="Microsoft Dynamics AX" hostname="***" hostpid="1348" loginname="***" isolationlevel="read committed (2)" xactid="1051989016" currentdb="6" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
   <executionStack>
    <frame line="1" stmtstart="40" sqlhandle="0x02000000f7def225b0edaecd8744b453ce09bdcff9b291f50000000000000000000000000000000000000000" />
    <frame line="1" sqlhandle="0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000" />
   </executionStack>
   <inputbuf>
(@P1 bigint,@P2 int)DELETE FROM DIMENSIONFOCUSUNPROCESSEDTRANSACTIONS WHERE ((PARTITION=5637144576) AND ((FOCUSDIMENSIONHIERARCHY=@P1) AND (STATE=@P2)))   </inputbuf>
  </process>
 </blocked-process>
 <blocking-process>
  <process />
 </blocking-process>
</blocked-process-report>

这个hobt_id所属的索引的索引定义是

CREATE UNIQUE CLUSTERED INDEX [I_7402FOCUSDIMENSIONHIERARCHYIDX] ON [dbo].[DIMENSIONFOCUSUNPROCESSEDTRANSACTIONS]
(
    [PARTITION] ASC,[FOCUSDIMENSIONHIERARCHY] ASC,[STATE] ASC,[GENERALJOURNALENTRY] ASC
)WITH (PAD_INDEX = OFF,STATISTICS_NORECOMPUTE = OFF,SORT_IN_TEMPDB = OFF,IGNORE_DUP_KEY = OFF,DROP_EXISTING = OFF,ONLINE = OFF,ALLOW_ROW_LOCKS = ON,ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
GO

没有涉及分区,这是表定义：

CREATE TABLE [dbo].[DIMENSIONFOCUSUNPROCESSEDTRANSACTIONS](
    [FOCUSDIMENSIONHIERARCHY] [bigint] NOT NULL DEFAULT ((0)),[GENERALJOURNALENTRY] [bigint] NOT NULL DEFAULT ((0)),[STATE] [int] NOT NULL DEFAULT ((0)),[RECVERSION] [int] NOT NULL DEFAULT ((1)),[PARTITION] [bigint] NOT NULL DEFAULT ((5637144576.)),[RECID] [bigint] NOT NULL,CONSTRAINT [I_7402RECID] PRIMARY KEY NONCLUSTERED 
(
    [RECID] ASC
)WITH (PAD_INDEX = OFF,ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY]

GO

ALTER TABLE [dbo].[DIMENSIONFOCUSUNPROCESSEDTRANSACTIONS]  WITH CHECK ADD CHECK  (([RECID]<>(0)))
GO

在整个数据库中的任何表上都没有定义触发器或外键.

确切的sql Server构建是：

Microsoft sql Server 2012 (SP3-CU4) (KB3165264) – 11.0.6540.0 (X64)
Jun 23 2016 17:45:11 Copyright (c) Microsoft Corporation Enterprise
Edition: Core-based Licensing (64-bit) on Windows NT 6.3 (Build
14393: ) (Hypervisor)

扩展事件非常简单,只需记录被阻止的进程报告：

CREATE EVENT SESSION [Dynperf_Blocking_Data] ON SERVER 
ADD EVENT sqlserver.blocked_process_report(
    ACTION(package0.collect_system_time,sqlserver.client_hostname,sqlserver.context_info)),ADD EVENT sqlserver.lock_escalation(
    ACTION(package0.collect_system_time,ADD EVENT sqlserver.xml_deadlock_report(
    ACTION(package0.collect_system_time,sqlserver.context_info)) 
ADD TARGET package0.event_file(SET filename=N'F:\sqlTrace\Dynamics_Blocking.xel',max_file_size=(100),max_rollover_files=(10))
WITH (MAX_MEMORY=32768 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=5 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=PER_NODE,TRACK_CAUSALITY=ON,STARTUP_STATE=ON)
GO

数据库在Read Committed Snapshot Isolation中配置,并且最大并行度设置为1.这是服务器配置：

+------------------------------------+-------+
|                name                | value |
+------------------------------------+-------+
| access check cache bucket count    |     0 |
| access check cache quota           |     0 |
| Ad Hoc Distributed Queries         |     0 |
| affinity I/O mask                  |     0 |
| affinity mask                      |     0 |
| affinity64 I/O mask                |     0 |
| affinity64 mask                    |     0 |
| Agent XPs                          |     1 |
| allow updates                      |     0 |
| backup compression default         |     1 |
| blocked process threshold (s)      |     2 |
| c2 audit mode                      |     0 |
| clr enabled                        |     0 |
| common criteria compliance enabled |     0 |
| contained database authentication  |     0 |
| cost threshold for parallelism     |     5 |
| cross db ownership chaining        |     0 |
| cursor threshold                   |    -1 |
| Database Mail XPs                  |     1 |
| default full-text language         |  1033 |
| default language                   |     0 |
| default trace enabled              |     1 |
| disallow results from triggers     |     0 |
| EKM provider enabled               |     0 |
| filestream access level            |     0 |
| fill factor (%)                    |     0 |
| ft crawl bandwidth (max)           |   100 |
| ft crawl bandwidth (min)           |     0 |
| ft notify bandwidth (max)          |   100 |
| ft notify bandwidth (min)          |     0 |
| index create memory (KB)           |     0 |
| in-doubt xact resolution           |     0 |
| lightweight pooling                |     0 |
| locks                              |     0 |
| max degree of parallelism          |     1 |
| max full-text crawl range          |     4 |
| max server memory (MB)             | 65536 |
| max text repl size (B)             | 65536 |
| max worker threads                 |     0 |
| media retention                    |     0 |
| min memory per query (KB)          |  1024 |
| min server memory (MB)             |     0 |
| nested triggers                    |     1 |
| network packet size (B)            |  4096 |
| Ole Automation Procedures          |     0 |
| open objects                       |     0 |
| optimize for ad hoc workloads      |     1 |
| PH timeout (s)                     |    60 |
| precompute rank                    |     0 |
| priority boost                     |     0 |
| query governor cost limit          |     0 |
| query wait (s)                     |    -1 |
| recovery interval (min)            |     0 |
| remote access                      |     1 |
| remote admin connections           |     0 |
| remote login timeout (s)           |    10 |
| remote proc trans                  |     0 |
| remote query timeout (s)           |   600 |
| Replication XPs                    |     0 |
| scan for startup procs             |     1 |
| server trigger recursion           |     1 |
| set working set size               |     0 |
| show advanced options              |     1 |
| SMO and DMO XPs                    |     1 |
| transform noise words              |     0 |
| two digit year cutoff              |  2049 |
| user connections                   |     0 |
| user options                       |     0 |
| xp_cmdshell                        |     0 |
+------------------------------------+-------+

我运行了一段时间的服务器端跟踪,我在跟踪文件中获得了与使用扩展事件相同的空节点.
此阻止的进程报告是使用另一台运行Dynamics AX的服务器上的服务器端跟踪捕获的,因此它不是特定于此服务器或构建的.

<blocked-process-report monitorLoop="1327922">
 <blocked-process>
  <process id="processbd9839848" taskpriority="0" logused="1044668" waitresource="KEY: 5:72057597098328064 (1d7966fe609a)" waittime="316928" ownerId="3415555263" transactionname="user_transaction" lasttranstarted="2017-03-27T07:59:29.290" XDES="0x1c1c0c3b0" lockMode="U" schedulerid="3" kpid="25236" status="suspended" spid="165" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2017-03-27T07:59:47.873" lastbatchcompleted="2017-03-27T07:59:47.873" lastattention="2017-03-27T07:58:01.490" clientapp="Microsoft Dynamics AX" hostname="***" hostpid="11072" loginname="***" isolationlevel="read committed (2)" xactid="3415555263" currentdb="5" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
   <executionStack>
    <frame line="1" stmtstart="236" stmtend="676" sqlhandle="0x020000004d6830193d42a167edd195c201f40bb772e9ece20000000000000000000000000000000000000000"/>
   </executionStack>
   <inputbuf>
(@P1 numeric(32,16),@P2 int,@P3 bigint,@P4 nvarchar(5),@P5 nvarchar(36),@P6 int,@P7 numeric(32,@P8 bigint,@P9 int)UPDATE PRODCALCTRANS SET REALCOSTAMOUNT=@P1,RECVERSION=@P2 WHERE (((((((PARTITION=@P3) AND (DATAAREAID=@P4)) AND (COLLECTREFPRODID=@P5)) AND (COLLECTREFLEVEL=@P6)) AND (LINENUM=@P7)) AND (RECID=@P8)) AND (RECVERSION=@P9))   </inputbuf>
  </process>
 </blocked-process>
 <blocking-process>
  <process/>
 </blocking-process>
</blocked-process-report>

有没有人对这些报道有解释？阻止查询的是什么？

如果我在锁定早已消失后查看报告,有没有办法找出发生了什么？

添加可能有用的一件事是这些查询是通过sp_cursorprepare和sp_cursorexecute运行的

到目前为止,我还没有能够重现它,它似乎是随机发生的,但经常发生.

它发生在几个(不同构建版本)和几个表/查询的实例上,所有这些都与Dynamics AX相关.

当时在后台没有发生索引或其他数据库维护作业.

使用answer by srutzky中提供的代码,我能够捕获与此阻止的进程报告相关的一些日志记录：

<blocked-process-report monitorLoop="1621637">
 <blocked-process>
  <process id="processd06909c28" taskpriority="0" logused="0" waitresource="KEY: 5:72057597585719296 (d2d87c26d920)" waittime="78785" ownerId="4436575948" transactionname="user_transaction" lasttranstarted="2017-04-13T07:39:17.590" XDES="0x3219d034e0" lockMode="U" schedulerid="3" kpid="133792" status="suspended" spid="106" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2017-04-13T07:39:17.657" lastbatchcompleted="2017-04-13T07:39:17.657" lastattention="1900-01-01T00:00:00.657" clientapp="Microsoft Dynamics AX" hostname="****" hostpid="11800" loginname="****" isolationlevel="read committed (2)" xactid="4436575948" currentdb="5" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
   <executionStack>
    <frame line="1" stmtstart="72" stmtend="256" sqlhandle="0x0200000076a6a92ab1256af09321b056ab243f187342f9960000000000000000000000000000000000000000"/>
    <frame line="1" sqlhandle="0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"/>
   </executionStack>
   <inputbuf>
(@P1 int,@P4 int)UPDATE PRODROUTEJOB SET JOBSTATUS=@P1,RECVERSION=@P2 WHERE ((RECID=@P3) AND (RECVERSION=@P4))   </inputbuf>
  </process>
 </blocked-process>
 <blocking-process>
  <process/>
 </blocking-process>
</blocked-process-report>

这可以在该时间周围的相同资源的日志记录表中找到：Gist because of character limit

进一步调查显示,在报告前后有一个空的阻塞过程,我有相同的资源ID报告,它有阻塞进程节点：

<blocked-process-report monitorLoop="1621636">
 <blocked-process>
  <process id="processd06909c28" taskpriority="0" logused="0" waitresource="KEY: 5:72057597585719296 (d2d87c26d920)" waittime="73765" ownerId="4436575948" transactionname="user_transaction" lasttranstarted="2017-04-13T07:39:17.590" XDES="0x3219d034e0" lockMode="U" schedulerid="3" kpid="133792" status="suspended" spid="106" sbid="0" ecid="0" priority="0" trancount="2" lastbatchstarted="2017-04-13T07:39:17.657" lastbatchcompleted="2017-04-13T07:39:17.657" lastattention="1900-01-01T00:00:00.657" clientapp="Microsoft Dynamics AX" hostname="***" hostpid="11800" loginname="***" isolationlevel="read committed (2)" xactid="4436575948" currentdb="5" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
   <executionStack>
    <frame line="1" stmtstart="72" stmtend="256" sqlhandle="0x0200000076a6a92ab1256af09321b056ab243f187342f9960000000000000000000000000000000000000000"/>
    <frame line="1" sqlhandle="0x0000000000000000000000000000000000000000000000000000000000000000000000000000000000000000"/>
   </executionStack>
   <inputbuf>
(@P1 int,RECVERSION=@P2 WHERE ((RECID=@P3) AND (RECVERSION=@P4))   </inputbuf>
  </process>
 </blocked-process>
 <blocking-process>
  <process status="sleeping" spid="105" sbid="0" ecid="0" priority="0" trancount="1" lastbatchstarted="2017-04-13T07:40:31.417" lastbatchcompleted="2017-04-13T07:40:31.423" lastattention="1900-01-01T00:00:00.423" clientapp="Microsoft Dynamics AX" hostname="**" hostpid="11800" loginname="**" isolationlevel="read committed (2)" xactid="4436165115" currentdb="5" lockTimeout="4294967295" clientoption1="671088672" clientoption2="128056">
   <executionStack/>
   <inputbuf>
(@P1 bigint,@P2 nvarchar(5),@P4 bigint,@P5 nvarchar(11),@P7 nvarchar(21),@P8 datetime2)SELECT T1.REGDATETIME,T1.REGDATETIMETZID,T1.WORKERPILOT,T1.WORKER,T1.WRKCTRIDPILOT,T1.REGTYPE,T1.PROFILEDATE,T1.JOBID,T1.JOBIDABS,T1.MATCHRECIDSTARTSTOP,T1.JOBACTIVE,T1.RESNO,T1.STARTITEMS,T1.GOODITEMS,T1.SCRAPITEMS,T1.FINISHEDCODE,T1.TMPGOODITEMS,T1.TMPSCRAPITEMS,T1.SYSMRPUPDATEREQUEST,T1.ERROR,T1.ERRORTXT,T1.TMPSTARTITEMS,T1.AUTOSTAMP,T1.ERRORSPECIFICATION,T1.COSTCATEGORY,T1.ONCALLACTIVITY,T1.TERMINALID,T1.PDSCWGOODITEMS,T1.PDSCWSCRAPITEMS,T1.PDSCWSTARTITEMS,T1.RETAILTERMINALID,T1.MODIFIEDDATETIME,T1.RECVERSION,T1.PARTITION,T1.RECID FROM JMGTERMREG T1 WHERE (((PARTITION=@P1) AND (DATAAREAID=@P2)) AND (((((WORKER=@P3) OR ((WORKER=@P4) AND (WRKCTRIDPILOT=@P5))) AND (REGTYPE=@P6)) AND (JOBID=@P7)) AND (REGDATETIME&gt;=@P8))) ORDER BY T1.REGDATETIME   </inputbuf>
  </process>
 </blocking-process>
</blocked-process-report>

使用srutzky提供的新脚本收集了新数据.
It’s posted on github因为邮寄长度最大.

由于最初发布的数据没有两个会话ID,因此on github again发布了一些新数据

新数据包括连接on github

解决方法

我现在无法测试这个理论,但是基于 most recent capture data posted to GitHub,我会说你的原因< process> node是空的,它需要当前正在运行的请求(许多属性在sys.dm_exec_requests中找到而不在sys.dm_exec_sessions中),并且没有当前正在运行的请求,它无法报告任何细节,类似于如何执行INNER sys.dm_exec_requests和sys.dm_exec_sessions之间的JOIN将排除会话处于活动状态但由于没有当前请求而处于空闲状态的行.

查看顶部数据集(monitorLoop值：1748823,1748824,1748825和1748827),我们可以看到以下内容：

>在每种情况下,被阻止进程的id都是相同的：process2552c1fc28,唯一不同的属性是waittime(可以理解).
>阻塞进程节点的属性显示lastbatchstarted和lastbatchcompleted的差异
>阻塞进程节点的属性显示spid和xactid的相同值

那么,阻塞过程的SessionID和TransactionID如何在4个不同的查询批次中相同？很简单,启动了显式事务,然后执行了这些批处理.并且因为这些是单独的批次,所以它们之间有时间被提交,此时没有当前请求,因此没有要显示的进程信息(但是会话和事务仍然存在).

为了对此进行额外的研究,您可以通过将以下T-sql放在sql Server代理“Transaction-sql脚本(T-sql)”作业步骤中,从sys.dm_exec_requests和sys.dm_tran_locks中捕获有用的信息,“数据库”是您正在研究的那个(在这种情况下,它是ID为6的那个),并安排此作业每10秒运行一次.下面的T-sql将在同一个数据库中创建两个表(如果它们不存在),然后如果任何请求阻塞自身,或者如果它是一个被阻止的删除或更新操作,则将填充“请求”表.如果找到任何请求,它将尝试捕获：

>关于阻塞过程的会话和请求信息(此部分不假设存在活动请求,因此右键至少获取会话信息)
>阻止和(希望)阻止进程的连接信息.
>对于那些相同的session_id的当前锁定(请记住,锁定信息不能保证100％准确,因为该信息可以在执行这两个语句之间的时间内发生变化;但是,信息足够经常足够值得捕捉).此部分目前已被注释掉.

sql Server代理T-sql作业步骤：

-- !! Remember to set the "Database" for the T-sql Job Step to
--    the DB that has database_id = 6 !!
SET NOCOUNT ON;
IF (OBJECT_ID(N'dbo.tmpBlockingResearch_Requests') IS NULL)
BEGIN
  -- Create requests capture table
  SELECT SYSDATETIME() AS [CaptureTime],req.*,ses.login_time,ses.[host_name],ses.[program_name],ses.host_process_id,ses.client_version,ses.client_interface_name,ses.security_id,ses.login_name,ses.nt_domain,ses.nt_user_name,ses.memory_usage,ses.total_scheduled_time,ses.endpoint_id,ses.last_request_start_time,ses.last_request_end_time,ses.is_user_process,ses.original_security_id,ses.original_login_name,ses.last_successful_logon,ses.last_unsuccessful_logon,ses.unsuccessful_logons,ses.authenticating_database_id
  INTO   dbo.tmpBlockingResearch_Requests
  FROM   sys.dm_exec_requests req
  INNER JOIN sys.dm_exec_sessions ses
          ON ses.[session_id] = req.[session_id]
  WHERE  1 = 0;
END;

IF (OBJECT_ID(N'dbo.tmpBlockingResearch_Connections') IS NULL)
BEGIN
  -- Create connections capture table
  SELECT SYSDATETIME() AS [CaptureTime],con.*
  INTO   dbo.tmpBlockingResearch_Connections
  FROM   sys.dm_exec_connections con
  WHERE  1 = 0;
END;

IF (OBJECT_ID(N'dbo.tmpBlockingResearch_Locks') IS NULL)
BEGIN
  -- Create locks capture table
  SELECT SYSDATETIME() AS [CaptureTime],loc.*
  INTO   dbo.tmpBlockingResearch_Locks
  FROM   sys.dm_tran_locks loc
  WHERE  1 = 0;
END;
---------------------------------
DECLARE @SessionIDs TABLE (SessionID SMALLINT NOT NULL,BlockingSessionID SMALLINT NOT NULL);

INSERT INTO dbo.tmpBlockingResearch_Requests
OUTPUT inserted.[session_id],inserted.[blocking_session_id]
INTO   @SessionIDs ([SessionID],[BlockingSessionID])
  SELECT SYSDATETIME() AS [CaptureTime],ses.authenticating_database_id
  FROM   sys.dm_exec_requests req
  INNER JOIN sys.dm_exec_sessions ses
          ON ses.[session_id] = req.[session_id]
  WHERE ses.[is_user_process] = 1
  AND   req.[database_id] = DB_ID()
  AND   (
          req.blocking_session_id IN (req.[session_id],-2,-3,-4)
    OR   (req.[command] IN (N'DELETE',N'UPDATE') AND req.[blocking_session_id] > 0)
        );

-- Get at least session info,if not also request info,on blocking process
INSERT INTO dbo.tmpBlockingResearch_Requests
  SELECT SYSDATETIME() AS [CaptureTime],ses.authenticating_database_id
  FROM   sys.dm_exec_requests req
  RIGHT JOIN sys.dm_exec_sessions ses
          ON ses.[session_id] = req.[session_id]
  WHERE ses.[session_id] IN (SELECT DISTINCT [BlockingSessionID] FROM @SessionIDs);

-- If any rows are captured this time,try to capture their connection info
INSERT INTO dbo.tmpBlockingResearch_Connections
  SELECT SYSDATETIME() AS [CaptureTime],con.*
  FROM   sys.dm_exec_connections con
  WHERE  con.[session_id] IN (
                              SELECT [SessionID]
                              FROM @SessionIDs
                              UNION -- No "ALL" so it does DISTINCT
                              SELECT [BlockingSessionID]
                              FROM @SessionIDs
                             );

/*
-- If any rows are captured this time,try to capture their lock info
INSERT INTO dbo.tmpBlockingResearch_Locks
  SELECT SYSDATETIME() AS [CaptureTime],loc.*
  FROM   sys.dm_tran_locks loc
  WHERE  loc.[request_session_id] IN (
                                      SELECT [SessionID]
                                      FROM @SessionIDs
                                      UNION -- No "ALL" so it does DISTINCT
                                      SELECT [BlockingSessionID]
                                      FROM @SessionIDs
                                     );
 */

我认为你应该能够通过打开一个查询选项卡并执行以下内容来重现这一点：

CREATE TABLE dbo.tmp (Col1 INT);
BEGIN TRAN;
INSERT INTO dbo.tmp (Col1) VALUES (1);

然后,打开第二个查询选项卡并执行以下操作：

UPDATE dbo.tmp
SET    Col1 = 2
WHERE  Col1 = 1;

附：只是要说明,唯一没有意义的是请求&会话信息 – dbo.tmpBlockingResearch_Requests – 仍然不包含阻塞会话的行.但我知道table变量中有阻塞会话ID,因为它确实拉入了两个SessionID的锁.这可能指向允许事务在客户端的“连接”关闭后保持打开但由于连接池仍然保持连接的情况.

原文链接：https://www.f2er.com/mssql/79700.html

sql-server – 阻塞进程报告中的空阻塞进程

解决方法

猜你在找的MsSQL相关文章