Re: [OpenSIPS-Users] SIPTRACE module behavior in 2.2

2016-04-26 Thread Yuri Ritvin 
The problem is solved.
The fix for the bug is 3c6b693

( dbdc46c

for 2.2 branch).

Many thanks to Ionut !

On Tue, Apr 12, 2016 at 6:29 PM, Yuri Ritvin  wrote:

> It looks like some information is missing in the SIPTRACE module
> documentation for OpenSIPS 2.2, or apparently it bears a bug. With the
> given example of the configuration the log file displays these messages:
> ERROR:siptrace:save_siptrace: invalid trace info
> ERROR:siptrace:trace_msg_out: failed to save siptrace
>
> And this is the config snippet:
>
>  SIPTRACE module
> loadmodule "siptrace.so"
> modparam("siptrace", "trace_id",
> "[tid]uri=mysql://opensips:opensipsrw@dbserver/opensips;table=sip_trace;")
> modparam("siptrace", "trace_on", 1)
>
> 
>
> if (method==INVITE && !has_totag()) {
> $var(user)="os...@thisnetwork.com";
> $var(trace_id) = "tid";
> sip_trace("$var(trace_id)", "d", "$var(user)");
> }
>
>
> Then at some particular scenario SIPTRACE module crashes the OpenSIPS 2.2
> application:
> #0  save_siptrace (info=0x7f6878bf6b58, msg=,
> vals=0x7f68722bcf80, keys=0x7f68722bd180) at siptrace.c:878
> hash = 
> it = 
> #1  0x7f68720b5415 in trace_onreply_out (t=,
> type=, ps=0x7fff0548a820) at siptrace.c:1982
> faked = 
> fromip_buff = "udp1XX.2X.XXX.185", '\000' 
> toip_buff = "udp1XX.2X.XXX.78", '\000' 
> msg = 0x7f6878c00740
> to_ip = {af = 2, len = 4, u = {addrl = {1310254956, 0}, addr32 =
> {1310254956, 0, 0, 0}, addr16 = {59244, 19992, 0, 0, 0, 0, 0, 0}, addr =
> "l\347\030N", '\000' }}
> len = 3
> statusbuf = "408\000\001\000\000"
> sbuf = 
> dst = 
> __FUNCTION__ = "trace_onreply_out"
> #2  0x7f68748789a1 in run_trans_callbacks (type=128,
> trans=0x7f6878bfecc8, req=, rpl=,
> code=) at t_hooks.c:209
> params = {req = 0x7f6878c00740, rpl = 0x, code =
> 408, param = 0x7f6878bfeb28, extra1 = 0x7fff0548a9a0, extra2 =
> 0x7f6878bfede0}
> cbp = 0x7f6878bfeb18
> backup = 0x7816c0
> trans_backup = 0x7f6878bfecc8
> __FUNCTION__ = "run_trans_callbacks"
> #3  0x7f6874878b00 in run_trans_callbacks_locked (type= optimized out>, trans=0x7f6878bfecc8, req=, rpl= optimized out>, code=)
> at t_hooks.c:262
> No locals.
> #4  0x7f68748851b1 in relay_reply (t=0x7f6878bfecc8, p_msg= optimized out>, branch=, msg_status= out>, cancel_bitmap=0x7fff0548aa7c)
> at t_reply.c:1255
> relay = 0
> save_clone = 0
> buf = 0x7f6888aa78a8 "SIP/2.0 408 Request Timeout\r\nVia:
> SIP/2.0/UDP
> 1XX.2X.XXX.78:8408;received=1XX.2X.XXX.78;branch=z9hG4bK-524287-1---af6608797b55630d;rport=8408\r\nTo:
> ;tag=3b8d"...
> res_len = 412
> relayed_code = 408
> relayed_msg = 0x
> bm = {to_tag_val = {
> s = 0x7f6888aa796c
> "3b8d6d10a54b0752c937c18d274bef37-402e\r\nFrom: \"TestingSubscriber1001\"<
> sip:testingsubscriber1...@sip.thisnetwork.com>;tag=735c442d\r\nCall-ID:
> PKSLf7Smdwyk-hULVsGkKg..\r\nCSeq: 2 INVITE\r\nServer: SBC-185\r\nConte"...,
> len = 37}}
> totag_retr = 0
> reply_status = RPS_COMPLETED
> uas_rb = 0x7f6878bfedc8
> cb_s = {
>   s = 0x7f6888aa78a8 "SIP/2.0 408 Request Timeout\r\nVia:
> SIP/2.0/UDP
> 1XX.2X.XXX.78:8408;received=1XX.2X.XXX.78;branch=z9hG4bK-524287-1---af6608797b55630d;rport=8408\r\nTo:
> ;tag=3b8d"..., len = 412}
> text = {s = 0x50daf3 "Request Timeout", len = 15}
> __FUNCTION__ = "relay_reply"
> #5  0x7f68746e in fake_reply (ticks=70, set=)
> at timer.c:260
> cancel_bitmap = 0
> do_cancel_branch = 
> reply_status = 
> #6  final_response_handler (ticks=70, set=) at
> timer.c:391
> old_ctx = 0x0
> my_ctx = 0x7f6888aa7f08
> r_buf = 0x7f6878bfeea0
> ---Type  to continue, or q  to quit---
> t = 0x7f6878bfecc8
> #7  timer_routine (ticks=70, set=) at timer.c:1066
> tl = 0x7f6878bfef18
> tmp_tl = 0x0
> id = 
> __FUNCTION__ = "timer_routine"
> #8  0x0047e28b in handle_timer_job () at timer.c:632
> t = 0x7f687890d760
> l = 
> __FUNCTION__ = "handle_timer_job"
> #9  0x004ed64d in handle_io (fm=0x7f6888a9c388, idx=1,
> event_type=) at net/net_tcp_proc.c:117
> ret = 0
> n = 
> con = 
> s = 
> rw = 
> resp = 
> response = {140733282036968, 140086962256117}
> __FUNCTION__ = "handle_io"
> #10 0x004ee140 in io_wait_loop_epoll (repeat=0, t=2, h= optimized out>) at ./io_wait_loop.h:221
> n = 1
> r = 1
> e = 0x7f6888a9c388
> ret = 1
> #11 0x004ef407 in tcp_worker_

Re: [OpenSIPS-Users] SIPTRACE module behavior in 2.2

2016-04-13 Thread Dragomir Haralambiev 
I have same massege in my log.
On Apr 13, 2016 1:30 AM, "Yuri Ritvin"  wrote:

> It looks like some information is missing in the SIPTRACE module
> documentation for OpenSIPS 2.2, or apparently it bears a bug. With the
> given example of the configuration the log file displays these messages:
> ERROR:siptrace:save_siptrace: invalid trace info
> ERROR:siptrace:trace_msg_out: failed to save siptrace
>
> And this is the config snippet:
>
>  SIPTRACE module
> loadmodule "siptrace.so"
> modparam("siptrace", "trace_id",
> "[tid]uri=mysql://opensips:opensipsrw@dbserver/opensips;table=sip_trace;")
> modparam("siptrace", "trace_on", 1)
>
> 
>
> if (method==INVITE && !has_totag()) {
> $var(user)="os...@thisnetwork.com";
> $var(trace_id) = "tid";
> sip_trace("$var(trace_id)", "d", "$var(user)");
> }
>
>
> Then at some particular scenario SIPTRACE module crashes the OpenSIPS 2.2
> application:
> #0  save_siptrace (info=0x7f6878bf6b58, msg=,
> vals=0x7f68722bcf80, keys=0x7f68722bd180) at siptrace.c:878
> hash = 
> it = 
> #1  0x7f68720b5415 in trace_onreply_out (t=,
> type=, ps=0x7fff0548a820) at siptrace.c:1982
> faked = 
> fromip_buff = "udp1XX.2X.XXX.185", '\000' 
> toip_buff = "udp1XX.2X.XXX.78", '\000' 
> msg = 0x7f6878c00740
> to_ip = {af = 2, len = 4, u = {addrl = {1310254956, 0}, addr32 =
> {1310254956, 0, 0, 0}, addr16 = {59244, 19992, 0, 0, 0, 0, 0, 0}, addr =
> "l\347\030N", '\000' }}
> len = 3
> statusbuf = "408\000\001\000\000"
> sbuf = 
> dst = 
> __FUNCTION__ = "trace_onreply_out"
> #2  0x7f68748789a1 in run_trans_callbacks (type=128,
> trans=0x7f6878bfecc8, req=, rpl=,
> code=) at t_hooks.c:209
> params = {req = 0x7f6878c00740, rpl = 0x, code =
> 408, param = 0x7f6878bfeb28, extra1 = 0x7fff0548a9a0, extra2 =
> 0x7f6878bfede0}
> cbp = 0x7f6878bfeb18
> backup = 0x7816c0
> trans_backup = 0x7f6878bfecc8
> __FUNCTION__ = "run_trans_callbacks"
> #3  0x7f6874878b00 in run_trans_callbacks_locked (type= optimized out>, trans=0x7f6878bfecc8, req=, rpl= optimized out>, code=)
> at t_hooks.c:262
> No locals.
> #4  0x7f68748851b1 in relay_reply (t=0x7f6878bfecc8, p_msg= optimized out>, branch=, msg_status= out>, cancel_bitmap=0x7fff0548aa7c)
> at t_reply.c:1255
> relay = 0
> save_clone = 0
> buf = 0x7f6888aa78a8 "SIP/2.0 408 Request Timeout\r\nVia:
> SIP/2.0/UDP
> 1XX.2X.XXX.78:8408;received=1XX.2X.XXX.78;branch=z9hG4bK-524287-1---af6608797b55630d;rport=8408\r\nTo:
> ;tag=3b8d"...
> res_len = 412
> relayed_code = 408
> relayed_msg = 0x
> bm = {to_tag_val = {
> s = 0x7f6888aa796c
> "3b8d6d10a54b0752c937c18d274bef37-402e\r\nFrom: \"TestingSubscriber1001\"<
> sip:testingsubscriber1...@sip.thisnetwork.com>;tag=735c442d\r\nCall-ID:
> PKSLf7Smdwyk-hULVsGkKg..\r\nCSeq: 2 INVITE\r\nServer: SBC-185\r\nConte"...,
> len = 37}}
> totag_retr = 0
> reply_status = RPS_COMPLETED
> uas_rb = 0x7f6878bfedc8
> cb_s = {
>   s = 0x7f6888aa78a8 "SIP/2.0 408 Request Timeout\r\nVia:
> SIP/2.0/UDP
> 1XX.2X.XXX.78:8408;received=1XX.2X.XXX.78;branch=z9hG4bK-524287-1---af6608797b55630d;rport=8408\r\nTo:
> ;tag=3b8d"..., len = 412}
> text = {s = 0x50daf3 "Request Timeout", len = 15}
> __FUNCTION__ = "relay_reply"
> #5  0x7f68746e in fake_reply (ticks=70, set=)
> at timer.c:260
> cancel_bitmap = 0
> do_cancel_branch = 
> reply_status = 
> #6  final_response_handler (ticks=70, set=) at
> timer.c:391
> old_ctx = 0x0
> my_ctx = 0x7f6888aa7f08
> r_buf = 0x7f6878bfeea0
> ---Type  to continue, or q  to quit---
> t = 0x7f6878bfecc8
> #7  timer_routine (ticks=70, set=) at timer.c:1066
> tl = 0x7f6878bfef18
> tmp_tl = 0x0
> id = 
> __FUNCTION__ = "timer_routine"
> #8  0x0047e28b in handle_timer_job () at timer.c:632
> t = 0x7f687890d760
> l = 
> __FUNCTION__ = "handle_timer_job"
> #9  0x004ed64d in handle_io (fm=0x7f6888a9c388, idx=1,
> event_type=) at net/net_tcp_proc.c:117
> ret = 0
> n = 
> con = 
> s = 
> rw = 
> resp = 
> response = {140733282036968, 140086962256117}
> __FUNCTION__ = "handle_io"
> #10 0x004ee140 in io_wait_loop_epoll (repeat=0, t=2, h= optimized out>) at ./io_wait_loop.h:221
> n = 1
> r = 1
> e = 0x7f6888a9c388
> ret = 1
> #11 0x004ef407 in tcp_worker_proc (unix_sock= out>) at net/net_tcp_proc.c:312
> __FUNCTION__ = "tcp_worker_proc"
> #12 0x004eb31d in tcp_start_processes (chd_rank=0x7653c8,
> startup_done=0x0) at net/net_tcp.c:1758
> r = 
> reader_fd = {92, 94}
>

[OpenSIPS-Users] SIPTRACE module behavior in 2.2

2016-04-12 Thread Yuri Ritvin 
It looks like some information is missing in the SIPTRACE module
documentation for OpenSIPS 2.2, or apparently it bears a bug. With the
given example of the configuration the log file displays these messages:
ERROR:siptrace:save_siptrace: invalid trace info
ERROR:siptrace:trace_msg_out: failed to save siptrace

And this is the config snippet:

 SIPTRACE module
loadmodule "siptrace.so"
modparam("siptrace", "trace_id",
"[tid]uri=mysql://opensips:opensipsrw@dbserver/opensips;table=sip_trace;")
modparam("siptrace", "trace_on", 1)



if (method==INVITE && !has_totag()) {
$var(user)="os...@thisnetwork.com";
$var(trace_id) = "tid";
sip_trace("$var(trace_id)", "d", "$var(user)");
}


Then at some particular scenario SIPTRACE module crashes the OpenSIPS 2.2
application:
#0  save_siptrace (info=0x7f6878bf6b58, msg=,
vals=0x7f68722bcf80, keys=0x7f68722bd180) at siptrace.c:878
hash = 
it = 
#1  0x7f68720b5415 in trace_onreply_out (t=,
type=, ps=0x7fff0548a820) at siptrace.c:1982
faked = 
fromip_buff = "udp1XX.2X.XXX.185", '\000' 
toip_buff = "udp1XX.2X.XXX.78", '\000' 
msg = 0x7f6878c00740
to_ip = {af = 2, len = 4, u = {addrl = {1310254956, 0}, addr32 =
{1310254956, 0, 0, 0}, addr16 = {59244, 19992, 0, 0, 0, 0, 0, 0}, addr =
"l\347\030N", '\000' }}
len = 3
statusbuf = "408\000\001\000\000"
sbuf = 
dst = 
__FUNCTION__ = "trace_onreply_out"
#2  0x7f68748789a1 in run_trans_callbacks (type=128,
trans=0x7f6878bfecc8, req=, rpl=,
code=) at t_hooks.c:209
params = {req = 0x7f6878c00740, rpl = 0x, code =
408, param = 0x7f6878bfeb28, extra1 = 0x7fff0548a9a0, extra2 =
0x7f6878bfede0}
cbp = 0x7f6878bfeb18
backup = 0x7816c0
trans_backup = 0x7f6878bfecc8
__FUNCTION__ = "run_trans_callbacks"
#3  0x7f6874878b00 in run_trans_callbacks_locked (type=, trans=0x7f6878bfecc8, req=, rpl=, code=)
at t_hooks.c:262
No locals.
#4  0x7f68748851b1 in relay_reply (t=0x7f6878bfecc8, p_msg=, branch=, msg_status=, cancel_bitmap=0x7fff0548aa7c)
at t_reply.c:1255
relay = 0
save_clone = 0
buf = 0x7f6888aa78a8 "SIP/2.0 408 Request Timeout\r\nVia:
SIP/2.0/UDP
1XX.2X.XXX.78:8408;received=1XX.2X.XXX.78;branch=z9hG4bK-524287-1---af6608797b55630d;rport=8408\r\nTo:
;tag=3b8d"...
res_len = 412
relayed_code = 408
relayed_msg = 0x
bm = {to_tag_val = {
s = 0x7f6888aa796c
"3b8d6d10a54b0752c937c18d274bef37-402e\r\nFrom: \"TestingSubscriber1001\"<
sip:testingsubscriber1...@sip.thisnetwork.com>;tag=735c442d\r\nCall-ID:
PKSLf7Smdwyk-hULVsGkKg..\r\nCSeq: 2 INVITE\r\nServer: SBC-185\r\nConte"...,
len = 37}}
totag_retr = 0
reply_status = RPS_COMPLETED
uas_rb = 0x7f6878bfedc8
cb_s = {
  s = 0x7f6888aa78a8 "SIP/2.0 408 Request Timeout\r\nVia:
SIP/2.0/UDP
1XX.2X.XXX.78:8408;received=1XX.2X.XXX.78;branch=z9hG4bK-524287-1---af6608797b55630d;rport=8408\r\nTo:
;tag=3b8d"..., len = 412}
text = {s = 0x50daf3 "Request Timeout", len = 15}
__FUNCTION__ = "relay_reply"
#5  0x7f68746e in fake_reply (ticks=70, set=)
at timer.c:260
cancel_bitmap = 0
do_cancel_branch = 
reply_status = 
#6  final_response_handler (ticks=70, set=) at
timer.c:391
old_ctx = 0x0
my_ctx = 0x7f6888aa7f08
r_buf = 0x7f6878bfeea0
---Type  to continue, or q  to quit---
t = 0x7f6878bfecc8
#7  timer_routine (ticks=70, set=) at timer.c:1066
tl = 0x7f6878bfef18
tmp_tl = 0x0
id = 
__FUNCTION__ = "timer_routine"
#8  0x0047e28b in handle_timer_job () at timer.c:632
t = 0x7f687890d760
l = 
__FUNCTION__ = "handle_timer_job"
#9  0x004ed64d in handle_io (fm=0x7f6888a9c388, idx=1,
event_type=) at net/net_tcp_proc.c:117
ret = 0
n = 
con = 
s = 
rw = 
resp = 
response = {140733282036968, 140086962256117}
__FUNCTION__ = "handle_io"
#10 0x004ee140 in io_wait_loop_epoll (repeat=0, t=2, h=) at ./io_wait_loop.h:221
n = 1
r = 1
e = 0x7f6888a9c388
ret = 1
#11 0x004ef407 in tcp_worker_proc (unix_sock=)
at net/net_tcp_proc.c:312
__FUNCTION__ = "tcp_worker_proc"
#12 0x004eb31d in tcp_start_processes (chd_rank=0x7653c8,
startup_done=0x0) at net/net_tcp.c:1758
r = 
reader_fd = {92, 94}
pid = 0
si = 
load_p = 0x7f6878bc58c8
__FUNCTION__ = "tcp_start_processes"
#13 0x0042f4af in main_loop (argc=,
argv=) at main.c:677
startup_done = 0x0
chd_rank = 44
#14 main (argc=, argv=) at
main.c:1252
cfg_stream = 
c = 
r = 
tmp = 0x7fff0548bf70 ""
tmp_len = 
port = 0
proto = 5282149