Interminável pesquisa na loja de consultas

10

Eu vou dizer desde o início que a minha pergunta / problema semelhante a esse anterior, mas desde que eu não tenho certeza se a causa ou a informação inicial é o mesmo, eu decidi postar minha pergunta com mais alguns detalhes.

Problema em questão:

  • em uma hora estranha (próximo ao final do dia útil), uma instância de produção começa a se comportar de maneira irregular:
    • CPU alta para a instância (de uma linha de base de ~ 30%, foi para o dobro e ainda estava crescendo)
    • aumento do número de transações / s (embora a carga do aplicativo não tenha visto nenhuma alteração)
    • aumento do número de sessões inativas
    • eventos de bloqueio estranhos entre sessões que nunca exibiram esse comportamento (até mesmo as sessões não confirmadas estavam causando o bloqueio)
    • as principais esperas do intervalo foram sem trava de página no 1º lugar, com bloqueios no 2º lugar

Investigação inicial:

  • usando sp_whoIsActive, vimos que uma consulta executada por nossa ferramenta de monitoramento decide rodar extremamente devagar e pegar muita CPU, algo que não havia acontecido antes;
  • seu nível de isolamento foi lido sem comprometimento;
  • vimos o plano em que vimos números malucos: StatementEstRows = "3.86846e + 010" com cerca de 150 TB de dados estimados a serem retornados
  • suspeitamos que o recurso de monitor de consulta da ferramenta de monitoramento tenha sido a causa. Por isso, desabilitamos o recurso (também abrimos um ticket com nosso provedor para verificar se eles têm conhecimento de algum problema)
  • desde o primeiro evento, isso aconteceu mais algumas vezes, toda vez que matamos a sessão, tudo volta ao normal;
  • percebemos que a consulta é extremamente semelhante a uma das consultas usadas pelo MS no BOL para o monitoramento do Query Store - consultas que recentemente regrediram no desempenho (comparando diferentes pontos no tempo)
  • executamos a mesma consulta manualmente e vemos o mesmo comportamento (a CPU usada aumenta cada vez mais, aumenta as esperas de trava, bloqueios inesperados etc.)

Consulta culpada:

Select qt.query_sql_text, 
    q.query_id, 
    qt.query_text_id, 
    rs1.runtime_stats_id AS runtime_stats_id_1,
    interval_1 = DateAdd(minute, -(DateDiff(minute, getdate(), getutcdate())), rsi1.start_time), 
    p1.plan_id AS plan_1, 
    rs1.avg_duration AS avg_duration_1, 
    rs2.avg_duration AS avg_duration_2,
    p2.plan_id AS plan_2, 
    interval_2 = DateAdd(minute, -(DateDiff(minute, getdate(), getutcdate())), rsi2.start_time), 
    rs2.runtime_stats_id AS runtime_stats_id_2
From sys.query_store_query_text AS qt 
Inner Join sys.query_store_query AS q 
    ON qt.query_text_id = q.query_text_id 
Inner Join sys.query_store_plan AS p1 
    ON q.query_id = p1.query_id 
Inner Join sys.query_store_runtime_stats AS rs1 
    ON p1.plan_id = rs1.plan_id 
Inner Join sys.query_store_runtime_stats_interval AS rsi1 
    ON rsi1.runtime_stats_interval_id = rs1.runtime_stats_interval_id 
 Inner Join sys.query_store_plan AS p2 
    ON q.query_id = p2.query_id 
Inner Join sys.query_store_runtime_stats AS rs2 
    ON p2.plan_id = rs2.plan_id 
Inner Join sys.query_store_runtime_stats_interval AS rsi2 
    ON rsi2.runtime_stats_interval_id = rs2.runtime_stats_interval_id
Where rsi1.start_time > DATEADD(hour, -48, GETUTCDATE()) 
    AND rsi2.start_time > rsi1.start_time 
    AND p1.plan_id <> p2.plan_id
    AND rs2.avg_duration > rs1.avg_duration * 2
Order By q.query_id, rsi1.start_time, rsi2.start_time

Configurações e informações:

  • SQL Server 2016 SP1 CU4 Enterprise em um cluster do Windows Server 2012R2
  • Armazenamento de consultas ativado e configurado como padrão (nenhuma configuração alterada)
  • banco de dados importado de uma instância do SQL 2005 (e ainda no nível de compatibilidade 100)

Observação empírica:

  • devido a estatísticas extremamente malucas, pegamos todos os objetos * plan_persist ** usados ​​no plano estimado ruim (nenhum plano real ainda, porque a consulta nunca foi concluída) e verificamos as estatísticas, alguns dos índices usados ​​no plano não tinham nenhuma estatística (DBCC SHOWSTATISTICS não retornou nada, selecione a partir de sys.stats mostrou a função NULL stats_date () para alguns índices

Solução rápida e suja:

  • crie manualmente estatísticas ausentes nos objetos do sistema relacionados ao Query Store ou
  • forçar a consulta a ser executada usando o novo CE (traceflag) - que também criará / atualizará as estatísticas necessárias ou
  • altere o nível de compatibilidade do banco de dados para 130 (por padrão, ele usará o novo CE)

Então, minha verdadeira pergunta seria:

Por que uma consulta no Query Store causaria problemas de desempenho em toda a instância? Estamos em um território de bug com o Query Store?

PS: Carregarei alguns arquivos (telas de impressão, estatísticas de IO e planos) em breve.

Arquivos adicionados ao Dropbox .

Plano 1 - plano inicial maluco estimado em produção

Plano 2 - plano real, antigo CE, em um ambiente de teste (mesmo comportamento, mesmas estatísticas malucas)

Plano 3 - plano real, nova CE, em um ambiente de teste

Marian
fonte
11
Acabamos desativando o armazenamento de consultas, temos certeza de qual foi a causa raiz (tivemos mais de um problema com certeza). Do meu lado, a CPU aumentaria tudo o que clicamos para exibir estatísticas do repositório de consultas.
A_V

Respostas:

6

Como eu disse na resposta, o teste empírico mostrou que havia índices nos objetos do sistema sys.plan_persisted * sem nenhuma (nenhuma) estatística criada sobre eles. Eu suspeito que é porque o banco de dados foi migrado de uma instância do SQL 2005 e mantido por um tempo no nível de compatibilidade 100, portanto, o novo CE não chegou a ser usado.

Verificação de contagem de linhas:

Select count(1) from NoNameDB.sys.plan_persist_runtime_stats with (nolock) --60362   
Select count(1) from NoNameDB.sys.plan_persist_plan with (nolock) --1853    
Select count(1) from NoNameDB.sys.plan_persist_runtime_stats_interval with (nolock) --671    
Select count(1) from NoNameDB.sys.plan_persist_query with (nolock) --1091    
Select count(1) from NoNameDB.sys.plan_persist_query_text with (nolock) --911

Isso mostrou que as estimativas iniciais estavam erradas. Feito com uma conexão DAC, caso contrário, as tabelas não estão disponíveis para consulta.

Verificação de estatísticas:

DBCC SHOW_STATISTICS ('sys.plan_persist_runtime_stats_interval', plan_persist_runtime_stats_interval_cidx);    
DBCC SHOW_STATISTICS ('sys.plan_persist_runtime_stats', plan_persist_runtime_stats_idx1);    
DBCC SHOW_STATISTICS ('sys.plan_persist_runtime_stats', plan_persist_runtime_stats_cidx);    
DBCC SHOW_STATISTICS ('sys.plan_persist_plan', plan_persist_plan_cidx);    
DBCC SHOW_STATISTICS ('sys.plan_persist_plan', plan_persist_plan_idx1);    
DBCC SHOW_STATISTICS ('sys.plan_persist_query', plan_persist_query_cidx)    
DBCC SHOW_STATISTICS ('sys.plan_persist_query_text', plan_persist_query_text_cidx);

Isso mostrou que alguns índices tinham estatísticas vazias (ausentes, nenhuma, zero).

Correção inicial:

UPDATE STATISTICS sys.plan_persist_runtime_stats WITH fullscan;
UPDATE STATISTICS sys.plan_persist_plan WITH fullscan;
UPDATE STATISTICS sys.plan_persist_runtime_stats_interval WITH fullscan;
UPDATE STATISTICS sys.plan_persist_query WITH fullscan;
UPDATE STATISTICS sys.plan_persist_query_text WITH fullscan;

Isso meio que corrigiu as estatísticas e fez a consulta terminar em 10 a 12 segundos.

Segunda correção :

(verificado apenas em um ambiente de teste) e, provavelmente, o adequado, pois mostrava as melhores estatísticas para a consulta, foi alterar o nível de compatibilidade do banco de dados para 130. O resultado final foi que a consulta terminou em cerca de 10 a 12 segundos com estatísticas de número normal (10 mil linhas).

Correção intermediária :

DBCC TRACEON (2312) -- new CE

Alguma ajuda relacionada sobre estatísticas nas tabelas ocultas do sistema.

Marian
fonte
3

O problema subjacente, que é visível se você abrir o plano real no SSMS e examinar o uso da CPU (ou examinar o XML), é o nó 32, um TVF. O culpado nas consultas lentas do Query Store é o acesso repetido dos TVFs na memória .

Custo de TVF

Não importa quantas linhas são retornadas desses TVFs, apenas o número de vezes que são acessadas. A correção será o que você puder fazer para afastar seus planos de lê-los várias vezes.

Com base na minha depuração limitada (tanto em habilidades quanto em tempo gasto), minha hipótese é que a totalidade da memória atribuída ao componente específico da memória dos dados do Query Store seja varrida a cada execução do TVF. Não pude afetar essa alocação de memória com sp_query_store_flush_dbou DBCC FREESYSTEMCACHE.

As soluções alternativas bem-sucedidas até agora incluem guias de plano, dicas (até OPTION(HASH JOIN, LOOP JOIN)agora funcionaram o suficiente para mim) e a execução das consultas do Query Store em um nó somente leitura de um AG.

Forrest
fonte