Efecto causado cuando es superado el "Max open file descriptors" en Asterisk

[Miguel Alberto Sanz Pardo]

Hola buenos días,

Hace un par de días comenzaron a aparecer este tipo de mensajes en el full.log de una centralita Asterisk 11.21.2 y tuve que reiniciarla:

[2016-04-27 11:06:51] DEBUG[23368][C-000011f5] rtp_engine.c: rtp-engine-local-bridge: Oooh, something is weird, backing out

[2016-04-27 11:06:51] ERROR[23368][C-000011f5] channel.c: ast_read() on chan 'SIP/ccm-prim-00003a5e' called with no recorded file descriptor.

[2016-04-27 11:56:47] ERROR[4866] acl.c: Cannot create socket

[2016-04-27 11:51:31] ERROR[14823][C-00000fb5] res_timing_timerfd.c: Failed to create timerfd timer: Too many open files

[2016-04-27 12:25:29] ERROR[27337][C-00000ef6] cdr_csv.c: Unable to re-open master file /var/log/asterisk//cdr-csv//Master.csv : Too many open files

Estuve buscando info. y si no me confundo lo que ocurrió es que se superó el número máximo de file descriptor abiertos:

# cat /proc/`pidof asterisk`/limits

Limit                     Soft Limit           Hard Limit           Units

Max cpu time              unlimited            unlimited            seconds

Max file size             unlimited            unlimited            bytes

Max data size             unlimited            unlimited            bytes

Max stack size            8388608              unlimited            bytes

Max core file size        unlimited            unlimited            bytes

Max resident set          unlimited            unlimited            bytes

Max processes             15795                15795                processes

Max open files            1024                 4096                 files

Max locked memory         unlimited            unlimited            bytes

Max address space         unlimited            unlimited            bytes

Max file locks            unlimited            unlimited            locks

Max pending signals       15795                15795                signals

Max msgqueue size         819200               819200               bytes

Max nice priority         0                    0

Max realtime priority     0                    0

Max realtime timeout      unlimited            unlimited            us

Los usuarios me reportaron varios problemas antes de reiniciar la centralita y ver posteriormente los logs:

- Al tratar de llamar estaban mucho rato a la espera hasta que se realizaba la llamada (Y no era problema del DNS)

- Cuando alguien llamaba desde otra centralita en la que tengo un mini contact center a usuarios de la centralita en la que tuve los problemas parecía como si las extensiones estuvieran ocupadas. 

- La centralita parecía estar sobrecargada y algunas conversaciones se oían mal.

- No se podía acceder a un interfaz web que tengo en la centralita

¿Alguien de aquí sabe qué problemas pueden ocurrir al alcanzar el max open file descriptors de asterisk? ¿Puede tener sentido lo que me estaba pasando?

Una vez vistos los posibles efectos he estado buscando la causa del problema y creo que la he encontrado, de manera que el número de file descriptors no llegue nunca a ese máximo nunca más (o eso espero). Podía aumentar el nº max de file descriptor abiertos pero no sería la solución al problema. 

Ahora mismo estoy monitorizando el sistema con un cron ejecutando ls /proc/`pidof asterisk`/fd/* |wc -l y escribiendo el resultado en un documento por si volviera a aparecer el problema

un saludo y gracias de antemano

Miguel Sanz

[Raúl Alexis Betancor Santana]

Ese era un problema habitual de Asterisk en las versiones < 1.4.X  ... la pila RTP y SIP, no liberaban correctamente los sockets en una condición 'medio rara' que se daba, y empezaba el sistema a quedarse con choporrocientos sockets abiertos, hasta que llegaba al límite de ficheros abiertos del proceso de asterisk y entonces empezaba a petar todo.

El comportamiento que has visto es normal en esas situaciones de llegar al límite de ficheros abiertos. Localizar el problema exacto suele ser jodido, porque suele ser una combinación de factores, no uno en concreto.

---

--
Este email pertenece a la lista de Asterisk-ES (http://www.asterisk-es.org)
Normas de la lista Asterisk-ES: http://comunidad.asterisk-es.org/index.php?title=Lista:normas-asterisk-es
---
Has recibido este mensaje porque estás suscrito al grupo "asterisk-es" de Grupos de Google.
Para anular la suscripción a este grupo y dejar de recibir sus mensajes, envía un correo electrónico a asterisk-es...@googlegroups.com.
Para publicar en este grupo, envía un correo electrónico a aster...@googlegroups.com.
Visita este grupo en https://groups.google.com/group/asterisk-es.
Para acceder a más opciones, visita https://groups.google.com/d/optout.

[Miguel Alberto Sanz Pardo]

Muchas gracias por tu respuesta Raúl ;)

En mi caso he encontrado/solucionado al menos parte del problema.

# ls /proc/`pidof asterisk`/fd/* -l 

...

lrwx------ 1 asterisk asterisk 64 Apr 29 10:05 /proc/32450/fd/10 -> socket:[567234]

lrwx------ 1 asterisk asterisk 64 Apr 29 10:05 /proc/32450/fd/100 -> socket:[1015811]

lrwx------ 1 asterisk asterisk 64 Apr 29 10:05 /proc/32450/fd/101 -> socket:[1015812]

lrwx------ 1 asterisk asterisk 64 Apr 29 10:05 /proc/32450/fd/102 -> socket:[1015814]

lrwx------ 1 asterisk asterisk 64 Apr 29 10:05 /proc/32450/fd/103 -> socket:[1015860]

lrwx------ 1 asterisk asterisk 64 Apr 29 10:05 /proc/32450/fd/104 -> socket:[1016380]

lrwx------ 1 asterisk asterisk 64 Apr 29 10:05 /proc/32450/fd/105 -> socket:[1016381]

lrwx------ 1 asterisk asterisk 64 Apr 29 10:05 /proc/32450/fd/106 -> anon_inode:[timerfd]

...

No se estaban liberando sockets asociados al anon_inode:[timerfd], pero ese problema ya lo he solucionado(en este caso provenia del código fuente del chan_sccp.so que estaba usando en la centralita para unos terminales CISCO en concreto, pero el developer ya lo ha corregido. Al transferir/capturar/desviar no se liberaba el timerfd con Asterisk 11)

Lo único que sigo viendo demasiados socket:[ ] sin liberar, no se si también estarán relacionados con el mismo problema o no, ni si es normal que haya tantos sockets abiertos.

Actualmente dispongo de una centralita Asterisk 11.21.2 la cual tiene establecido un trunk SIP con una CISCO Call Manager(mientras acabo la migración de la telefonía)., no sé si entre ambas puede que haya algún conflicto y vayan dejando sockets abiertos (además del problema que ya tenía con el canal SCCP)