Temos um SQL Server 2019 CU18 onde descobrimos um problema estranho com o querystore. Normalmente, o tamanho médio do logbackup por hora é de 40 MB, mas assim que habilitamos o querystore, o tamanho médio do logbackup é de 2,5 GB.
Há (de acordo com o querystore) 140.000 consultas executadas/hora. Isso é cerca de 40 execuções/segundo.
Esta é a configuração do nosso querystore:
ALTER DATABASE [db_name]
SET QUERY_STORE = ON
(
OPERATION_MODE = READ_WRITE
,CLEANUP_POLICY = (STALE_QUERY_THRESHOLD_DAYS = 45)
,DATA_FLUSH_INTERVAL_SECONDS = 900
,MAX_STORAGE_SIZE_MB = 2048
,INTERVAL_LENGTH_MINUTES = 30
,SIZE_BASED_CLEANUP_MODE = AUTO
,QUERY_CAPTURE_MODE = AUTO
);
Quando abro um arquivo de logbackup tão grande, fn_dump_dblog
vejo que várias transações acontecem no mesmo segundo. Todas as transações têm o nome 'SwapPage'.
Operação | CONTEXTO | Unidade de AlocaçãoId | ID da página | Nome da transação |
---|---|---|---|---|
LOP_INÍCIO_EXATO | LCX_NULO | NULO | NULO | Página de troca |
LOP_INSYSXACT | LCX_ÍNDICE_INTERIOR | 72057594047692800 | 0001:00056321 | NULO |
LOP_INSYSXACT | LCX_AGRUPADO | 72057594047692800 | 0001:000a871c | NULO |
LOP_INSYSXACT | LCX_AGRUPADO | 72057594047692800 | 0001:0000041b | NULO |
LOP_INSYSXACT | LCX_AGRUPADO | 72057594047692800 | 0001:0000041c | NULO |
PÁGINA_FORMATO_LOP | LCX_PÁGINA_DE_REORGANIZAÇÃO_DESLINKADA | 72057594047692800 | 0001:000a8715 | NULO |
LOP_MODIFY_HEADER | LCX_PÁGINA_DE_REORGANIZAÇÃO_DESLINKADA | 72057594047692800 | 0001:000a8715 | NULO |
LOP_INSYSXACT | LCX_AGRUPADO | 72057594047692800 | 0001:000a8715 | NULO |
LOP_MODIFY_HEADER | LCX_HEAP | 72057594047692800 | 0001:000a871c | NULO |
LOP_MODIFY_HEADER | LCX_HEAP | 72057594047692800 | 0001:0000041c | NULO |
LOP_INSERIR_LINHAS | LCX_AGRUPADO | 72057594047692800 | 0001:000a8715 | NULO |
LOP_MODIFY_HEADER | LCX_HEAP | 72057594047692800 | 0001:000a8715 | NULO |
LOP_MODIFY_HEADER | LCX_HEAP | 72057594047692800 | 0001:000a8715 | NULO |
LOP_MODIFY_ROW | LCX_ÍNDICE_INTERIOR | 72057594047692800 | 0001:00056321 | NULO |
LOP_MODIFY_HEADER | LCX_HEAP | 72057594047692800 | 0001:0000041b | NULO |
LOP_MODIFY_HEADER | LCX_HEAP | 72057594047692800 | 0001:0000041b | NULO |
LOP_MIGRAR_BLOQUEIOS | LCX_NULO | NULO | 0001:000a8715 | NULO |
LOP_INSYSXACT | LCX_AGRUPADO | 72057594047692800 | 0001:000a8715 | NULO |
LOP_INSYSXACT | LCX_AGRUPADO | 72057594047692800 | 0001:0000041c | NULO |
LOP_INSYSXACT | LCX_PÁGINA_DE_REORGANIZAÇÃO_DESLINKADA | 72057594047692800 | 0001:0000041b | NULO |
LOP_INSYSXACT | LCX_AGRUPADO | 72057594047692800 | 0001:000a871c | NULO |
LOP_INSYSXACT | LCX_ÍNDICE_INTERIOR | 72057594047692800 | 0001:00056321 | NULO |
LOP_COMMIT_XACT | LCX_NULO | NULO | NULO | NULO |
A unidade de alocação aponta para plan_persist_runtime_stats.
Após um comentário de Paul White, configurei um Evento Estendido para capturar query_store_index_rebuild_started
e query_store_index_rebuild_finished
. Para minha surpresa, o querystore estava fazendo reconstruções de índice. Estes são os resultados deste rastreamento:
evento | carimbo de data/hora | tamanho_atual_kb |
---|---|---|
query_store_index_rebuild_iniciado | 2024-12-05 07:51:10.353 | 874208 |
query_store_index_rebuild_concluído | 2024-12-05 07:52:29.073 | 868832 |
query_store_index_rebuild_iniciado | 2024-12-05 08:20:58.497 | 873504 |
query_store_index_rebuild_concluído | 2024-12-05 08:22:18.320 | 869152 |
query_store_index_rebuild_iniciado | 2024-12-05 08:36:03.147 | 874528 |
query_store_index_rebuild_concluído | 2024-12-05 08:37:19.670 | 869664 |
query_store_index_rebuild_iniciado | 2024-12-05 09:06:00.943 | 874336 |
query_store_index_rebuild_concluído | 2024-12-05 09:07:12.750 | 870304 |
Parece que a reconstrução do índice foi iniciada em torno de 874 MB, o tamanho máximo do querystore está definido como 2048.
Também incluí o stacktrace do query_store_index_rebuild_started
evento no Evento Estendido.
sqllang!XeSqlPkg::CollectClientHostnameActionInvoke sqllang!XeSqlPkg::CollectDatabaseIdActionInvoke sqllang!XeSqlPkg::CollectDatabaseNameActionInvoke sqllang!XeSqlPkg
::CollectNtUsernameActionInvoke sqllang!XeSqlPkg::CollectSessionIdActionInvoke sqllang!XeSqlPkg::CollectTSqlStack<XE_ActionForwarder> sqllang!XeSqlPkg::CollectTSqlStackActionInvoke qds!XeQdsPkg::query_store_index_rebuild_started::Publicar
qds!CDBQDS::ReclaimFreePages
qds!CDBQDS::DoSizeRetention
qds!CDBQDS::ProcessQdsBackgroundTask
qds!CQDSManager::AcquireGenericQdsDbAndProcess<<lambda_e51628d7833f66b5a045fa5bf2d27953>>
qds!CDBQDS::ProcessQdsBackgroundTask
sqldk!SOS_Task::Param::Executar
sqldk!SOS_Scheduler:: Executar tarefa sqldk
!SOS_Scheduler::ProcessTasks
sqldk!SchedulerManager::WorkerEntryPoint
sqldk!SystemThreadDispatcher::ProcessWorker
sqldk!SchedulerManager::ThreadEntryPoint
KERNEL32+0x17AC4
ntdll+0x5A8C1
Eu esperava descobrir o que está acionando a reconstrução do índice, mas não tive sorte.
Após algumas dicas do Zikato, adicionei alguns eventos extras relacionados ao querystore ao meu trace. Isso mostra que a reconstrução do índice só é acionada se um query_store_size_retention_cleanup_started
evento tiver ocorrido.
Reconstruir:
Toda vez que a limpeza é executada, 0 KB é excluído, mas aparentemente uma reconstrução é necessária. O que me confunde é a aparência do evento de limpeza. Pensei que isso só seria acionado quando o querystore atingisse 90% do tamanho máximo de armazenamento.
Aumentar o tamanho máximo do querystore não faz diferença.
Alguém passou pelo mesmo problema ou pode explicar o que está acontecendo? Outros bancos de dados na instância não têm esse problema.