[OpenSIPS-Users] pua_dialoginfo SVN 6958 causing crashes

Mon Jul 12 11:58:54 CEST 2010

Hi,

I see the core file was not generate - it can provide useful 
information.  So, if you can reproduce this crash, use "ulimit -c 
unlimited" before starting opensips to be sure that you will get a corefile.

After that, use gdb to extract a backtrace - if you do not know how to 
do it, let me know.

Regards,
Bogdan

osiris123d wrote:
> I recently compiled pua_dialoginfo SVN 6958 so that I could use the caller
> and callee _spec_param.  Seems that ever since I started using that my
> OpenSIPS process has been crashing a lot.  Wanted to capture a syslog since
> 1.6.3 is coming out soon.  I finally caught a debug=6 syslog and it shows
> the following
>
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27286]:
> DBG:tm:run_trans_callbacks: trans=0x7f0fdd761da0, callback type 128, id 0 e
> ntered
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27286]:
> DBG:dialog:next_state_dlg: dialog 0x7f0fdd75c610 changed from state 1 to st
> ate 2, due event 2
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27286]:
> DBG:dialog:run_dlg_callbacks: dialog=0x7f0fdd75c610, type=128
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27286]:
> DBG:dialog:run_dlg_callbacks: dialog=0x7f0fdd75c610, type=128
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27286]:
> DBG:dialog:fetch_dlg_value: looking for <dlg_peer>
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27286]:
> DBG:dialog:fetch_dlg_value: var found-> <sip:8005558355 at irock.com;user=phon
> e#015#012>!
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27286]:
> DBG:pua_dialoginfo:__dialog_sendpublish: peer_uri = sip:8005558355 at irock.co
> m;user=phone#015#012
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27286]:
> DBG:core:parse_to_param: user=phone
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27300]:
> CRITICAL:core:receive_fd: EOF on 6
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27300]:
> DBG:core:handle_ser_child: dead child 1, pid 27286 (shutting down?)
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27300]:
> DBG:core:io_watch_del: io_watch_del (0x74e920, 6, -1, 0x0) fd_no=18 called
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> INFO:core:handle_sigs: child process 27286 exited by a signal 11
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> INFO:core:handle_sigs: core was not generated
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> INFO:core:handle_sigs: terminating due to SIGCHLD
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27298]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 kernel: [445173.921384] opensips[27286]: segfault at
> 28 ip 00000000004cac06 sp 00007fff4401ddb0 error 6 in o
> pensips[400000+140000]
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27300]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27297]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27295]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27289]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27294]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27296]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27299]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27291]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27288]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27290]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27292]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27287]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27293]: INFO:core:sig_usr:
> signal 15 received
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:rls:destroy:
> start
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:presence:update_db_subs: delete expired
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> INFO:pike:pike_exit: destroying...
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:pdt:mod_destroy: cleaning up
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:pua_bla:destroy: destroying module ...
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:pua_mi:destroy:
> destroying module ...
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:pua_usrloc:destroy: destroying module ...
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:pua:destroy:
> destroying module ...
> Jul 11 19:22:08 Proxy01 media-dispatcher[2778]: debug: Connection to
> OpenSIPS lost: Connection was closed cleanly.
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:pua:print_ua_pres: #011pres_uri= sip:9012732001 at irock.com   len= 24
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:pua:print_ua_pres: #011etag= a.1278894007.27286.1.0 - len= 22
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:pua:print_ua_pres: #011id= DIALOG_PUBLISH
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:pua:print_ua_pres: #011expires= 3598
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:pua:db_update:
> --------
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:pua:db_update:
> INSERTDB_FLAG
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:presence_xml:destroy: start
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:presence_mwi:destroy: destroying module ...
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> NOTICE:presence:destroy: destroy module ...
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:presence:update_db_subs: delete expired
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: conn=0x8181b8 (tail=8484704) MC=0x
> 8177c0
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: new query=|delete from active_watc
> hers where expires<?|
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: new statement(0x818938) on connect
> ion: (0x8181b8) 0x817760
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_val2bind: added val (0): len=4; type=3; is_null=0
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:xlog:destroy:
> destroy module...
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: conn=0x817620 (tail=8484704) MC=0x
> 8177c0
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: new query=|delete from location wh
> ere expires<? AND expires!=?|
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: new statement(0x7f8ab0) on connect
> ion: (0x817620) 0x817760
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_val2bind: added val (0): len=40; type=12; is_null=0
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_val2bind: added val (1): len=40; type=12; is_null=0
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:pool_remove: connection still kept in the pool
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:tm:tm_shutdown:
> tm_shutdown : start
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:tm:unlink_timer_lists: emptying DELETE list
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:tm:tm_shutdown:
> emptying hash table
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:tm:tm_shutdown:
> releasing timers
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:tm:tm_shutdown:
> removing semaphores
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:tm:tm_shutdown:
> destroying callback lists
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]: DBG:tm:tm_shutdown:
> tm_shutdown : done
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:shm_mem_destroy: 
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:shm_mem_destroy: destroying the shared memory lock
> Jul 11 19:22:08 Proxy01 /usr/local/sbin/opensips[27285]:
> DBG:core:handle_sigs: terminating due to SIGCHLD
>   

-- 
Bogdan-Andrei Iancu
OpenSIPS Bootcamp
20 - 24 September 2010, Frankfurt, Germany
www.voice-system.ro