El método del perfil del tiempo de respuesta

Una lentitud solo tiene causa raíz cuando cada segundo de la espera tiene explicación. Por eso el método empieza por el tiempo que alguien espera, y no por indicadores de toda la base de datos: mide ese tiempo en una operación concreta, lo divide en partes y ataca primero la mayor.

Qué es

El tiempo de respuesta (R) es cuánto demoró la operación para quien la espera. WaitScope lee el trace 10046 de la sesión y divide R en componentes: la CPU de cada tipo de llamada, cada evento de espera y el tiempo que el trace no explica, dentro de las llamadas y entre ellas. La suma de los componentes es exactamente R, así que todo el tiempo tiene dueño.

El método lo describieron Cary Millsap y Jeff Holt en el libro Optimizing Oracle Performance (O'Reilly, 2003), y el nombre Method R es de ellos. El perfil del informe sigue el mismo principio: el tiempo total dividido en partes que suman R.

Los pasos

1. Elija la operación que importa para el negocio. Una tarea con alguien esperándola: cerrar un pedido, emitir una factura, un proceso por lotes que se pasó de su horario. La media de toda la base de datos mezcla esa operación con todas las demás y oculta la causa.
2. Mida R con el trace de esa operación. Active el trace 10046 con esperas solo en la sesión que ejecuta la operación, justo antes de que empiece, y desactívelo justo después de que termine (activar el trace con DBMS_MONITOR, niveles del 10046). En el informe, R es el Tiempo total del Resumen, y el Período muestra si el trace cubre la operación.
3. Ataque el mayor componente. El perfil del tiempo de respuesta viene ordenado por duración. Ningún ajuste ahorra más que el componente que reduce: eliminar un componente del 5% de R quita como máximo el 5% del tiempo.
4. Antes de tocar el SQL, mire la espera por la aplicación y el tiempo no contabilizado. SQL*Net message from client es tiempo fuera de la base de datos, que el ajuste de SQL no reduce (sesión esperando a la aplicación). Un tiempo no contabilizado alto apunta a cola de CPU, trace sin esperas o trace incompleto (dentro de las llamadas, entre llamadas). Corrija la medición antes de sacar conclusiones.
5. Baje a la sentencia, al plan y al objeto. En Sentencias principales por componente, vea qué sentencias gastaron el tiempo del mayor componente. En el detalle de la sentencia, el plan de ejecución muestra la operación que concentra el trabajo, y Objetos con más tiempo de espera muestra la tabla o el índice.
6. Cambie una cosa a la vez. Con dos cambios juntos, no hay forma de saber cuál de ellos cambió el tiempo, ni si uno empeoró lo que el otro mejoró.
7. Mida de nuevo con un trace nuevo. Repita la misma operación, en las mismas condiciones y con el trace activado de la misma forma, y compare el Tiempo total y el componente que atacó. Envíe el archivo nuevo: el mismo archivo de antes abre el informe que ya existe (envío repetido). En el Historial de la consola, la columna Tiempo total muestra el R de cada análisis.

El papel del diagnóstico

La sección Diagnóstico del informe señala patrones que suelen explicar el perfil, en orden de gravedad y, en general, con un enlace al dato que sustenta cada uno. Son pistas, no conclusiones: confírmelas en el perfil y en la sentencia antes de actuar (cómo leer el Diagnóstico).

Cada hallazgo tiene una página en esta documentación, con la causa, la solución y cómo confirmarlo; la lista está en por dónde seguir. La API devuelve el código de cada hallazgo en el campo code, por ejemplo TEMPO_NA_APLICACAO.

En el informe de ejemplo

El informe de ejemplo, hecho con el trace sintético, tiene un Tiempo total de 0,007 s. En el perfil, el mayor componente es SQL*Net message from client, con el 71,3%, y el Diagnóstico empieza por La sesión pasó la mayor parte del tiempo esperando a la aplicación.

Según el paso 4, la conclusión viene antes de mirar el SQL: aunque todos los demás componentes bajaran a cero, R caería como máximo un 28,7%. El siguiente componente, db file sequential read, pesa el 18,5%. Solo entonces vale la pena bajar a la sentencia #1, cuyo plan concentra el tiempo en la operación TABLE ACCESS BY INDEX ROWID (operación que concentra el plan).

Lo que el método no hace

• No explica todo el sistema. El trace muestra una sesión: quién retiene el lock que ella espera, o qué más se ejecutaba en el servidor, queda fuera de él.
• No mide por dentro el tiempo fuera de la base de datos. El tiempo de la aplicación aparece como espera, sin el detalle de lo que ella hacía.
• No funciona con tareas mezcladas. El trace de una sesión que hace varias tareas da un perfil que no describe ninguna de ellas: haga el trace solo de la operación elegida.
• No reemplaza la prueba. Un ajuste que acelera una operación puede retrasar otra: mida también las demás operaciones que importan.

Los límites del producto están en lo que WaitScope no hace.

Por dónde seguir

Cada página trata un hallazgo del Diagnóstico. Agrupadas por el paso del método en el que suelen aparecer:

• Tiempo fuera de la base de datos: sesión esperando a la aplicación y muchos FETCH con pocas filas.
• Tiempo que el trace no explica: dentro de las llamadas, huecos entre llamadas y CPU por encima del tiempo transcurrido.
• Un componente domina: componente dominante, CPU dominante, lectura lenta y muchas lecturas.
• Espera por otras sesiones o por la base de datos: bloqueo, contención, commit, configuración, RAC y Resource Manager.
• Parse y bind: muchos hard parses, un PARSE en cada ejecución y literales en lugar de bind.
• Plan y PL/SQL: operación que concentra el plan, estimación de filas errónea y fila a fila en PL/SQL.
• Otros registros: llamadas lentas, errores de Oracle, fin de datos, rollback, deadlock y trace vacío.

Para leer el informe sección por sección, empiece por el perfil y por el Diagnóstico.