Con mucha frecuencia me encuentro en situaciones en las que hay que interpretar un archivo de dump de Oracle, muchas de estas veces el contenido del archivo tiene información de debug. También a menudo me encuentro con DBAs que aún teniendo estos archivos importantísimos no saben cómo interpretarlos.
En programación de sistemas se busca el escribir código por componentes que a su vez puedan ser ejecutados por otros componentes, el componente que solicita el servicio está interesado únicamente en el resultado del componente llamado. Prácticamente se trata de cajas negras que solicitan un servicio.
El paradigma de este tipo más conocido son las capas de red, donde se tienen -hablando en terminología de programación orientada a objetos- mensajes y atributos que se exponen a los componentes que soliciten un servicio.
Lo mismo sucede con Oracle, dentro de su kernel existen varias capas. Oracle es un producto muy bien instrumentado, y cada capa genera sus mensajes.
Las capas genéricas del kernel de Oracle son -digo genéricas porque éstas han sido las mismas a través de varias versiones del producto pero se han añadido nuevas capas-
OCI Oracle Call Interface
UPI User Program Interface
OPI Oracle Program Interface
KK Compilation Layer
KX Execution Layer
K2 Distributed Execution Layer
NPI Network Program Interface
KZ Security Layer
KQ Query Layer
RPI Recursive Program Interface
KA Access Layer
KD Data Layer
KT Transaction Layer
KC Cache Layer
KS Services Layer
KJ Lock Management Layer
KG Generic Layer
S Operating System Dependencies
September 15, 2008 at 2:14 pm
Hola.
En una base de datos sucedió el siguiente error:
Del alert:
ORA-07445: exception encountered: core dump [koudcon()+40] [SIGBUS] [unknown code] [0x800003FFBFEC0000] [] []
Del trace:
Ioctl ASYNC_CONFIG error, errno = 1
*** SESSION ID:(17.28511) 2008-07-14 07:30:47.736
Exception signal: 10 (SIGBUS), code: 0 (unknown code), addr: 0×800003ffbfec0000, PC: [0x4000000002be5a90, koudcon()+40]
Oracle contestó que se trataba de un bug propio de la versión 9 y recomendó un parche.
Existen varios mensajes que no se como interpretar, o de que manera están relacionados con la lista que expones.
Por ejemplo:
koudcon()+40 (del error del alert)
kpndbcon()+1656
ddfnet2Normal()+296
sou2o()+40
Entre otras.
saludos!
September 30, 2008 at 5:39 pm
Gracias Yatel por enviarme el trace completo, voy a copiar lo que nos interesa para nuestro análisis.
Dentro del trace en la sección de los registros encontramos la misma dirección apuntada cuando se generó el evento SIGBUS cuando se estaba llamando la función koudcon().
*** SESSION ID:(17.28511) 2008-07-14 07:30:47.736Exception signal: 10 (SIGBUS), code: 0 (unknown code), addr: 0x800003ffbfec0000, PC: [0x4000000002be5a90, koudcon()+40]
Registers:
r1: 800003ffbfebffd0 r22: 7fff sr4: b6b5800
rp: 4000000002be5a87 arg3: 7fff sr0: ac88c00
r3: 800003ffbffff3c0 arg2: 7fff sr1: 0
r4: 0 arg1: 0 sr2: 0
r5: 0 arg0: 800003ffbfebffff sr3: 0
r6: 1 dp: 8000000100112638 sr5: 395800
r7: 8000000100160c38 ret0: 800003ffbfebffe8 sr6: ea68400
r8: c00000002effe903 ret1: 800003ffbffffa20 sr7: ac88c00
r9: 800003ffbfffd5c8 sp: 800003ffbffff850 cr0: 1000000000001
r10: 3f r31: 800003ffbfec0000 cr8: fffffffffc071000
r11: 800003ffbfffd588 sar: 10 cr9: 0
r12: 800003ffbfffd584 pcoqh: 4000000002be5a93 ccr: 92ba0c0
r13: 4 pcsqh: 395800 cr12: 92ba1c0
r14: 800003ffbfea8020 pcoqt: 4000000002be5a97 cr13: 8211e00
r15: 800003ffbfea7fb0 pcsqt: 395800 cr24: 0
r16: 800003ffbfea6ec0 eiem: ffffffffffffffff cr25: 81dcb20
r17: 800003ffbfea6ee8 iir: f403342 cr26: 1
r18: e isr: ea68400 mpsfu_hi: 800003ffbfee1408
r19: 800000010018df28 ior: 800003ffbfec0000 mpsfu_lo: 95c56000
r20: 30 ipsw: 8040e0f mpsfu_ov: 9d65e00
r21: 10b38f0000000001 goto: 81bb84c pad: c0b3b87ba36b
De modo que la dirección pertenece a una variable de tipo bind.
Más adelante en el trace aparece la sentencia que generó el error.
SELECT RDM.ITEM_ID ARTICULO3,
_CEDIS
_PARAMETRO3 = 'Y'RDM.STD_CASEPACK CASEPACKRDM3,
RMS.SUPP_PACK_SIZE CASEPACKRMS3
FROM ITEM_MASTER RDM,
RMS100.ITEM_SUPP_COUNTRY@FCRMSPRD RMS,
RMS100.ITEM_LOC@FCRMSPRD RMS1
WHERE RDM.ITEM_ID = RMS.ITEM
AND RMS.ITEM = RMS1.ITEM
AND RMS.SUPPLIER = RMS1.PRIMARY_SUPP
AND RMS.ORIGIN_COUNTRY_ID = RMS1.PRIMARY_CNTRY
AND RMS1.LOC_TYPE = 'W'
AND RMS1.LOC =
AND RMS.PRIMARY_SUPP_IND = 'Y'
AND RDM.STD_CASEPACK RMS.SUPP_PACK_SIZE
AND
Inmediatamente después aparece la sección del stack
----- Call Stack Trace -----calling call entry argument values in hex
location type point (? means dubious value)
-------------------- -------- -------------------- ----------------------------
ksedmp()+184 ? ksedst() 800003FFBFFFD588 ?
800003FFBFFFF8B0 ?
34FF8BEC349DB6 ?
8000000100112638 ?
ssexhd()+636 ? ksedmp() 40000000016F11F7 ?
800003FFBFFFD540 ?
C0000000001A130B ?
800003FFBFFFFE18 ?
_sigreturn()+0 ? ssexhd() 0092BA0C0 ? 000000000 ?
00F403342 ?
800003FFBFFFF850 ?
koudcon()+40 ? _sigreturn() 000000000 ? 000000000 ?
000000000 ? 000000000 ?
kodmcon()+564 ? koudcon() 000000000 ? 000000000 ?
00000000E ? 00000003F ?
kokorsc()+964 ? kodmcon() 000000000 ? 000000000 ?
.....
kksald()+344 ? opiprs() 800000010011EDC0 ?
.....
main()+228 ? sou2o() 000000000 ?
C00000000020BB4B ?
000000002 ? 0680F0A9F ?
$START$()+160 ? main() 0680F0771 ? 000000000 ?
000000001 ?
800003FFBFFF08AB ?
--------------------- Binary Stack Dump ---------------------
Dado que es un stack (pila) leeremos la sección desde la primer línea que aparece pero teniendo en mente que estamos leyendo a partir de la última función ejecutada hasta la primer función ejecutada (cuando no se generaba el problema, incluso cuando se inició la sesión) que corresponde a main().
De este modo la última función es
ksedmp() función para preparar dumps dentro de la capa de servicios (Services Layer)
ssexhd() función dentro de la capa de servicios del sistema operativo (Operating System Dependencies)
_sigreturn() función que regresa la señal enviada por el sistema operativo después de ser llamado
koudcon() función en la que se presenta el error (como ya lo había notificado el RDBMS)
*** SESSION ID:(17.28511) 2008-07-14 07:30:47.736Exception signal: 10 (SIGBUS), code: 0 (unknown code), addr: 0×800003ffbfec0000, PC: [0x4000000002be5a90, koudcon()+40]
Así que tenemos un trace que nos muestra una sesión que ejecuta lo siguiente
1) compilación de SQL. Lo que significa que dicho código no había sido ejecutado anteriormente (función kksald()),
2) no aparece una capa KX de ejecución pero sí aparecen las capas de acceso al sistema operativo. Para resolver el SQL Oracle necesita acceder a una dirección de memoria (Oracle solicita al sistema operativo el contenido de la dirección independientemente de si éste se encuentra en memoria o si ha sido enviado a la memoria virtual),
3) ejecución de la función koudcon(), otra función propia del RDBMS de Oracle, que solicita la lectura de lo que se encuentra en la dirección 0×800003ffbfec0000,
4) el sistema operativo regresa un error porque la dirección compartida (el sistema operativo es Unix) no tiene privilegios de acceso por parte del usuario oracle o bien porque no existe nada en dicha dirección,
5) el error se notifica a la función ssexhd()* desde el sistema operativo, esta es una función propia del RDBMS y se encuentra en las librerías
./libserver11.a./libagtsh.so.1.0
./libagtsh.so
./libagent11.a
./libgeneric11.a
./liborasdk.so.11.1
./libclntsh.so
./libclntsh.so.11.1
./libclntsh.so.10.1
./liborasdk.so
6) la función ssexhd() debe de tener una sección para el manejo de excepciones y es precisamente en esta parte de su código donde se ejecuta la función ksedmp() de la capa KS (Services Layer) que es la que finalmente se encarga de generar las entradas en
-alert log
-salida estándar de la sesión que tuvo el problema
-el trace file (incluída su generación)
Finalmente tengo un par de comentarios.
A. Dado que el error se presenta en cierta dirección de memoria para un pedazo de código que se ejecuta muy frecuentemente (en las capas KK, S y KX) no creo que el error sea repetible y no es precisamente este SQL el que tendrá siempre problemas. El usuario final puede ejecutar nuevamente su proceso, pero dado que hay un problema de direccionamiento y/o cálculo de las direcciones donde se almacenan datos el problema estará latente y otro proceso será impactado. La situación que presentas es un bug.
B. Es muy importante revisar el resto de los traces cuando éstos se presentan, en el trace dentro del “Binary Stack Dump” hay siempre información relevante. En el resto de los logs (incluída la salida estándar) dice
ksedmp: internal or fatal errorORA-07445: exception encountered: core dump [koudcon()+40] [SIGBUS] [unknown code] [0x800003FFBFEC0000] [] []
Pero en el trace file aparece lo siguiente
.....800003FFC0000920 004F5241 2D303734 34353A20 65786365 [.ORA-07445: exce]
800003FFC0000930 7074696F 6E20656E 636F756E 74657265 [ption encountere]
800003FFC0000940 643A2063 6F726520 64756D70 205B6B6F [d: core dump [ko]
800003FFC0000950 7564636F 6E28292B 34305D20 5B534947 [udcon()+40] [SIG]
800003FFC0000960 4255535D 205B756E 6B6E6F77 6E20636F [BUS] [unknown co]
800003FFC0000970 64655D20 5B307838 30303030 33464642 [de] [0x800003FFB]
800003FFC0000980 46454330 3030305D 205B5D20 5B5D0A00 [FEC0000] [] []..]
.....
que es información nueva para el administrador si éste se guía únicamente por la información humanamente legible en los otros logs. Aquí nos dice claramente que existe un evento del sistema operativo SIGBUS (en otro lugar con el tipo 10), con esta información podemos acceder a la nota 211909.1 -que no transcribiré aquí- que nos explica con mucho menor detalle lo que expliqué en este comentario.
Para fines prácticos hay que aplicar un parche.
Espero que el ejemplo de cómo podemos interpretar y descifrar un error utilizando el conocimiento de las capas del kernel de Oracle.
Notas:
*La función ssexhd() pertenece al RDMS por lo que tiene que ser portable con distintos sistemas operativos, es por ello que Oracle Corporation nos dice que los mensajes arrojados por esta función pueden variar dependiendo del sistema operativo sobre el que se instaló el RDBMS.
September 30, 2008 at 6:01 pm
[...] trace mediante un método que pudiera además hacer uso de la información que publiqué en el post Capas del Kernel de Oracle. Me pareció tan interesante que además de generar un comentario al post original decidí copiar [...]
April 18, 2009 at 11:09 am
Hola Karl.
Me gusta tu blog, veo que te gusta mucho los internals de Oracle.
A propósito, tu sabes sobre las vistas x$ sobre las cuales se basan las vistas conocidas.
Por ejemplo, en la vista X$KSMSD se basa v$sga.
Tu que crees que signifique “KSMSD”, o hay alguna otra vista que indique el significado de dichas vistas x$ ?
saludos!!
April 29, 2009 at 10:11 am
Gracias Yatel.
Sobre la primer pregunta de la relación entre vistas y las tablas fijas x$ sobre las que se basan hice un post http://karlmudespacher.wordpress.com/2009/04/29/fixed-tables-vs-views-tablas-fijas-y-vistas dedicado.
En el caso de la tabla fija x$ksmsd no he encontrado la descripción del nombre dentro de las estructuras de la instancia ni en el código del RDBMS. Sin duda está en el área de desarrollo en un documento, en mi opinión la tabla fija viene de X$KernelServiceMemorySgaDefinition. Cuando uno llega a este nivel en las estructuras de Oracle es cuando creo pueden entrar las opiniones no fundamentadas. Sin embargo también a estos niveles Oracle casi siempre utiliza la primer letra de una palabra para una estructura, y con un poco de suerte el nombre que creemos es el correcto.
Por ejemplo X$GLOB (que es de donde vienen todos los objetos existentes, independientemente del tipo) bien puede ser X$GenericLayerOBject.