Crash de Asterisk y cores

Nota: Este post lo tenía en borrador durante un largo tiempo. Así que con el último caso que en estos momentos estoy analizando decidí terminar este texto.

Una cosa que podría hacerte lidiar es cuando un Asterisk presenta caídas sin explicación alguna. A veces el cliente me indica que tiene problemas con su PBX Asterisk y no sabe que realmente sucede.   Generalmente me dicen que las llamadas se cortan y que la PBX se cae varias veces al día e incluso he escuchado que se ha tenido que reiniciar unas 400 veces al día,  posiblemente esto último puede ser una exageración.

En estos caso los mensajes de la CLI pueden no dar  muchos indicios que está realmente sucediendo. La mejor forma es analizar y generar un backtrace en el momento que el sistema cae.  Asterisk cuenta con un script llamado safe_asterisk que vuelve a ejecuta Asterisk y en caso que haya una caida, uno puede correr Asterisk de esta manera  y tener una continuidad “ininterrumpida”.

Primero, se  debe indicar que se generen .core cuando se presenten las caídas, con estos archivos se puede analizar que puede estar sucediendo.  Para esto verifica que Asterisk esté corriendo con el parámetro -g, en caso que se esté arrancando con safe_asterisk este agrega el parámetro necesitado, para ver como está corriendo ejecuta  “ps aux  | grep asterisk”  debería aparecer lo siguiente en la consola

asteriskdev# ps aux | grep asterisk
root 2526 0.0 0.0 1752 312 pts/0 S 14:14 0:00 /bin/sh /usr/sbin/safe_asterisk
root 2528 19.0 1.6 30768 17460 pts/0 Dl 14:14 0:00 /usr/sbin/asterisk -f -vvvg -c
root 2556 0.0 0.0 3276 704 pts/0 S+ 14:14 0:00 grep asterisk

En caso anterior estoy usando safe_asterisk para arrancar Asterisk. Si ejecutas solamente asterisk, recuerda agregar el párametró -g. En distribuciones tipo Debian puedes encontrar el archivo /etc/defaults/asterisk, ahí busca la variable de configuración COREDUMP y seteala en yes

Nota: En caso que quieras analizar el core en otra máquina la arquitectura, sistema y la compilación debe ser igual al sistema donde se producen.

Un punto importante es que durante la configuración, antes de la compilación, se debe habilitar la opción DONT_OPTIMIZE. También es muy recomendable agregar los flags de compilación DEBUG_THREADSBETTER_BACKTRACES. Esto lo puedes conseguir ejecutando “make menuconfig”, escoges Compiler Flags, seleccionas y “Save and Exit” o directamente.

Ahora,  luego de las caídas los archivos van quedando generalmente donde arrancaste el proceso. Recuerda que debes correr “asterisk -g” o en tu configuración del script de inicio del sistema.

Luego cuando tengas tu archivo core, debes usar gdb para hacer la parte más entretenida del proceso para averiguar que diantes está sucediendo.

Después de asegurarte que tienes gdb instalado, puedes tomar un backtrace de la caída.

gdb -se "asterisk" -ex "bt full" -ex "thread apply all bt" --batch -c archivo_core > /tmp/log_backtrace.txt

Esto te genera un archivo en  /tmp/log_backtrace.txt  de tu archivo_core.  Acá pego un caso del caso actual, esto da una pista de lo que puede estar sucediento


[New LWP 12112]
[New LWP 7195]
[New LWP 12039]
Warning: couldn't activate thread debugging using libthread_db: Cannot find new threads: generic error

warning: File "/lib/x86_64-linux-gnu/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "$debugdir:$datadir/auto-load".

warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
To enable execution of this file add
add-auto-load-safe-path /lib/x86_64-linux-gnu/libthread_db-1.0.so
line to your configuration file "/root/.gdbinit".
To completely disable this security protection add
set auto-load safe-path /
line to your configuration file "/root/.gdbinit".
For more information about this security protection see the
"Auto-loading safe path" section in the GDB manual.  E.g., run from the shell:
info "(gdb)Auto-loading safe path"
Warning: couldn't activate thread debugging using libthread_db: Cannot find new threads: generic error

warning: File "/lib/x86_64-linux-gnu/libthread_db-1.0.so" auto-loading has been declined by your `auto-load safe-path' set to "$debugdir:$datadir/auto-load".

warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
503    /home/buildbot/build/libmariadb/violite.c: No existe el fichero o el directorio.
Core was generated by `asterisk -g'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  vio_blocking (vio=0x0, block=1 '\001', previous_mode=0x0) at /home/buildbot/build/libmariadb/violite.c:503

Otra forma es de la siguiente manera “interactiva”

gdb -se "asterisk" -c archivo_core | tee /tmp/log_backtrace.txt

 

Esto te lleva a la consola de gdb, donde podrías usar bt, bt full o thread apply all bt. Y donde podrás encontrarte preciosuras la siguiente salida:

 

warning: Unable to find libthread_db matching inferior's thread library, thread debugging will not be available.
503    /home/buildbot/build/libmariadb/violite.c: No existe el fichero o el directorio.
Core was generated by `asterisk -g'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  vio_blocking (vio=0x0, block=1 '\001', previous_mode=0x0) at /home/buildbot/build/libmariadb/violite.c:503
(gdb) bt
#0  vio_blocking (vio=0x0, block=1 '\001', previous_mode=0x0) at /home/buildbot/build/libmariadb/violite.c:503
#1  0x00007f15c1b3aa8e in my_real_read (net=0x7f15e001ad80, complen=0x7f1622bcc2c0) at /home/buildbot/build/libmariadb/net.c:709
#2  0x00007f15c1b3ac17 in my_net_read (net=0x0) at /home/buildbot/build/libmariadb/net.c:723
#3  0x00007f15c1b2a285 in net_safe_read (mysql=0x7f15e001ad80) at /home/buildbot/build/libmariadb/libmariadb.c:390
#4  0x00007f15c1b2a4f7 in mthd_my_read_query_result (mysql=0x0) at /home/buildbot/build/libmariadb/libmariadb.c:2333
#5  0x00007f15c1b28ed4 in mysql_autocommit (mysql=0x0, mode=<optimized out>) at /home/buildbot/build/libmariadb/libmariadb.c:3230
#6  0x00007f15c1b159db in MADB_DbcSetAttr (Dbc=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0, isWChar=0 '\000') at /home/buildbot/build/ma_connection.c:181
#7  0x00007f15c1b08c80 in MA_SQLSetConnectAttr (ConnectionHandle=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0) at /home/buildbot/build/odbc_3_api.c:2662
#8  0x00007f15c1b08ee8 in SQLSetConnectAttr (ConnectionHandle=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0) at /home/buildbot/build/odbc_3_api.c:2676
#9  0x00007f162003f5d9 in SQLSetConnectAttr () from /usr/lib/x86_64-linux-gnu/libodbc.so.2
#10 0x00007f162028b606 in _ast_odbc_request_obj2 (name=0x20701c8 "asterisk", flags=..., flags@entry=..., file=0x0, file@entry=0x7f15a4a2cb8a "cdr_adaptive_odbc.c", 
    function=0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff>, function@entry=0x7f15a4a2dbc0 <__PRETTY_FUNCTION__.15369> "odbc_log", lineno=0, lineno@entry=411)
    at res_odbc.c:1385
#11 0x00007f162028c673 in _ast_odbc_request_obj (name=<optimized out>, check=check@entry=0, file=file@entry=0x7f15a4a2cb8a "cdr_adaptive_odbc.c", 
    function=function@entry=0x7f15a4a2dbc0 <__PRETTY_FUNCTION__.15369> "odbc_log", lineno=lineno@entry=411) at res_odbc.c:1439
#12 0x00007f15a4a29e67 in odbc_log (cdr=0x7f15e0001070) at cdr_adaptive_odbc.c:411
#13 0x00000000004929b5 in post_cdr (cdr=0x7f15e0001070) at cdr.c:3271
#14 0x0000000000498d40 in cdr_detach (cdr=<optimized out>) at cdr.c:3568
#15 cdr_object_dispatch (cdr=0x0) at cdr.c:1199
#16 0x000000000049933f in handle_channel_cache_message (data=data@entry=0x0, sub=0x1, sub@entry=0x1c94dc8, message=0x0) at cdr.c:2129
#17 0x00000000005b9f0e in router_dispatch (data=0x1c963a8, sub=0x1c94dc8, message=0x7f1504003ce8) at stasis_message_router.c:201
#18 0x00000000005ae0bb in subscription_invoke (message=0x7f1504003ce8, sub=0x1c94dc8) at stasis.c:433
#19 dispatch_exec_async (local=<optimized out>) at stasis.c:695
#20 0x00000000005c32b6 in ast_taskprocessor_execute (tps=0x1c93a58) at taskprocessor.c:776
#21 default_tps_processing_function (data=data@entry=0x1c91ef8) at taskprocessor.c:184
#22 0x00000000005d496a in dummy_start (data=<optimized out>) at utils.c:1237
#23 0x00007f16245760a4 in start_thread (arg=0x7f1622bcd700) at pthread_create.c:403
#24 0x00007f162385e87d in __GI_epoll_pwait (epfd=0, events=0x1, maxevents=0, timeout=-1, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:54
#25 0x0000000000000000 in ?? ()
(gdb) bt
#0  vio_blocking (vio=0x0, block=1 '\001', previous_mode=0x0) at /home/buildbot/build/libmariadb/violite.c:503
#1  0x00007f15c1b3aa8e in my_real_read (net=0x7f15e001ad80, complen=0x7f1622bcc2c0) at /home/buildbot/build/libmariadb/net.c:709
#2  0x00007f15c1b3ac17 in my_net_read (net=0x0) at /home/buildbot/build/libmariadb/net.c:723
#3  0x00007f15c1b2a285 in net_safe_read (mysql=0x7f15e001ad80) at /home/buildbot/build/libmariadb/libmariadb.c:390
#4  0x00007f15c1b2a4f7 in mthd_my_read_query_result (mysql=0x0) at /home/buildbot/build/libmariadb/libmariadb.c:2333
#5  0x00007f15c1b28ed4 in mysql_autocommit (mysql=0x0, mode=<optimized out>) at /home/buildbot/build/libmariadb/libmariadb.c:3230
#6  0x00007f15c1b159db in MADB_DbcSetAttr (Dbc=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0, isWChar=0 '\000') at /home/buildbot/build/ma_connection.c:181
#7  0x00007f15c1b08c80 in MA_SQLSetConnectAttr (ConnectionHandle=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0) at /home/buildbot/build/odbc_3_api.c:2662
#8  0x00007f15c1b08ee8 in SQLSetConnectAttr (ConnectionHandle=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0) at /home/buildbot/build/odbc_3_api.c:2676
#9  0x00007f162003f5d9 in SQLSetConnectAttr () from /usr/lib/x86_64-linux-gnu/libodbc.so.2
#10 0x00007f162028b606 in _ast_odbc_request_obj2 (name=0x20701c8 "asterisk", flags=..., flags@entry=..., file=0x0, file@entry=0x7f15a4a2cb8a "cdr_adaptive_odbc.c", 
    function=0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff>, function@entry=0x7f15a4a2dbc0 <__PRETTY_FUNCTION__.15369> "odbc_log", lineno=0, lineno@entry=411)
    at res_odbc.c:1385
#11 0x00007f162028c673 in _ast_odbc_request_obj (name=<optimized out>, check=check@entry=0, file=file@entry=0x7f15a4a2cb8a "cdr_adaptive_odbc.c", 
    function=function@entry=0x7f15a4a2dbc0 <__PRETTY_FUNCTION__.15369> "odbc_log", lineno=lineno@entry=411) at res_odbc.c:1439
#12 0x00007f15a4a29e67 in odbc_log (cdr=0x7f15e0001070) at cdr_adaptive_odbc.c:411
#13 0x00000000004929b5 in post_cdr (cdr=0x7f15e0001070) at cdr.c:3271
#14 0x0000000000498d40 in cdr_detach (cdr=<optimized out>) at cdr.c:3568
#15 cdr_object_dispatch (cdr=0x0) at cdr.c:1199
#16 0x000000000049933f in handle_channel_cache_message (data=data@entry=0x0, sub=0x1, sub@entry=0x1c94dc8, message=0x0) at cdr.c:2129
#17 0x00000000005b9f0e in router_dispatch (data=0x1c963a8, sub=0x1c94dc8, message=0x7f1504003ce8) at stasis_message_router.c:201
#18 0x00000000005ae0bb in subscription_invoke (message=0x7f1504003ce8, sub=0x1c94dc8) at stasis.c:433
#19 dispatch_exec_async (local=<optimized out>) at stasis.c:695
#20 0x00000000005c32b6 in ast_taskprocessor_execute (tps=0x1c93a58) at taskprocessor.c:776
#21 default_tps_processing_function (data=data@entry=0x1c91ef8) at taskprocessor.c:184
#22 0x00000000005d496a in dummy_start (data=<optimized out>) at utils.c:1237
#23 0x00007f16245760a4 in start_thread (arg=0x7f1622bcd700) at pthread_create.c:403
#24 0x00007f162385e87d in __GI_epoll_pwait (epfd=0, events=0x1, maxevents=0, timeout=-1, set=0x0) at ../sysdeps/unix/sysv/linux/epoll_pwait.c:54
#25 0x0000000000000000 in ?? ()
(gdb) bt full
#0  vio_blocking (vio=0x0, block=1 '\001', previous_mode=0x0) at /home/buildbot/build/libmariadb/violite.c:503
        sd_flags = <optimized out>
        save_flags = <optimized out>
        tmp = 0 '\000'
        sock = <optimized out>
#1  0x00007f15c1b3aa8e in my_real_read (net=0x7f15e001ad80, complen=0x7f1622bcc2c0) at /home/buildbot/build/libmariadb/net.c:709
        pos = 0x7f15e0016ce0 "\005"
        length = 0
        i = 0
        retry_count = 0
        len = 4294967295
        alarmed = 1 '\001'
        net_blocking = 1 '\001'
        remain = 4
#2  0x00007f15c1b3ac17 in my_net_read (net=0x0) at /home/buildbot/build/libmariadb/net.c:723
        len = <optimized out>
        complen = <optimized out>
#3  0x00007f15c1b2a285 in net_safe_read (mysql=0x7f15e001ad80) at /home/buildbot/build/libmariadb/libmariadb.c:390
        net = 0x0
        len = 0
#4  0x00007f15c1b2a4f7 in mthd_my_read_query_result (mysql=0x0) at /home/buildbot/build/libmariadb/libmariadb.c:2333
        pos = <optimized out>
        field_count = <optimized out>
        fields = <optimized out>
        length = <optimized out>
#5  0x00007f15c1b28ed4 in mysql_autocommit (mysql=0x0, mode=<optimized out>) at /home/buildbot/build/libmariadb/libmariadb.c:3230
No locals.
#6  0x00007f15c1b159db in MADB_DbcSetAttr (Dbc=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0, isWChar=0 '\000') at /home/buildbot/build/ma_connection.c:181
        ValidAttrs = {2, 1, 0}
#7  0x00007f15c1b08c80 in MA_SQLSetConnectAttr (ConnectionHandle=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0) at /home/buildbot/build/odbc_3_api.c:2662
        Dbc = 0x0
        ret = <optimized out>
#8  0x00007f15c1b08ee8 in SQLSetConnectAttr (ConnectionHandle=0x7f15e001aa50, Attribute=102, ValuePtr=0x1, StringLength=0) at /home/buildbot/build/odbc_3_api.c:2676
No locals.
#9  0x00007f162003f5d9 in SQLSetConnectAttr () from /usr/lib/x86_64-linux-gnu/libodbc.so.2
No symbol table info available.
#10 0x00007f162028b606 in _ast_odbc_request_obj2 (name=0x20701c8 "asterisk", flags=..., flags@entry=..., file=0x0, file@entry=0x7f15a4a2cb8a "cdr_adaptive_odbc.c", 
    function=0xffffffffffffffff <error: Cannot access memory at address 0xffffffffffffffff>, function@entry=0x7f15a4a2dbc0 <__PRETTY_FUNCTION__.15369> "odbc_log", lineno=0, lineno@entry=411)
    at res_odbc.c:1385
        obj = 0x2093d58
        class = 0x2092198
        nativeerror = 0
        numfields = 0
        diagbytes = 0
        state = "\000\000\000\000\000\000\000\000D\314"
        diagnostic = "\000\000\000\000\001\000\000\000\224\255\262\301\025\177\000\000\000
\000\000\000\001\000\000\000\030\000\000\000\060\000\000\000\360\307\274\"\026\177\000\000
\060\307\274\"\026\177\000\000\000\000\000\000\000\000\000\000\320Y\002\340\025\177\000\000
\320\314\274\"\026\177\000\000\000\002\000\000\000\000\000\000\220\001\a\002\000\000\000\000
\000\017\000\340\025\177\000\000@\373\000\200\025\177\000\000\247V]\000\000\000\000\000\350_\a
\002\000\000\000\000\030\000\000\000\060\000\000\000\360\307\274\"\026\177\000\000\060\307\274
\"\026\177\000\000\b\000\000\000\000\000\000\000\070\000\000\000\025\177\000\000\001\000\000\000
\000\000\000\000\000\002\000\000\000\000\000\000\321\001\a\002\000\000\000\000\232\031|#\026\177
\000\000n\000\000\000w", '\000' <repeats 11 times>...
        __PRETTY_FUNCTION__ = "_ast_odbc_request_obj2"
#11 0x00007f162028c673 in _ast_odbc_request_obj (name=<optimized out>, check=check@entry=0, file=file@entry=0x7f15a4a2cb8a "cdr_adaptive_odbc.c", 
    function=function@entry=0x7f15a4a2dbc0 <__PRETTY_FUNCTION__.15369> "odbc_log", lineno=lineno@entry=411) at res_odbc.c:1439
No locals.
#12 0x00007f15a4a29e67 in odbc_log (cdr=0x7f15e0001070) at cdr_adaptive_odbc.c:411
        first = 1
        tableptr = 0x2070190
        entry = <optimized out>
        obj = <optimized out>
        sql = 0x7f15e00259d0
        sql2 = 0x7f15e0007640
        tmp = <optimized out>
        colbuf = "\377\377\377\377\377\377\377\377", '\000' <repeats 16 times>, "h\276E\000\000\000\000\000\377\377\377\377\000\000\000\000\000\312\274\"\026\177\000\000\000\000\000\000\001\003\000\000`\244\261
#\026\177\000\000\000\000\000\000\000\000\000\000\210w\000\340\025\177\000\000\377\377\377\377\377\377\377
\377\230\215\274$\026\177\000\000X\312\274\"\026\177\000\000\001\000\000\000\000\000\000\000 \311\274\
"\026\177\000\000\250\304\206#\026\177\000\000\001\200\255\373\000\000\000\000\210w\000\340\025\177\000\000
\340%I\000\000\000\000\000P\313\274\"\026\177\000\000\240\312\274\"\026\177\000\000xh\000\340\025\177\000
\000xh\000\340\025\177\000\000@\373\000\200\025\177\000\000\000\002\000\000\000\000\000\000"...
        colptr = 0x7f1622bccd4f ""
        stmt = <optimized out>
        rows = 0
        __PRETTY_FUNCTION__ = "odbc_log"
#13 0x00000000004929b5 in post_cdr (cdr=0x7f15e0001070) at cdr.c:3271
        mod_cfg = 0x1c853b8
        __PRETTY_FUNCTION__ = "post_cdr"

 

Bueno, con esto ya tienes un paso adelantado. Si tienes alguna consulta no dudes en contactarme.

 

Nota: Si llegaste hasta aqui puede que interesen los temas que escribo. Puedes seguirme en Twitter o suscribirte a los nuevos artículos

Algunos artículos que pueden ser de tu interes

Deja un comentario

Tu dirección de correo electrónico no será publicada. Los campos obligatorios están marcados con *