[OpenSIPS-Users] Command "opensipsctl dialplan reload" randomly hangs

[DanB]

Hey Guys,

I have noticed the "opensipsctl dialplan reload" command randomly
hanging, sometimes even the server itself becoming non responsible,
other times reloading the dialplan into memory but not reporting
anything on console, the last one becoming unusable until server
restart. This happened in the past as well but with the traffic
increase, it becomes more and more annoying. I suspect the same bug
which was present in the past with fifo hanging.
I should mention that I got about 2000 records in the dialplan table,
so I would say not that much loaded.

The version I am running:
sip1:/home/employee/dan# opensips -V
version: opensips 1.6.1-notls (x86_64/linux)
flags: STATS: Off, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST,
SHM_MEM, SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
svnrevision: 2:6509M
@(#) $Id: main.c 6169 2009-09-22 12:48:37Z bogdan_iancu $
main.c compiled on 14:43:30 Jan 11 2010 with gcc 4.3.2


All I could find in the logs was database reconnection in the case of
hang but no error or something else reported (running debug 7).
Bellow some of the log:
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:mi_fifo:mi_fifo_server: entered consume
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:mi_fifo:mi_fifo_server: **** done consume
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:mi_fifo:mi_fifo_server: done parsing the mi tree
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]: DBG:dialplan:dp_load_db: init
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
INFO:db_mysql:db_mysql_submit_query: disconect event for 0x77f060
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
INFO:db_mysql:reset_all_statements: reseting all statements on
connection: (0x77fd18) 0x77f060
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_connect: opening connection:
mysql://xxxx:xxxx@192.168.11.253/sipeandb
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_connect: connection type is 192.168.11.253 via
TCP/IP
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_connect: protocol version is 10
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_connect: server version is 5.0.51a-24+lenny1-log
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
INFO:db_mysql:db_mysql_submit_query: re-connected successful for
0x77f060
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:core:db_new_result: allocate 48 bytes for result set at 0x784258
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: 8 columns returned from the query
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:core:db_allocate_columns: allocate 224 bytes for result columns at
0x7842a0
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7842e0)[0]=[dpid]
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x7842f0)[1]=[pr]
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x784300)[2]=[match_op]
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x784310)[3]=[match_exp]
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x784320)[4]=[match_len]
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: use DB_INT result type
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x784330)[5]=[subst_exp]
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x784340)[6]=[repl_exp]
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: RES_NAMES(0x784350)[7]=[attrs]
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_get_columns: use DB_STRING result type
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:db_mysql:db_mysql_fetch_result: converting row 0 of 2042 count 500
Apr 22 14:27:19 sip1 /usr/sbin/opensips[16299]:
DBG:core:db_allocate_rows: allocate 136000 bytes for result rows and
values at 0x79c5d8

Ta,
DanB