"Snapshot too old usando un indice sobre una fecha ¿?

[gnzsoloyo]

Tengo un misterio que no logramos resolver, y que nos está causando un enorme dolor de cabeza.
En el sistema, toas las aplicaciones postean sus mensajes en una cola, y luego estos mensajes se graban en una serie de tablas, todas relacionadas con una tabla cabecera, que denominaremos log_sistema. Esta cabecera llega a recibir 36 millones de registros/día (si, son bastantes).
Diariamente se eliminan de esa tabla todos los registros anteriores a cierta fecha, a fin de mantener solamente una cantidad de días, para análisis de performance. Este proceso de borrado se hace automáticamente por medio de un SP que corre todos los días.
Para determinar el rango a borrar el SP realiza algunas consultas, buscando las fechas más antiguas, y es una de las comprobaciones la que nos está causando problemas.
En la consulta problemática, usamos dos variables, una NUMBER y otra DATE. La variable fechaHasta es una variable DATE que contiene un DateTime representando la fecha hasta la cual se borrarán registros.
Si usamos un rango:

Código SQL:

SELECT COUNT(1)
INTO totalDias
FROM log_sistema
WHERE TIEMPO BETWEEN fechaDesde AND fechaHasta
AND ROWNUM = 1;
 

la consulta se ejecuta perfectamente y muy rápida.
Pero si buscamos directamente la menor a esa fecha:

Código SQL:

SELECT COUNT(1)
INTO totalDias
FROM log_sistema
WHERE TIEMPO < fechaHasta
AND ROWNUM = 1;
 

la consulta dura una enormidad y termina cayendo por "snapshot too old".
Un detalle: No podemos modificar los segmentos de rollback porque los administradores de base de datos no lo autorizan, así que esa solución no es una opción.

El misterio: Lo que no podemos entender es por qué falla, teniendo en cuenta que estamos usando un INDEX sobre el campo "TIEMPO", y pidiendo que busque el menor a cierta fecha, ambas cosas contenidas en el indice.
¿Qué puede causar que falle esta consulta tan elemental, cuyo plan de consulta usa efectivamente (ya lo comprobamos) el indice definido para el campo?

[huesos52]

gnzsoloyo, podrías compartir el plan de ejecución de ambas consultas?

[jc3000]

Hola.

Asumo que fechadesde y fechahasta son DATE, ¿ que tipo de dato es tiempo ? ¿ que campos y en que orden forman parte del indice ?

Salu2

[gnzsoloyo]

Todos los datos son DATE, tanto las dos variables, como el campo indexado (TIEMPO).
En realidad del tipo de datos del resto de las columnas es medio irrelevante, porque jamás las usaremos, ni las consultamos, pero si quieres saberlo cuatro son NUMBER y una es VARCHAR(1000).
De todos modos el mayor de los misterios y la razón del post es el siguiente:
- Sabemos a ciencia cierta que hay apenas algunos miles de registros entre fechaHasta y el registro más antiguo (alrededor de 47.000).
- Si enviamos a buscar el rango como lo pongo en el primer caso, nos devuelve el dato instantáneamente (0,44 segundos).
- Si lo enviamos a buscar por "< fechahasta", se cae por snapshot too old, luego de varios minutos.
- Si envío a buscar una fecha anterior al más antiguo que exista, caso en que debería devolver NULL, se cae por snapshot too old, luego de varios minutos.

Entonces la pregunta es: ¿Por qué pierde tiempo buscando un dato que no existe (la primera entrada del indice es mayor a ese valor), y por qué, en el segundo caso, pese a tener pocos registros (hay entradas, pero son pocas), tarda tanto y se cae?

Es ese punto el que tenemos que resolver: Necesitamos que no pierda tiempo leyendo si no tiene registros o bien, que tarde poco si los tiene.

[matanga]

- Sabemos a ciencia cierta que hay apenas algunos miles de registros entre fechaHasta y el registro más antiguo (alrededor de 47.000).

Esto no es un factor decisivo, la cantidad resultante de registros solo afecta al fetch (que en este caso, por la función count(), es de 1 registro), pero no afecta para nada al costo de resolver la consulta, por ejemplo, un fullscan que devuelva 1 registro puede tardar más que un indexscan que devuelva 100 registros.

- Si enviamos a buscar el rango como lo pongo en el primer caso, nos devuelve el dato instantáneamente (0,44 segundos).
- Si lo enviamos a buscar por "< fechahasta", se cae por snapshot too old, luego de varios minutos.

Aquí hay dos temas, por un lado, los tiempos en resolver cada consulta, que según comentas, en ambos casos se utiliza el índice sobre el campo Tiempo, pero seguramente sea con diferentes operaciones (ej: index range-scan para la primera e index full-scan para la segunda), por lo que deberías postear el plan de ejecución para poder compararlas, y por otro lado, el error snapshot too old, donde la probabilidad de que ocurra aumenta a mayor cantidad de registros leídos o mayor tiempo en resolver la consulta.

La operación index full-scan en la segunda consulta podría explicar el mayor tiempo de respuesta, y teniendo en cuenta que a los efectos de transacciones es lo mismo que un table full-scan, también podría explicar el error ORA-01555.

- Si envío a buscar una fecha anterior al más antiguo que exista, caso en que debería devolver NULL, se cae por snapshot too old, luego de varios minutos.
Entonces la pregunta es: ¿Por qué pierde tiempo buscando un dato que no existe (la primera entrada del indice es mayor a ese valor), y por qué, en el segundo caso, pese a tener pocos registros (hay entradas, pero son pocas), tarda tanto y se cae?

El optimizador sabe el valor mínimo o máximo de una columna por los histogramas en la vista ALL_TAB_COL_STATISTICS (campos HIGH_VALUE y LOW_VALUE), si la tabla Log_Sistema tiene inserciones constantes, es probable que esta información esté desactualizada, y por lo tanto, la condición WHERE Tiempo < Valor_Mínimo se tenga que resolver con un index full-scan, en este caso, la solución seria aumentar la frecuencia en que se calculan las estadísticas (dbms_stats.gather_table_stats)

Es ese punto el que tenemos que resolver: Necesitamos que no pierda tiempo leyendo si no tiene registros o bien, que tarde poco si los tiene.

Primero hay que tener en mente una premisa, los procesos de depuración no son compatibles con OLTP, y por lo tanto, se recomienda ejecutarlos en horarios nocturnos o de poca carga de trabajo, dicho esto, la soluciones pueden ser varias:

1. Si el rendimiento no importa, y el problema es el ORA-01555, lo fácil es incrementar el tablespace de undo y el parámetro undo_retention (compatible con OLTP).

2. Si el problema es el rendimiento y además el ORA-01555, tienes las opciones (no tan compatibles con OLTP por los table lock):
2.1. Utilizar Table Partitioning por rangos sobre el campo Tiempo, esto hace que el proceso de depuración sea principalmente de sentencias DDL como alter table Log_Sistema add partition y alter table Log_Sistema truncate partition.
2.2. Utilizar una tabla temporal, por ejemplo:

Código:

create global temporary temp_log_sistema 
as select * from log_sistema
/
create index idx_tiempo on temp_log_sistema(tiempo)
/ 
truncate table log_sistema
/
insert into log_sistema
select * from temp_log_sistema
where tiempo >= fechaHasta
/

3. Utilizar un trigger sobre la tabla Log_Sistema para que en cada insert busque los registros menores a fechaHasta y los mueva a una tabla Log_Sistema_Historico (depuración online y compatible con OLTP).

Saludos

[gnzsoloyo]

Estos serían los planes de consulta que el SQL Navigator 5 me indica que tomará Oracle:
SQL Statement from editor:

Código SQL:

SELECT SUM(1)  logid
  FROM LOG_SISTEMA  WHERE 
      (TIEMPO BETWEEN
          TO_DATE('07/08/2012 12:00:00', 'DD/MM/YYYY hh24:mi:ss') AND
          TO_DATE('07/08/2012 12:04:59', 'DD/MM/YYYY hh24:mi:ss'))
 

------------------------------------------------------------

Cost=2,64018716311899E-308

SELECT STATEMENT RULE
(3) SORT AGGREGATE
(2) NON-UNIQUE INDEX RANGE SCAN LOG4NET.TIEMPO_IDX [Not Analyzed]

SQL Statement from editor:

Código SQL:

SELECT SUM(1)  logid
  FROM LOG_SISTEMA  WHERE 
      (TIEMPO 
          < TO_DATE('07/08/2012 12:04:59', 'DD/MM/YYYY hh24:mi:ss'))
 

------------------------------------------------------------

Cost=2,64018716311899E-308

SELECT STATEMENT RULE
(3) SORT AGGREGATE
(2) NON-UNIQUE INDEX RANGE SCAN LOG4NET.TIEMPO_IDX [Not Analyzed]

El detalle del index full scan ha sido bastante revelador, a lo que hay que sumar el hecho de que no existe ningún momento en el día o la semana en que esa tabla y sus índices estén sin uso (se han llegado a computar 1200 entradas/segundo a la taba de logs, en 7*24*365).
Con eso ya tenemos una idea de lo que nos está pasando.
Ahora hemos modificado el SP en el segmento de esa consulta para sortear el problema.
Veremos cómo resulta al entrar en producción.

[matanga]

Los planes de ejecución informan que el optimizador esta funcionando en modo RBO en vez de CBO, ¿esto es así por diseño?, ten en mente que el modo basado en Reglas es mucho más ineficiente que el modo basado en Costo.

Saludos

[huesos52]

Gnzsoloyo, Tengo entendido que es una BD oracle 8i. cierto?
En esta versión no existe CBO. Todos los planes de ejecución son hechos con RBO.

Esta podría ser una respuesta lógica a lo que puede estar pasando y las diferencias entre ambas consultas.

En RBO al realizar el plan de ejecución basado en reglas y no en costos, el no acotar la consulta con un limite inferior, deja abierta la posibilidad a oracle de buscar datos asumiendo una distribución de datos equitativa entre los rangos de fechas solicitados.

El optimizador sabe el valor mínimo o máximo de una columna por los histogramas en la vista ALL_TAB_COL_STATISTICS (campos HIGH_VALUE y LOW_VALUE), si la tabla Log_Sistema tiene inserciones constantes, es probable que esta información esté desactualizada, y por lo tanto, la condición WHERE Tiempo < Valor_Mínimo se tenga que resolver con un index full-scan, en este caso, la solución seria aumentar la frecuencia en que se calculan las estadísticas (dbms_stats.gather_table_stats)

Este comentario de matanga es muy acertado, y lo mas seguro es que por tu versión se presente esto, ya que las estadisticas no aplican para versiones de oracle 8i.

Personalmente hice un ejercicio parecido aca en mi trabajo (De igual forma la tabla de logs) y ambas consultas me respondían en tiempos muy similares. La versión que tenemos es la 11g.

saludos

[matanga]

Iniciado por huesos52

Gnzsoloyo, Tengo entendido que es una BD oracle 8i. cierto?
En esta versión no existe CBO. Todos los planes de ejecución son hechos con RBO.

No veo que se comente sobre la versión de Oracle, de todos modos, el optimizador basado en costo (CBO) fue introducido en Oracle 7, posteriormente en Oracle 8i aparece el paquete dbms_stats (que reemplaza el comando analyze) y además el modo CBO pasa a ser el recomendado para nuevos desarrollos mientras que el modo RBO se mantiene solo por compatibilidad, y finalmente, en Oracle 10g el modo RBO queda descontinuado.

En es este caso, a menos que existan razones específicas, recomiendo utilizar CBO, ya que reducir el tiempo de la consulta u optimizar el acceso a la tabla (cantidad de bloques leídos) puede ser una solución al error ORA-01555.

Saludos