Proses pemblokiran kosong dalam laporan proses yang diblokir

28

Saya mengumpulkan laporan proses yang diblokir menggunakan Extended Events, dan untuk beberapa alasan dalam beberapa laporan blocking-processnode kosong. Ini adalah xml lengkap:

<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>

Definisi indeks untuk indeks yang dimiliki hobt_id ini adalah

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

Tidak ada partisi yang terlibat, ini adalah definisi tabel:

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, STATISTICS_NORECOMPUTE = OFF, IGNORE_DUP_KEY = OFF, ALLOW_ROW_LOCKS = ON, ALLOW_PAGE_LOCKS = ON) ON [PRIMARY]
) ON [PRIMARY]

GO

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

Tidak ada pemicu atau kunci asing yang ditentukan pada tabel di seluruh database.

Membangun SQL Server yang tepat adalah:

Microsoft SQL Server 2012 (SP3-CU4) (KB3165264) - 11.0.6540.0 (X64)
Jun 23 2016 17:45:11 Hak cipta (c) Microsoft Corporation Enterprise Edition: Lisensi Berbasis Core (64-bit) pada Windows NT 6.3 ( Build 14393:) (Hypervisor)

Acara yang diperpanjang cukup sederhana, hanya mencatat laporan proses yang diblokir:

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,sqlserver.client_hostname,sqlserver.context_info)),
ADD EVENT sqlserver.xml_deadlock_report(
    ACTION(package0.collect_system_time,sqlserver.client_hostname,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

Basis data dikonfigurasikan dalam Isolasi Snapshot yang Dibaca Baca, dan derajat paralelisme maksimum ditetapkan ke 1. Ini adalah konfigurasi server:

+------------------------------------+-------+
|                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 |
+------------------------------------+-------+

Saya menjalankan jejak sisi server untuk sementara waktu dan saya mendapatkan node kosong yang sama dalam file jejak seperti yang saya lakukan menggunakan peristiwa yang diperluas.
Laporan proses yang diblokir ini ditangkap menggunakan jejak sisi server di server lain yang juga menjalankan Dynamics AX, sehingga tidak khusus untuk server atau build ini.

<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,16),@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>

Adakah yang punya penjelasan untuk laporan ini? Apa yang memblokir permintaan?

Apakah ada cara untuk mengetahui apa yang terjadi jika saya melihat laporan setelah kunci sudah lama hilang?

Satu hal yang mungkin berguna untuk ditambahkan adalah bahwa kueri ini dijalankan melalui sp_cursorprepare dansp_cursorexecute

Sejauh ini saya belum bisa mereproduksi, sepertinya itu terjadi secara acak tetapi sangat sering.

Ini terjadi pada beberapa instance (dari build yang berbeda) dan beberapa tabel / query, semua yang berhubungan dengan Dynamics AX.

Tidak ada indeks atau pekerjaan pemeliharaan basis data lainnya yang terjadi di latar belakang pada saat itu.

Menggunakan kode yang disediakan dalam jawaban oleh srutzky, saya dapat menangkap beberapa logging terkait dengan laporan proses yang diblokir ini:

<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,@P2 int,@P3 bigint,@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>

Ini ditemukan di tabel logging untuk sumber daya yang sama sekitar waktu itu: Intisari karena batas karakter

Investigasi lebih lanjut menunjukkan bahwa sebelum dan sesudah laporan dengan proses pemblokiran kosong saya memiliki laporan untuk resourceid yang sama yang memiliki simpul proses pemblokiran:

<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,@P2 int,@P3 bigint,@P4 int)UPDATE PRODROUTEJOB SET JOBSTATUS=@P1,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),@P3 bigint,@P4 bigint,@P5 nvarchar(11),@P6 int,@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>

Menggunakan skrip baru yang disediakan oleh srutzky, data baru telah dikumpulkan. Itu diposting di github karena panjang posting maksimum.

Karena data yang awalnya diposting tidak memiliki kedua sesi id, beberapa data baru telah diposting di github lagi

Data baru termasuk koneksi di github

Tom V - Tim Monica
sumber

Jawaban:

6

Saya tidak dapat menguji teori ini saat ini, tetapi berdasarkan pada data penangkapan terbaru yang diposting ke GitHub , saya akan mengatakan bahwa alasan bahwa <process>simpul Anda kosong adalah karena memerlukan permintaan yang sedang berjalan (banyak atribut ditemukan di sys.dm_exec_requestsdan tidak di sys.dm_exec_sessions) dan tanpa permintaan yang sedang berjalan, tidak dapat melaporkan detail, mirip dengan bagaimana melakukan INNER JOINantara sys.dm_exec_requestsdansys.dm_exec_sessions akan mengecualikan baris di mana Sesi aktif tetapi menganggur karena tidak ada permintaan saat ini.

Melihat kumpulan data teratas ( monitorLoopnilai: 1748823, 1748824, 1748825, dan 1748827) kita dapat melihat yang berikut ini:

  • yang iddari blocked-processadalah sama dalam setiap kasus: process2552c1fc28 , dan satu-satunya atribut yang berbeda adalahwaittime (dimengerti).
  • atribut dari blocking-processnode menunjukkan perbedaan pada keduanya lastbatchstarteddanlastbatchcompleted
  • atribut dari blocking-processnode menunjukkan nilai identik untuk spiddanxactid

Jadi, bagaimana SessionID dan TransactionID dari proses pemblokiran bisa sama di 4 batch kueri yang berbeda? Mudah, transaksi eksplisit dimulai dan kemudian batch ini dieksekusi. Dan karena ini adalah kumpulan yang terpisah, ada waktu di antara mereka yang dikirimkan, pada titik mana tidak ada permintaan saat ini, maka tidak ada info proses untuk ditampilkan (tetapi sesi dan transaksi masih ada).

Untuk melakukan penelitian tambahan mengenai hal ini, Anda dapat menangkap informasi yang bermanfaat dari sys.dm_exec_requestsdan sys.dm_tran_locksdengan menempatkan T-SQL berikut dalam Agen Server SQL "Skrip Transaksi-SQL (T-SQL)" Langkah Pekerjaan, mengatur "Basis Data" menjadi yang sedang Anda teliti (dalam hal ini adalah yang memiliki ID 6), dan menjadwalkan pekerjaan ini untuk berjalan setiap 10 detik. T-SQL di bawah ini akan membuat dua tabel dalam DB yang sama jika tidak ada dan kemudian akan mengisi tabel "Permintaan" jika ada permintaan yang memblokir sendiri, atau jika itu adalah operasi Hapus atau Perbarui yang sedang diblokir . Jika ada permintaan yang ditemukan, itu akan mencoba menangkap:

  • Info Sesi dan Permintaan tentang proses pemblokiran (bagian ini tidak menganggap bahwa ada Permintaan aktif, karenanya RIGHT JOIN untuk setidaknya mendapatkan info Sesi)
  • Info koneksi untuk proses pemblokiran dan (semoga).
  • kunci saat ini untuk session_id yang sama (hanya perlu diingat bahwa info kunci tidak dijamin 100% akurat karena info itu dapat berubah dalam waktu antara dua pernyataan yang dieksekusi; tetap saja, info tersebut cukup baik sering cukup untuk menjadi layak ditangkap). Bagian ini sedang dikomentari.

Langkah Pekerjaan T-SQL SQL Server Agent:

-- !! 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], 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
  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], 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
  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
                                     );
 */

Saya pikir Anda harus dapat mereproduksi ini dengan membuka satu tab permintaan dan menjalankan yang berikut:

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

Lalu, buka tab kueri kedua dan jalankan yang berikut:

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

PS Hanya untuk menyatakannya, satu-satunya hal yang tidak masuk akal adalah bahwa info permintaan & sesi - dbo.tmpBlockingResearch_Requests- masih tidak pernah berisi baris untuk sesi pemblokiran. Namun saya tahu bahwa variabel tabel memiliki id sesi pemblokiran di dalamnya seperti halnya menarik kunci untuk kedua SessionID. Ini bisa mengarah ke skenario di mana Transaksi diizinkan tetap terbuka setelah "koneksi" dari klien ditutup tetapi koneksi tetap dipertahankan karena Connection Pooling.

Solomon Rutzky
sumber
@ TomV Saya telah meninjau data penelitian terbaru dan memiliki teori yang cukup solid. Saya telah memperbarui jawaban saya sesuai dengan itu, termasuk menambahkan bagian ke pertanyaan penelitian saya, jadi tolong ganti SQL langkah pekerjaan dengan pertanyaan baru di sini (saya juga berkomentar di luar permintaan "kunci" karena kami tidak benar-benar membutuhkan data itu sekarang dan ini banyak data). Saya sarankan memotong / menjatuhkan tabel penelitian yang ada untuk memulai dari awal.
Solomon Rutzky
@ TomV, Ok. Dan saya telah memperbarui permintaan repro saya menjadi PEMBARUAN alih-alih SELECT sehingga harus lebih mewakili situasi Anda. Saya juga menambahkan catatan di akhir tentang baris yang hilang di tabel permintaan. Semoga tabel Koneksi baru setidaknya akan mengkonfirmasi keberlanjutan keberadaan SessionID yang memblokir. (PS, saya mulai membersihkan komentar saya di atas).
Solomon Rutzky
Pekerjaan Anda aktif. Saya perlu mencari waktu untuk menguji repro dan menganalisisnya minggu depan
Tom V - Team Monica
Hai Solomon. 2 contoh baru telah diposting di github. Sayangnya saya tidak dapat memicu proses pemblokiran kosong BPR menggunakan case repro yang disediakan.
Tom V - Tim Monica
Tampak sangat cepat karena saya tidak punya banyak waktu. Sepertinya info Koneksi menunjukkan ID sesi pemblokiran masih aktif tetapi tidak ada di tabel sesi. Saya dapat menguji ini nanti, tetapi saya cukup yakin bahwa ini menunjukkan pooling koneksi (koneksi masih ada) dan koneksi ditutup antara perintah namun transaksi jelas terbuka (karena transaction_id selalu sama seperti yang kita lihat terakhir kali). Akan melihat lebih dekat nanti ..
Solomon Rutzky
4

Transaksi yang diblokir dapat terjadi karena eskalasi kunci.

Ini dijelaskan dalam artikel Dukungan Microsoft:

Cara mengatasi masalah pemblokiran yang disebabkan oleh eskalasi kunci di SQL Server

...
Kunci eskalasi tidak menyebabkan sebagian besar masalah pemblokiran. Untuk menentukan apakah eskalasi kunci terjadi sekitar waktu ketika Anda mengalami masalah pemblokiran, mulailah pelacakan SQL Profiler yang mencakup peristiwa Kunci: Eskalasi. Jika Anda tidak melihat Kunci: Kejadian eskalasi, eskalasi kunci tidak terjadi di server Anda dan informasi dalam artikel ini tidak berlaku untuk situasi Anda.

Jika eskalasi kunci terjadi, pastikan bahwa eskalasi kunci meja memblokir pengguna lain
...

Periksa Peristiwa Diperpanjang (file fisik) untuk peristiwa eskalasi kunci yang terjadi sebelum proses diblokir acara .

Menjelaskan

Ada artikel Microsoft Blog yang masuk ke detail lebih lanjut:

Eskalasi dan Pemblokiran Kunci SQL Server

...
Langkah 2: Kumpulkan Eskalasi Kunci dan Acara Laporan Proses yang Diblokir.

Eskalasi kunci dan peristiwa proses laporan yang diblokir tidak secara otomatis ditangkap oleh SQL Server. Untuk mengetahui apakah peristiwa ini terjadi, kita perlu memberitahu SQL Server untuk merekamnya. Tim kami menggunakan Penganalisis Kinerja untuk alat Microsoft Dynamics untuk mengumpulkan informasi itu. Lihat pos ini oleh Rod Hansen untuk informasi lebih lanjut tentang alat dan cara mengumpulkan detail pemblokiran dengannya. Jika Anda hanya ingin menggunakan SQL Server Profiler, peristiwa yang perlu Anda kumpulkan ditunjukkan di bawah ini: ...

Setelah Anda menangkap eskalasi kunci dan proses yang diblokir, Anda harus menentukan apakah eskalasi kunci adalah akar dari proses yang diblokir:

...
Langkah 3: Tinjau Jejak di SQL Server Profiler.

Ada dua indikator utama yang akan memberi tahu Anda jika pemblokiran terkait dengan eskalasi kunci.

Pertama, Anda melihat serangkaian peristiwa eskalasi kunci segera sebelum peristiwa laporan proses yang diblokir. Di bawah ini adalah contoh yang diambil dari jejak yang dihasilkan oleh alat Penganalisa Kinerja untuk alat Microsoft Dynamics. Ini adalah satu hal yang harus dicari dalam penelusuran, tetapi ini saja tidak berarti eskalasi kunci yang menyebabkan pemblokiran. ...

dan selanjutnya

Untuk memverifikasi bahwa pemblokiran sebenarnya terkait dengan eskalasi kunci, Anda perlu melihat detail laporan proses yang diblokir. Di bagian TextData, cari waitresource (lihat tangkapan layar di bawah). Jika waitresource dimulai dengan OBJECT, kami tahu pernyataan diblokir sedang menunggu kunci level tabel untuk dirilis sebelum dapat melanjutkan. Jika waitresource dimulai dengan KUNCI atau PAG alih-alih OBJECT, maka eskalasi kunci tidak terlibat dalam blok tertentu . Eskalasi kunci akan selalu meningkatkan cakupan kunci ke OJBECT terlepas dari mana ia dimulai

Larutan

(hanya jika yang disebutkan di atas cocok)

Solusinya adalah dengan mengaktifkan bendera jejak 1224 yang akan mematikan eskalasi kunci:

Eskalasi dan Pemblokiran Kunci SQL Server

Jika Anda melihat dua hal ini bersama-sama, itu adalah taruhan yang cukup bagus bahwa eskalasi kunci menyebabkan pemblokiran dan Anda mungkin akan mendapat manfaat dari penerapan SQL Server jejak bendera 1224.

Bendera Pelacak SQL Server untuk Dynamics AX

Bendera jejak 1224 menonaktifkan eskalasi kunci berdasarkan jumlah kunci. Mengaktifkan tanda jejak ini dapat mengurangi kemungkinan pemblokiran karena penguncian eskalasi - sesuatu yang telah saya lihat dengan sejumlah implementasi AX. Skenario yang paling umum di mana ini menjadi masalah adalah ketika ada persyaratan untuk Perencanaan Master untuk dijalankan pada siang hari

Menjawab

Pada akhirnya bisa jadi eskalasi kunci adalah penyebab utama dari proses yang diblokir.


Solusi Alternatif (simpul proses kosong)

Setelah penyelidikan lebih lanjut dari beberapa laporan yang diblokir, penjelasan alternatif berikut dapat dibuat.

Peristiwa Diperpanjang menangkap laporan diblokir_process_ yang tidak terkait dengan proses lain pada saat itu.

Ergo: Mereka harus diblokir karena alasan yang berbeda

Saya sarankan Anda menangkap kerangka waktu jenis menunggu dari tampilan sys.dm_os_wait_stats pada SQL Server Anda dan menghubungkan angka-angka dengan laporan yang diblokir_process_laporan yang terjadi selama pengukuran Anda. Paul Randall memiliki skrip yang bagus: Kirimkan statistik tunggu Anda dan dapatkan saran saya serta 30 hari Pluralsight gratis sebagai imbalannya

Skrip menangkap penghitung saat ini, menunggu selama 23 jam (dapat dimodifikasi), menangkap kembali penghitung saat ini dan membandingkannya untuk memberi Anda 95% jenis menunggu terbaik. Anda bisa mencobanya selama 1 jam dan siapkan file XEL.

Anda mungkin menemukan jenis tunggu (mis. LCK_M_SH, ...) yang memberi tahu Anda bahwa penyimpanan Anda lambat dalam penulisan. Atau Anda memiliki beberapa overhead lainnya (mis. CX_PACKET_WAITS, ....). Sesuatu memperlambat pembaruan Anda. Anda kemudian dapat melihat apakah sys.dm_os_wait_stats terkait dengan laporan blocked_process_reports dengan node kosong.

Ada kasus ketika SPID diblokir sedang diblokir oleh SPID yang sama:

Kolom yang diblokir di tabel sysprocesses diisi untuk menunggu latch setelah Anda menginstal SQL Server 2000 SP4

Ketika SPID sedang menunggu kait halaman I / O, Anda mungkin memperhatikan bahwa kolom yang diblokir secara singkat melaporkan bahwa SPID memblokir itu sendiri. Perilaku ini adalah efek samping dari cara kait digunakan untuk operasi I / O pada halaman data. Saat utas mengeluarkan permintaan I / O, SPID yang menerbitkan permintaan I / O memperoleh kait pada halaman. Semua operasi SQL Server 2000 I / O tidak sinkron. Oleh karena itu, SPID akan mencoba untuk mendapatkan kait lain pada halaman yang sama jika SPID yang mengeluarkan permintaan I / O harus menunggu sampai permintaan selesai. Kait kedua ini diblokir oleh kait pertama. Oleh karena itu, kolom yang diblokir melaporkan bahwa SPID memblokir sendiri. Ketika permintaan I / O selesai, kait pertama dilepaskan. Kemudian, permintaan kait kedua dikabulkan.

Jawaban Alternatif

Ini adalah indikasi lebih lanjut bahwa Anda mungkin mengalami masalah IO. Masalah-masalah ini menghasilkan "proses yang diblokir" tetapi tanpa SPID asing terkait. Peristiwa Diperpanjang mungkin tidak melaporkan proses / SPID dalam node yang terpisah.

John alias hot2use
sumber
Saya mungkin salah membaca ini, tetapi tidakkah info ini membuktikan bahwa masalahnya bukan kunci eskalasi? Satu bagian yang dikutip mengatakan "look at the blocked process report details.", dan XML paling atas dalam pertanyaan adalah laporan proses yang diblokir. Selanjutnya, bagian kutipan yang sama itu mengatakan "If waitresource starts with KEY or PAG instead of OBJECT, then lock escalation isn’t involved in that specific block.",, dan XML yang diblokir-proses-laporan muncul waitresource="KEY: 6:72057..... Jadi itu berarti bahwa "kunci eskalasi tidak terlibat" di sini.
Solomon Rutzky
Tidak, Anda TIDAK salah membaca ini. Bagian yang disediakan dalam pertanyaan adalah satu masalah di server ini. Jawaban saya adalah pendekatan global terhadap masalah yang dapat terjadi karena pemblokiran dan penguncian eskalasi. Jika Anda dapat memperbaiki beberapa masalah utama (diblokir_process_reports untuk penguncian tingkat OBJECT), maka masalah yang lebih kecil (diblokir_process_laporan di tingkat lain) dapat menyelesaikan sendiri. Ini adalah alasan mengapa saya juga menambahkan jawaban alternatif kedua.
John aka hot2use