[OpenSIPS-Users] CRITICAL:core:sig_alarm_abort: BUG - shutdown timeout triggered, dying...
Josip Djuricic
josip.djuricic at voljatel.hr
Fri Dec 18 14:01:51 CET 2009
Hi Bogdan,
I've had to swithch to v1.6 stable, so It's working now :)
What I notice is that on trunk version I had this
UsrLoc Stats:
usrloc:registered_users = 387432
usrloc:location-users = 387432
usrloc:location-contacts = 12005
usrloc:location-expires = 375427
but on stable 1.6 I have this:
UsrLoc Stats:
usrloc:registered_users = 12005
usrloc:location-users = 12005
usrloc:location-contacts = 12005
usrloc:location-expires = 375427
And I can confirm that memory is now stable, I think it seg faulted because at that ime it has gone 10 times trough 100000users registration, what means usrloc:registered_users had more than 1 000 000 users, that could explain what happened. Somehow I think it was not clearing registered users no matter they expired and was deleted from db.
Perhaps you can confirm that you can reproduce this problem?
Also is there a possibility to get list of known limitations or perhaps bugs on v1.6 that I should be aware of (concerning stability issues before puttying the system in production use)? I know you mentioned release 1.6.1, so what should be important fixes you mentioned in that mail?
Once again sorry for lot of questions.
Thanks,
Josip
-----Original Message-----
From: users-bounces at lists.opensips.org [mailto:users-bounces at lists.opensips.org] On Behalf Of Bogdan-Andrei Iancu
Sent: Friday, December 18, 2009 1:26 PM
To: OpenSIPS users mailling list
Subject: Re: [OpenSIPS-Users] CRITICAL:core:sig_alarm_abort: BUG - shutdown timeout triggered, dying...
Hi Josip,
A key question - how many records do you have in usrloc?
I'm asking because opensips is flushing the usrloc at shutdown and if
you have too many records, this will take some time. Also, the shutdown
time is control by an alarm (couple of seconds), so if the shutdown
takes too long, the alarm will simply kill opensips.
Regards,
Bogdan
Josip Djuricic wrote:
> Hi,
>
> this is what happened tonight on trunk version of opensips. Any ideas?
>
> This is from log, I'm including backtrace also:
>
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:has_stmt_ctx: ctx found for location
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_do_prepared_query: conn=0x791860 (tail=7936152)
> MC=0x798138
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_do_prepared_query: set values for the statement run
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (0): len=11; type=254; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (1): len=32; type=254; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (2): len=40; type=12; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (3): len=8; type=5; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (4): len=25; type=254; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (5): len=4; type=3; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (6): len=4; type=3; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (7): len=4; type=3; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (8): len=10; type=254; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (11): len=21; type=254; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (13): len=40; type=12; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_val2bind: added val (14): len=12; type=254; is_null=0
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> DBG:db_mysql:db_mysql_do_prepared_query: doing BIND_PARAM in...
> Dec 18 03:40:34 test03 /usr/local/sbin/opensips[14946]:
> CRITICAL:core:sig_alarm_abort: BUG - shutdown timeout triggered, dying...
>
> Backtrace from gdb:
> bt:
> #0 0x00007f7d671b3ed5 in raise () from /lib/libc.so.6
> #1 0x00007f7d671b53f3 in abort () from /lib/libc.so.6
> #2 0x00000000004280e0 in sig_alarm_abort (signo=<value optimized out>)
> at main.c:426
> #3 <signal handler called>
> #4 0x00007f7d67243970 in read () from /lib/libc.so.6
> #5 0x00007f7d66be3008 in vio_read () from /usr/lib/libmysqlclient.so.15
> #6 0x00007f7d66be3067 in vio_read_buff () from
> /usr/lib/libmysqlclient.so.15
> #7 0x00007f7d66be41f9 in ?? () from /usr/lib/libmysqlclient.so.15
> #8 0x00007f7d66be459d in my_net_read () from /usr/lib/libmysqlclient.so.15
> #9 0x00007f7d66bdeb72 in cli_safe_read () from
> /usr/lib/libmysqlclient.so.15
> #10 0x00007f7d66bdf2e9 in ?? () from /usr/lib/libmysqlclient.so.15
> #11 0x00007f7d66bb354c in ?? () from /usr/lib/libmysqlclient.so.15
> #12 0x00007f7d66bb61aa in cli_stmt_execute () from
> /usr/lib/libmysqlclient.so.15
> #13 0x00007f7d66bb5c1d in mysql_stmt_execute () from
> /usr/lib/libmysqlclient.so.15
> #14 0x00007f7d66f691c6 in db_mysql_do_prepared_query (conn=0x791860,
> query=0x7f7d671816d0, v=0x7ffff9c7bdd0, n=15, uv=0x0, un=0) at dbase.c:479
> #15 0x00007f7d66f6b235 in db_mysql_insert (_h=0x791860,
> _k=0x7ffff9c7bfb0, _v=0x7ffff9c7bdd0, _n=15) at dbase.c:864
> #16 0x00007f7d653c233e in db_insert_ucontact (_c=<value optimized out>)
> at ucontact.c:513
> #17 0x00007f7d653cf456 in timer_urecord (_r=0x7f7d607edb88) at urecord.c:326
> #18 0x00007f7d653c80f4 in mem_timer_udomain (_d=0x7f7d5b781d98) at
> udomain.c:695
> #19 0x00007f7d653bd78c in synchronize_all_udomains () at dlist.c:589
> #20 0x00007f7d653cda90 in destroy () at ul_mod.c:373
> #21 0x0000000000487e6c in destroy_modules () at sr_module.c:370
> #22 0x0000000000427c4c in cleanup (show_status=1) at main.c:336
> ---Type <return> to continue, or q <return> to quit---
> #23 0x00000000004287b2 in handle_sigs () at main.c:533
> #24 0x000000000042b78d in main (argc=<value optimized out>,
> argv=0x7ffff9c7c3b8) at main.c:913
>
>
> bt full:
> #0 0x00007f7d671b3ed5 in raise () from /lib/libc.so.6
> No symbol table info available.
> #1 0x00007f7d671b53f3 in abort () from /lib/libc.so.6
> No symbol table info available.
> #2 0x00000000004280e0 in sig_alarm_abort (signo=<value optimized out>)
> at main.c:426
> __FUNCTION__ = "sig_alarm_abort"
> #3 <signal handler called>
> No symbol table info available.
> #4 0x00007f7d67243970 in read () from /lib/libc.so.6
> No symbol table info available.
> #5 0x00007f7d66be3008 in vio_read () from /usr/lib/libmysqlclient.so.15
> No symbol table info available.
> #6 0x00007f7d66be3067 in vio_read_buff () from
> /usr/lib/libmysqlclient.so.15
> No symbol table info available.
> #7 0x00007f7d66be41f9 in ?? () from /usr/lib/libmysqlclient.so.15
> No symbol table info available.
> #8 0x00007f7d66be459d in my_net_read () from /usr/lib/libmysqlclient.so.15
> No symbol table info available.
> #9 0x00007f7d66bdeb72 in cli_safe_read () from
> /usr/lib/libmysqlclient.so.15
> No symbol table info available.
> #10 0x00007f7d66bdf2e9 in ?? () from /usr/lib/libmysqlclient.so.15
> No symbol table info available.
> #11 0x00007f7d66bb354c in ?? () from /usr/lib/libmysqlclient.so.15
> ---Type <return> to continue, or q <return> to quit---
> No symbol table info available.
> #12 0x00007f7d66bb61aa in cli_stmt_execute () from
> /usr/lib/libmysqlclient.so.15
> No symbol table info available.
> #13 0x00007f7d66bb5c1d in mysql_stmt_execute () from
> /usr/lib/libmysqlclient.so.15
> No symbol table info available.
> #14 0x00007f7d66f691c6 in db_mysql_do_prepared_query (conn=0x791860,
> query=0x7f7d671816d0, v=0x7ffff9c7bdd0, n=15, uv=0x0, un=0) at dbase.c:479
> i = 0
> code = <value optimized out>
> cols = 0
> pq_ptr = (struct prep_stmt *) 0x795768
> ctx = (struct my_stmt_ctx *) 0x797d40
> mysql_bind = (MYSQL_BIND *) 0x7957a8
> __FUNCTION__ = "db_mysql_do_prepared_query"
> #15 0x00007f7d66f6b235 in db_mysql_insert (_h=0x791860,
> _k=0x7ffff9c7bfb0, _v=0x7ffff9c7bdd0, _n=15) at dbase.c:864
> ret = -4
> #16 0x00007f7d653c233e in db_insert_ucontact (_c=<value optimized out>)
> at ucontact.c:513
> dom = <value optimized out>
> keys = {0x7f7d655d3800, 0x7f7d655d3820, 0x7f7d655d3830,
> 0x7f7d655d3840, 0x7f7d655d3850, 0x7f7d655d3860, 0x7f7d655d3870,
> 0x7f7d655d3880, 0x7f7d655d3890, 0x7f7d655d38a0, 0x7f7d655d38b0,
> 0x7f7d655d38c0, 0x7f7d655d38d0, 0x7f7d655d38e0, 0x7f7d655d3810}
> vals = {{type = DB_STR, nul = 0, free = 80, val = {int_val =
> 1605337072, double_val = 6.9256369771630863e-310, time_val =
> 140176452976624, string_val = 0x7f7d5faf7ff0 "48521226208 at 85.94.64.4000",
> str_val = {s = 0x7f7d5faf7ff0 "48521226208 at 85.94.64.4000", len =
> 11}, blob_val = {s = 0x7f7d5faf7ff0 "48521226208 at 85.94.64.4000", len =
> 11}, bitmap_val = 1605337072}}, {type = DB_STR, nul = 0,
> free = 80, val = {int_val = 1575961464, double_val =
> 6.9256355258152125e-310, time_val = 140176423601016, string_val =
> 0x7f7d5def4378 "sip:48521226208 at 85.94.64.40:5060\030", str_val = {
> s = 0x7f7d5def4378 "sip:48521226208 at 85.94.64.40:5060\030", len =
> 32}, blob_val = {s = 0x7f7d5def4378
> "sip:48521226208 at 85.94.64.40:5060\030", len = 32}, bitmap_val =
> 1575961464}}, {
> ---Type <return> to continue, or q <return> to quit---
> type = DB_DATETIME, nul = 0, free = 1730116182, val = {int_val =
> 1261104688, double_val = 6.2306850215014372e-315, time_val = 1261104688,
> string_val = 0x4b2aee30 <Address 0x4b2aee30 out of bounds>,
> str_val = {s = 0x4b2aee30 <Address 0x4b2aee30 out of bounds>, len
> = 1723556284}, blob_val = {s = 0x4b2aee30 <Address 0x4b2aee30 out of
> bounds>, len = 1723556284}, bitmap_val = 1261104688}}, {
> type = DB_DOUBLE, nul = 0, free = 0, val = {int_val = 0, double_val
> = -1, time_val = -4616189618054758400, string_val = 0xbff0000000000000
> <Address 0xbff0000000000000 out of bounds>, str_val = {
> s = 0xbff0000000000000 <Address 0xbff0000000000000 out of
> bounds>, len = 38148576}, blob_val = {s = 0xbff0000000000000 <Address
> 0xbff0000000000000 out of bounds>, len = 38148576},
> bitmap_val = 0}}, {type = DB_STR, nul = 0, free = 7962936, val =
> {int_val = 1556542472, double_val = 6.9256345663895301e-310, time_val =
> 140176404182024,
> string_val = 0x7f7d5cc6f408
> "1026220-11715 at 85.94.64.4040:5060\030", str_val = {s = 0x7f7d5cc6f408
> "1026220-11715 at 85.94.64.4040:5060\030", len = 25}, blob_val = {
> s = 0x7f7d5cc6f408 "1026220-11715 at 85.94.64.4040:5060\030", len =
> 25}, bitmap_val = 1556542472}}, {type = DB_INT, nul = 0, free = 0, val =
> {int_val = 2, double_val = 9.8813129168249309e-324,
> time_val = 2, string_val = 0x2 <Address 0x2 out of bounds>,
> str_val = {s = 0x2 <Address 0x2 out of bounds>, len = 7936152}, blob_val
> = {s = 0x2 <Address 0x2 out of bounds>, len = 7936152},
> bitmap_val = 2}}, {type = DB_INT, nul = 0, free = 0, val =
> {int_val = 0, double_val = 0, time_val = 0, string_val = 0x0, str_val =
> {s = 0x0, len = 1727435206}, blob_val = {s = 0x0,
> len = 1727435206}, bitmap_val = 0}}, {type = DB_INT, nul = 0,
> free = 7936096, val = {int_val = 0, double_val =
> 6.9531436082559078e-310, time_val = 140733193388032,
> string_val = 0x7fff00000000 <Address 0x7fff00000000 out of
> bounds>, str_val = {s = 0x7fff00000000 <Address 0x7fff00000000 out of
> bounds>, len = 4}, blob_val = {
> s = 0x7fff00000000 <Address 0x7fff00000000 out of bounds>, len =
> 4}, bitmap_val = 0}}, {type = DB_STR, nul = 0, free = -104349808, val =
> {int_val = 1556006040,
> double_val = 6.9256345398862678e-310, time_val = 140176403645592,
> string_val = 0x7f7d5cbec498 "Djuro-sipp", str_val = {s = 0x7f7d5cbec498
> "Djuro-sipp", len = 10}, blob_val = {
> s = 0x7f7d5cbec498 "Djuro-sipp", len = 10}, bitmap_val =
> 1556006040}}, {type = DB_STR, nul = 1, free = 7954320, val = {int_val =
> 7962184, double_val = 3.9338415802668398e-317, time_val = 7962184,
> string_val = 0x797e48 "�\031F\002", str_val = {s = 0x797e48
> "�\031F\002", len = 1727431784}, blob_val = {s = 0x797e48 "�\031F\002",
> len = 1727431784}, bitmap_val = 7962184}}, {type = DB_STR,
> nul = 1, free = 7936096, val = {int_val = 4, double_val =
> 1.9762625833649862e-323, time_val = 4, string_val = 0x4 <Address 0x4 out
> of bounds>, str_val = {s = 0x4 <Address 0x4 out of bounds>,
> len = -104349808}, blob_val = {s = 0x4 <Address 0x4 out of
> bounds>, len = -104349808}, bitmap_val = 4}}, {type = DB_STR, nul = 0,
> free = -104349680, val = {int_val = 7948472,
> double_val = 3.9270669521310646e-317, time_val = 7948472,
> string_val = 0x7948b8 "udp:85.94.64.137:5060", str_val = {s = 0x7948b8
> "udp:85.94.64.137:5060", len = 21}, blob_val = {
> s = 0x7948b8 "udp:85.94.64.137:5060", len = 21}, bitmap_val =
> 7948472}}, {type = DB_BITMAP, nul = 1, free = 0, val = {int_val =
> 1700610472, double_val = 6.9256416842944766e-310,
> time_val = 140176548250024, string_val = 0x7f7d655d41a8 "`\030y",
> str_val = {s = 0x7f7d655d41a8 "`\030y", len = 1700610560}, blob_val = {s
> = 0x7f7d655d41a8 "`\030y", len = 1700610560},
> bitmap_val = 1700610472}}, {type = DB_DATETIME, nul = 0, free =
> 1658929360, val = {int_val = 1261103488, double_val =
> 6.2306790927136871e-315, time_val = 1261103488,
> string_val = 0x4b2ae980 <Address 0x4b2ae980 out of bounds>,
> str_val = {s = 0x4b2ae980 <Address 0x4b2ae980 out of bounds>, len =
> 1698436436}, blob_val = {
> s = 0x4b2ae980 <Address 0x4b2ae980 out of bounds>, len =
> 1698436436}, bitmap_val = 1261103488}}, {type = DB_STR, nul = 0, free =
> -104349504, val = {int_val = 38100192,
> ---Type <return> to continue, or q <return> to quit---
> double_val = 1.8823995967155495e-316, time_val = 38100192,
> string_val = 0x2455ce0 "85.94.64.137", str_val = {s = 0x2455ce0
> "85.94.64.137", len = 12}, blob_val = {s = 0x2455ce0 "85.94.64.137",
> len = 12}, bitmap_val = 38100192}}}
> my_ps = (db_ps_t) 0x795768
> __FUNCTION__ = "db_insert_ucontact"
> #17 0x00007f7d653cf456 in timer_urecord (_r=0x7f7d607edb88) at urecord.c:326
> No locals.
> #18 0x00007f7d653c80f4 in mem_timer_udomain (_d=0x7f7d5b781d98) at
> udomain.c:695
> ptr = (struct urecord *) 0x7f7d607edb88
> dest = <value optimized out>
> i = 102
> it = {node = 0x7f7d61fd4ac0, map = 0x7f7d5b786448}
> prev = {node = 0x7f7d61768948, map = 0x7f7d5b786448}
> __FUNCTION__ = "mem_timer_udomain"
> #19 0x00007f7d653bd78c in synchronize_all_udomains () at dlist.c:589
> res = 0
> ptr = (dlist_t *) 0x7f7d5b781d38
> #20 0x00007f7d653cda90 in destroy () at ul_mod.c:373
> __FUNCTION__ = "destroy"
> #21 0x0000000000487e6c in destroy_modules () at sr_module.c:370
> t = (struct sr_module *) 0x78b368
> foo = (struct sr_module *) 0x78b298
> #22 0x0000000000427c4c in cleanup (show_status=1) at main.c:336
> No locals.
> ---Type <return> to continue, or q <return> to quit---
> #23 0x00000000004287b2 in handle_sigs () at main.c:533
> chld = 0
> chld_status = 139
> i = <value optimized out>
> do_exit = 1
> __FUNCTION__ = "handle_sigs"
> #24 0x000000000042b78d in main (argc=<value optimized out>,
> argv=0x7ffff9c7c3b8) at main.c:913
> cfg_log_stderr = <value optimized out>
> cfg_stream = <value optimized out>
> c = <value optimized out>
> r = <value optimized out>
> tmp = 0x7ffff9c7ce66 ""
> tmp_len = <value optimized out>
> port = <value optimized out>
> proto = <value optimized out>
> ret = <value optimized out>
> seed = 2757097520
> rfd = <value optimized out>
> __FUNCTION__ = "main"
>
> thread apply all bt:
> Thread 1 (process 14946):
> #0 0x00007f7d671b3ed5 in raise () from /lib/libc.so.6
> #1 0x00007f7d671b53f3 in abort () from /lib/libc.so.6
> #2 0x00000000004280e0 in sig_alarm_abort (signo=<value optimized out>)
> at main.c:426
> #3 <signal handler called>
> #4 0x00007f7d67243970 in read () from /lib/libc.so.6
> #5 0x00007f7d66be3008 in vio_read () from /usr/lib/libmysqlclient.so.15
> #6 0x00007f7d66be3067 in vio_read_buff () from
> /usr/lib/libmysqlclient.so.15
> #7 0x00007f7d66be41f9 in ?? () from /usr/lib/libmysqlclient.so.15
> #8 0x00007f7d66be459d in my_net_read () from /usr/lib/libmysqlclient.so.15
> #9 0x00007f7d66bdeb72 in cli_safe_read () from
> /usr/lib/libmysqlclient.so.15
> #10 0x00007f7d66bdf2e9 in ?? () from /usr/lib/libmysqlclient.so.15
> #11 0x00007f7d66bb354c in ?? () from /usr/lib/libmysqlclient.so.15
> #12 0x00007f7d66bb61aa in cli_stmt_execute () from
> /usr/lib/libmysqlclient.so.15
> #13 0x00007f7d66bb5c1d in mysql_stmt_execute () from
> /usr/lib/libmysqlclient.so.15
> #14 0x00007f7d66f691c6 in db_mysql_do_prepared_query (conn=0x791860,
> query=0x7f7d671816d0, v=0x7ffff9c7bdd0, n=15, uv=0x0, un=0) at dbase.c:479
> #15 0x00007f7d66f6b235 in db_mysql_insert (_h=0x791860,
> _k=0x7ffff9c7bfb0, _v=0x7ffff9c7bdd0, _n=15) at dbase.c:864
> #16 0x00007f7d653c233e in db_insert_ucontact (_c=<value optimized out>)
> at ucontact.c:513
> #17 0x00007f7d653cf456 in timer_urecord (_r=0x7f7d607edb88) at urecord.c:326
> #18 0x00007f7d653c80f4 in mem_timer_udomain (_d=0x7f7d5b781d98) at
> udomain.c:695
> #19 0x00007f7d653bd78c in synchronize_all_udomains () at dlist.c:589
> #20 0x00007f7d653cda90 in destroy () at ul_mod.c:373
> ---Type <return> to continue, or q <return> to quit---
> #21 0x0000000000487e6c in destroy_modules () at sr_module.c:370
> #22 0x0000000000427c4c in cleanup (show_status=1) at main.c:336
> #23 0x00000000004287b2 in handle_sigs () at main.c:533
> #24 0x000000000042b78d in main (argc=<value optimized out>,
> argv=0x7ffff9c7c3b8) at main.c:913
>
>
>
> _______________________________________________
> Users mailing list
> Users at lists.opensips.org
> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>
--
Bogdan-Andrei Iancu
www.voice-system.ro
_______________________________________________
Users mailing list
Users at lists.opensips.org
http://lists.opensips.org/cgi-bin/mailman/listinfo/users
More information about the Users
mailing list