8 Apr
2011
8 Apr
'11
12:02 a.m.
Hi!
Kamailio 3.0.3.
I have a strange problem with one of our Kamailio servers. This one is
used for routing (with carrierroute) and to send presence information
(with pua module)
Once every 10 day or so I get this error and then Kamailio stops
responding to any SIP packets.
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: WARNING:
<script>: Failure route - M=INVITE RURI=sip:8615XXXX@178.XX.XX.XX
F=sip:861XXXXX@188.120.93.114:1025 T=sip:86155XXXX@sip1.uni-tel.dk
IP=178.XX.XX.XX ID=6de881ec07f9c6494ee589cf208da358(a)10.11.87.206
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:95]: cannot find AVP 'carrier'
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:805]: invalid carrier id -1
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
<script>: cr_next_domain failed
Shared memory size is 128M and over halv is free just before the
error. The server is in production and does handle debug>1 well, so I
do not have much information in the log files. Private memory is the
default size.
Any ideas what it could be, or how to investegate further?
I think my next steps would be to increase the private memory og to
increase children=4 to children=8
--
Morten Isaksen
8 Apr
8 Apr
1:52 a.m.
Hello,
do you get high CPU usage by kamailio?
What you can do is to attach with gdb to kamailio processes and see what
they are doing:
gdb /path/to/kamailio pid_of_a_kamailio_process
bt
You should attach to the sip worker processes - you can find the type of
processes with 'kamctl ps'.
Cheers,
Daniel
On 4/7/11 9:02 PM, Morten Isaksen wrote:
Hi!
Kamailio 3.0.3.
I have a strange problem with one of our Kamailio servers. This one is
used for routing (with carrierroute) and to send presence information
(with pua module)
Once every 10 day or so I get this error and then Kamailio stops
responding to any SIP packets.
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: WARNING:
<script>: Failure route - M=INVITE RURI=sip:8615XXXX@178.XX.XX.XX
F=sip:861XXXXX@188.120.93.114:1025 T=sip:86155XXXX@sip1.uni-tel.dk
IP=178.XX.XX.XX ID=6de881ec07f9c6494ee589cf208da358(a)10.11.87.206
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:95]: cannot find AVP 'carrier'
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:805]: invalid carrier id -1
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
<script>: cr_next_domain failed
Shared memory size is 128M and over halv is free just before the
error. The server is in production and does handle debug>1 well, so I
do not have much information in the log files. Private memory is the
default size.
Any ideas what it could be, or how to investegate further?
I think my next steps would be to increase the private memory og to
increase children=4 to children=8
--
Daniel-Constantin Mierla
http://www.asipto.com
2 a.m.
Hi,
No, normal CPU usage.
Thanks for the sugestion - I will try that next time.
/Morten
On Thu, Apr 7, 2011 at 10:52 PM, Daniel-Constantin Mierla
<miconda(a)gmail.com> wrote:
Hello,
do you get high CPU usage by kamailio?
What you can do is to attach with gdb to kamailio processes and see what
they are doing:
gdb /path/to/kamailio pid_of_a_kamailio_process
bt
You should attach to the sip worker processes - you can find the type of
processes with 'kamctl ps'.
Cheers,
Daniel
On 4/7/11 9:02 PM, Morten Isaksen wrote:
--
Morten Isaksen
Hi!
Kamailio 3.0.3.
I have a strange problem with one of our Kamailio servers. This one is
used for routing (with carrierroute) and to send presence information
(with pua module)
Once every 10 day or so I get this error and then Kamailio stops
responding to any SIP packets.
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: WARNING:
<script>: Failure route - M=INVITE RURI=sip:8615XXXX@178.XX.XX.XX
F=sip:861XXXXX@188.120.93.114:1025 T=sip:86155XXXX@sip1.uni-tel.dk
IP=178.XX.XX.XX ID=6de881ec07f9c6494ee589cf208da358(a)10.11.87.206
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:95]: cannot find AVP 'carrier'
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:805]: invalid carrier id -1
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
<script>: cr_next_domain failed
Shared memory size is 128M and over halv is free just before the
error. The server is in production and does handle debug>1 well, so I
do not have much information in the log files. Private memory is the
default size.
Any ideas what it could be, or how to investegate further?
I think my next steps would be to increase the private memory og to
increase children=4 to children=8
--
Daniel-Constantin Mierla
http://www.asipto.com
20 Apr
20 Apr
1:17 a.m.
Hi,
It happend again.
I got the result from gdb. Here is the output from a bt indside gdb
for each worker and one bt full for one of the workers.
They are all stuck in futexlock.h
My C debuging skills are a bit rusty so I hope one of you have some ideas.
/Morten
(gdb) bt
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
#1 0x00002acaf17b2e0d in futex_get (t=<value optimized out>,
type=<value optimized out>, ps=0x7fffafb7d7a0)
at ../../mem/../futexlock.h:113
#2 publ_cback_func (t=<value optimized out>, type=<value optimized
out>, ps=0x7fffafb7d7a0) at send_publish.c:272
#3 0x00002acaeeb97815 in run_trans_callbacks_internal
(cb_lst=0x2acaf3cfd260, type=256, trans=0x2acaf3cfd1f0,
params=0x7fffafb7d7a0)
at t_hooks.c:290
#4 0x00002acaeeb97a6e in run_trans_callbacks (type=0, trans=0x2,
req=0x0, rpl=0x246, code=0) at t_hooks.c:317
#5 0x00002acaeebbfcb3 in local_reply (t=0x2acaf3cfd1f0, p_msg=<value
optimized out>, branch=0, msg_status=<value optimized out>,
cancel_bitmap=<value optimized out>) at t_reply.c:1847
#6 0x00002acaeebc29e8 in reply_received (p_msg=0x8d36c8) at t_reply.c:2133
#7 0x000000000044780e in forward_reply (msg=0x8d36c8) at forward.c:689
#8 0x000000000047ff02 in receive_msg (
buf=0x874a40 "SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP
178.21.248.8;branch=z9hG4bKcd3a.d99d6403.0\r\nTo:
sip:+380432571592@sip.uni-tel.dk;user=phone;tag=4e546d1f8c10c6f99af9c51d895c9c87-c9ca\r\nFrom:
sip:+380432571592@sip.uni-"..., len=<value optimized out>,
rcv_info=0x7fffafb7dd20) at receive.c:257
#9 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
#10 0x0000000000455cdf in main_loop () at main.c:1447
#11 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
(gdb) bt
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
#1 0x00002acaeeb7ea32 in futex_get (i=<value optimized out>) at
../../mem/../futexlock.h:100
#2 _lock (i=<value optimized out>) at lock.h:98
#3 lock_hash (i=<value optimized out>) at h_table.c:98
#4 0x00002acaeeba1b99 in t_lookup_request (p_msg=0x8d36c8,
leave_new_locked=0, cancel=0x7fffafb7d5e0) at t_lookup.c:548
#5 0x00002acaeeba3532 in t_check_msg (p_msg=0x8d36c8,
param_branch=<value optimized out>) at t_lookup.c:1104
#6 0x00002acaeebab7b1 in t_check_trans (msg=0x2acaf1f4b2e8,
foo=<value optimized out>, bar=0x2 <Address 0x2 out of bounds>) at
tm.c:1881
#7 0x000000000041345c in do_action (h=0x7fffafb7dab0, a=0x8a6f98,
msg=0x8d36c8) at action.c:860
#8 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x89f8d8,
msg=0x8d36c8) at action.c:1293
#9 0x0000000000416084 in run_top_route (a=0x89f8d8, msg=0x8d36c8,
c=<value optimized out>) at action.c:1341
#10 0x000000000047ff4c in receive_msg (
buf=0x874a40 "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len=<value optimized out>,
rcv_info=0x7fffafb7dd20) at receive.c:196
#11 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
#12 0x0000000000455cdf in main_loop () at main.c:1447
#13 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
#1 0x00002acaeeb7ea32 in futex_get (i=<value optimized out>) at
../../mem/../futexlock.h:100
#2 _lock (i=<value optimized out>) at lock.h:98
#3 lock_hash (i=<value optimized out>) at h_table.c:98
#4 0x00002acaeeba1b99 in t_lookup_request (p_msg=0x8d36c8,
leave_new_locked=0, cancel=0x7fffafb7d5e0) at t_lookup.c:548
#5 0x00002acaeeba3532 in t_check_msg (p_msg=0x8d36c8,
param_branch=<value optimized out>) at t_lookup.c:1104
#6 0x00002acaeebab7b1 in t_check_trans (msg=0x2acaf1f4b2e8,
foo=<value optimized out>, bar=0x2 <Address 0x2 out of bounds>) at
tm.c:1881
#7 0x000000000041345c in do_action (h=0x7fffafb7dab0, a=0x8a6f98,
msg=0x8d36c8) at action.c:860
#8 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x89f8d8,
msg=0x8d36c8) at action.c:1293
#9 0x0000000000416084 in run_top_route (a=0x89f8d8, msg=0x8d36c8,
c=<value optimized out>) at action.c:1341
#10 0x000000000047ff4c in receive_msg (
buf=0x874a40 "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len=<value optimized out>,
rcv_info=0x7fffafb7dd20) at receive.c:196
#11 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
#12 0x0000000000455cdf in main_loop () at main.c:1447
#13 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
(gdb) bt
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
#1 0x00002acaeeb7e9fa in futex_get (i=<value optimized out>) at
../../mem/../futexlock.h:113
#2 _lock (i=<value optimized out>) at lock.h:98
#3 lock_hash (i=<value optimized out>) at h_table.c:98
#4 0x00002acaeebca0e3 in t_uac_prepare (uac_r=0x7fffafb7c270,
dst_req=0x7fffafb7c060, dst_cell=0x7fffafb7c058) at uac.c:319
#5 0x00002acaeebcb4ae in t_uac_with_ids (uac_r=0x2acaf1f4b2e8,
ret_index=0x0, ret_label=0x0) at uac.c:531
#6 0x00002acaeebcc9c7 in request (uac_r=0x7fffafb7c270, ruri=0x11,
to=0x1b, from=0x8e0fe0, next_hop=0x2acaf19c01c0) at uac.c:778
#7 0x00002acaf17af3ff in send_publish (publ=<value optimized out>) at
send_publish.c:556
#8 0x00002acaf19c4f67 in dialog_publish (state=<value optimized out>,
entity=<value optimized out>, peer=<value optimized out>,
callid=<value optimized out>, initiator=<value optimized out>,
lifetime=43200, localtag=0x0, remotetag=0x0, localtarget=0x0,
remotetarget=0x0) at dialog_publish.c:349
#9 0x00002acaf19c6880 in __dialog_created (dlg=0x2acaf575eb38,
type=<value optimized out>, _params=<value optimized out>)
at pua_dialoginfo.c:351
#10 0x00002acaf134ef0f in run_create_callbacks (dlg=0x2acaf575eb38,
msg=<value optimized out>) at dlg_cb.c:230
#11 0x00002acaf13563c7 in dlg_new_dialog (msg=0x8d36c8,
t=0x2acaf157d940) at dlg_handlers.c:643
#12 0x00002acaeeb9751a in run_reqin_callbacks_internal
(hl=0x2acaf1e55018, trans=0x2acaf6fa1630, params=0x2acaeede2920) at
t_hooks.c:376
#13 0x00002acaeeb7ec5a in build_cell (p_msg=0x8d36c8) at h_table.c:346
#14 0x00002acaeeba240e in new_t (p_msg=0x8d36c8) at t_lookup.c:1332
#15 t_newtran (p_msg=0x8d36c8) at t_lookup.c:1472
#16 0x00002acaeeb8d92b in t_relay_to (p_msg=0x2acaf1f4b2e8, proxy=0x0,
proto=0, replicate=0) at t_funcs.c:272
#17 0x000000000041345c in do_action (h=0x7fffafb7dab0, a=0x8c8918,
msg=0x8d36c8) at action.c:860
#18 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x8c8918,
msg=0x8d36c8) at action.c:1293
#19 0x0000000000496815 in rval_get_int (h=0x2acaf1f4b2e8, msg=0x0,
i=0x7fffafb7d1ac, rv=0xffffffffffffffff, cache=0x0) at rvalue.c:897
#20 0x000000000049b68c in rval_expr_eval_int (h=0x7fffafb7dab0,
msg=0x8d36c8, res=0x7fffafb7d1ac, rve=0x8c8a08) at rvalue.c:1837
#21 0x000000000049b73d in rval_expr_eval_int (h=0x7fffafb7dab0,
msg=0x8d36c8, res=0x7fffafb7d5b8, rve=0x8c90d8) at rvalue.c:1844
#22 0x0000000000411d16 in do_action (h=0x7fffafb7dab0, a=0x8c9928,
msg=0x8d36c8) at action.c:834
#23 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x8bda00,
msg=0x8d36c8) at action.c:1293
#24 0x0000000000413054 in do_action (h=0x7fffafb7dab0, a=0x8bd7f0,
msg=0x8d36c8) at action.c:479
#25 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x89f8d8,
msg=0x8d36c8) at action.c:1293
#26 0x0000000000416084 in run_top_route (a=0x89f8d8, msg=0x8d36c8,
c=<value optimized out>) at action.c:1341
#27 0x000000000047ff4c in receive_msg (
buf=0x874a40 "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route: <sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia
: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len=<value optimized out>,
rcv_info=0x7fffafb7dd20) at receive.c:196
#28 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
#29 0x0000000000455cdf in main_loop () at main.c:1447
#30 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
(gdb) bt full
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
No symbol table info available.
#1 0x00002acaeeb7ea32 in futex_get (i=<value optimized out>) at
../../mem/../futexlock.h:100
v = <value optimized out>
#2 _lock (i=<value optimized out>) at lock.h:98
No locals.
#3 lock_hash (i=<value optimized out>) at h_table.c:98
No locals.
#4 0x00002acaeeba1b99 in t_lookup_request (p_msg=0x8d36c8,
leave_new_locked=0, cancel=0x7fffafb7d5e0) at t_lookup.c:548
p_cell = <value optimized out>
isACK = 0
t_msg = <value optimized out>
branch = 0xfffffffffffffffc
match_status = <value optimized out>
hash_bucket = <value optimized out>
#5 0x00002acaeeba3532 in t_check_msg (p_msg=0x8d36c8,
param_branch=<value optimized out>) at t_lookup.c:1104
local_branch = 0
canceled = 9042808
ret = <value optimized out>
#6 0x00002acaeebab7b1 in t_check_trans (msg=0x2acaf1f4b2e8,
foo=<value optimized out>, bar=0x2 <Address 0x2 out of bounds>) at
tm.c:1881
t = <value optimized out>
#7 0x000000000041345c in do_action (h=0x7fffafb7dab0, a=0x8a6f98,
msg=0x8d36c8) at action.c:860
ret = -5
v = <value optimized out>
dst = {send_sock = 0x2acaedccc000, to = {s = {sa_family =
37544, sa_data = "\220\000\000\000\000\000`\253\220\000\000\000\000"},
sin = {
sin_family = 37544, sin_port = 144, sin_addr = {s_addr =
0}, sin_zero = "`\253\220\000\000\000\000"}, sin6 = {sin6_family =
37544,
sin6_port = 144, sin6_flowinfo = 0, sin6_addr = {in6_u =
{u6_addr8 = "`\253\220\000\000\000\000\000LK\207\000\000\000\000",
u6_addr16 = {
43872, 144, 0, 0, 19276, 135, 0, 0}, u6_addr32 =
{9481056, 0, 8866636, 0}}}, sin6_scope_id = 9480096}}, id = 0, proto =
-46 '\322',
send_flags = 74 'J'}
tmp = <value optimized out>
new_uri = <value optimized out>
end = <value optimized out>
crt = <value optimized out>
f = 0xfffffffffffffffc
len = <value optimized out>
user = <value optimized out>
uri = {user = {s = 0x7fffafb7da60 "\310\066\215", len = 0},
passwd = {s = 0x7fffafb7da40 "\001", len = 5767096}, host = {
s = 0x1be1460 "8*\225\233\062", len = -1684723232}, port =
{s = 0x100000000 <Address 0x100000000 out of bounds>, len = 134},
params = {
s = 0x0, len = 29234864}, sip_params = {s = 0x100000000
<Address 0x100000000 out of bounds>, len = -1687727470}, headers = {
s = 0x36b7 <Address 0x36b7 out of bounds>, len = 8208},
port_no = 24939, proto = 24941, type = 1869180009, flags = 21,
transport = {
---Type <return> to continue, or q <return> to quit---
s = 0x1be1460 "8*\225\233\062", len = 0}, ttl = {s = 0x0,
len = 21}, user_param = {s = 0x1be1460 "8*\225\233\062", len = 21},
maddr = {
s = 0x0, len = -1346905536}, method = {s = 0x57ffb8 "%s:
%sERROR: forward_reply: no 2nd via found in reply\n", len =
-1687738517}, lr = {
s = 0x18 <Address 0x18 out of bounds>, len = 21}, r2 = {s
= 0x15 <Address 0x15 out of bounds>, len = 29234272}, transport_val =
{
s = 0x15 <Address 0x15 out of bounds>, len = 21}, ttl_val
= {s = 0x1be1460 "8*\225\233\062", len = -1687354197}, user_param_val
= {
s = 0x2a00000033 <Address 0x2a00000033 out of bounds>, len
= 5458017}, maddr_val = {s = 0x6f00000003 <Address 0x6f00000003 out of
bounds>,
len = 2}, method_val = {s = 0x1 <Address 0x1 out of
bounds>, len = 7200}, lr_val = {s = 0x1bacb40 "CEST", len = 5267113},
r2_val = {
s = 0x90a606 "", len = -1346905500}}
next_hop = {user = {s = 0x10 <Address 0x10 out of bounds>, len
= -1687029130}, passwd = {s = 0x1ff4 <Address 0x1ff4 out of bounds>,
len = -1687023672}, host = {s = 0x8 <Address 0x8 out of
bounds>, len = 29234892}, port = {
s = 0x1be16cc "16:42:57 /usr/local/sbin/kamailio[14007]:
WARNING: <script>: ua=CEC-PBX", len = -1684723232}, params = {s =
0x329b952a00 "",
len = -1684723200}, sip_params = {s = 0x2acaf3e05470 "",
len = -1684723144}, headers = {s = 0x329b94fae0 "@íen = -1346905792},
port_no = 16, proto = 0, type = 48, flags = 2948061504,
transport = {s = 0x7fffafb7d880 "", len = 29235008}, ttl = {
s = 0x1e8c0 <Address 0x1e8c0 out of bounds>, len =
29243072}, user_param = {s = 0x329b722698 "double free or corruption
(out)",
len = 117056}, maddr = {s = 0x329b9529e0 "", len =
-1687739828}, method = {s = 0x329b9535a0 "", len = 5767096}, lr = {
s = 0x1 <Address 0x1 out of bounds>, len = -1687631697},
r2 = {s = 0x7fffafb7dad8 "\330", <incomplete sequence \370\211>, len =
8231792},
transport_val = {s = 0x7fffafb7dd8c "\020", len =
-289787385}, ttl_val = {s = 0x8d36c8 "\033x\r", len = 412},
user_param_val = {
s = 0x313500000000 <Address 0x313500000000 out of bounds>,
len = 29243072}, maddr_val = {s = 0x2010 <Address 0x2010 out of
bounds>,
len = 134}, method_val = {s = 0x2010 <Address 0x2010 out
of bounds>, len = 29234864}, lr_val = {s = 0x90 <Address 0x90 out of
bounds>,
len = -1687731159}, r2_val = {s = 0x3000000010 <Address
0x3000000010 out of bounds>, len = -1684723232}}
u = <value optimized out>
port = <value optimized out>
i = <value optimized out>
flags = <value optimized out>
sct = <value optimized out>
sjt = <value optimized out>
rve = <value optimized out>
mct = <value optimized out>
rv = <value optimized out>
rv1 = <value optimized out>
c1 = {cache_type = 8866741, val_type = RV_NONE, c = {avp_val =
{n = 133, s = {s = 0x85 <Address 0x85 out of bounds>, len = 29234880},
re = 0x85}, pval = {rs = {s = 0x85 <Address 0x85 out of
bounds>, len = 29234880}, ri = 1303224171, flags = 0}}}
#8 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x89f8d8,
msg=0x8d36c8) at action.c:1293
t = 0x8a6f98
ret = 1
mod = <value optimized out>
#9 0x0000000000416084 in run_top_route (a=0x89f8d8, msg=0x8d36c8,
c=<value optimized out>) at action.c:1341
ctx = {rec_lev = 1, run_flags = 0, last_retcode = -1, jmp_env
= {{__jmpbuf = {9254600, -7918255915006962580, 0, 9042136, 9482320,
140736141450636, -7918229962976915956,
-7918255915011241414}, __mask_was_saved = 0, __saved_mask = {__val =
{9254600, 2, 5317260, 928,
8866420, 0, 8866368, 9254608, 1, 140736141450528,
9254600, 8866429, 5321012, 9479616, 47051076858778, 9295328}}}}}
p = 0x7fffafb7dab0
---Type <return> to continue, or q <return> to quit---
ret = <value optimized out>
sfbk = 0
#10 0x000000000047ff4c in receive_msg (
buf=0x874a40 "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len=<value optimized out>, rcv_info=0x7fffafb7dd20) at
receive.c:196
msg = 0x0
ctx = {rec_lev = 9034719, run_flags = 0, last_retcode =
9295720, jmp_env = {{__jmpbuf = {47051129731136, 8, 47051127553476, 2,
217355168616,
47051061455248, 47051127553501, 4294967295},
__mask_was_saved = -236996544, __saved_mask = {__val = {8230504,
9007856, 16, 9482320,
140736141450636, 0, 217350982997, 1, 0, 8963168,
47051127486569, 217355168616, 2, 150476210, 217351006434, 0}}}}}
ret = <value optimized out>
inb = {
s = 0x874a40 "INVITE
sip:20322595@178.21.248.8:5060;transport=udp SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len = 928}
#11 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
len = 928
tmp = <value optimized out>
from = <value optimized out>
fromlen = 16
ri = {src_ip = {af = 2, len = 4, u = {addrl = {351802802,
420}, addr32 = {351802802, 0, 420, 0}, addr16 = {5554, 5368, 0, 0,
420, 0, 0, 0},
addr =
"\262\025\370\024\000\000\000\000\244\001\000\000\000\000\000"}},
dst_ip = {af = 2, len = 4, u = {addrl = {150476210, 0},
addr32 = {150476210, 0, 0, 0}, addr16 = {5554, 2296, 0,
0, 0, 0, 0, 0}, addr = "\262\025\370\b", '\000' <repeats 11
times>}},
src_port = 5060, dst_port = 5060, proto_reserved1 = 0,
proto_reserved2 = 0, src_su = {s = {sa_family = 2,
sa_data =
"\023IJ\025\370\024\000\000\000\000\000\000\000"}, sin = {sin_family =
2, sin_port = 50195, sin_addr = {s_addr = 351802802},
sin_zero = "\000\000\000\000\000\000\000"}, sin6 =
{sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 351802802,
sin6_addr = {in6_u = {
u6_addr8 = '\000' <repeats 15 times>, u6_addr16 =
{0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id =
0}},
bind_address = 0x8972f0, proto = 1 '\001'}
buf = "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."...
#12 0x0000000000455cdf in main_loop () at main.c:1447
i = 2
pid = <value optimized out>
si = 0x8972f0
si_desc = "udp receiver child=2
sock=178.21.248.8:5060\000\000\000\000\000\004", '\000' <repeats 11
times>, "\001", '\000' <repeats 11 times>,
"\b\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\004",
'\000' <repeats 23 times>"\350,
\337\267\257\377\177\000\000\252\267H\000\000\000\000"
#13 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
cfg_stream = 0x1b95010
c = <value optimized out>
r = <value optimized out>
tmp = 0x7fffafb7ef76 ""
---Type <return> to continue, or q <return> to quit---
tmp_len = 16777216
port = 0
proto = 0
ret = <value optimized out>
seed = 524492455
rfd = <value optimized out>
debug_save = 0
debug_flag = 0
dont_fork_cnt = 0
n_lst = 0x0
On Thu, Apr 7, 2011 at 10:52 PM, Daniel-Constantin Mierla
<miconda(a)gmail.com> wrote:
Hello,
do you get high CPU usage by kamailio?
What you can do is to attach with gdb to kamailio processes and see what
they are doing:
gdb /path/to/kamailio pid_of_a_kamailio_process
bt
You should attach to the sip worker processes - you can find the type of
processes with 'kamctl ps'.
Cheers,
Daniel
On 4/7/11 9:02 PM, Morten Isaksen wrote:
--
Morten Isaksen
Hi!
Kamailio 3.0.3.
I have a strange problem with one of our Kamailio servers. This one is
used for routing (with carrierroute) and to send presence information
(with pua module)
Once every 10 day or so I get this error and then Kamailio stops
responding to any SIP packets.
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: WARNING:
<script>: Failure route - M=INVITE RURI=sip:8615XXXX@178.XX.XX.XX
F=sip:861XXXXX@188.120.93.114:1025 T=sip:86155XXXX@sip1.uni-tel.dk
IP=178.XX.XX.XX ID=6de881ec07f9c6494ee589cf208da358(a)10.11.87.206
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:95]: cannot find AVP 'carrier'
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:805]: invalid carrier id -1
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
<script>: cr_next_domain failed
Shared memory size is 128M and over halv is free just before the
error. The server is in production and does handle debug>1 well, so I
do not have much information in the log files. Private memory is the
default size.
Any ideas what it could be, or how to investegate further?
I think my next steps would be to increase the private memory og to
increase children=4 to children=8
--
Daniel-Constantin Mierla
http://www.asipto.com
26 Apr
26 Apr
1:50 p.m.
Hello,
thanks for feedback. Going to work on it asap.
Cheers,
Daniel
On 4/19/11 10:17 PM, Morten Isaksen wrote:
Hi,
It happend again.
I got the result from gdb. Here is the output from a bt indside gdb
for each worker and one bt full for one of the workers.
They are all stuck in futexlock.h
My C debuging skills are a bit rusty so I hope one of you have some ideas.
/Morten
(gdb) bt
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
#1 0x00002acaf17b2e0d in futex_get (t=<value optimized out>,
type=<value optimized out>, ps=0x7fffafb7d7a0)
at ../../mem/../futexlock.h:113
#2 publ_cback_func (t=<value optimized out>, type=<value optimized
out>, ps=0x7fffafb7d7a0) at send_publish.c:272
#3 0x00002acaeeb97815 in run_trans_callbacks_internal
(cb_lst=0x2acaf3cfd260, type=256, trans=0x2acaf3cfd1f0,
params=0x7fffafb7d7a0)
at t_hooks.c:290
#4 0x00002acaeeb97a6e in run_trans_callbacks (type=0, trans=0x2,
req=0x0, rpl=0x246, code=0) at t_hooks.c:317
#5 0x00002acaeebbfcb3 in local_reply (t=0x2acaf3cfd1f0, p_msg=<value
optimized out>, branch=0, msg_status=<value optimized out>,
cancel_bitmap=<value optimized out>) at t_reply.c:1847
#6 0x00002acaeebc29e8 in reply_received (p_msg=0x8d36c8) at t_reply.c:2133
#7 0x000000000044780e in forward_reply (msg=0x8d36c8) at forward.c:689
#8 0x000000000047ff02 in receive_msg (
buf=0x874a40 "SIP/2.0 200 OK\r\nVia: SIP/2.0/UDP
178.21.248.8;branch=z9hG4bKcd3a.d99d6403.0\r\nTo:
sip:+380432571592@sip.uni-tel.dk;user=phone;tag=4e546d1f8c10c6f99af9c51d895c9c87-c9ca\r\nFrom:
sip:+380432571592@sip.uni-"..., len=<value optimized out>,
rcv_info=0x7fffafb7dd20) at receive.c:257
#9 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
#10 0x0000000000455cdf in main_loop () at main.c:1447
#11 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
(gdb) bt
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
#1 0x00002acaeeb7ea32 in futex_get (i=<value optimized out>) at
../../mem/../futexlock.h:100
#2 _lock (i=<value optimized out>) at lock.h:98
#3 lock_hash (i=<value optimized out>) at h_table.c:98
#4 0x00002acaeeba1b99 in t_lookup_request (p_msg=0x8d36c8,
leave_new_locked=0, cancel=0x7fffafb7d5e0) at t_lookup.c:548
#5 0x00002acaeeba3532 in t_check_msg (p_msg=0x8d36c8,
param_branch=<value optimized out>) at t_lookup.c:1104
#6 0x00002acaeebab7b1 in t_check_trans (msg=0x2acaf1f4b2e8,
foo=<value optimized out>, bar=0x2<Address 0x2 out of bounds>) at
tm.c:1881
#7 0x000000000041345c in do_action (h=0x7fffafb7dab0, a=0x8a6f98,
msg=0x8d36c8) at action.c:860
#8 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x89f8d8,
msg=0x8d36c8) at action.c:1293
#9 0x0000000000416084 in run_top_route (a=0x89f8d8, msg=0x8d36c8,
c=<value optimized out>) at action.c:1341
#10 0x000000000047ff4c in receive_msg (
buf=0x874a40 "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len=<value optimized out>,
rcv_info=0x7fffafb7dd20) at receive.c:196
#11 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
#12 0x0000000000455cdf in main_loop () at main.c:1447
#13 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
#1 0x00002acaeeb7ea32 in futex_get (i=<value optimized out>) at
../../mem/../futexlock.h:100
#2 _lock (i=<value optimized out>) at lock.h:98
#3 lock_hash (i=<value optimized out>) at h_table.c:98
#4 0x00002acaeeba1b99 in t_lookup_request (p_msg=0x8d36c8,
leave_new_locked=0, cancel=0x7fffafb7d5e0) at t_lookup.c:548
#5 0x00002acaeeba3532 in t_check_msg (p_msg=0x8d36c8,
param_branch=<value optimized out>) at t_lookup.c:1104
#6 0x00002acaeebab7b1 in t_check_trans (msg=0x2acaf1f4b2e8,
foo=<value optimized out>, bar=0x2<Address 0x2 out of bounds>) at
tm.c:1881
#7 0x000000000041345c in do_action (h=0x7fffafb7dab0, a=0x8a6f98,
msg=0x8d36c8) at action.c:860
#8 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x89f8d8,
msg=0x8d36c8) at action.c:1293
#9 0x0000000000416084 in run_top_route (a=0x89f8d8, msg=0x8d36c8,
c=<value optimized out>) at action.c:1341
#10 0x000000000047ff4c in receive_msg (
buf=0x874a40 "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len=<value optimized out>,
rcv_info=0x7fffafb7dd20) at receive.c:196
#11 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
#12 0x0000000000455cdf in main_loop () at main.c:1447
#13 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
(gdb) bt
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
#1 0x00002acaeeb7e9fa in futex_get (i=<value optimized out>) at
../../mem/../futexlock.h:113
#2 _lock (i=<value optimized out>) at lock.h:98
#3 lock_hash (i=<value optimized out>) at h_table.c:98
#4 0x00002acaeebca0e3 in t_uac_prepare (uac_r=0x7fffafb7c270,
dst_req=0x7fffafb7c060, dst_cell=0x7fffafb7c058) at uac.c:319
#5 0x00002acaeebcb4ae in t_uac_with_ids (uac_r=0x2acaf1f4b2e8,
ret_index=0x0, ret_label=0x0) at uac.c:531
#6 0x00002acaeebcc9c7 in request (uac_r=0x7fffafb7c270, ruri=0x11,
to=0x1b, from=0x8e0fe0, next_hop=0x2acaf19c01c0) at uac.c:778
#7 0x00002acaf17af3ff in send_publish (publ=<value optimized out>) at
send_publish.c:556
#8 0x00002acaf19c4f67 in dialog_publish (state=<value optimized out>,
entity=<value optimized out>, peer=<value optimized out>,
callid=<value optimized out>, initiator=<value optimized out>,
lifetime=43200, localtag=0x0, remotetag=0x0, localtarget=0x0,
remotetarget=0x0) at dialog_publish.c:349
#9 0x00002acaf19c6880 in __dialog_created (dlg=0x2acaf575eb38,
type=<value optimized out>, _params=<value optimized out>)
at pua_dialoginfo.c:351
#10 0x00002acaf134ef0f in run_create_callbacks (dlg=0x2acaf575eb38,
msg=<value optimized out>) at dlg_cb.c:230
#11 0x00002acaf13563c7 in dlg_new_dialog (msg=0x8d36c8,
t=0x2acaf157d940) at dlg_handlers.c:643
#12 0x00002acaeeb9751a in run_reqin_callbacks_internal
(hl=0x2acaf1e55018, trans=0x2acaf6fa1630, params=0x2acaeede2920) at
t_hooks.c:376
#13 0x00002acaeeb7ec5a in build_cell (p_msg=0x8d36c8) at h_table.c:346
#14 0x00002acaeeba240e in new_t (p_msg=0x8d36c8) at t_lookup.c:1332
#15 t_newtran (p_msg=0x8d36c8) at t_lookup.c:1472
#16 0x00002acaeeb8d92b in t_relay_to (p_msg=0x2acaf1f4b2e8, proxy=0x0,
proto=0, replicate=0) at t_funcs.c:272
#17 0x000000000041345c in do_action (h=0x7fffafb7dab0, a=0x8c8918,
msg=0x8d36c8) at action.c:860
#18 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x8c8918,
msg=0x8d36c8) at action.c:1293
#19 0x0000000000496815 in rval_get_int (h=0x2acaf1f4b2e8, msg=0x0,
i=0x7fffafb7d1ac, rv=0xffffffffffffffff, cache=0x0) at rvalue.c:897
#20 0x000000000049b68c in rval_expr_eval_int (h=0x7fffafb7dab0,
msg=0x8d36c8, res=0x7fffafb7d1ac, rve=0x8c8a08) at rvalue.c:1837
#21 0x000000000049b73d in rval_expr_eval_int (h=0x7fffafb7dab0,
msg=0x8d36c8, res=0x7fffafb7d5b8, rve=0x8c90d8) at rvalue.c:1844
#22 0x0000000000411d16 in do_action (h=0x7fffafb7dab0, a=0x8c9928,
msg=0x8d36c8) at action.c:834
#23 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x8bda00,
msg=0x8d36c8) at action.c:1293
#24 0x0000000000413054 in do_action (h=0x7fffafb7dab0, a=0x8bd7f0,
msg=0x8d36c8) at action.c:479
#25 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x89f8d8,
msg=0x8d36c8) at action.c:1293
#26 0x0000000000416084 in run_top_route (a=0x89f8d8, msg=0x8d36c8,
c=<value optimized out>) at action.c:1341
#27 0x000000000047ff4c in receive_msg (
buf=0x874a40 "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia
: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len=<value optimized out>,
rcv_info=0x7fffafb7dd20) at receive.c:196
#28 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
#29 0x0000000000455cdf in main_loop () at main.c:1447
#30 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
(gdb) bt full
#0 0x000000329b6d0a19 in syscall () from /lib64/libc.so.6
No symbol table info available.
#1 0x00002acaeeb7ea32 in futex_get (i=<value optimized out>) at
../../mem/../futexlock.h:100
v =<value optimized out>
#2 _lock (i=<value optimized out>) at lock.h:98
No locals.
#3 lock_hash (i=<value optimized out>) at h_table.c:98
No locals.
#4 0x00002acaeeba1b99 in t_lookup_request (p_msg=0x8d36c8,
leave_new_locked=0, cancel=0x7fffafb7d5e0) at t_lookup.c:548
p_cell =<value optimized out>
isACK = 0
t_msg =<value optimized out>
branch = 0xfffffffffffffffc
match_status =<value optimized out>
hash_bucket =<value optimized out>
#5 0x00002acaeeba3532 in t_check_msg (p_msg=0x8d36c8,
param_branch=<value optimized out>) at t_lookup.c:1104
local_branch = 0
canceled = 9042808
ret =<value optimized out>
#6 0x00002acaeebab7b1 in t_check_trans (msg=0x2acaf1f4b2e8,
foo=<value optimized out>, bar=0x2<Address 0x2 out of bounds>) at
tm.c:1881
t =<value optimized out>
#7 0x000000000041345c in do_action (h=0x7fffafb7dab0, a=0x8a6f98,
msg=0x8d36c8) at action.c:860
ret = -5
v =<value optimized out>
dst = {send_sock = 0x2acaedccc000, to = {s = {sa_family =
37544, sa_data = "\220\000\000\000\000\000`\253\220\000\000\000\000"},
sin = {
sin_family = 37544, sin_port = 144, sin_addr = {s_addr =
0}, sin_zero = "`\253\220\000\000\000\000"}, sin6 = {sin6_family =
37544,
sin6_port = 144, sin6_flowinfo = 0, sin6_addr = {in6_u =
{u6_addr8 = "`\253\220\000\000\000\000\000LK\207\000\000\000\000",
u6_addr16 = {
43872, 144, 0, 0, 19276, 135, 0, 0}, u6_addr32 =
{9481056, 0, 8866636, 0}}}, sin6_scope_id = 9480096}}, id = 0, proto =
-46 '\322',
send_flags = 74 'J'}
tmp =<value optimized out>
new_uri =<value optimized out>
end =<value optimized out>
crt =<value optimized out>
f = 0xfffffffffffffffc
len =<value optimized out>
user =<value optimized out>
uri = {user = {s = 0x7fffafb7da60 "\310\066\215", len = 0},
passwd = {s = 0x7fffafb7da40 "\001", len = 5767096}, host = {
s = 0x1be1460 "8*\225\233\062", len = -1684723232}, port =
{s = 0x100000000<Address 0x100000000 out of bounds>, len = 134},
params = {
s = 0x0, len = 29234864}, sip_params = {s = 0x100000000
<Address 0x100000000 out of bounds>, len = -1687727470}, headers = {
s = 0x36b7<Address 0x36b7 out of bounds>, len = 8208},
port_no = 24939, proto = 24941, type = 1869180009, flags = 21,
transport = {
---Type<return> to continue, or q<return> to quit---
s = 0x1be1460 "8*\225\233\062", len = 0}, ttl = {s = 0x0,
len = 21}, user_param = {s = 0x1be1460 "8*\225\233\062", len = 21},
maddr = {
s = 0x0, len = -1346905536}, method = {s = 0x57ffb8 "%s:
%sERROR: forward_reply: no 2nd via found in reply\n", len =
-1687738517}, lr = {
s = 0x18<Address 0x18 out of bounds>, len = 21}, r2 = {s
= 0x15<Address 0x15 out of bounds>, len = 29234272}, transport_val =
{
s = 0x15<Address 0x15 out of bounds>, len = 21}, ttl_val
= {s = 0x1be1460 "8*\225\233\062", len = -1687354197}, user_param_val
= {
s = 0x2a00000033<Address 0x2a00000033 out of bounds>, len
= 5458017}, maddr_val = {s = 0x6f00000003<Address 0x6f00000003 out of
bounds>,
len = 2}, method_val = {s = 0x1<Address 0x1 out of
bounds>, len = 7200}, lr_val = {s = 0x1bacb40 "CEST", len = 5267113},
r2_val = {
s = 0x90a606 "", len = -1346905500}}
next_hop = {user = {s = 0x10<Address 0x10 out of bounds>, len
= -1687029130}, passwd = {s = 0x1ff4<Address 0x1ff4 out of bounds>,
len = -1687023672}, host = {s = 0x8<Address 0x8 out of
bounds>, len = 29234892}, port = {
s = 0x1be16cc "16:42:57 /usr/local/sbin/kamailio[14007]:
WARNING:<script>: ua=CEC-PBX", len = -1684723232}, params = {s =
0x329b952a00 "",
len = -1684723200}, sip_params = {s = 0x2acaf3e05470 "",
len = -1684723144}, headers = {s = 0x329b94fae0 "@íen = -1346905792},
port_no = 16, proto = 0, type = 48, flags = 2948061504,
transport = {s = 0x7fffafb7d880 "", len = 29235008}, ttl = {
s = 0x1e8c0<Address 0x1e8c0 out of bounds>, len =
29243072}, user_param = {s = 0x329b722698 "double free or corruption
(out)",
len = 117056}, maddr = {s = 0x329b9529e0 "", len =
-1687739828}, method = {s = 0x329b9535a0 "", len = 5767096}, lr = {
s = 0x1<Address 0x1 out of bounds>, len = -1687631697},
r2 = {s = 0x7fffafb7dad8 "\330",<incomplete sequence \370\211>, len =
8231792},
transport_val = {s = 0x7fffafb7dd8c "\020", len =
-289787385}, ttl_val = {s = 0x8d36c8 "\033x\r", len = 412},
user_param_val = {
s = 0x313500000000<Address 0x313500000000 out of bounds>,
len = 29243072}, maddr_val = {s = 0x2010<Address 0x2010 out of
bounds>,
len = 134}, method_val = {s = 0x2010<Address 0x2010 out
of bounds>, len = 29234864}, lr_val = {s = 0x90<Address 0x90 out of
bounds>,
len = -1687731159}, r2_val = {s = 0x3000000010<Address
0x3000000010 out of bounds>, len = -1684723232}}
u =<value optimized out>
port =<value optimized out>
i =<value optimized out>
flags =<value optimized out>
sct =<value optimized out>
sjt =<value optimized out>
rve =<value optimized out>
mct =<value optimized out>
rv =<value optimized out>
rv1 =<value optimized out>
c1 = {cache_type = 8866741, val_type = RV_NONE, c = {avp_val =
{n = 133, s = {s = 0x85<Address 0x85 out of bounds>, len = 29234880},
re = 0x85}, pval = {rs = {s = 0x85<Address 0x85 out of
bounds>, len = 29234880}, ri = 1303224171, flags = 0}}}
#8 0x0000000000415d2b in run_actions (h=0x7fffafb7dab0, a=0x89f8d8,
msg=0x8d36c8) at action.c:1293
t = 0x8a6f98
ret = 1
mod =<value optimized out>
#9 0x0000000000416084 in run_top_route (a=0x89f8d8, msg=0x8d36c8,
c=<value optimized out>) at action.c:1341
ctx = {rec_lev = 1, run_flags = 0, last_retcode = -1, jmp_env
= {{__jmpbuf = {9254600, -7918255915006962580, 0, 9042136, 9482320,
140736141450636, -7918229962976915956,
-7918255915011241414}, __mask_was_saved = 0, __saved_mask = {__val =
{9254600, 2, 5317260, 928,
8866420, 0, 8866368, 9254608, 1, 140736141450528,
9254600, 8866429, 5321012, 9479616, 47051076858778, 9295328}}}}}
p = 0x7fffafb7dab0
---Type<return> to continue, or q<return> to quit---
ret =<value optimized out>
sfbk = 0
#10 0x000000000047ff4c in receive_msg (
buf=0x874a40 "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len=<value optimized out>, rcv_info=0x7fffafb7dd20) at
receive.c:196
msg = 0x0
ctx = {rec_lev = 9034719, run_flags = 0, last_retcode =
9295720, jmp_env = {{__jmpbuf = {47051129731136, 8, 47051127553476, 2,
217355168616,
47051061455248, 47051127553501, 4294967295},
__mask_was_saved = -236996544, __saved_mask = {__val = {8230504,
9007856, 16, 9482320,
140736141450636, 0, 217350982997, 1, 0, 8963168,
47051127486569, 217355168616, 2, 150476210, 217351006434, 0}}}}}
ret =<value optimized out>
inb = {
s = 0x874a40 "INVITE
sip:20322595@178.21.248.8:5060;transport=udp SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."..., len = 928}
#11 0x00000000005067ab in udp_rcv_loop () at udp_server.c:520
len = 928
tmp =<value optimized out>
from =<value optimized out>
fromlen = 16
ri = {src_ip = {af = 2, len = 4, u = {addrl = {351802802,
420}, addr32 = {351802802, 0, 420, 0}, addr16 = {5554, 5368, 0, 0,
420, 0, 0, 0},
addr =
"\262\025\370\024\000\000\000\000\244\001\000\000\000\000\000"}},
dst_ip = {af = 2, len = 4, u = {addrl = {150476210, 0},
addr32 = {150476210, 0, 0, 0}, addr16 = {5554, 2296, 0,
0, 0, 0, 0, 0}, addr = "\262\025\370\b", '\000'<repeats 11
times>}},
src_port = 5060, dst_port = 5060, proto_reserved1 = 0,
proto_reserved2 = 0, src_su = {s = {sa_family = 2,
sa_data =
"\023IJ\025\370\024\000\000\000\000\000\000\000"}, sin = {sin_family =
2, sin_port = 50195, sin_addr = {s_addr = 351802802},
sin_zero = "\000\000\000\000\000\000\000"}, sin6 =
{sin6_family = 2, sin6_port = 50195, sin6_flowinfo = 351802802,
sin6_addr = {in6_u = {
u6_addr8 = '\000'<repeats 15 times>, u6_addr16 =
{0, 0, 0, 0, 0, 0, 0, 0}, u6_addr32 = {0, 0, 0, 0}}}, sin6_scope_id =
0}},
bind_address = 0x8972f0, proto = 1 '\001'}
buf = "INVITE sip:20322595@178.21.248.8:5060;transport=udp
SIP/2.0\r\nRecord-Route:
<sip:178.21.248.20;lr;ftag=as3d313976>\r\nVia: SIP/2.0/UDP
178.21.248.20;branch=z9hG4bKdd3a.3d0516e1.0\r\nVia: SIP/2.0/UDP
81.27."...
#12 0x0000000000455cdf in main_loop () at main.c:1447
i = 2
pid =<value optimized out>
si = 0x8972f0
si_desc = "udp receiver child=2
sock=178.21.248.8:5060\000\000\000\000\000\004", '\000'<repeats 11
times>, "\001", '\000'<repeats 11 times>,
"\b\000\000\000\000\000\000\000\001\000\000\000\000\000\000\000\004",
'\000'<repeats 23 times>"\350,
\337\267\257\377\177\000\000\252\267H\000\000\000\000"
#13 0x0000000000456de2 in main (argc=<value optimized out>,
argv=0x7fffafb7dfe8) at main.c:2251
cfg_stream = 0x1b95010
c =<value optimized out>
r =<value optimized out>
tmp = 0x7fffafb7ef76 ""
---Type<return> to continue, or q<return> to quit---
tmp_len = 16777216
port = 0
proto = 0
ret =<value optimized out>
seed = 524492455
rfd =<value optimized out>
debug_save = 0
debug_flag = 0
dont_fork_cnt = 0
n_lst = 0x0
On Thu, Apr 7, 2011 at 10:52 PM, Daniel-Constantin Mierla
<miconda(a)gmail.com> wrote:
--
Daniel-Constantin Mierla
http://www.asipto.com
Hello,
do you get high CPU usage by kamailio?
What you can do is to attach with gdb to kamailio processes and see what
they are doing:
gdb /path/to/kamailio pid_of_a_kamailio_process
bt
You should attach to the sip worker processes - you can find the type of
processes with 'kamctl ps'.
Cheers,
Daniel
On 4/7/11 9:02 PM, Morten Isaksen wrote:
Hi!
Kamailio 3.0.3.
I have a strange problem with one of our Kamailio servers. This one is
used for routing (with carrierroute) and to send presence information
(with pua module)
Once every 10 day or so I get this error and then Kamailio stops
responding to any SIP packets.
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: WARNING:
<script>: Failure route - M=INVITE RURI=sip:8615XXXX@178.XX.XX.XX
F=sip:861XXXXX@188.120.93.114:1025 T=sip:86155XXXX@sip1.uni-tel.dk
IP=178.XX.XX.XX ID=6de881ec07f9c6494ee589cf208da358(a)10.11.87.206
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:95]: cannot find AVP 'carrier'
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:805]: invalid carrier id -1
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
<script>: cr_next_domain failed
Shared memory size is 128M and over halv is free just before the
error. The server is in production and does handle debug>1 well, so I
do not have much information in the log files. Private memory is the
default size.
Any ideas what it could be, or how to investegate further?
I think my next steps would be to increase the private memory og to
increase children=4 to children=8
--
Daniel-Constantin Mierla
http://www.asipto.com
8 Apr
8 Apr
2:08 p.m.
On 04/07/2011 10:02 PM, Morten Isaksen wrote:
Hi!
Kamailio 3.0.3.
I have a strange problem with one of our Kamailio servers. This one is
used for routing (with carrierroute) and to send presence information
(with pua module)
Once every 10 day or so I get this error and then Kamailio stops
responding to any SIP packets.
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: WARNING:
<script>: Failure route - M=INVITE RURI=sip:8615XXXX@178.XX.XX.XX
F=sip:861XXXXX@188.120.93.114:1025 T=sip:86155XXXX@sip1.uni-tel.dk
IP=178.XX.XX.XX ID=6de881ec07f9c6494ee589cf208da358(a)10.11.87.206
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:95]: cannot find AVP 'carrier'
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:805]: invalid carrier id -1
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
<script>: cr_next_domain failed
Hello Morten,
Do you have the carrier avp set in the failure route (it is ok if it's
set in normal route it should be visible from there)? Also can you
paste the lines from failure_route that are around the cr_next_domain .
My suspicion is that you have some calls that reach failure route, but
because of some particular cfg lines, they are not correctly routed and
the daemon just sleeps in some lines of code on each worker.
For replicating the bug and retrieve the line of code where the workers
block(as Daniel suggested), it would be better if you decrease the
number of worker and keep the same shm memory config value.
Marius
Shared memory size is 128M and over halv is free just
before the
error. The server is in production and does handle debug>1 well, so I
do not have much information in the log files. Private memory is the
default size.
Any ideas what it could be, or how to investegate further?
I think my next steps would be to increase the private memory og to
increase children=4 to children=8
9 Apr
9 Apr
1:09 p.m.
Hi Marius,
The carrier avp is always set in route[0].
My failure_route looks like this.
xlog("L_WARN", "Failure route - M=$rm RURI=$ru F=$fu T=$tu
IP=$si ID=$ci\n");
if (t_check_status("408|404|5[0-9][0-9]|6[0-9][0-9]") &&
!t_check_status("503")) {
revert_uri();
if (!cr_next_domain("$avp(s:carrier)",
"$avp(s:domain)", "$rU",
"$avp(s:host)",
"$T_reply_code", "$avp(s:domain)")) {
xlog("L_ERR", "cr_next_domain failed\n");
exit;
}
if (!cr_route("$avp(s:carrier)", "$avp(s:domain)",
"$rU", "$rU",
"call_id")) {
xlog("L_ERR", "cr_route failed\n");
exit;
}
$avp(s:host)= $rd;
t_on_failure("COREROUTE");
append_branch();
xlog("L_WARN", "Outgoing M=$rm RURI=$ru F=$fu T=$tu
IP=$si ID=$ci\n");
xlog("$si -> $rd");
if (!t_relay()) {
xlog("L_ERR", "t_relay failed\n");
exit;
};
}
On Fri, Apr 8, 2011 at 11:08 AM, marius zbihlei <marius.zbihlei(a)1and1.ro> wrote:
On 04/07/2011 10:02 PM, Morten Isaksen wrote:
--
Morten Isaksen
Hi!
Kamailio 3.0.3.
I have a strange problem with one of our Kamailio servers. This one is
used for routing (with carrierroute) and to send presence information
(with pua module)
Once every 10 day or so I get this error and then Kamailio stops
responding to any SIP packets.
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: WARNING:
<script>: Failure route - M=INVITE RURI=sip:8615XXXX@178.XX.XX.XX
F=sip:861XXXXX@188.120.93.114:1025 T=sip:86155XXXX@sip1.uni-tel.dk
IP=178.XX.XX.XX ID=6de881ec07f9c6494ee589cf208da358(a)10.11.87.206
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:95]: cannot find AVP 'carrier'
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
carrierroute [cr_func.c:805]: invalid carrier id -1
Apr 6 08:05:48 sip-core-1 /usr/local/sbin/kamailio[9186]: ERROR:
<script>: cr_next_domain failed
Hello Morten,
Do you have the carrier avp set in the failure route (it is ok if it's set
in normal route it should be visible from there)? Also can you paste the
lines from failure_route that are around the cr_next_domain . My suspicion
is that you have some calls that reach failure route, but because of some
particular cfg lines, they are not correctly routed and the daemon just
sleeps in some lines of code on each worker.
For replicating the bug and retrieve the line of code where the workers
block(as Daniel suggested), it would be better if you decrease the number of
worker and keep the same shm memory config value.
Marius
Shared memory size is 128M and over halv is free
just before the
error. The server is in production and does handle debug>1 well, so I
do not have much information in the log files. Private memory is the
default size.
Any ideas what it could be, or how to investegate further?
I think my next steps would be to increase the private memory og to
increase children=4 to children=8
_______________________________________________
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
11 Apr
11 Apr
1:35 p.m.
On 04/09/2011 11:09 AM, Morten Isaksen wrote:
Hi Marius,
Hello,
Thanks for the update, but unfortunately I can't spot anything wrong. As
Daniel noted, please send a trace of the worker process (you can also
select the worker's pid from the log file)Attack with GDB for several
times and issue a bt (or bt full) command. If the traces are different,
this will help. Also do a ngrep to see that indeed you have traffic and
K is not responding at all.
Marius
The carrier avp is always set in route[0].
My failure_route looks like this.
xlog("L_WARN", "Failure route - M=$rm RURI=$ru F=$fu T=$tu
IP=$si ID=$ci\n");
if (t_check_status("408|404|5[0-9][0-9]|6[0-9][0-9]")&&
!t_check_status("503")) {
revert_uri();
if (!cr_next_domain("$avp(s:carrier)",
"$avp(s:domain)", "$rU",
"$avp(s:host)",
"$T_reply_code", "$avp(s:domain)")) {
xlog("L_ERR", "cr_next_domain failed\n");
exit;
}
if (!cr_route("$avp(s:carrier)", "$avp(s:domain)",
"$rU", "$rU",
"call_id")) {
xlog("L_ERR", "cr_route failed\n");
exit;
}
$avp(s:host)= $rd;
t_on_failure("COREROUTE");
append_branch();
xlog("L_WARN", "Outgoing M=$rm RURI=$ru F=$fu T=$tu
IP=$si ID=$ci\n");
xlog("$si -> $rd");
if (!t_relay()) {
xlog("L_ERR", "t_relay failed\n");
exit;
};
}
4752
days inactive
4771
days old
7 comments
3 participants
participants (3)
-
Daniel-Constantin Mierla -
marius zbihlei -
Morten Isaksen