Amigos hemos hablado en
el anterior artículo respecto de los distintos estados en los que se pueden
encontrar las sesiones abiertas.
Hay un
estado en particular que genera muchas consultas por parte de uds y tiene que
ver con el estado “Suspended”.
La
pregunta que se repite suele ser la siguiente. “Cómo es que la query que corre bajo la sesión nº xx se encuentra en
estado “suspended” si veo con el sp_who2, (o con el active monitor etc), que
soy el único que está atacando la base de datos y además mi isolation level lo seteo con el hint with (nolock)?
La
respuesta es la siguiente…
NO se
trata de que nuestra query no pueda ser resuelta por estar lockeada por otro
proceso nuestra tabla/base de datos a la que queremos acceder..; Lo que
ocurre realmente es que nuestra query está esperando por la liberación de recursos
del sistema para poder ser resuelta. (ejemplo memoria, procesador, i/o).
Recursos lógicos o físicos…
Entendamos que los estados “suspended” son
inevitables en el sql server puesto que el scheduler va organizando y dando
permisos de ejecución a los spids bajo el lema “primero entrado, primero salido”. Cuándo un spid entra en estado “suspended”?
cuando está siendo ejecutado (estado running) y tiene que esperar por la liberación de algún recurso físico o lógico
del sistema. En ese caso, el “scheduler” lo flaguea como “suspended” y le da el
estado “running” a otro proceso que esté en cola, es decir, que tenga el estado
“runnable”.
Qué
debería preocuparnos entonces de un estado suspended? Que el mismo se
transforme en una constante y que se prolongue en el tiempo provocando time outs,
bloqueos o lentitud considerable de nuestro sistema de base de datos.
Qué podemos hacer para evitar
este tipo de espera, cuando se transforman en algo reiterado, que generan
tantas molestias y quejas de los usuarios finales.? Pues sin lugar a dudas
en primer lugar siguiendo las mejores prácticas (ver apartado “como
minimizar la ocurrencia de bloqueos” del siguiente post del año 2015: http://gherrerasqlserver.blogspot.com.ar/2015/06/bloqueos-en-sql-server-que-son-como.html)
El
motivo de mi insistencia en revisar las mejores prácticas tiene que ver con un
principio muy simple. Cuanto más rápido se resuelva una query, menos tiempo
tendremos ocupado un recurso del sistema y por consecuencia lógica, más lejos
estaremos de ver estos molestos estados “suspended”
Ahora bien, como a todos nos ha ocurrido a
medida que fuimos ganando peso en nuestra querida profesión de DBA, llega un día
en que queremos saber “algo más” acerca de los motivos que están generando incómodas
esperas a nuestros procesos, a pesar de entender que somos prolijos dba
apegados a las mejores prácticas…
Les propongo para ello dos tipos de estudios a
saber:
1) ESTUDIO “WAITING TASKS” - permiten
entender el tipo de espera que está afectando a nuestro sistema cuando notamos
al mismo especialmente lento, cuando una query no termina de devolver
resultados mostrando un estado “suspended”,
cuando percibimos bloqueos, cuando recibimos una queja puntual de
usuarios finales por times out etc.
Es decir se trata de un estudio del “ahora” para tratar de entender y
solucionar un problema específico cuyas consecuencias pueden ser las
anteriormente descriptas
2 2) ESTUDIO “WAITING STATS” - (acumuladas
desde el último reinicio de estadísticas). con el objetivo de poder diagnosticar
problemas de performance de nuestro sistema a partir del análisis de las
estadísticas que nos hablan de los tipos
de espera que ocurren con mayor asiduidad en nuestro sistema.
1 1)
Query “ESTUDIO
“WAITING TASKS” “
Se
trata de una query hecha en base al join de vistas del sistema que Microsoft
nos ofrece a saber:
-
Sys.dm_os_waiting_task
: informa acerca de las colas de tareas que esperan por un recurso
-
Sys.dm_exec_requests : informa sobre cada solicitud recibida por
el motor de bd.
-
Sys.dm_exec_sessions : nos devuelve una fila por cada sesión
abierta en el server.
- Msdb.dbo.sysjobs
(tabla): informa los nombres de los Jobs
(si el proceso en espera es un job)
Esta
query es vital para entender cuáles son
los problemas que pueden estar aquejando a nuestro sistema de base de datos
ante time outs o bloqueos que estén ocurriendo en el momento.
Verán,
que entrega información valiosísima tal como: el nº de spid, el status, el tipo
de espera, el nombre del job o proceso, la cantidad de ms de cpu que lleva
consumidos, la cantidad de páginas de memoria, los ms desde que la sesión fue
establecida, las lecturas y escrituras físicas y lógicas, la sesión que está
bloqueando (si se trata de una sesión bloqueada) etc .
Por
último, y antes de dejarles la query, quiero aclararles que en ella filtro el “sesión_id
> 49”, dado que son los sesión id que corresponden a procesos de usuarios
(del 1 al 49) son sesión id del sistema.
-------------------------------------------------------------
-- Estudiar Waiting Task
-- Autor: Gustavo Herrera Sql Server Para Todos
-------------------------------------------------------------
select
c.nt_user_name,
a.session_id,
c.status,
a.wait_type,
a.wait_duration_ms,
c.host_name,
c.program_name,
w.name
as job_name,
c.cpu_time
as 'cpu_session(ms)',
c.memory_usage
as 'pages_memory_session_usage',
c.total_elapsed_time
as 'time_since_session_was_established(ms)',
c.last_request_start_time,
c.last_request_end_time,
c.reads
as 'reads(session)',
c.writes
as 'writes(session)',
c.logical_reads
as 'logical_reads(session)',
(select [TEXT] from sys.dm_exec_sql_text(b.plan_handle)) as 'query',
a.blocking_session_id,
resource_description
---
from sys.dm_os_waiting_tasks as
a
--
left join sys.dm_exec_requests as b
on a.waiting_task_address =
b.task_address
--
left join sys.dm_exec_sessions as c –
on (a.session_id = c.session_id)
--
left join msdb.dbo.sysjobs as w --Devuelve el
nombre del job
on
(substring(left(w.job_id,8),7,2)+
substring(left(w.job_id,8),5,2) +
substring(left(w.job_id,8),3,2) +
substring(left(w.job_id,8),1,2))=
substring(c.program_name,32,8)
--
where a.session_id > 49
order by a.session_id
La query devuelve resultados como este:
Para poner
a prueba nuestra query , antes de ejecutarla contra el server he generado 2
queries que scanean tablas de millones de registros (sesión_id 56 y 57) y he
corrido un job que actualiza una de esas tablas.
El resultado es el que pueden ver en el
cuadro de arriba.
Acorde al tipo de wait task, una sesión puede
verse reflejada tantas veces como thereads tenga asignados.
A no desesperar luego ahondaremos en los distintos tipos de espera (wait ype)
2) Query ESTUDIO
“WAITING STATS”
Se
trata de una query hecha en base a la vista del sistema sys.dm_os_wait_stats.
A través
de esta query podremos ver agrupados todos los waits y el porcentaje que
representan del total de los waits del sistema ordenados de modo decreciente.
Se han
filtrado en esta query algunos tipos de waits considerados “no relevantes”
Listamos solamente los tipos de espera que al menos representan un % 1 de los tipos de espera que nuestro server ha tenido desde el último reinicio de estadísticas (*)
------------------------------------
-- ESTUDIO ESTADíSTICAS DE ESPERA --
-- ---------------------------------
-- Esta query debe ser ejecutada en un solo paso (1 y 2
al mismo tiempo)
--1) Armo una temporal con las estadísticas de espera
acumuladas
WITH
[WaitsStatsStudio] AS
(SELECT
[wait_type],
[wait_time_ms] /
1000.0 AS [WaitS],
[signal_wait_time_ms] / 1000.0 AS [SignalS],
[waiting_tasks_count] AS [WaitCount],
100.0 *
[wait_time_ms] / SUM ([wait_time_ms]) OVER() AS [Percentage],
ROW_NUMBER() OVER(ORDER BY [wait_time_ms] DESC) AS [RowNum]
FROM sys.dm_os_wait_stats
--
WHERE
[wait_type] NOT IN ('BROKER_EVENTHANDLER','BROKER_RECEIVE_WAITFOR',
'BROKER_TASK_STOP', 'BROKER_TO_FLUSH','BROKER_TRANSMITTER','CHECKPOINT_QUEUE',
'CHKPT', 'CLR_AUTO_EVENT','CLR_MANUAL_EVENT', 'CLR_SEMAPHORE','DBMIRROR_DBM_EVENT',
'DBMIRROR_EVENTS_QUEUE','DBMIRROR_WORKER_QUEUE', 'DBMIRRORING_CMD','DIRTY_PAGE_POLL',
'DISPATCHER_QUEUE_SEMAPHORE', 'EXECSYNC', 'FSAGENT','FT_IFTS_SCHEDULER_IDLE_WAIT',
'FT_IFTSHC_MUTEX','HADR_CLUSAPI_CALL','HADR_FILESTREAM_IOMGR_IOCOMPLETION',
'HADR_LOGCAPTURE_WAIT','HADR_NOTIFICATION_DEQUEUE','HADR_TIMER_TASK','HADR_WORK_QUEUE',
'KSOURCE_WAKEUP', 'LAZYWRITER_SLEEP','LOGMGR_QUEUE', 'MEMORY_ALLOCATION_EXT','ONDEMAND_TASK_QUEUE',
'PREEMPTIVE_XE_GETTARGETSTATE','PWAIT_ALL_COMPONENTS_INITIALIZED','PWAIT_DIRECTLOGCONSUMER_GETNEXT',
'QDS_PERSIST_TASK_MAIN_LOOP_SLEEP', N'QDS_ASYNC_QUEUE','QDS_CLEANUP_STALE_QUERIES_TASK_MAIN_LOOP_SLEEP',
'QDS_SHUTDOWN_QUEUE', 'REDO_THREAD_PENDING_WORK','REQUEST_FOR_DEADLOCK_SEARCH','RESOURCE_QUEUE',
'SERVER_IDLE_CHECK','SLEEP_BPOOL_FLUSH','SLEEP_DBSTARTUP', 'SLEEP_DCOMSTARTUP','SLEEP_MASTERDBREADY',
'SLEEP_MASTERMDREADY','SLEEP_MASTERUPGRADED', 'SLEEP_MSDBSTARTUP','SLEEP_SYSTEMTASK','SLEEP_TASK',
'SLEEP_TEMPDBSTARTUP', 'SNI_HTTP_ACCEPT','SP_SERVER_DIAGNOSTICS_SLEEP', 'SQLTRACE_BUFFER_FLUSH',
'SQLTRACE_INCREMENTAL_FLUSH_SLEEP','SQLTRACE_WAIT_ENTRIES', 'WAIT_FOR_RESULTS','WAITFOR', 'WAITFOR_TASKSHUTDOWN',
'WAIT_XTP_RECOVERY', 'WAIT_XTP_HOST_WAIT', 'WAIT_XTP_OFFLINE_CKPT_NEW_LOG','WAIT_XTP_CKPT_CLOSE',
'XE_DISPATCHER_JOIN','XE_DISPATCHER_WAIT', 'XE_TIMER_EVENT')
AND
[waiting_tasks_count] > 0)
-- 2 Listo
aquellos Waits que me representan un %
mayor al 0.99 % del total --
SELECT
MAX
([W1].[wait_type]) AS [Tipo Espera],
CAST
(MAX ([W1].[Percentage]) AS DECIMAL (5,2)) AS [% Porcentaje],
MAX
([W1].[WaitCount]) AS [Q Ocurrencias],
CAST
(MAX
([W1].[WaitS]) AS DECIMAL (16,2)) AS [Q Espera(segundos)],
CAST
(MAX
([W1].[SignalS]) AS DECIMAL (16,2)) AS [Q Señal Espera (segundos)],
CAST
((MAX ([W1].[WaitS]) / MAX ([W1].[WaitCount])) AS DECIMAL (16,4)) AS [Avg Espera
(segundos)],
CAST
((MAX ([W1].[SignalS]) / MAX ([W1].[WaitCount])) AS DECIMAL (16,4)) AS [Avg Señal
Espera (segundos)]
FROM
[WaitsStatsStudio] AS [W1]
INNER JOIN [WaitsStatsStudio] AS
[W2]
ON [W2].[RowNum] <= [W1].[RowNum]
GROUP BY [W1].[RowNum]
having MAX( [W1].[Percentage] ) > 0.99;
GO
Veremos un resultado como el de la siguiente pantalla:
(*) Cada vez que querramos volver a cero el
contador de estadísticas a nivel de server debemos correr esta sentencia:
|
1
2
|
DBCC SQLPERF
(N'sys.dm_os_wait_stats',
CLEAR);
GO
|
Como verán, en “Tipos de Espera”, tenemos una serie de descripciones que serán
objeto del próximos posts..Pero no los quiero dejar sin una breve explicación
de los mismos y en siguientes posts profundizamos les parece? Comencemos…
CXPACKET .
Este tipo
de espera indica la presencia de paralelismo en los planes de ejecución de las
queries. Cuando ocurre este tipo de
espera? Cuando una query tiene varios threads de ejecución paralelos y uno o
más de ellos demora más tiempo que el resto en resolverse. Esto hace que el
resto de los threads queden bloqueados a la espera de que los hilos tardíos terminen
su tarea.
Si el
CXPACKET está acompañado de Pegaloatch_xx waits puede ser un indicador de
scaneo de tablas.
De lo
contrario hay cosas por hacer, seteos por mejorar ..como por ejemplo el Cost
Threshold Parallelism setting, mas será objeto de un futuro post. Lo prometo.
PAGEILOATCH_XX.
Indica que
el Sql Server está esperando por una página que será leída desde el disco.
Puede ser indicativos de problemas de I/O de disco o de problemas de memoria
(tal vez haya demasiada lectura desde disco en lugar de lectura desde memoria).
En la práctica ocurre ante largos scans en tablas. Casi nunca ocurren ante
queries e idx eficientes.
ASINC NETWORK IO
Rara vez
relacionado con problemas de red como su
nombre podría inferirlo suele deberse a esperas que el Sql Server hace
detrás de una consulta pobrísima de un cliente o programa que trae un set
enorme de datos, seguramente sin sentido o en la forma menos performante. (un
select * from) sería un caso típico.
WRITELOG
Indica que
el Log Mangement está aguardando por un flush hacia el disco. Puede indicar que
el subsistema i/o no puede lidear con el volumen del flush de log . En sistemas
con grandes volúmenes puede indicar la presencia de límites internos de flush
log. Tal vez si este es el caso sea hora de de dividir la carga en múltiples
bases de datos o incrementar nuestras transacciones (el tamaño de las mismas)
BROKER RECEIVE WAITFOR
El Servicce
Broker está esperando por nuevos mensajes para su recepción
MSQL XP
El SqlSrv
está aguardando por la finalización de la ejecución de un store procedure
extendido. Tal vez pueda haber un error en nuestro código XP
OLEDB
Puede
indicar una espera causada por un server linkeado o tal vez a algún producto
que esté utilizando vistas del sistema para monitorear..
BACKUPIO
Indica
esperas producidas por procesos de backup lentos (por ejemplo hechos a cintas o
sistemas I/O poco eficientes)..
LCK_M_XX
Nos habla
de un thread esperando por poder establecer un lockeo e indica problemas de
bloqueo. Repasar las mejores prácticas (ver en este post link hacia las mismas)..
BACKUPBUFFER
Suele
aparecer junto al BackupIo y muestra un thread de backup esperando por un
buffer para hacer un write del backup dentro de El.
IO COMPLETION
Suele indicar
problemas del subsistema de I/O. Habla de sobrecarga en el mismo.
PAGELATCH_XX
Se trata cuando
una tarea está esperando para mover data desde el disco al buffer cache. Fallas
de velocidad I/O, presión de memoria, falta de idx pueden ser algunos de los
disparadores de este wait.
RESOURCE SEMAPHORE
Son queries
esperando por su ejecución en memoria. Puede indicar presión de memoria o mucha
concurrencia de carga.
LATCH
Un latch es
un objeto que asegura la integridad de los objetos que residen en Memoria,
particularmente de las páginas residentes. Por lo tanto un wait está indicando
que hay al menos una tarea bloqueando otras tareas para evitar lectura o
escritura.
Amigos os prometo que los próximos post estarán dedicados a profundizar en los distintos tipos de espera.
Como siempre quedo a vuestra disposición.
Espero que les sea de suma utilidad estas dos queries y que las puedan incorporar sus tareas habituales.
Saludos cordiales desde Argentina
Gustavo Herrera.
