Série: Solucionando Problemas (Parte 1) – Leituras Lógicas Excessivas

Posted on novembro 13, 2012

2


 

Introdução

Como um dos vilões de performance do SQL Server, ele pode causar bastante dor de cabeça e tempo para otimização. As Leituras Lógicas acontecem quando os dados que estavam no disco são colocados na memória do SQL Server (Data Cache), após isso, todas as leituras que refereciarem esse mesmo conjunto que foi carregado pela primeira vez, não precisará mais acessar o disco mais sim o Cache, o que passa ser uma operação muito mais eficiente e performática. Ou seja, toda vez que o SQL Server recebe uma requisição, se a página não estiver em cache, leituras físicas são executadas, se essa página já estiver em cache então o SQL Server simplesmente usa o Data Cache para retornar a consulta assim realizando leituras lógicas.

SYS.dm_exec_query_stats

Essa Dynamic Management View tem como objetivo capturar informações do Cache, assim todas as consultas que são colocadas no Buffer Pool apareceram nesta view. A cada objeto que é colocado em Cache é disponibilizado diversas informações. Para melhor entender, você pode ver aqui – http://msdn.microsoft.com/pt-br/library/ms189741.aspx . Com isso, nós podemos utilizar outras Dynamic Management Views e assim retornar o texto da consulta e seu plano de execução, agora podemos saber quais consultas estão consumindo mais no nosso ambiente.

 

SELECT TOP 30 WITH TIES

        total_logical_reads,

        last_logical_reads,

        min_logical_reads,

        max_logical_writes,

        sql_handle,

        plan_handle,

        query_hash,

        query_plan_hash,

        plan_generation_num,

        creation_time,

        last_execution_time,

        execution_count,

        total_physical_reads,

        total_logical_writes,

        total_elapsed_time,

        C.dbid,

        C.objectid,

        text,

        C.encrypted,

        query_plan

FROM sys.dm_exec_query_stats as EQS

CROSS APPLY sys.dm_exec_sql_text(EQS.sql_handle) AS C

CROSS APPLY sys.dm_exec_query_plan(EQS.plan_handle) AS T

ORDER BY total_logical_reads DESC

GO

image

(Figura 1 – Cache de Planos de Execução Parte 1.)

image

(Figura 2 – Cache de Planos de Execução Parte 2. Informações do Texto de Plano de Execução das Consultas em Cache.)

O Problema

Agora imagine em seu sistema se deparar com consultas que estão realizando diversas leituras lógicas. Bem leituras lógicas são logicamente melhores do que leituras físicas porém quando vemos consultas específicas realizando diversas leituras lógicas e dependendo do plano de execução da consulta devemos nos preocupar, leituras lógicas excessivas requer que os dados sejam lidos do Data Cache e com isso podemos ter pressão de memória e problemas de performance, veremos com mais detalhes esse problema agora.

 

O Cenário

Nesse momento analisaremos e entenderemos como problemas de leituras lógicas podem afetar o ambiente consideravelmente em alguma partes.

 

1 – Verificação dos Planos em Cache – Maiores Leituras Lógicas

SELECT TOP 1 WITH TIES

        total_logical_reads,

        last_logical_reads,

        min_logical_reads,

        max_logical_writes,

        sql_handle,

        plan_handle,

        query_hash,

        query_plan_hash,

        plan_generation_num,

        creation_time,

        last_execution_time,

        execution_count,

        total_physical_reads,

        total_logical_writes,

        total_elapsed_time,

        C.dbid,

        C.objectid,

        text,

        C.encrypted,

        query_plan

FROM sys.dm_exec_query_stats as EQS

CROSS APPLY sys.dm_exec_sql_text(EQS.sql_handle) AS C

CROSS APPLY sys.dm_exec_query_plan(EQS.plan_handle) AS T

ORDER BY total_logical_reads DESC

GO

Capture

(Figura 3 – Quantidade de Leituras Lógicas.)

 

image

(Figura 4 – Texto e Plano de Execução da Consulta.)

 

2 – Verificação da Expectativa de Vida da Página no Cache

Usamos essa consulta para verificar a Expectativa de Vida da página de dados dentro do Cache. Quando possuímos diversas leituras lógicas e dependendo da configuração do seu ambiente, as páginas que estão sendo carregadas rapidamente podem ser retiradas do Cache. Isso ocorre porque o Cache enche, em com isso páginas que estavam guardadas no Cache terão que ser tiradas para que novas entrem, porém essas páginas que foram retiradas, são necessárias para consultas realizadas frequentemente, com isso temos um ciclo ruim, páginas utéis são retiradas para se colocar outras causando assim um grande consumo de I/O e CPU. A média desse contador é 300, se estiver menor que isso estamos tendo uma Expectativa Baixa.

 

SELECT cntr_value AS [Page Life Expectancy]

FROM sys.dm_os_performance_counters

WHERE object_name LIKE ‘%Manager%’

AND counter_name = ‘Page Life Expectancy’

 

image

(Figura 5 – Expectativa Baixa das Páginas em Cache.)

 

3 – Verificando o Wait Stats

Conseguimos verificar qual a maior espera no nosso ambiente. Para cada espera temos uma explicação, com isso podemos rastrear e ter uma noção de como o nosso ambiente se comporta e qual seu maior problema. Cada ambiente se comporta de um jeito, e com essa consuta conseguiremos rastrear o que de mais frequente aparece quando possuímos o problema de Excessivas Leituras Lógicas acontecendo no ambiente.

 

WITH Waits AS

(

     SELECT wait_type,

             wait_time_ms / 1000. AS wait_time_sec,

           100. * wait_time_ms / SUM(wait_time_ms) OVER ( ) AS pct,

             ROW_NUMBER() OVER ( ORDER BY wait_time_ms DESC ) AS rn

FROM sys.dm_os_wait_stats

WHERE wait_type NOT IN ( ‘CLR_SEMAPHORE’, ‘RESOURCE_QUEUE’, ‘SLEEP_TASK’, ‘SLEEP_SYSTEMTASK’, ‘XE_DISPATCHER_WAIT’,

                         ‘WAITFOR’, ‘LOGMGR_QUEUE’, ‘FT_IFTS_SCHEDULER_IDLE_WAIT’,‘FT_IFTS_SCHEDULER_IDLE_WAIT’,

                         ‘BROKER_EVENTHANDLER’, ‘XE_TIMER_EVENT’, ‘REQUEST_FOR_DEADLOCK_SEARCH’)

)

 

SELECT TOP 100 wait_type AS [Wait Type],

                CAST(wait_time_sec AS DECIMAL(12, 2)) AS [Wait Time (s)] ,

                  CAST(pct AS DECIMAL(12, 2)) AS [Wait Time (%)]

FROM Waits

ORDER BY wait_time_sec DESC

 

image

(Figura 6 – Maior Wait Stats do Ambiente. 25.56%)

 

O Wait Type = SQLTRACE_BUFFER_FLUSH aparece quando uma tarefa espera que outra tarefa que está em segundo plano libere buffers de rastreamento para o disco a cada 4 segundos. Isso ocorre porque das primeiras vezes que essas consultas foram executadas, grandes leituras físicas foram executadas, causando assim uma grande espera. Esse contador pode aparecer em diversos casos, porém aparecer em 1ª lugar, pode nos alertar esse tipo de problema.

 

4 – Verificando Leituras no Disco

Só para constatar melhor esse tipo de problema de performance, iremos visualizar a quantidade de leituras que foram executadas do arquivo de dados do banco em questão. Com isso poderemos constatar melhor o que está acontecendo com nosso ambiente.

 

SELECT DB_NAME(database_id) AS DatabaseName,

        FILE_ID,

        FILE_NAME(FILE_ID) AS NAME,

        D.io_stall_read_ms AS ReadsIOStall,

        D.num_of_reads AS NumsReads,

        CAST(D.io_stall_read_ms / (1.0 + num_of_reads) AS NUMERIC(10,1)) AS AvgReadsStall,

        io_stall_read_ms + io_stall_write_ms AS IOStalls,

        num_of_reads + num_of_writes AS TotalIO,

        CAST(( io_stall_read_ms + io_stall_write_ms ) / (1.0 + num_of_reads + num_of_writes) AS NUMERIC(10,1)) AS AvgIOStall

FROM sys.dm_io_virtual_file_stats(DB_ID(),NULL) AS D

 

Capture

(Figura 7 – Enorme Quantidade de IOStall e Média de Leituras no Arquivo de Dados do Banco de Dados.)

 

5 – Verificando no SO

Durante esse periodo de Excessivas Leituras Lógicas você pode se deparar com os aumentos significativos no(a)…..

image

(Figura 8 – Aumento de Leituras no Disco no qual se encontra o arquivo do banco de dados.)

 

image

(Figura 9 – Devido o grande problema da expectativa de vida da página de dados no Cache a CPU podera aumentar consideravelmente.)

A Solução

Agora iremos entender como podemos melhorar nosso ambiente diante desse problema.

 

1 – Verificação da Configuração MAX Server Memory

Essa configuração é só por precaução, porém de extrema necessidade. Se seu ambiente de alguma forma foi configurado com pouca memória para o SQL Server, então você terá mais e mais problemas no Cache. Com pouca memória para o SQL Server ele terá que frequentemente retirar páginas utéis do Cache para colocar novas.

 

2 – Verificação do Plano de Execução e STATISTICS IO ON

Tendo o plano de execução da consulta é mais fácil entender o que a mesma está fazendo em seu ambiente. Por isso iremos ver como a consulta em questão está se comportando e o que podemos fazer para melhorar o impacto da mesma.

 

image

(Figura 10 – Plano de Execução da Consulta.)

 

(5 row(s) affected)
Table ‘DadosLogicalReads’. Scan count 9, logical reads 101922, physical reads 1504, read-ahead reads 101922, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

(1 row(s) affected)

SELECT [Nome],[NomeAbreviado],[DataNascimento],[Email],[Telefone]

FROM [PerformanceConsideration].[dbo].[DadosLogicalReads]

WHERE [UniqueID]=‘10470C3E-03A3-4645-ECB9-2D4121F4A47F’

Essa consulta está realizando milhares de leituras lógicas para retornar o resultado desejado, o que ela necessita é um índice adequado e com isso teremos um grande ganho de performance.

 

CREATE NONCLUSTERED INDEX idxNCL_DadosLogicalReads

ON DadosLogicalReads (UniqueID)

INCLUDE (Nome, NomeAbreviado, DataNascimento, Email, Telefone)

(5 row(s) affected)
Table ‘DadosLogicalReads’. Scan count 1, logical reads 5, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

(1 row(s) affected)

 

SELECT [Nome],[NomeAbreviado],[DataNascimento],[Email],[Telefone]

FROM [PerformanceConsideration].[dbo].[DadosLogicalReads]

WHERE [UniqueID]=‘10470C3E-03A3-4645-ECB9-2D4121F4A47F’

 

Ou seja, nesse momento passamos de 101.922 leituras lógicas para somente 5.
Se compararmos as consultas para ver o custo para o QO (Query Optimizer) temos: …..

 

SELECT Nome, NomeAbreviado, DataNascimento, Email, Telefone

FROM PerformanceConsideration.dbo.DadosLogicalReads

WHERE UniqueID = ‘10470C3E-03A3-4645-ECB9-2D4121F4A47F’

go

SELECT Nome, NomeAbreviado, DataNascimento, Email, Telefone

FROM PerformanceConsideration.dbo.DadosLogicalReads WITH(INDEX(0))

WHERE UniqueID = ‘10470C3E-03A3-4645-ECB9-2D4121F4A47F’

image

(Figura 11 – Comparação das Consultas.)

 

Além de termos pouquíssimas leituras lógicas não possuímos mais custo algum para o QO (Query Optimizer) comparado com a consulta que tanto nos causava problema de performance.

 

Conclusão

Essa é alguma das formas de se rastrear problemas de Excessivas Leituras Lógicas, desse modo podemos diminuir drasticamente o impacto das consultas dentro do banco de dados.