Parches a instalar en una nueva instalación de Oracle 11.2

¿Vas a instalar Oracle 11.2?
Entonces revisá la nota 1392633.1 "Things to Consider Before Upgrading to 11.2.0.3 to Avoid Poor Performance or Wrong Results". Indica todos los parches necesarios según la versión exacta a instalar (hasta el cuarto dígito, 11.2.0.8 por ejemplo). También está la referencia para 11.2.0.2.
Si ya instalaste y no la revisaste, vas a encontrar varios parches para aplicar ya, porque estos son bugs que impactan en la performance.

A pesar que el proceso de instalación es algo bien conocido y rutinario, esta es una de esas novedades que obliga a actualizar la vieja receta. Instalar estos parches junto con la instalación inicial ahorra tiempo y evita problemas en producción.

Otra novedad que ya tiene varios meses es el paquete oracle-rdbms-server-11gR2-preinstall.prm. Parte de Oracle Enterprise Linux, ajusta parámetros del kernel y del sistema operativo, e instala paquetes faltantes. Está también disponible para 12c, y se pueden ver los detalles de cómo usarlo en este artículo de OTN.

De todas formas, la nota de cabecera para instalaciones es la 169706.1 "Oracle Database (RDBMS) on Unix AIX,HP-UX,Linux,Mac OS X,Solaris,Tru64 Unix Operating Systems Installation and Configuration Requirements Quick Reference (8.0.5 to 11.2)", aunque al día de hoy todavía no tiene una referencia a la nota anterior, 1392633.1.

También existen guías rápidas de instalación hechas por reconocidos profesionales Oracle, como por ejemplo las de Tim Hall o las viejas de Puschitz, donde se muestra las sentencias a ejecutar en cada sistema operativo. Son muy buenas porque resumen los pasos a seguir para un ambiente en particular, a partir del manual de instalación (por ejemplo, para Oracle 11.2 en Linux x64: http://docs.oracle.com/cd/E11882_01/install.112/e47689/toc.htm) lo que ahorra mucho tiempo.
Pero para instalar un ambiente de producción es necesario revisar todas las notas de soporte (http://support.oracle.com) en busca de nuevos fixes (parches) que corrijan defectos (bugs) detectados después que la versión está disponible, por lo que no se evita el trabajo de revisar las dos notas anteriores.

Histogramas de tiempos de ejecución SQL con AWK

Hace unos días tuve que analizar la performance de una aplicación java que usa Oracle y evaluar si el problema de lentitud estaba en las sentencias SQL ejecutadas. El escenario es:
 - el código no se puede modificar
 - la base de datos usada recibe cientos de sentencias por segundo de varias aplicaciones que vienen del mismo servidor.
 - en el mismo servidor de aplicaciones se ejecutan varias aplicaciones java similares a la que tiene problemas.

Como el problema es en producción, no había posibilidad de bajar el resto de las aplicaciones para dejar solo el tráfico de la problemática.

Así que la alternativa disponible fue habilitar un log de ejecución de sentencias en la aplicación.
Esto genera una entrada por cada ejecución en el archivo con este formato:

2013-09-09 14:38:44,066 [org.hibernate.SQL] Sentencia

No sabemos en qué momento se escribe la entrada en el log. Puede ser antes o después de ejecutar la sentencia. Pero lo que sí sabemos es que el tiempo de ejecución es como máximo el tiempo entre dos entradas consecutivas. Así que como una aproximación sirve para tener una idea de por donde puede venir el problema.

Obtener datos útiles de archivos de log con sentencias SQL es una alternativa muy conocida y bien aprovechada en MySQL con utilitarios como pt-query-digest. Sin intentar imitarlo, me alcanza con ver los tiempos de ejecución de las sentencias, cosa que se puede obtener con un simple script AWK tomando el tiempo transcurrido entre dos entradas consecutivas. Por ejemplo, para ver las que demoraron más de un segundo:

oracle@oraculo:~> awk '{split($3,a,":"); sec=60*(60*a[1]+a[2])+a[3]; if(b!=0 && (sec-b)>1){ print $3 " - " sec - b; }; b=sec}' /tmp/pp.txt
    14:38:49,899 - 5,015
    14:38:51,995 - 2,094
    14:43:46,037 - 2,067
    14:43:51,054 - 5,015
    14:43:56,072 - 5,015

Así puedo ir al log y ver cuales fueron esas sentencias para después analizar si realmente tienen buenos planes de ejecución.

Limpié del archivo entradas iniciales antes de empezar la ejecución de sentencias, y algunas entradas finales, mirando con un editor los números de línea (vi y g es lo más simple). Así nos quedamos con las líneas 6821 a 74572:

oracle@oraculo:~> head -n 74572 myjavaapp.2013091112.log | tail -n +6821 > /tmp/pp.txt

Las sentencias SQL incluidas en este log son:

oracle@oraculo:~> grep -ic insert /tmp/pp.txt
    507
oracle@oraculo:~> grep -ic delete /tmp/pp.txt
    0
oracle@oraculo:~> grep -ic update /tmp/pp.txt
    524
oracle@oraculo:~> grep -ic select /tmp/pp.txt
    2254

Para tener una visión más clara del tiempo de ejecución de las sentencias, armo histogramas de tiempos de ejecución, redondeando a 0,1 segundo (tiempos más chicos no me interesa optimizar). El formato de esta salida es: tiempo de ejecución en segundos y cantidad de sentencias.

oracle@oraculo:~> awk 'BEGIN {b=0;} { split($3,a,":"); sec=60*(60*a[1]+a[2])+a[3]; if(b!=0){ n[int((sec-b)*10+.5)/10]++}; b=sec} END {for (i in n) print i,n[i]}' /tmp/pp2.txt | sort -n
   
    0 2268
    0,1 161
    0,2 421
    0,3 207
    0,4 90
    0,5 68
    0,6 50
    0,7 11
    0,8 1
    0,9 2
    2,1 2
    5 3

Se puede ver con claridad que la mayoría de las sentencias se resuelven en menos de 0,4 segundos, lo que indica con claridad que la base de datos no está teniendo problemas, y se debe analizar el código de la aplicación en busca de más pistas de la lentitud observada.

Espero les sea útil.
Un saludo.

Automatizar recover UNTIL CANCEL

Relacionado a mi post anterior, otra de las cosas que ocurre frecuentemente al actualizar una base Oracle de test con un respaldo de producción, es la necesidad de realizar recuperación incompleta UNTIL CANCEL. En este caso la sentencia RECOVER nos va a preguntar qué archivelogs se debe aplicar para dejar la base en un estado consistente.

08:41:07 SYS@test>recover database until cancel using backup controlfile;
ORA-00279: change 2691063472 generated at 03/12/2013 01:30:02 needed for thread 1
ORA-00289: suggestion : /u01/app/oracle/flash_recovery_area/test/archivelog/2013_03_13/o1_mf_1_58643_%u_.arc
ORA-00280: change 2691063472 for thread 1 is in sequence #58643


08:41:29 Specify log: {=suggested | filename | AUTO | CANCEL}

Si estamos recuperando al momento en que se tomó el respaldo, éste incluye archivelogs y ya los copiamos desde el respaldo al directorio sugerido (/u01/app/oracle/flash_recovery_area/test/archivelog/2013_03_13), entonces podemos indicar AUTO para que los aplique sin mayores problemas.
Como referencia, la restauración de archivelogs con RMAN se hace con el comando 'restore archivelog ...'.

Cuando es necesario ir a un momento en el tiempo posterior, usando respaldos adicionales de archivelogs, y sin tener definido con exactitud el tiempo al que queremos llegar, debemos ir aceptando manualmente cada archivelog para luego ver si es hasta ahí donde queremos llegar (por ejemplo si interesa recuperar hasta el momento previo en que se borraron datos en una tabla, y no contamos con la funcionalidad FLASHBACK).

Al presionar enter y aceptar la sugerencia, si el archivo existe en el destino se aplica:

08:41:04 Specify log: {=suggested | filename | AUTO | CANCEL}
 
ORA-00279: change 2691076177 generated at 03/12/2013 02:02:53 needed for thread 1
ORA-00289: suggestion : /u01/app/oracle/flash_recovery_area/TEST/archivelog/2013_03_13/o1_mf_1_58644_%u_.arc
ORA-00280: change 2691076177 for thread 1 is in sequence #58644
ORA-00278: log file '/u01/app/oracle/flash_recovery_area/test/archivelog/2013_03_13/o1_mf_1_58643_8n0rj3kr_.arc' no
longer needed for this recovery

Si todavía no trajimos este archivelog desde el respaldo, o lo dejamos en otro directorio, va a dar este error:

08:41:04 Specify log: {=suggested | filename | AUTO | CANCEL}
 
ORA-00308: cannot open archived log
'/u01/app/oracle/flash_recovery_area/test/archivelog/2013_03_13/o1_mf_1_58645_%u_.arc'
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3

Luego que aplicamos todos los archivelogs que nos parecen necesarios para llegar al tiempo que nos interesa, ingresamos CANCEL. Y aquí es donde puede aparecer el problema: la base todavía no está en un punto consistente.

08:41:04 Specify log: {=suggested | filename | AUTO | CANCEL}
cancel
ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01194: file 1 needs more recovery to be consistent
ORA-01110: data file 1: '/u02/oradata/test/system01.dbf'

Esto es un aviso de que nos faltó aplicar archivelogs, o que nos pasamos del punto que nos interesaba (si tenemos varios respaldos de archivelogs y los trajimos todos, podemos estar aplicando ya el siguiente grupo de archivos).

Cuando cancelamos la recuperación y llegamos a un punto consistente, el mensaje es claro:

09:07:53 Specify log: {=suggested | filename | AUTO | CANCEL}
cancel
Media recovery cancelled.

Ahora sí queda la base lista para ser usada después de abrirla con resetlogs.

09:08:00 SYS@test>alter database open resetlogs;

Database altered.

Si tenemos muchos archivelogs para aplicar, estar pendiente de la pregunta para presionar enter es algo tedioso, y se puede automatizar fácilmente con un script en bash, que continúa la aplicación mientras el resultado de cancelar el recovery no sea exitoso:

#/bin/bash
###############################
# reco.sh
#
# ncalero 5/2010 - recupera aplicando
# archivelogs hasta que CANCEL sea exitoso
#
###############################

RESULT=/tmp/reco.txt
LOG=/tmp/reco-full.txt

# flag que cuenta si aparecen estos errores. Termina cuando sea cero
SIGO=1
while [ $SIGO -gt 0 ]; do
echo "..."
sqlplus / as sysdba <$RESULT 2>&1
recover database until cancel using backup controlfile;
CANCEL
exit;
EOF

# buscamos mensaje "ORA-01194: file 1 needs more recovery to be consistent"
SIGO=`grep -c 01194 $RESULT`
echo "ora-1194 = $SIGO"

if [[ $SIGO -gt 0 ]] ; then
   # se dio el error, hacemos doble validacion con el otro error
   # ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
   SIGO=`grep -c 01547 $RESULT`
   echo "ora-1547 = $SIGO"
fi
cat $RESULT >>$LOG
done

echo " ### Se puede recuperar!!! ### "

Al ejecutar este script, se muestran dos líneas por errores de intentar cancelar, y termina cuando la base queda en un estado consistente:

oracle@oraculo:/local/work/scripts> ./reco.sh
...
ora-1194 = 1
ora-1547 = 1
...
ora-1194 = 1
ora-1547 = 1
...
ora-1194 = 1
ora-1547 = 1
...
ora-1194 = 1
ora-1547 = 1
...
ora-1194 = 1
ora-1547 = 1
### Se puede recuperar!!! ###

Una última consideración: si cuando ingresamos cancel nos dice que necesita más recovery e intentamos resolver el problema dejando la base en un punto anterior en el tiempo al último archivelog aplicado, vamos a obtener el siguiente error:

RMAN> recover database until scn 2691031554;
Starting recover at 12/MAR/2013 09:14:47
using channel ORA_DISK_1
RMAN-00571: ===========================================================
RMAN-00569: =============== ERROR MESSAGE STACK FOLLOWS ===============
RMAN-00571: ===========================================================
RMAN-03002: failure of recover command at 03/12/2013 09:14:48
RMAN-06556: datafile 1 must be restored from backup older than scn 2691031554

Esto se debe a que no podemos deshacer la aplicación de archivelogs que hicimos antes con el comando RECOVER. Tenemos que volver a traer los datafile desde el respaldo con el que empezamos esta maniobra y aplicar los archivelogs hasta ese punto, sin volver a pasarnos.

Espero que les sea útil.
Un saludo.