Pusty proces blokowania w raporcie o zablokowanym procesie

28

Zbieram raporty o zablokowanych procesach przy użyciu zdarzeń rozszerzonych iz jakiegoś powodu w niektórych raportach blocking-processwęzeł jest pusty. To jest pełny 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>

Definicja indeksu dla indeksu, do którego należy identyfikator hobt_id, to

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

Brak partycjonowania, oto definicja tabeli:

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

Nie ma żadnych wyzwalaczy ani kluczy obcych zdefiniowanych w żadnej z tabel w całej bazie danych.

Dokładna wersja SQL Server to:

Microsoft SQL Server 2012 (SP3-CU4) (KB3165264) - 11.0.6540.0 (X64)
23 czerwca 2016 17:45:11 Prawa autorskie (c) Microsoft Corporation Enterprise Edition: Licencjonowanie na podstawie rdzenia (64-bitowe) w systemie Windows NT 6.3 ( Kompilacja 14393:) (Hypervisor)

Rozszerzone zdarzenia są dość proste, wystarczy zalogować raporty zablokowanych procesów:

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

Baza danych jest skonfigurowana w trybie Read Committed Snapshot Isolation, a maksymalny stopień równoległości jest ustawiony na 1. Oto konfiguracja serwera:

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

Przez chwilę prowadziłem śledzenie po stronie serwera i otrzymuję te same puste węzły w pliku śledzenia, co przy użyciu zdarzeń rozszerzonych.
Ten zablokowany raport procesu został przechwycony przy użyciu śledzenia po stronie serwera na innym serwerze, na którym również działa Dynamics AX, więc nie jest specyficzny dla tego serwera ani kompilacji.

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

Czy ktoś ma wyjaśnienie tych raportów? Co blokuje zapytanie?

Czy jest jakiś sposób, aby dowiedzieć się, co się dzieje, jeśli patrzę na raporty po tym, jak zamki już dawno minęły?

Jedną z rzeczy, które mogą być przydatne do dodania jest to, że te zapytania są uruchamiane przez sp_cursorprepareisp_cursorexecute

Jak dotąd nie byłem w stanie go odtworzyć, wydaje się, że dzieje się to losowo, ale bardzo często.

Dzieje się tak w kilku instancjach (różnych wersji) i kilku tabelach / zapytaniach, wszystkie związane z Dynamics AX.

W tym czasie nie ma w tle żadnych zadań związanych z utrzymaniem indeksu lub bazy danych.

Korzystając z kodu podanego w odpowiedzi przez srutzky, byłem w stanie przechwycić rejestrowanie związane z tym zablokowanym raportem procesu:

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

Znajduje się to w tabelach rejestrowania dla tego samego zasobu w tym czasie: Gist ze względu na limit znaków

Dalsze dochodzenie pokazuje, że tuż przed raportem z pustym procesem blokowania i po nim mam raporty dla tego samego zasobu, który ma węzły procesu blokowania:

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

Za pomocą nowego skryptu dostarczonego przez srutzky zebrano nowe dane. Jest opublikowany na github ze względu na maksymalną długość postu.

Ponieważ pierwotnie opublikowane dane nie miały obu identyfikatorów sesji, niektóre nowe dane zostały ponownie opublikowane na github

Nowe dane, w tym połączenia na github

Tom V - Team Monica
źródło

Odpowiedzi:

6

W tej chwili nie mogę przetestować tej teorii, ale w oparciu o najnowsze dane przechwytywania opublikowane w GitHub , powiedziałbym, że przyczyną tego, że twój <process>węzeł jest pusty, jest to, że wymaga on aktualnie uruchomionego żądania (wiele atrybutów znajduje się w sys.dm_exec_requestsi nie wchodzi sys.dm_exec_sessions) i bez aktualnie uruchomionego żądania nie może zgłosić żadnych szczegółów, podobnie jak w przypadku INNER JOINpośrednich sys.dm_exec_requestsi sys.dm_exec_sessionswyklucza wiersze, w których sesja jest aktywna, ale jest bezczynna z powodu braku bieżącego żądania.

Patrząc na najwyższy zestaw danych ( monitorLoopwartości: 1748823, 1748824, 1748825 i 1748827) możemy zobaczyć, co następuje:

  • idz blocked-processjest taka sama w każdym przypadku: process2552c1fc28 , a tylko to cecha różni się waittime(jest zrozumiałe).
  • atrybuty blocking-processwęzłów pokazują różnice zarówno w, jak lastbatchstartedi wlastbatchcompleted
  • atrybuty blocking-processwęzłów pokazują identyczne wartości dla spidixactid

Jak więc SessionID i TransactionID procesu blokowania mogą być takie same dla 4 różnych partii zapytań? Łatwo, rozpoczęto jawną transakcję, a następnie te partie zostały wykonane. A ponieważ są to oddzielne partie, między nimi jest czas, w którym to momencie nie ma bieżącego żądania, a zatem nie ma informacji o procesie do wyświetlenia (ale sesja i transakcja wciąż tam są).

W tym celu dodatkowe badania nad tym, można uchwycić pomocnych informacji od sys.dm_exec_requestsi sys.dm_tran_locksprzez umieszczenie następującej T-SQL w „scenariuszu transakcja-SQL (T-SQL)” SQL Server Agenta Job kroku, ustawienie „Database” Być jeden, którego szukasz (w tym przypadku jest to identyfikator o wartości 6) i planujesz uruchamianie tego zadania co 10 sekund. Poniższy T-SQL utworzy dwie tabele w tym samym DB, jeśli nie istnieją, a następnie zapełni tabelę „Żądania”, jeśli jakiekolwiek żądanie albo sam się blokuje, albo jeśli jest to operacja usuwania lub aktualizacji, która jest blokowana . Jeśli zostaną znalezione jakieś żądania, spróbuje przechwycić:

  • Informacje o sesji i żądaniu dotyczące procesu blokowania (w tej części nie zakłada się, że istnieje aktywne żądanie, dlatego RIGHT JOINprzynajmniej należy uzyskać informacje o sesji)
  • Informacje o połączeniu dla zablokowanych i (miejmy nadzieję) procesów blokujących.
  • bieżące blokady dla tych samych identyfikatorów session_id (pamiętaj tylko, że nie można zagwarantować, że informacje o blokadzie są w 100% dokładne, ponieważ informacje te mogą się zmieniać w czasie między wykonaniem tych dwóch instrukcji; jednak informacje są wystarczająco dobre, aby warte uchwycenia). Ta sekcja jest obecnie komentowana.

SQL Server Agent T-SQL Zadanie Krok:

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

Myślę, że powinieneś być w stanie to odtworzyć, otwierając jedną kartę zapytania i wykonując następujące czynności:

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

Następnie otwórz drugą kartę zapytania i wykonaj następujące czynności:

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

PS Wystarczy powiedzieć, że jedyne, co nie ma sensu, to to, że informacje o żądaniach i sesjach - dbo.tmpBlockingResearch_Requests- wciąż nie zawierają wierszy dla sesji blokujących. Wiem jednak, że zmienna tabeli ma identyfikator sesji blokującej, ponieważ ściągnęła blokady dla obu identyfikatorów SessionID. Może to wskazywać na scenariusz, w którym transakcja może pozostać otwarta po zamknięciu „połączenia” od klienta, ale połączenie jest nadal utrzymywane z powodu łączenia pul.

Solomon Rutzky
źródło
@TomV Przejrzałem najnowsze dane badawcze i mam dość solidną teorię. Zaktualizowałem odpowiednio swoją odpowiedź, w tym dodając sekcję do moich zapytań badawczych, więc proszę zastąpić tutaj krok zadania SQL nowymi zapytaniami (skomentowałem również zapytanie „blokuje”, ponieważ tak naprawdę nie potrzebujemy teraz tych danych i to dużo danych). Sugeruję obcięcie / upuszczenie istniejących tabel badań, aby zacząć od nowa.
Solomon Rutzky
@TomV Ok. I zaktualizowałem moje zapytanie repro, aby było UPDATE zamiast SELECT, więc powinno być bardziej reprezentatywne dla twojej sytuacji. Na końcu dodałem notatkę o brakujących wierszach w tabeli żądań. Mamy nadzieję, że nowa tabela połączeń przynajmniej potwierdzi dalsze istnienie blokującego identyfikatora SessionID. (PS, zacząłem oczyszczać swoje komentarze powyżej).
Solomon Rutzky
Twoja praca jest aktywna. Muszę znaleźć trochę czasu, aby przetestować repro i przeanalizować je w przyszłym tygodniu
Tom V - Team Monica
Cześć Solomon. 2 nowe przykłady zostały opublikowane na github. Niestety nie mogłem uruchomić pustego procesu blokowania BPR za pomocą dostarczonej skrzynki repro.
Tom V - Team Monica
Przyjrzałem się bardzo szybko, ponieważ nie mam dużo czasu. Wygląda na to, że informacje o połączeniach pokazują, że identyfikator sesji blokującej jest nadal aktywny, ale nie ma go w tabeli sesji. Mogę to przetestować później, ale jestem prawie pewien, że wskazuje to na łączenie połączeń (połączenie wciąż istnieje) i połączenie jest zamykane między poleceniami, ale transakcja jest wyraźnie otwarta (ponieważ identyfikator_transakcji jest zawsze taki sam, jak widzieliśmy poprzednio). Przyjrzymy się później ..
Solomon Rutzky
4

Zablokowane transakcje mogą wystąpić z powodu eskalacji blokad.

Wyjaśnia to artykuł pomocy technicznej Microsoft:

Jak rozwiązać problemy z blokowaniem spowodowane eskalacją blokady w programie SQL Server

...
Eskalacja blokady nie powoduje większości problemów z blokowaniem. Aby ustalić, czy eskalacja blokady występuje w czasie, gdy występują problemy z blokowaniem, uruchom śledzenie programu SQL Profiler, które obejmuje zdarzenie Lock: Escalation. Jeśli nie widzisz żadnych zdarzeń Zablokuj: eskalacja, eskalacja blokady nie występuje na serwerze, a informacje w tym artykule nie dotyczą Twojej sytuacji.

Jeśli występuje eskalacja blokady, sprawdź, czy eskalowana blokada tabeli blokuje innych użytkowników
...

Sprawdź Rozszerzone zdarzenia (plik fizyczny) pod kątem zdarzeń eskalacji blokady , które wystąpiły przed zablokowanym zdarzeniem procesu .

Wyjaśnianie

Istnieje artykuł na blogu Microsoft, który zawiera bardziej szczegółowe informacje:

SQL Server Blokowanie eskalacji i blokowanie

...
Krok 2: Zbierz zdarzenia dotyczące eskalacji blokady i zablokowanego procesu.

Zablokuj eskalację i zablokowane zdarzenia raportu procesu nie są automatycznie przechwytywane przez SQL Server. Aby wiedzieć, czy te zdarzenia się zdarzają, musimy powiedzieć SQL Serverowi, aby je zarejestrował. Nasz zespół korzysta z narzędzia Performance Analyzer dla Microsoft Dynamics do gromadzenia tych informacji. Sprawdź ten post Rod Hansena, aby uzyskać więcej informacji na temat narzędzia i sposobu zbierania za jego pomocą szczegółów blokowania. Jeśli chcesz tylko użyć SQL Server Profiler, zdarzenia, które musisz zebrać, są pokazane poniżej: ...

Po przechwyceniu eskalacji blokady i zablokowanych procesów musisz ustalić, czy eskalacje blokady są główną przyczyną zablokowanych procesów:

...
Krok 3: Przejrzyj dane śledzenia w programie SQL Server Profiler.

Istnieją dwa główne wskaźniki, które powiedzą ci, czy blokowanie jest powiązane z eskalacją blokady.

Najpierw zobaczysz szereg zdarzeń eskalacji blokady bezpośrednio poprzedzających zdarzenia raportu zablokowanego procesu. Poniżej znajduje się przykład wzięty ze śladu utworzonego przez narzędzie Performance Analyzer dla Microsoft Dynamics. Jest to jedna rzecz, której należy szukać w śladzie, ale samo to nie oznacza, że ​​eskalacja blokady powoduje blokowanie. ...

i dalej

Aby sprawdzić, czy blokowanie jest w rzeczywistości związane z eskalacją blokady, należy spojrzeć na szczegóły raportu o zablokowanym procesie. W sekcji TextData poszukaj waitresource (patrz zrzut ekranu poniżej). Jeśli waitresource zaczyna się od OBJECT, wiemy, że zablokowana instrukcja czeka na blokadę na poziomie tabeli, aby ją zwolnić, zanim będzie mogła kontynuować. Jeśli waitresource zaczyna się od KEY lub PAG zamiast OBJECT, eskalacja blokady nie jest zaangażowana w ten konkretny blok . Eskalacja blokady zawsze zwiększy zakres blokady do OJBECT, niezależnie od tego, gdzie się zaczyna

Rozwiązanie

(tylko jeśli wyżej wymienione mecze)

Najwyraźniej rozwiązaniem jest włączenie flagi śledzenia 1224, która wyłączy eskalację blokady:

SQL Server Blokowanie eskalacji i blokowanie

Jeśli zobaczysz te dwie rzeczy razem, to całkiem dobrze, że eskalacja blokady powoduje blokowanie i prawdopodobnie skorzystasz z implementacji flagi śledzenia SQL Server 1224.

Flagi śledzenia SQL Server dla Dynamics AX

Flaga śledzenia 1224 wyłącza eskalację blokad na podstawie liczby blokad. Włączenie tej flagi śledzenia może zmniejszyć prawdopodobieństwo zablokowania z powodu eskalacji blokady - coś, co widziałem w wielu implementacjach AX. Najczęstszym scenariuszem, w którym staje się to problemem, jest to, że wymagane jest uruchomienie Master Planning w ciągu dnia

Odpowiedź

W końcu może się zdarzyć, że eskalacja blokady jest główną przyczyną zablokowanych procesów.


Alternatywne rozwiązanie (pusty węzeł procesu)

Po dalszym zbadaniu niektórych raportów zablokowanych_procesów można przedstawić następujące alternatywne wyjaśnienie.

Rozszerzone zdarzenia przechwytują zablokowane_procesy_procesów, które nie są powiązane z żadnymi innymi procesami w tym czasie.

Ergo: Muszą być zablokowane z innego powodu

Proponuję uchwycić przedział czasowy typów oczekiwania z widoku sys.dm_os_wait_stats na serwerze SQL Server i skorelować liczby z raportami zablokowanych_procesów podczas pomiarów. Paul Randall ma dobry skrypt: wyślij mi statystyki oczekiwania i uzyskaj moją radę oraz 30 dni darmowego Pluralsight w zamian

Skrypty przechwytują bieżące liczniki, czekają 23 godziny (można je modyfikować), ponownie przechwytują bieżące liczniki i porównują je, aby uzyskać 95% typów oczekiwania. Możesz to wypróbować na przykład przez 1 godzinę i mieć pod ręką plik XEL.

Możesz znaleźć typ oczekiwania (np. LCK_M_SH,…), który mówi ci, że twoje miejsce jest wolne w pisaniu. Lub że masz inne koszty ogólne (np. CX_PACKET_WAITS,….). Coś spowalnia twoje aktualizacje. Następnie możesz sprawdzić, czy sys.dm_os_wait_stats odnoszą się do raportów zablokowanych_procesów z pustymi węzłami.

Zdarzają się przypadki, gdy zablokowany identyfikator SPID jest blokowany przez ten sam identyfikator SPID:

Zablokowana kolumna w tabeli sysprocesses jest zapełniana dla oczekiwania na zatrzask po zainstalowaniu SQL Server 2000 SP4

Gdy SPID czeka na zatrzaśnięcie strony we / wy, możesz zauważyć, że zablokowana kolumna na krótko informuje, że SPID się blokuje. To zachowanie jest efektem ubocznym sposobu, w jaki zatrzaski są używane do operacji we / wy na stronach danych. Gdy wątek wydaje żądanie we / wy, identyfikator SPID, który wydaje żądanie we / wy, uzyskuje zatrzask na stronie. Wszystkie operacje we / wy programu SQL Server 2000 są asynchroniczne. Dlatego SPID będzie próbował uzyskać inną zatrzask na tej samej stronie, jeśli SPID, który wysłał żądanie We / Wy, musi poczekać na zakończenie żądania. Ten drugi zatrzask jest blokowany przez pierwszy zatrzask. Dlatego zablokowana kolumna zgłasza, że ​​SPID się blokuje. Po zakończeniu żądania we / wy pierwsza blokada zostaje zwolniona. Następnie drugie żądanie zatrzasku jest uwzględniane.

Alternatywna odpowiedź

To kolejny znak, że możesz mieć problemy z IO. Te problemy powodują „zablokowane procesy”, ale bez powiązanego obcego identyfikatora SPID. Rozszerzone zdarzenia mogą nie zgłaszać procesu / identyfikatora SPID w osobnym węźle.

John aka hot2use
źródło
Mogę to źle odczytać, ale czy te informacje nie dowodzą, że problemem nie jest eskalacja blokady? Jedna cytowana sekcja mówi "look at the blocked process report details.", a najwyższy kod XML w pytaniu to raport zablokowanego procesu. Następnie, ta sama cytowana sekcja mówi, "If waitresource starts with KEY or PAG instead of OBJECT, then lock escalation isn’t involved in that specific block."i pokazuje XML zablokowanego procesu-raportu waitresource="KEY: 6:72057..... Oznacza to, że „eskalacja blokady nie jest zaangażowana” tutaj.
Solomon Rutzky
Nie, NIE czytasz tego źle. Sekcja podana w pytaniu to jeden problem na tym serwerze. Moja odpowiedź to globalne podejście do problemów, które mogą wystąpić z powodu blokowania i eskalacji blokady. Jeśli możesz naprawić niektóre poważne problemy (zablokowane_procesy_procesów dla blokowania poziomu OBJECT), wówczas mniejsze problemy (zablokowane_procesy_procesowe na innych poziomach) mogą rozwiązać się same. Z tego powodu dodałem także drugą alternatywną odpowiedź.
John aka hot2use,