Estou coletando relatórios de processos bloqueados usando Eventos Estendidos e, por algum motivo, em alguns relatórios, o blocking-process
nó está vazio. Este é o xml completo:
<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>
A definição de índice para o índice ao qual este hobt_id pertence é
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
Não há particionamento envolvido, esta é a definição de tabela:
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
Não há gatilhos ou chaves estrangeiras definidos em nenhuma das tabelas no banco de dados inteiro.
A compilação exata do SQL Server é:
Microsoft SQL Server 2012 (SP3-CU4) (KB3165264) - 11.0.6540.0 (X64)
23 de junho de 2016 17:45:11 Copyright (c) Microsoft Corporation Enterprise Edition: licenciamento baseado em núcleo (64 bits) no Windows NT 6.3 ( Compilação 14393:) (Hypervisor)
Os eventos estendidos são bastante simples, apenas registrando os relatórios de processo bloqueados:
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
O banco de dados é configurado em Isolamento de Captura Instantânea Confirmada de Leitura e o grau máximo de paralelismo é definido como 1. Esta é a configuração do servidor:
+------------------------------------+-------+
| 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 |
+------------------------------------+-------+
Executei um rastreamento do lado do servidor por um tempo e recebo os mesmos nós vazios em um arquivo de rastreamento que os eventos estendidos.
Este relatório de processo bloqueado foi capturado usando um rastreamento do lado do servidor em outro servidor também executando o Dynamics AX, portanto, não é específico para este servidor ou compilação.
<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>
Alguém tem uma explicação para esses relatórios? O que está bloqueando a consulta?
Existe alguma maneira de descobrir o que estava acontecendo se eu estiver olhando os relatórios depois que os bloqueios desaparecerem?
Uma coisa que pode ser útil adicionar é que essas consultas são executadas via sp_cursorprepare
esp_cursorexecute
Até agora não consegui reproduzi-lo, parece acontecer aleatoriamente, mas com muita frequência.
Isso acontece em várias instâncias (de diferentes compilações) e em várias tabelas / consultas, todas relacionadas ao Dynamics AX.
Não há nenhum índice ou outros trabalhos de manutenção de banco de dados ocorrendo em segundo plano no momento.
Usando o código fornecido na resposta por srutzky , consegui capturar alguns logs relacionados a este relatório de processo bloqueado:
<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>
Isso é encontrado nas tabelas de log do mesmo recurso nessa época: Gist por causa do limite de caracteres
Uma investigação mais aprofundada mostra que, imediatamente antes e depois do relatório com um processo de bloqueio vazio, tenho relatórios para o mesmo recurso que possui nós do processo de bloqueio:
<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>
Usando o novo script fornecido por srutzky, novos dados foram coletados. É postado no github por causa do tamanho máximo da postagem.
Como os dados postados originalmente não tinham os dois IDs de sessão, alguns novos dados foram postados no github novamente
Novos dados, incluindo as conexões no github
fonte
Transações bloqueadas podem ocorrer devido a escalações de bloqueio.
Isso é explicado no artigo de suporte da Microsoft:
Como resolver problemas de bloqueio causados pelo escalonamento de bloqueios no SQL Server
Verifique os Eventos Estendidos (arquivo físico) para eventos de escalação de bloqueios que ocorreram antes do processo bloqueado evento do .
Explicando
Há um artigo do Blog da Microsoft que entra em mais detalhes:
Escalação e bloqueio de bloqueio do SQL Server
Depois de capturar as escalações de bloqueio e os processos bloqueados, é necessário determinar se as escalações de bloqueio são a causa principal dos processos bloqueados:
e mais
Solução
(somente se as correspondências mencionadas acima)
Aparentemente, a solução é ativar o sinalizador de rastreamento 1224, que desativará a escalação de bloqueio:
Escalação e bloqueio de bloqueio do SQL Server
Sinalizadores de rastreamento do SQL Server para Dynamics AX
Responda
No final, pode ser que a escalação de bloqueios seja a causa raiz dos processos bloqueados.
Solução alternativa (nó do processo vazio)
Após uma investigação mais aprofundada de alguns relatórios de processo_ bloqueados, a seguinte explicação alternativa pode ser feita.
Os Eventos Estendidos estão capturando blocks_process_reports que não estão relacionados a nenhum outro processo no momento.
Ergo: eles devem ser bloqueados por um motivo diferente
Sugiro que você capture um período de tempo dos tipos de espera na exibição sys.dm_os_wait_stats no SQL Server e correlacione os números com os blocks_process_reports que ocorrem durante suas medições. Paul Randall tem um bom roteiro: envie-me suas estatísticas de espera e receba meu conselho e 30 dias de Pluralsight grátis em troca
Os scripts capturam os contadores atuais, aguardam 23 horas (podem ser modificadas), recapturam os contadores atuais novamente e os comparam para fornecer os 95% melhores tipos de espera. Você pode tentar isso por 1 hora e ter o arquivo XEL à mão.
Você pode encontrar um tipo de espera (por exemplo, LCK_M_SH,…) que esteja informando que seu armazenamento é lento por escrito. Ou que você tenha alguma outra sobrecarga (por exemplo, CX_PACKET_WAITS,….). Algo está atrasando suas atualizações. Você pode ver se os sys.dm_os_wait_stats se relacionam com o locked_process_reports com os nós vazios.
Há casos em que um SPID bloqueado está sendo bloqueado pelo mesmo SPID:
A coluna bloqueada na tabela sysprocesses é preenchida para espera de trava após a instalação do SQL Server 2000 SP4
Resposta Alternativa
Essa é mais uma indicação de que você pode estar tendo problemas de IO. Esses problemas resultam em "processos bloqueados", mas sem um SPID externo relacionado. Eventos estendidos podem não relatar o processo / SPID em um nó separado.
fonte
"look at the blocked process report details."
, e o XML mais importante da questão é o relatório do processo bloqueado. Em seguida, a mesma seção citada diz,"If waitresource starts with KEY or PAG instead of OBJECT, then lock escalation isn’t involved in that specific block."
e o XML do relatório de processo bloqueado é exibidowaitresource="KEY: 6:72057....
. Isso significa que "a escalação de bloqueio não está envolvida" aqui.