Desde o Caché 2017, o mecanismo SQL inclui um novo conjunto de estatísticas. Ele registra o número de vezes que uma consulta é executada e o tempo que leva para executá-la.

Esta é uma mina de ouro para qualquer pessoa que está monitorando e tentando otimizar o desempenho de uma aplicação que inclui muitas instruções SQL, mas que não é tão fácil de acessar os dados como algumas pessoas desejam.

Este artigo e o código de exemplo associado explicam como usar essas informações e como extrair rotineiramente um resumo de estatísticas diárias e manter um registro histórico de desempenho do SQL de sua aplicação.

O que está registrado?

Toda vez que uma instrução SQL é executada, o tempo gasto é registrado. Esse registro é muito leve e você não pode desativá-lo. Para minimizar o custo, as estatísticas são mantidas na memória e gravadas no disco periodicamente. Os dados incluem o número de vezes que uma consulta foi executada no dia e a média e o tempo total gasto.

Os dados não são gravados no disco imediatamente, e depois de gravados, as estatísticas são atualizadas pela tarefa "Atualizar estatísticas de consulta SQL" que geralmente é programada para se executada a cada hora. Essa tarefa pode ser executada manualmente, mas se você quiser ver as estatísticas em tempo real enquanto testa uma consulta, todo o processo requer um pouco de paciência.

Aviso: No InterSystems IRIS 2019 e anteriores, essas estatísticas não são coletadas para SQL embutido em classes ou rotinas que foram implantadas usando o mecanismo  %Studio.Project:Deploy. Nada quebrará com o código de exemplo, mas pode enganar você (me enganou) fazendo-o pensar que tudo estava OK porque nada parecia tão custoso. 

Como você vê as informações?

Você pode ver a lista de consultas no portal de gerenciamento. Vá para a página SQL e clique na aba ‘Instruções SQL’. É ótimo para uma nova consulta que você está executando e examinando, mas se houver milhares de consultas em execução, pode-se tornar incontrolável.

A alternativa é usar o SQL para pesquisar as consultas. As informações são armazenadas em tabelas no esquema INFORMATION_SCHEMA. Este esquema tem várias tabelas e incluí alguns exemplos de consultas SQL no final deste artigo.

Quando as estatísticas são removidas?

Os dados de uma consulta são removidos sempre que ela é recompilada. Portanto, para consultas dinâmicas, isso pode significar quando as consultas em cache são limpas. Para SQL embutido, isso significa quando a classe ou rotina em que o SQL está embutido é recompilado.

Em um site ativo, é razoável esperar que as estatísticas sejam mantidas por mais de um dia, mas as tabelas que contêm as estatísticas não podem ser usadas como uma fonte de referência para relatórios ou análises de longo prazo.

Como você pode resumir as informações?

Recomendo extrair os dados todas as noites em tabelas permanentes que são mais fáceis de trabalhar ao gerar os relatórios de desempenho. Há uma chance de que algumas informações sejam perdidas se as classes forem compiladas durante o dia, mas é improvável que isso faça alguma diferença real em sua análise de consultas lentas.

O código a seguir é um exemplo de como você pode extrair as estatísticas em um resumo diário para cada consulta. Inclui três classes curtas:

* Uma tarefa que deve ser executada todas as noites. * DRL.MonitorSQL é a classe principal que extrai e armazena os dados das tabelas INFORMATION_SCHEMA.
  • A terceira classe DRL.MonitorSQLText é uma otimização que armazena o texto da consulta (potencialmente longo) uma vez e armazena apenas o hash da consulta nas estatísticas de cada dia.
  • Notas sobre o exemplo

    A tarefa é extraída do dia anterior e, portanto, deve ser agendada logo após a meia-noite.

    Você pode exportar mais dados históricos, se houver. Para extrair os últimos 120 dias

    Faça ##class(DRL.MonitorSQL).Capture($h-120,$h-1)

    O código de exemplo lê o ^rIndex global diretamente porque as versões mais antigas das estatísticas não expunham a Data ao SQL.

    A variação, incluí loops em todos os namespaces na instância, mas isso nem sempre é apropriado.

    Como consultar os dados extraídos

    Uma vez que os dados são extraídos, você pode encontrar as consultas mais pesadas executando

    SELECT top 20
    S.RunDate,S.RoutineName,S.TotalHits,S.SumpTIme,S.Hash,t.QueryText
    from DRL.MonitorSQL S
    left join DRL.MonitorSQLText T on S.Hash=T.Hash
    where RunDate='08/25/2019'
    order by SumpTime desc

     

    Além disso, se você escolher o hash para uma consulta custosa, poderá ver o histórico dessa consulta com

     

    SELECT S.RunDate,S.RoutineName,S.TotalHits,S.SumpTIme,S.Hash,t.QueryText
    from DRL.MonitorSQL S
    left join DRL.MonitorSQLText T on S.Hash=T.Hash
    where S.Hash='CgOlfRw7pGL4tYbiijYznQ84kmQ='
    order by RunDate

    No início deste ano, obtive dados de um site ativo e examinei as consultas mais custosas. Uma consulta demorava em média menos de 6 segundos, mas estava sendo chamada 14.000 vezes por dia, totalizando quase 24 horas decorridas todos os dias. Efetivamente, um núcleo estava totalmente ocupado com esta única consulta. Pior ainda, a segunda consulta que leva uma hora foi uma variação da primeira.

    Data de Execução Nome da Rotina Visitas  Totais Tempo Total Hash Texto da Consulta (abreviado)
    16/03/2019   14.576 85.094 5xDSguu4PvK04se2pPiOexeh6aE= DECLARE C CURSOR FOR SELECT * INTO :%col(1) , :%col(2) , :%col(3) , :%col(4)  …
    16/03/2019   15.552 3.326 rCQX+CKPwFR9zOplmtMhxVnQxyw= DECLARE C CURSOR FOR SELECT * INTO :%col(1) , :%col(2) , :%col(3) , :%col(4) , …
    16/03/2019   16.892 597 yW3catzQzC0KE9euvIJ+o4mDwKc= DECLARE C CURSOR FOR SELECT * INTO :%col(1) , :%col(2) , :%col(3) , :%col(4) , :%col(5) , :%col(6) , :%col(7) ,
    16/03/2019   16.664 436 giShyiqNR3K6pZEt7RWAcen55rs= DECLARE C CURSOR FOR SELECT * , TKGROUP INTO :%col(1) , :%col(2) , :%col(3) , ..
    16/03/2019   74.550 342 4ZClMPqMfyje4m9Wed0NJzxz9qw= DECLARE C CURSOR FOR SELECT …

    Tabela 1: Resultados reais do site do cliente

    Tabelas no esquema INFORMATION_SCHEMA

    Assim como as estatísticas, as tabelas neste esquema controlam onde as consultas, colunas, índices etc. são usados. Normalmente, a instrução SQL é a tabela inicial e é juntada em algo como “Statements.Hash=OtherTable.Statement”.

    A consulta equivalente para acessar essas tabelas diretamente para encontrar as consultas mais custosas para um dia seria…

     

    SELECT DS.Day,Loc.Location,DS.StatCount,DS.StatTotal,S.Statement,S.Hash
    FROM INFORMATION_SCHEMA.STATEMENT_DAILY_STATS DS
    left join INFORMATION_SCHEMA.STATEMENTS  S
    on S.Hash=DS.Statement
    left join INFORMATION_SCHEMA.STATEMENT_LOCATIONS  Loc
    on S.Hash=Loc.Statement
    where Day='08/26/2019'
    order by DS.stattotal desc

     

    Esteja você pensando em configurar um processo mais sistemático ou não, recomendo que todos com uma grande aplicação que usa SQL executem essa consulta hoje.

    Se uma consulta específica parecer custosa, você pode obter o histórico  executando 

    SELECT DS.Day, Loc.Location, DS.StatCount, DS.StatTotal, S.Statement, S.Hash
    FROM INFORMATION_SCHEMA.STATEMENT_DAILY_STATS DS 
    left join INFORMATION_SCHEMA.STATEMENTS S
    on S.Hash=DS.Statement
    left join INFORMATION_SCHEMA.STATEMENT_LOCATION Loc
    on S.Hash=Loc.Statement
    where S.Hash='jDqCKaksff/4up7Ob0UXlkT2xKY='
    order by DS.Day

     

     
    Exemplo de código para extrair estatísticas diariamente
    Isenção de responsabilidade padrão - este exemplo é apenas para ilustração. Não há suporte ou garantia de funcionamento. 

    Class DRL.MonitorSQLTask Extends %SYS.Task.Definition
    {
    Parameter TaskName = "SQL Statistics Summary";
    Method OnTask() As %Status
    {
                  set tSC=$$$OK
                  TRY {
                                 do ##class(DRL.MonitorSQL).Run()
                  }
                  CATCH exp {
                                set tSC=$SYSTEM.Status.Error("Error in SQL Monitor Summary Task")
                  }
                  quit tSC
     }
    }

    Class DRL.MonitorSQLText Extends %Persistent
    {
    /// Hash do texto da consulta
    Property Hash As %String;
     

    /// texto de consulta para hash
    Property QueryText As %String(MAXLEN = 9999);
    Index IndHash On Hash [ IdKey, Unique ];
    }

    /// Resumo das estatísticas de consulta SQL de custo muito baixo coletadas no Caché 2017.1 e posterior.

    /// Consulte a documentação sobre "Detalhes da instrução SQL" para obter informações sobre os dados de origem.

    /// Os dados são armazenados por data e hora para dar suporte a consultas ao longo do tempo.

    /// Normalmente executado para resumir os dados da consulta SQL do dia anterior.
    Class DRL.MonitorSQL Extends %Persistent
    {
    /// RunDate e RunTime identificam exclusivamente uma execução
    Property RunDate As %Date;
    /// Horário em que a captura foi iniciada
    /// RunDate e RunTime identificam exclusivamente uma execução
    Property RunTime As %Time;
    /// Contagem do total de acessos para o período
    Property TotalHits As %Integer;
    /// Soma de pTime
    Property SumPTime As %Numeric(SCALE = 4);
    /// Rotina onde o SQL é encontrado
    Property RoutineName As %String(MAXLEN = 1024);
    /// Hash do texto da consulta
    Property Hash As %String;
    Property Variance As %Numeric(SCALE = 4);
    /// Namespace onde as consultas são executadas
    Property Namespace As %String;
    /// A execução padrão processará os dados dos dias anteriores para um único dia.
    /// Outras combinações de intervalo de datas podem ser obtidas usando o método de captura.
    ClassMethod Run()
    {
                  //Cada execução é identificada pela data / hora de início para manter os itens relacionados juntos
                  set h=$h-1
                  do ..Capture(+h,+h)
    }
    /// Captura estatísticas históricas para um intervalo de datas
    ClassMethod Capture(dfrom, dto)
    {
                  set oldstatsvalue=$system.SQL.SetSQLStatsJob(-1)
                    set currNS=$znspace
                    set tSC=##class(%SYS.Namespace).ListAll(.nsArray)
                    set ns=""
          set time=$piece($h,",",2)
          kill ^||TMP.MonitorSQL
                    do {
                                   set ns=$o(nsArray(ns))
                                   quit:ns=""
                                   use 0 write !,"processing namespace ",ns
                                   zn ns
                                               for dateh=dfrom:1:dto {
                                                              set hash=""
                                                              set purgedun=0
                                                              do {
                                                                            set hash=$order(^rINDEXSQL("sqlidx",1,hash))
                                                                            continue:hash=""
                                                                            set stats=$get(^rINDEXSQL("sqlidx",1,hash,"stat",dateh))
                                                                            continue:stats=""
                                                                            set ^||TMP.MonitorSQL(dateh,ns,hash)=stats
                                                              &SQL(SELECT  Location into :tLocation FROM INFORMATION_SCHEMA.STATEMENT_LOCATIONS WHERE Statement=:hash)
                                                                            if SQLCODE'=0 set Location=""
                                                                            set ^||TMP.MonitorSQL(dateh,ns,hash,"Location")=tLocation
                                                              &SQL(SELECT  Statement INTO :Statement FROM INFORMATION_SCHEMA.STATEMENTS WHERE Hash=:hash)
                                                                            if SQLCODE'=0 set Statement=""
                                                                            set ^||TMP.MonitorSQL(dateh,ns,hash,"QueryText")=Statement
                                                              while hash'=""
                                               }
                    while ns'=""
                    zn currNS
                    set dateh=""
                    do {
                                   set dateh=$o(^||TMP.MonitorSQL(dateh))
                                   quit:dateh=""
                                   set ns=""
                                   do {
                                                 set ns=$o(^||TMP.MonitorSQL(dateh,ns))
                                                 quit:ns=""
                                                 set hash=""
                                                 do {
                                                             set hash=$o(^||TMP.MonitorSQL(dateh,ns,hash))
                                                              quit:hash=""
                                                             set stats=$g(^||TMP.MonitorSQL(dateh,ns,hash))
                                                              continue:stats=""
                                                              // No loop, pela primeira vez, exclua todas as estatísticas do dia para que seja executável novamente
                                                              // Mas se executarmos por um dia após os dados brutos terem sido eliminados, isso destruirá tudo
                                                              // então faça aqui, onde já sabemos que há resultados para inserir em seu lugar.
                                                              if purgedun=0 {
                                                                            &SQL(DELETE FROM websys.MonitorSQL WHERE RunDate=:dateh )
                                                                            set purgedun=1
                                                              }
                                                              set tObj=##class(DRL.MonitorSQL).%New()
                                                              set tObj.Namespace=ns
                                                              set tObj.RunDate=dateh
                                                              set tObj.RunTime=time
                                                              set tObj.Hash=hash
                                                              set tObj.TotalHits=$listget(stats,1)
                                                              set tObj.SumPTime=$listget(stats,2)
                                                              set tObj.Variance=$listget(stats,3)
                                                              set tObj.Variance=$listget(stats,3)
                                                             set queryText=^||TMP.MonitorSQL(dateh,ns,hash,"QueryText")
                                                             set tObj.RoutineName=^||TMP.MonitorSQL(dateh,ns,hash,"Location")
                                                        &SQL(Select ID into :TextID from DRL.MonitorSQLText where Hash=:hash)
                                                              if SQLCODE'=0 {
                                                                            set textref=##class(DRL.MonitorSQLText).%New()
                                                                            set textref.Hash=tObj.Hash
                                                                            set textref.QueryText=queryText
                                                                            set sc=textref.%Save()
                                                              }                                                       
                                                              set tSc=tObj.%Save()
                                                              //evite duplicar o texto da consulta em cada registro porque pode ser muito longo. Use uma tabela de pesquisa
                                                              //com chave no hash. Se não existir, adicione..
                                                              if $$$ISERR(tSc) do $system.OBJ.DisplayError(tSc)

                                                              if $$$ISERR(tSc) do $system.OBJ.DisplayError(tSc)
                                                 while hash'=""
                                   while ns'=""
                    while dateh'=""
                  do $system.SQL.SetSQLStatsJob(0)
    }
    Query Export(RunDateH1 As %Date, RunDateH2 As %Date) As %SQLQuery
    {
    SELECT S.Hash,RoutineName,RunDate,RunTime,SumPTime,TotalHits,Variance,RoutineName,T.QueryText
                  FROM DRL.MonitorSQL S LEFT JOIN DRL.MonitorSQLText T on S.Hash=T.Hash
                  WHERE RunDate>=:RunDateH1 AND RunDate<=:RunDateH2
    }
    }