20 May
2010
20 May
'10
1:53 p.m.
Forwarded the message from sr-users to sr-dev list
Cheers
Marius
25 May
25 May
11:32 a.m.
Hi,
Just to add some more info that could help:
- The same problem happened again and I've been able to print the buffer
with the message that has caused the deadlock:
0x8158040 <buf.4000>: "INVITE
sip:yyyyyy@xxxxxxxxx.com<sip%3Ayyyyyy@xxxxxxxxx.com>SIP/2.0\r\nRecord-Route:
<sip:10.172.0.252;lr=on;ftag=as2b58915e>\r\nVia:
SIP/2.0/UDP 10.172.0.252;branch=z9hG4bKa81d.d5c45ce4.0\r\nVia: SIP/2.0/UDP
10.172.0.253:5060;branch=z"...
0x8158108 <buf.4000+200>: "9hG4bK3fd5e08b;rport=5060\r\nFrom:
\"SSSSSS Ssssss\" <sip:zzzzz@xxxxxxxxx.com
<sip%3Azzzzz(a)xxxxxxxxx.com>>;tag=as2b58915e\r\nTo15e\r\nTo:
<sip:yyyyy@xxxxxxxxxx.com <sip%3Ayyyyy(a)xxxxxxxxxx.com>>\r\nContact\nContact: <
sip:zzzzz@10.172.0.253 <sip%3Azzzzz(a)10.172.0.253>>\r\nCall-ID\nCall-ID:
50bec1d32a47ca2b3a71253357c4f11e@x"...
0x81581d0 <buf.4000+400>: "xxxxxxxx.com\r\nCSeq: 102
INVITE\r\nUser-Agent: Vvvvvvvvvvvvv\r\nMax-Forwards: 68\r\nDate: Tue, 25 May
2010 17:20:08 GMT\r\nAllow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER,
SUBSCRIBE, NOTIFY\r\nSupported: replace"...
0x8158298 <buf.4000+600>: "s\r\nOrigin: from-phone\r\nContent-Type:
application/sdp\r\nContent-Length: 263\r\n\r\nv=0\r\no=root 28715 28715 IN
IP4 10.172.0.253\r\ns=session\r\nc=IN IP4 10.172.0.253\r\nt=0 0\r\nm=audio
15034 RTP/AVP 18 101\r\na=rtpma"...
0x8158360 <buf.4000+800>: "p:18 G729/8000\r\na=fmtp:18
annexb=no\r\na=rtpmap:101 telephone-event/8000\r\na=fmtp:101
0-16\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\n"
- By checking the backtraces I've seen that the pua_dialoginfo module could
be involved and in this server we applied the patches from:
http://sip-router.org/tracker/index.php?do=details&task_id=18 and
http://sip-router.org/tracker/index.php?do=details&task_id=20d=20. I think these
were ported to 3.0.0 but not to 1.5. Could they be causing the problem?
Thank you in advance.
Regards,
Santi
2010/5/20 marius zbihlei <marius.zbihlei(a)1and1.ro>
Forwarded the message from sr-users to sr-dev list
Cheers
Marius
Santiago Gimeno wrote:
Hi,
The problem happened again and I can provide some more info.
6 of the UDP worker processes got blocked. By checking the logs I can see
that 4 of them, that seem to be related to the same INVITE request, got
blocked at the same time. The other 2 got blocked some hours later and not
at the same time.
From the 4 first processes, the backtrace of 3 of them is this:
#0 0xb7f6d410 in ?? ()
#1 0xbff60768 in ?? ()
#2 0x00000001 in ?? ()
#3 0xa7358180 in ?? ()
#4 0xb7ec94ac in sched_yield () from /lib/tls/i686/cmov/libc.so.6
#5 0xb7b37463 in lock_hash (i=19819) at ../../mem/../fastlock.h:182
#6 0xb7b52587 in t_lookup_request (p_msg=0x82403d0, leave_new_locked=1)
at t_lookup.c:468
#7 0xb7b534ae in t_newtran (p_msg=0x82403d0) at t_lookup.c:1124
The backtrace of the other is:
#0 0xb7f6d410 in ?? ()
#1 0xbff60138 in ?? ()
#2 0x00000001 in ?? ()
#3 0xa7358180 in ?? ()
#4 0xb7ec94ac in sched_yield () from /lib/tls/i686/cmov/libc.so.6
#5 0xb7b37463 in lock_hash (i=19819) at ../../mem/../fastlock.h:182
#6 0xb7b6ce01 in t_uac (method=0xbff60558, headers=0x81e3108,
body=0x81d9afb, dialog=0xa772c6a8, cb=0xb734a622 <publ_cback_func>,
cbp=0xa7715158)
at uac.c:306
#7 0xb7b6e311 in request (m=0xbff60558, ruri=0x81d9adc, to=0x81d9adc,
from=0x81d9adc, h=0x81e3108, b=0x81d9afb, oburi=0xb73564ac,
cb=0xb734a622 <publ_cback_func>, cbp=0xa7715158) at uac.c:503
#8 0xb7349641 in send_publish (publ=0x81d9aa8) at send_publish.c:552
#9 0xb73339bf in dialog_publish (state=0xb7335bb4 "Trying",
entity=0xa7709f34, peer=0xa7709f3c, callid=0xa7709f2c, initiator=1,
lifetime=300,
localtag=0x0, remotetag=0x0, localtarget=0x0, remotetarget=0x0) at
dialog_publish.c:347
#10 0xb73348ea in __dialog_created (dlg=0xa7709ef0, type=2,
_params=0xb7a7cb9c) at pua_dialoginfo.c:343
#11 0xb7a586ff in run_create_callbacks (dlg=0xa7709ef0, msg=0x81f18a8) at
dlg_cb.c:230
#12 0xb7a60d1f in dlg_new_dialog (msg=0x81f18a8, t=0xa75deeb0) at
dlg_handlers.c:494
#13 0xb7a61f77 in dlg_onreq (t=0xa75deeb0, type=1, param=0xb7b785a8) at
dlg_handlers.c:414
#14 0xb7b4a791 in run_reqin_callbacks (trans=0xa75deeb0, req=0x81f18a8,
code=1) at t_hooks.c:272
#15 0xb7b376af in build_cell (p_msg=0x81f18a8) at h_table.c:284
#16 0xb7b535fa in t_newtran (p_msg=0x81f18a8) at t_lookup.c:1064
#17 0xb7b4540c in t_relay_to (p_msg=0x81f18a8, proxy=0x0, flags=8) at
t_funcs.c:212
#18 0xb7b58ac7 in w_t_relay (p_msg=0x81f18a8, proxy=0x0, flags=0x8
<Address 0x8 out of bounds>) at tm.c:1002
#19 0x0805301c in do_action (a=0x818c370, msg=0x81f18a8) at action.c:874
#20 0x080557aa in run_action_list (a=0x818c370, msg=0x81f18a8) at
action.c:145
#21 0x0809c304 in eval_expr (e=0x818c3d8, msg=0x81f18a8, val=0x0) at
route.c:1171
#22 0x0809bd80 in eval_expr (e=0x818c400, msg=0x81f18a8, val=0x0) at
route.c:1488
#23 0x0809bd16 in eval_expr (e=0x818c428, msg=0x81f18a8, val=0x0) at
route.c:1493
#24 0x080527ed in do_action (a=0x818c740, msg=0x81f18a8) at action.c:729
#25 0x080557aa in run_action_list (a=0x818be08, msg=0x81f18a8) at
action.c:145
#26 0x08053efb in do_action (a=0x81a12e0, msg=0x81f18a8) at action.c:120
#27 0x080557aa in run_action_list (a=0x818ee78, msg=0x81f18a8) at
action.c:145
#28 0x08053efb in do_action (a=0x81b3448, msg=0x81f18a8) at action.c:120
#29 0x080557aa in run_action_list (a=0x81b0ed0, msg=0x81f18a8) at
action.c:145
#30 0x08054491 in do_action (a=0x81b5f68, msg=0x81f18a8) at action.c:746
#31 0x080557aa in run_action_list (a=0x81b5f68, msg=0x81f18a8) at
action.c:145
#32 0x08054f2d in do_action (a=0x81b5fd0, msg=0x81f18a8) at action.c:752
#33 0x080557aa in run_action_list (a=0x81aefd0, msg=0x81f18a8) at
action.c:145
#34 0x08053efb in do_action (a=0x818bc08, msg=0x81f18a8) at action.c:120
#35 0x080557aa in run_action_list (a=0x8187910, msg=0x81f18a8) at
action.c:145
#36 0x08055b43 in run_top_route (a=0x8187910, msg=0x81f18a8) at
action.c:120
#37 0x0808c659 in receive_msg (
buf=0x8158040 "INVITE
sip:xxxxx@xxxxxxxxxxxxxx.com<sip%3Axxxxx@xxxxxxxxxxxxxx.com><mailto:
sip%3Axxxxx(a)xxxxxxxxxxxxxx.com <sip%253Axxxxx(a)xxxxxxxxxxxxxx.com>>
SIP/2.0\r\nRecord-Route: <sip:10.100.29.7;lr=on;ftag=as60035314>\r\nVia:
SIP/2.0/UDP 10.100.29.7;branch=z9hG4bKb6d4.a49d7633.0\r\nVia: SIP/2.0/UDP
10.100.29.8:5060;branch=z9hG"..., len=926, rcv_info=0xbff62334) at
receive.c:175
#38 0x080c3ea3 in udp_rcv_loop () at udp_server.c:449
#39 0x0806e394 in main (argc=9, argv=0xbff62514) at main.c:774,
Hello
I am a little busy atm, so before I dig into the code, I have a question
for core devs. Is the LOCK_HASH() call recursive (being called again from
the same process will not block) ? I ask this because in the 4th blocked
INVITE the hash _might_ be blocked by both t_newtran(#16 0xb7b535fa in
t_newtran (p_msg=0x81f18a8) at t_lookup.c:1064)
and 6 t_uac (#6 0xb7b6ce01 in t_uac (method=0xbff60558,
headers=0x81e3108, body=0x81d9afb, dialog=0xa772c6a8, cb=0xb734a622
<publ_cback_func>, cbp=0xa7715158)), thus causing a deadlock.
Thanks
Marius
_______________________________________________
SIP Express Router (SER) and Kamailio (OpenSER) - sr-users mailing list
sr-users(a)lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-users
_______________________________________________
sr-dev mailing list
sr-dev(a)lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
4:44 p.m.
New subject: [Fwd: Re: [SR-Users] Kamailio 1.5 stops processing messages]
On May 20, 2010 at 13:53, marius zbihlei <marius.zbihlei(a)1and1.ro> wrote:
Forwarded the message from sr-users to sr-dev list
Cheers
Marius
[...]
Hello
I am a little busy atm, so before I dig into the code, I have a
question for core devs. Is the LOCK_HASH() call recursive (being
called again from the same process will not block) ? I ask this
because in the 4th blocked INVITE the hash _might_ be blocked by
both t_newtran(#16 0xb7b535fa in t_newtran (p_msg=0x81f18a8) at
t_lookup.c:1064)
No it's not recursive (it will deadlock if called twice for the same
entry in the same process). This is true for all *ser versions
(sip-router, kamailio < 3.0, ser *).
and 6 t_uac (#6 0xb7b6ce01 in t_uac
(method=0xbff60558,
headers=0x81e3108, body=0x81d9afb, dialog=0xa772c6a8, cb=0xb734a622
<publ_cback_func>, cbp=0xa7715158)), thus causing a deadlock.
Andrei
5:10 p.m.
Andrei Pelinescu-Onciul wrote:
On May 20, 2010 at 13:53, marius zbihlei
<marius.zbihlei(a)1and1.ro> wrote:
Hello Andrei
I have looked thru the code and it seems this is the case. While the
transaction is locked in t_newtrans(), the tm callbacks are called,
which call the pua_dialog callback, which in turn call a transaction
function that requires the same lock; so the mutex is locked twice from
the same process. Is there anyway we can prevent this from the future?
One way is to patch pua_dialog so it doesn't call t_uac()(?) but this
still leaves the possibility of another lock happening somewhere else. I
was thinking that a better approach was implementing a recursive mutex.
If the recursive mutex solution is not desired, what can we do to
prevent these types of deadlocks ?
Marius
Forwarded the message from sr-users to sr-dev
list
Cheers
Marius
[...]
Hello
I am a little busy atm, so before I dig into the code, I have a
question for core devs. Is the LOCK_HASH() call recursive (being
called again from the same process will not block) ? I ask this
because in the 4th blocked INVITE the hash _might_ be blocked by
both t_newtran(#16 0xb7b535fa in t_newtran (p_msg=0x81f18a8) at
t_lookup.c:1064)
No it's not recursive (it will deadlock if called twice for the same
entry in the same process). This is true for all *ser versions
(sip-router, kamailio < 3.0, ser *).
and 6 t_uac
(#6 0xb7b6ce01 in t_uac (method=0xbff60558,
headers=0x81e3108, body=0x81d9afb, dialog=0xa772c6a8, cb=0xb734a622
<publ_cback_func>, cbp=0xa7715158)), thus causing a deadlock.
Andrei
26 May
26 May
7:15 p.m.
New subject: [Fwd: Re: [SR-Users] Kamailio 1.5 stops processing messages]
On May 25, 2010 at 17:10, marius zbihlei <marius.zbihlei(a)1and1.ro> wrote:
Andrei Pelinescu-Onciul wrote:
I don't like it. It would induce a performance hit (depending on the
arch. and the locking method used). While the performance hit of a
single locking operation will be small, given the number of
locks/unlocks we do under heavy traffic it will have a measurable impact
on the overall performance.
Moreover it's only use would be to "hide" bugs in the code (IMHO locking
twice it's a bug).
On May 20, 2010 at 13:53, marius zbihlei
<marius.zbihlei(a)1and1.ro> wrote:
Hello Andrei
I have looked thru the code and it seems this is the case. While the
transaction is locked in t_newtrans(), the tm callbacks are called,
which call the pua_dialog callback, which in turn call a transaction
function that requires the same lock; so the mutex is locked twice
from the same process. Is there anyway we can prevent this from the
future? One way is to patch pua_dialog so it doesn't call t_uac()(?)
but this still leaves the possibility of another lock happening
somewhere else. I was thinking that a better approach was
implementing a recursive mutex. Forwarded the message from sr-users to sr-dev
list
Cheers
Marius
[...]
Hello
I am a little busy atm, so before I dig into the code, I have a
question for core devs. Is the LOCK_HASH() call recursive (being
called again from the same process will not block) ? I ask this
because in the 4th blocked INVITE the hash _might_ be blocked by
both t_newtran(#16 0xb7b535fa in t_newtran (p_msg=0x81f18a8) at
t_lookup.c:1064)
No it's not recursive (it will deadlock if called twice for the same
entry in the same process). This is true for all *ser versions
(sip-router, kamailio < 3.0, ser *).
If the recursive mutex solution is not desired, what can we do to
prevent these types of deadlocks ?
Well, there is no general solution and I'm not familiar with the dialog
code in question. Somehow locking twice should be avoided (unsafe
callback called from failure route?).
Does the same deadlock appears with 3.0/sip-router?
Marius
>>and 6 t_uac (#6 0xb7b6ce01 in t_uac (method=0xbff60558,
>>headers=0x81e3108, body=0x81d9afb, dialog=0xa772c6a8, cb=0xb734a622
>><publ_cback_func>, cbp=0xa7715158)), thus causing a deadlock.
>>
>
Andrei
7 Jun
7 Jun
12:02 p.m.
Hi,
Have you got any update on this issue?
Thank you and sorry for the inconvenience.
Best regards,
Santi
2010/5/26 Andrei Pelinescu-Onciul <andrei(a)iptel.org>
On May 25, 2010 at 17:10, marius zbihlei
<marius.zbihlei(a)1and1.ro> wrote:
Hello Andrei
I have looked thru the code and it seems this is the case. While the
transaction is locked in t_newtrans(), the tm callbacks are called,
which call the pua_dialog callback, which in turn call a transaction
function that requires the same lock; so the mutex is locked twice
from the same process. Is there anyway we can prevent this from the
future? One way is to patch pua_dialog so it doesn't call t_uac()(?)
but this still leaves the possibility of another lock happening
somewhere else. I was thinking that a better approach was
implementing a recursive mutex.
I don't like it. It would induce a performance hit (depending on the
arch. and the locking method used). While the performance hit of a
single locking operation will be small, given the number of
locks/unlocks we do under heavy traffic it will have a measurable impact
on the overall performance.
Moreover it's only use would be to "hide" bugs in the code (IMHO locking
twice it's a bug).
Andrei Pelinescu-Onciul wrote:
>On May 20, 2010 at 13:53, marius zbihlei <marius.zbihlei(a)1and1.ro>
wrote:
Forwarded the message from sr-users to sr-dev list
Cheers
Marius
[...]
Hello
I am a little busy atm, so before I dig into the code, I have a
question for core devs. Is the LOCK_HASH() call recursive (being
called again from the same process will not block) ? I ask this
because in the 4th blocked INVITE the hash _might_ be blocked by
both t_newtran(#16 0xb7b535fa in t_newtran (p_msg=0x81f18a8) at
t_lookup.c:1064)
No it's not recursive (it will deadlock if called twice for the same
entry in the same process). This is true for all *ser versions
(sip-router, kamailio < 3.0, ser *).
If the recursive mutex solution is not desired, what can we do to
prevent these types of deadlocks ?
Well, there is no general solution and I'm not familiar with the dialog
code in question. Somehow locking twice should be avoided (unsafe
callback called from failure route?).
Does the same deadlock appears with 3.0/sip-router?
Marius
>>and 6 t_uac (#6 0xb7b6ce01 in t_uac (method=0xbff60558,
>>headers=0x81e3108, body=0x81d9afb, dialog=0xa772c6a8, cb=0xb734a622
>><publ_cback_func>, cbp=0xa7715158)), thus causing a deadlock.
>>
>
Andrei
_______________________________________________
sr-dev mailing list
sr-dev(a)lists.sip-router.org
http://lists.sip-router.org/cgi-bin/mailman/listinfo/sr-dev
12 Jun
12 Jun
2:19 p.m.
Hi,
2010/5/26 Andrei Pelinescu-Onciul <andrei(a)iptel.org>
Does the same deadlock appears with 3.0/sip-router?
I have tried to reproduce the problem with the master version from git. (
kamctl fifo version shows: Server:: kamailio (3.0.99-dev1 (i386/linux))). I
have used a modified version of kamailio.cfg sample file so it supports
pua_dialoginfo and presence_dialoginfo. After some hours of testing, one of
the udp worker processes has blocked. From the backtrace, the deadlock
doesn't look the same but apparently the pua_dialoginfo module is also
involved. Here is the backtrace:
#0 0xb764766e in strncmp () from /lib/i686/cmov/libc.so.6
#1 0xb6f63ea2 in search_htable (pres=0xbfffc828, hash_code=359) at
hash.c:127
#2 0xb6f72574 in send_publish (publ=0x82d8814) at send_publish.c:426
#3 0xb6f5a9f2 in dialog_publish (state=0xb6f5d554 "confirmed",
entity=0xbfffcb0c, peer=0xa7245470, callid=0xa7245480, initiator=0,
lifetime=43200,
localtag=0x0, remotetag=0x0, localtarget=0xbfffcb04,
remotetarget=0xa7245498) at dialog_publish.c:349
#4 0xb6f5bf09 in __dialog_sendpublish (dlg=0xad5e13bc, type=8,
_params=0xb713ac04) at pua_dialoginfo.c:225
#5 0xb71113c4 in run_dlg_callbacks (type=8, dlg=0xad5e13bc, msg=0x82d7ad8,
dir=2, dlg_data=0x0) at dlg_cb.c:252
#6 0xb711a296 in dlg_onreply (t=0xad5d84dc, type=128, param=0xbfffcca8) at
dlg_handlers.c:381
#7 0xb727b2c5 in run_trans_callbacks_internal (cb_lst=0xad5d851c, type=128,
trans=0xad5d84dc, params=0xbfffcca8) at t_hooks.c:290
#8 0xb727b5ab in run_trans_callbacks (type=128, trans=0x1, req=0xb3b75130,
rpl=0x82d7ad8, code=200) at t_hooks.c:317
#9 0xb72a4543 in relay_reply (t=0xad5d84dc, p_msg=0x82d7ad8, branch=0,
msg_status=200, cancel_bitmap=0xbfffcfa0, do_put_on_wait=1) at
t_reply.c:1749
#10 0xb72a5021 in reply_received (p_msg=0x82d7ad8) at t_reply.c:2222
#11 0x0808c985 in forward_reply (msg=0x82d7ad8) at forward.c:751
#12 0x080c7ec4 in receive_msg (
buf=0x82634c0 "SIP/2.0 200 OK\r\nRecord-Route:
<sip:192.168.1.47;lr=on;did=d94.d1a539e5>\r\nVia: SIP/2.0/UDP
192.168.1.47;branch=z9hG4bKa7f2.1b4b7f12.0, SIP/2.0/UDP
127.0.1.1:5061;received=192.168.1.47;branch=z9hG4bK-31"...,
len=597, rcv_info=0xbfffd1b8) at receive.c:266
#13 0x0814ac83 in udp_rcv_loop () at udp_server.c:527
#14 0x0809b54f in main_loop () at main.c:1462
#15 0x0809e7fb in main (argc=3, argv=0xbfffd4d4) at main.c:2315
I have gone through the code and the process is blocked in this line of code
at ./modules_k/pua/hash.c:127
if((p->pres_uri->len==pres->pres_uri->len) &&
(strncmp(p->pres_uri->s,
pres->pres_uri->s,pres->pres_uri->len)==0))
but I don't understand why it is blocking in the strncmp function as all the
values seem ok. From gdb:
(gdb) print p->pres_uri->s
$8 = 0xa7294204 "sip:service@192.168.1.47:5060D
IALOG_PUBLISH.598-3004(a)127.0.1.1\nm=audio 6000 RTP/AVP 0\r\na=rtpmap:0
PCMU/8000\r\n"
(gdb) print p->pres_uri->len
$9 = 29
(gdb) print pres->pres_uri->len
$10 = 29
(gdb) print pres->pres_uri->s
$11 = 0x82d8850 "sip:service@192.168.1.47:5060u\210-\b#\002"
Any idea why this is happening?
Thanks.
Best regards,
Santi
14 Jun
14 Jun
7:46 p.m.
New subject: [Fwd: Re: [SR-Users] Kamailio 1.5 stops processing messages]
On Jun 12, 2010 at 13:19, Santiago Gimeno <santiago.gimeno(a)gmail.com> wrote:
Hi,
2010/5/26 Andrei Pelinescu-Onciul <andrei(a)iptel.org>
By "blocked" you mean eating 100% cpu?
Could you run a ps -lwwww <pid_of_blocked_process> ?
Does the same deadlock appears with 3.0/sip-router?
I have tried to reproduce the problem with the master version from git. (
kamctl fifo version shows: Server:: kamailio (3.0.99-dev1 (i386/linux))). I
have used a modified version of kamailio.cfg sample file so it supports
pua_dialoginfo and presence_dialoginfo. After some hours of testing, one of
the udp worker processes has blocked. From the backtrace, the deadlock
doesn't look the same but apparently the pua_dialoginfo module is also
involved. Here is the backtrace:
#0 0xb764766e in strncmp () from /lib/i686/cmov/libc.so.6
#1 0xb6f63ea2 in search_htable (pres=0xbfffc828, hash_code=359) at
[...]
I have gone through the code and the process is
blocked in this line of code
at ./modules_k/pua/hash.c:127
if((p->pres_uri->len==pres->pres_uri->len) &&
(strncmp(p->pres_uri->s,
pres->pres_uri->s,pres->pres_uri->len)==0))
but I don't understand why it is blocking in the strncmp function as all the
values seem ok. From gdb:
(gdb) print p->pres_uri->s
$8 = 0xa7294204 "sip:service@192.168.1.47:5060D
IALOG_PUBLISH.598-3004(a)127.0.1.1\nm=audio 6000 RTP/AVP 0\r\na=rtpmap:0
PCMU/8000\r\n"
(gdb) print p->pres_uri->len
$9 = 29
(gdb) print pres->pres_uri->len
$10 = 29
(gdb) print pres->pres_uri->s
$11 = 0x82d8850 "sip:service@192.168.1.47:5060u\210-\b#\002"
Any idea why this is happening?
If it's using 100% cpu it might mean the list that search_htable()
iterates on is corrupted and has become cyclic.
You could also try compiling with debugging options, e.g.:
make config mode=debug; make all
or
make config CC_EXTRA_OPTS="-O0" ; make all
Andrei
7:58 p.m.
Hi,
2010/6/14 Andrei Pelinescu-Onciul <andrei(a)iptel.org>
By "blocked" you mean eating 100% cpu?
Could you run a ps -lwwww <pid_of_blocked_process> ?
Yes, it was eating 100% cpu, but I can't run the ps command because I had to
reboot the computer. I'll do it the next time.
FYI, I ran the strace -p <pid> command and could see no activity at all in
the process.
If it's using 100% cpu it might mean the list that search_htable()
iterates on is corrupted and has become cyclic.
You could also try compiling with debugging options, e.g.:
make config mode=debug; make all
or
make config CC_EXTRA_OPTS="-O0" ; make all
Thanks, I will do that and report back if the problem happens again.
Best regards,
Santi
9 Jul
9 Jul
11:27 a.m.
Hi,
2010/6/14 Andrei Pelinescu-Onciul <andrei(a)iptel.org>
If it's using 100% cpu it might mean the list that search_htable()
> iterates on is corrupted and has become cyclic.
>
> You could also try compiling with debugging options, e.g.:
> make config mode=debug; make all
> or
> make config CC_EXTRA_OPTS="-O0" ; make all
>
>
I have finally performed a test (7 calls per second / duration of call:
8secs) and couldn't reproduce the locking, but after a few hours kamailio
crashed. The backtrace of the core file is:
#0 0xb7f50424 in __kernel_vsyscall ()
#1 0xb7df9640 in raise () from /lib/i686/cmov/libc.so.6
#2 0xb7dfb018 in abort () from /lib/i686/cmov/libc.so.6
#3 0x08131857 in qm_free (qm=0xb5745000, p=0xb6b41804, file=0xb776a40f
"pua: send_publish.c", func=0xb776a584 "publ_cback_func", line=382)
at mem/q_malloc.c:447
#4 0xb775ead6 in publ_cback_func (t=0xb6b07b4c, type=256, ps=0xbfd51690) at
send_publish.c:382
#5 0xb7a716a1 in run_trans_callbacks_internal (cb_lst=0xb6b07b8c, type=256,
trans=0xb6b07b4c, params=0xbfd51690) at t_hooks.c:290
#6 0xb7a717a7 in run_trans_callbacks (type=256, trans=0xb6b07b4c, req=0x0,
rpl=0x82c5074, code=412) at t_hooks.c:317
#7 0xb7a96a5c in local_reply (t=0xb6b07b4c, p_msg=0x82c5074, branch=0,
msg_status=412, cancel_bitmap=0xbfd518a8) at t_reply.c:1882
#8 0xb7a97e12 in reply_received (p_msg=0x82c5074) at t_reply.c:2217
#9 0x08086b7d in forward_reply (msg=0x82c5074) at forward.c:751
#10 0x080b9b70 in receive_msg (
buf=0x8256200 "SIP/2.0 412 Conditional request failed\r\nVia:
SIP/2.0/UDP 192.168.222.203;branch=z9hG4bK2fb5.a8a0e8e3.0\r\nTo:
sip:service@192.168.222.203:5060;tag=d3a667e9ba3dcfdbb46cfb20f8a24cf9-3e9e\r\nFrom:
sip:servic"..., len=391, rcv_info=0xbfd51adc) at receive.c:266
#11 0x08129890 in udp_rcv_loop () at udp_server.c:527
#12 0x0809246d in main_loop () at main.c:1462
#13 0x08094e12 in main (argc=1, argv=0xbfd51e14) at main.c:2315
And the log shows this:
Jul 8 15:38:05 devserver kamailio[27367]: WARNING: dialog
[dlg_handlers.c:815]: unable to find dialog for BYE with route param
'fbc.923ee663' [3263:913236777]
Jul 8 15:38:05 devserver kamailio[27367]: WARNING: dialog
[dlg_handlers.c:815]: unable to find dialog for BYE with route param
'1f7.f91bb257' [2033:1965797791]
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [uac.c:281]: t_uac:
short of cell shmem
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: pua [send_publish.c:565]:
in t_request tm module function
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: pua_dialoginfo
[dialog_publish.c:351]: while sending publish
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [t_lookup.c:1347]:
ERROR: new_t: out of mem:
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [t_lookup.c:1487]:
ERROR: t_newtran: new_t failed
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [uac.c:281]: t_uac:
short of cell shmem
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: pua [send_publish.c:565]:
in t_request tm module function
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: pua_dialoginfo
[dialog_publish.c:351]: while sending publish
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [t_lookup.c:1347]:
ERROR: new_t: out of mem:
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [t_lookup.c:1487]:
ERROR: t_newtran: new_t failed
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [t_lookup.c:1347]:
ERROR: new_t: out of mem:
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [t_lookup.c:1487]:
ERROR: t_newtran: new_t failed
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [t_lookup.c:1347]:
ERROR: new_t: out of mem:
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [t_lookup.c:1487]:
ERROR: t_newtran: new_t failed
Jul 8 15:38:05 devserver kamailio[27367]: WARNING: dialog
[dlg_handlers.c:815]: unable to find dialog for BYE with route param
'2b6.b125ba63' [1714:917197339]
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: tm [uac.c:281]: t_uac:
short of cell shmem
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: pua [send_publish.c:565]:
in t_request tm module function
Jul 8 15:38:05 devserver kamailio[27367]: ERROR: pua [send_publish.c:225]:
when trying to send PUBLISH
Jul 8 15:38:05 devserver kamailio[27367]: : <core> [mem/q_malloc.c:446]:
BUG: qm_free: freeing already freed pointer, first free: pua: hash.c:
delete_htable(264) - aborting
Jul 8 15:38:06 devserver kamailio[27381]: : <core> [pass_fd.c:293]: ERROR:
receive_fd: EOF on 9
Jul 8 15:38:07 devserver kamailio[27364]: ALERT: <core> [main.c:737]: child
process 27367 exited by a signal 6
Jul 8 15:38:07 devserver kamailio[27364]: ALERT: <core> [main.c:740]: core
was generated
The log shows lots of "out of mem" warnings, but I don't know if it is
related to the crahs.
Any ideas?
Best regards,
Santi
5250
days inactive
5300
days old
9 comments
3 participants
participants (3)
-
Andrei Pelinescu-Onciul -
marius zbihlei -
Santiago Gimeno