Opensips 2.1.2 occasionally crashes when connection to database fails when
using db_virtual module. In this case, there is only one backend.
It's a rare problem - usually when the query fails, it doesn't cause a crash.
But the crash has happened multiple times, on different machines connected to
different databases.
This query is generated by a timer route that runs every minute. I'm waiting
for it to happen again so I can get a core dump file.
The configuration for db_virtual is as follows:
modparam("db_virtual", "db_urls", "define set1 FAILOVER")
modparam("db_virtual", "db_urls", "postgres://xxx:[email protected]:5433/xxx")
modparam("db_virtual", "db_max_consec_retrys", 5)
modparam("db_virtual", "db_probe_time", 10)
And the log:
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
DBG:db_postgres:db_postgres_submit_query: 0x7f054ab9a770 PQsendQuery failed:
could not rec
eive data from server: Connection timed out#012 Query: select
ip,grp,mask,port,proto,pattern,context_info,id from opensips_permissions
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
DBG:db_postgres:free_query: PQclear(0xce33f0) result set
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
ERROR:db_postgres:db_postgres_submit_query: 0x7f054ab9a770 PQsendQuery Error:
could not re
ceive data from server: Connection timed out#012 Query: select
ip,grp,mask,port,proto,pattern,context_info,id from opensips_permissions
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]: ERROR:core:db_do_query:
error while submitting query - [select
ip,grp,mask,port,proto,pattern,context_info,id from opensips_permissions ]
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
DBG:db_virtual:db_virtual_query: failover call failed
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]: DBG:core:pool_remove:
removing connection from the pool
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
DBG:db_postgres:db_postgres_free_connection: PQfinish(0xcdaf50)
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
DBG:db_postgres:db_postgres_free_connection: pkg_free(0x7f054ab9a898)
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
DBG:db_virtual:db_virtual_query: curent_con = 0
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
DBG:db_virtual:db_virtual_query: flags2 = 2
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10815]:
DBG:db_virtual:db_virtual_query: curent_con = 0
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10817]:
NOTICE:core:io_wait_loop_epoll: EPOLLIN(read) event: epollwait() set event
EPOLLHUP - connection closed by the remote peer!
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10817]:
DBG:core:handle_tcp_worker: dead tcp worker 6 (pid 10815, no 0) (shutting down?)
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10817]: DBG:core:io_watch_del:
[TCP_main] io_watch_del op on index 25 32 (0x84b1e0, 32, 25, 0x0,0x1) fd_no=27
called
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10817]:
NOTICE:core:io_wait_loop_epoll: EPOLLIN(read) event: epollwait() set event
EPOLLHUP - connection closed by the remote peer!
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10817]: CRITICAL:core:receive_fd:
EOF on 35
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10817]: DBG:core:handle_worker:
dead child 17, pid 10815 (shutting down?)
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10817]: DBG:core:io_watch_del:
[TCP_main] io_watch_del op on index 17 35 (0x84b1e0, 35, 17, 0x0,0x1) fd_no=26
called
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:core:handle_sigs:
status = 139
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: INFO:core:handle_sigs:
child process 10815 exited by a signal 11
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: INFO:core:handle_sigs:
core was generated
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: INFO:core:handle_sigs:
terminating due to SIGCHLD
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10817]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10816]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10814]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10813]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10812]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10811]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10810]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10809]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10808]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10807]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10806]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10802]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10801]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10803]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10804]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10800]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10799]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10805]: INFO:core:sig_usr: signal
15 received
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: INFO:core:cleanup: cleanup
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: INFO:pike:pike_exit:
destroying...
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:tm:tm_shutdown:
tm_shutdown : start
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]:
DBG:tm:unlink_timer_lists: emptying DELETE list for set 0
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:tm:tm_shutdown:
emptying hash table
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:tm:tm_shutdown:
releasing timers
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:tm:tm_shutdown:
removing semaphores
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:tm:tm_shutdown:
destroying callback lists
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:tm:tm_shutdown:
tm_shutdown : done
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]:
NOTICE:db_virtual:destroy: destroying module...
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:core:shm_mem_destroy:
destroying the shared memory lock
Oct 24 18:32:10 rst-lab-gw /usr/sbin/opensips[10798]: DBG:core:handle_sigs:
terminating due to SIGCHLD
Thanks,
Jeremiah
_______________________________________________
Users mailing list
[email protected]
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
