Para los que nunca han hecho uso de, Aastra es una marca de telefonía con base en Ontario, Canadá. Últimamente, su crecimiento se ha dado fuertemente gracias a la prevalencia de sistemas como Elastix que se integran muy bien con sus teléfonos. Mi percepción personal de la marca desde el punto de vista del valor del producto es intermedio: no es una marca tan barata como Grandstream o Yealink, pero tampoco es una tan cara como Polycom o Cisco. Es una marca que está a muy buenos medios términos en cuanto a calidad y funcionalidades se refiere.
Un «inconveniente» que tienen sus teléfonos es que son extremadamente sensibles al retraso de paquetes cuando están en modo de stand by. Esto quiere decir que constantemente los teléfonos están enviando paquetes a Asterisk para medir el estado del servicio, y si el servidor por un momento se retrasa con la respuesta, inevitablemente veremos el mensaje de «No service» en la pantalla de los teléfonos, que es como si no estuviéramos registrados.
La solución no siempre está bien establecida porque tenemos que encontrar (y solucionar) lo que sea que esté causando este retraso. Puede ser un problema de la red (no es muy común, pero puede ser) o puede ser que el servidor de Asterisk se encuentre en un proceso que consuma muchos procesos/CPU y ocasione que se retrase para emitir una respuesta. En este caso, vamos a analizar una posible cause de este segundo escenario.
El cliente que hoy me ha reportado que sus teléfonos están perdiendo el registro frecuentemente es una agencia automotriz, que tiene alrededor de unos 140 teléfonos conectados entre Linksys 921 y diversos modelos de la serie Aastra 675x (aunque el problema solo es con los Aastra, por la razón arriba mencionada).
Indagando un poco más, observe que de pronto sus procesos de MySQL subían alredor del 80% del CPU por unos segundos y luego, bajaban a 0%. Esto quiere decir que algo se come el procesador por un instante y luego lo suelta, pudiendo ser la causa del problema que tenemos. Indagué un poco más y me doy cuenta que por default Elastix no utiliza índices en las tablas de CDR, lo cual hace que todos los reportes del detalle de llamadas tengan que «barrer» todos los registros de la tabla para encontrar los que necesitamos. Para un PBX pequeño no hay mucho problema, pero para una tabla que tiene 3.6 millones de registros, buscar en todos ellos resulta algo de uso intensivo de CPU. Para corroborar mi teoria, activé el log de consultas lentas de MySQL, y al hacer un mysqldumpslow desde el Linux CLI, obtuve lo siguiente (no se fijen en el query, fíjense en el tiempo total para ejecutarlo):
[codesyntax lang=»bash»]
[root@100 asterisk]# mysqldumpslow -t 5 /var/log/mysql/mysql-slow.log
Reading mysql slow query log from /var/log/mysql/mysql-slow.log
Count: 14 Time=40.50s (567s) Lock=0.00s (0s) Rows=58.6 (820), asteriskuser[asteriskuser]@[XXX.XXX.XXX.XXX]
SELECT * from (SELECT billsec as billsec ,calldate as calldate,clid as clid,src as src,dst as dst,dcontext as dcontext,channel as channel,dstchannel as dstchannel,lastapp as lastapp,lastdataas lastdata,duration as duration,disposition as disposition,amaflags as amaflags,accountcode as accountcode,uniqueid as uniqueid,userfield as userfield, calldate + INTERVAL duration SECOND as fecha_termino from cdr where calldate >= 'S') as resultado where fecha_termino >='S'order by calldate limit N, N
[/codesyntax]
Como se observa, cada consulta toma 40 segundos. ¡Esto es un mar de tiempo solo para ver las llamadas que ha hecho una extensión el día de hoy! El problema se confirma con un EXPLAIN del mismo query:
[codesyntax lang=»sql»]
mysql> EXPLAIN SELECT * FROM ( SELECT billsec AS billsec ,calldate AS calldate,clid AS clid,src AS src,dst AS dst,dcontext AS dcontext,channel AS channel,dstchannel AS dstchannel,lastapp AS lastapp,lastdata AS lastdata,duration AS duration, disposition AS disposition,amaflags AS amaflags,accountcode AS accountcode,uniqueid AS uniqueid,userfield AS userfield, calldate + INTERVAL duration SECOND AS fecha_termino FROM cdr WHERE calldate >= ‘2011-01-01 00:00:01’) AS resultado WHERE fecha_termino >=’2011/06/17 16:44:23 ‘ORDER BY calldate LIMIT 0, 10000;
+----+-------------+------------+------+---------------+------+---------+------+---------+-----------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra
|
+----+-------------+------------+------+---------------+------+---------+------+---------+-----------------------------+
| 1 | PRIMARY | | ALL | NULL | NULL | NULL | NULL | 592484 | Using where; Using filesort |
| 2 | DERIVED | cdr | ALL | NULL | NULL | NULL | NULL | 3617505 | Using where |
+----+-------------+------------+------+---------------+------+---------+------+---------+-----------------------------+
2 rows in set (27.90 sec)
[/codesyntax]
Allí se nota como la consulta NO usa índices y tiene que recorrer los 3.6M de registros. ¿La solución? Agregar un índice al campo calldate que es donde se hacen las consultas de manera principal. Esto se hace con el siquiente comando en MySQL (ojo: dependiendo del tamaño de la tabla de CDR este proceso puede demorar desde segundos hasta horas, por lo que planea muy bien que tu equipo esté disponible para ejecutar esta tarea)
[codesyntax lang=»sql»]
ALTER TABLE `asteriskcdrdb`.`cdr` ADD INDEX `calldate` (`calldate`);
[/codesyntax]
Y al terminar el proceso, podemos validar ejecutando el mismo EXPLAIN:
[codesyntax lang=»sql»]
+----+-------------+------------+-------+---------------+----------+---------+------+--------+-----------------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra|
+----+-------------+------------+-------+---------------+----------+---------+------+--------+-----------------------------+
| 1 | PRIMARY | | ALL | NULL | NULL | NULL | NULL | 592516 | Using where; Using filesort |
| 2 | DERIVED | cdr | range | calldate | calldate | 8 | NULL | 652745 | Using where |
+----+-------------+------------+-------+---------------+----------+---------+------+--------+-----------------------------+
2 rows in set (8.84 sec)
[/codesyntax]
Como se observa, la consulta ahora está reducida a 650K registros o bien un 82% de ahorro en cuanto al número de registros que se tienen que consultar.
Aunque esta puede bien no ser la única cause del problema, es un excelente primer paso. Ya ahorramos procesamiento en este ejercicio, ahora hay que indagar en que otros procesos del sistema podemos ahorrarnos unos ciclos para así dejar más recursos disponibles para nuestras llamadas.
Suerte,
