Zbieram raporty o zablokowanych procesach przy użyciu zdarzeń rozszerzonych iz jakiegoś powodu w niektórych raportach blocking-process
wę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_cursorprepare
isp_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>=@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
źródło
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
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
Po przechwyceniu eskalacji blokady i zablokowanych procesów musisz ustalić, czy eskalacje blokady są główną przyczyną zablokowanych procesów:
i dalej
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
Flagi śledzenia SQL Server dla Dynamics AX
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
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.
źródło
"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-raportuwaitresource="KEY: 6:72057....
. Oznacza to, że „eskalacja blokady nie jest zaangażowana” tutaj.