[OpenSIPS-Users] Siptrace Issue
Seth Schultz
sschultz at scholarchip.com
Wed Feb 6 21:29:07 CET 2013
I have seen this error occur on both 1.8.2 and 1.9.0. Below is the
output from opensips -V on both versions I am running. The trace I
provided came from 1.9.0-rc-notls.
Thanks,
Seth
(My development environment)
version: opensips 1.9.0-rc-notls (x86_64/linux)
flags: STATS: Off, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MEM,
SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
svnrevision: 2:9753M
@(#) $Id: main.c 9329 2012-10-16 17:23:32Z bogdan_iancu $
main.c compiled on 17:29:59 Feb 5 2013 with gcc 4.6
and
(My production environment)
version: opensips 1.8.2-notls (x86_64/linux)
flags: STATS: Off, USE_IPV6, USE_TCP, DISABLE_NAGLE, USE_MCAST, SHM_MEM,
SHM_MMAP, PKG_MALLOC, F_MALLOC, FAST_LOCK-ADAPTIVE_WAIT
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16,
MAX_URI_SIZE 1024, BUF_SIZE 65535
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
svnrevision: 2:9718M
@(#) $Id: main.c 9330 2012-10-16 17:25:38Z bogdan_iancu $
main.c compiled on 01:14:02 Feb 4 2013 with gcc 4.5.2
Seth Schultz
E-Mail: sschultz at scholarchip.com
Phone: 212.255.8005 x 124
Fax: 212.255.8091
On 2/6/2013 3:24 PM, Bogdan-Andrei Iancu wrote:
> Thanks !
>
> Looks like the actual socket structure is altered :
> sock_str = {s = 0x7f4818da11b8 "udp:172.16.1.115", len = 21}
>
> length is 21, while only 16 chars are printed -> 5 are missing ( ':' +
> 4 for port) .
>
> What exact opensips revision are you using ? I need to figure out a
> way to see where in the code the sock_str is altered.
>
> Regards,
>
> Bogdan-Andrei Iancu
> OpenSIPS Founder and Developer
> http://www.opensips-solutions.com
>
>
> On 02/06/2013 09:59 PM, Seth Schultz wrote:
>> Here is the output:
>>
>> #0 0x00007f4820da1425 in raise () from /lib/x86_64-linux-gnu/libc.so.6
>> (gdb) f 5
>> #5 0x00007f4815ef8a61 in trace_msg_out (msg=0x7f4817464340,
>> sbuf=<optimized out>, send_sock=<optimized out>, proto=1,
>> to=<optimized out>) at siptrace.c:1053
>> 1053 if (save_siptrace(msg,avp,&avp_value,db_keys,db_vals)
>> < 0) {
>> (gdb) p trace_local_ip
>> $1 = {s = 0x0, len = 0}
>> (gdb) p send_sock
>> $2 = <optimized out>
>> (gdb) p to
>> $3 = <optimized out>
>> (gdb) f 6
>> #6 0x00007f4815efbe5c in trace_onreq_out (t=<optimized out>,
>> type=<optimized out>, ps=0x7fff9f5d43d0) at siptrace.c:937
>> 937 trace_msg_out( ps->req, (str*)ps->extra1,
>> (gdb) p ((struct dest_info*)ps->extra2)->send_sock
>> $4 = (struct socket_info *) 0x7f4818d72e08
>> (gdb) p *((struct dest_info*)ps->extra2)->send_sock
>> $5 = {socket = 5, name = {s = 0x7f4818d72f10 "172.16.1.115", len =
>> 12}, address = {af = 2, len = 4, u = {addrl = {1929449644, 0}, addr32
>> = {1929449644, 0, 0, 0}, addr16 = {4268, 29441, 0, 0, 0, 0, 0,
>> 0}, addr = "\254\020\001s", '\000' <repeats 11 times>}},
>> address_str = {s = 0x7f4818da1190 "172.16.1.115", len = 12}, port_no
>> = 5060, port_no_str = {s = 0x7f4818da1170 "5060", len = 4},
>> flags = SI_NONE, su = {s = {sa_family = 2, sa_data =
>> "\023\304\254\020\001s\000\000\000\000\000\000\000"}, sin =
>> {sin_family = 2, sin_port = 50195, sin_addr = {s_addr = 1929449644},
>> sin_zero = "\000\000\000\000\000\000\000"}, sin6 = {sin6_family
>> = 2, sin6_port = 50195, sin6_flowinfo = 1929449644, 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}}, proto = 1, sock_str = {s =
>> 0x7f4818da11b8 "udp:172.16.1.115", len = 21}, adv_sock_str = {s = 0x0,
>> len = 0}, adv_name_str = {s = 0x0, len = 0}, adv_port_str = {s =
>> 0x0, len = 0}, adv_address = {af = 0, len = 0, u = {addrl = {0, 0},
>> addr32 = {0, 0, 0, 0}, addr16 = {0, 0, 0, 0, 0, 0, 0, 0},
>> addr = '\000' <repeats 15 times>}}, adv_port = 0, children = 8,
>> next = 0x0, prev = 0x0}
>>
>> On 2/6/2013 2:56 PM, Bogdan-Andrei Iancu wrote:
>>> Cool :)
>>>
>>> In gdb, please do :
>>>
>>> f 5
>>> p trace_local_ip
>>> p send_sock
>>> p to
>>> f 6
>>> p ((struct dest_info*)ps->extra2)->send_sock
>>> p *((struct dest_info*)ps->extra2)->send_sock
>>>
>>> Thanks,
>>>
>>> Bogdan-Andrei Iancu
>>> OpenSIPS Founder and Developer
>>> http://www.opensips-solutions.com
>>>
>>>
>>> On 02/06/2013 09:48 PM, Seth Schultz wrote:
>>>> Thanks for all your help. I was finally able to get the system to
>>>> dump a core file. Here is the output from the backtrace.
>>>>
>>>> #0 0x00007f4820da1425 in raise () from
>>>> /lib/x86_64-linux-gnu/libc.so.6
>>>> #1 0x00007f4820da4b8b in abort () from
>>>> /lib/x86_64-linux-gnu/libc.so.6
>>>> #2 0x00007f4815ee2d30 in pipport2su (pipport=<optimized out>,
>>>> tmp_su=0x7fff9f5d4230, proto=<optimized out>) at siptrace.c:1798
>>>> #3 0x00007f4815ee4ba3 in trace_send_hep_duplicate
>>>> (toip=0x7f48160ff9e0 "udp:xxx.xxx.xxx.xxx:5060",
>>>> fromip=0x7f4818da11b8 "udp:172.16.1.115", body=<optimized out>) at
>>>> siptrace.c:1619
>>>> #4 save_siptrace (avp=0x7f4794ebf600, first_val=0x7fff9f5d4300,
>>>> vals=0x7f48160ffdc0, keys=0x7f48160ffcc0, msg=<optimized out>) at
>>>> siptrace.c:533
>>>> #5 0x00007f4815ef8a61 in trace_msg_out (msg=0x7f4817464340,
>>>> sbuf=<optimized out>, send_sock=<optimized out>, proto=1,
>>>> to=<optimized out>) at siptrace.c:1053
>>>> #6 0x00007f4815efbe5c in trace_onreq_out (t=<optimized out>,
>>>> type=<optimized out>, ps=0x7fff9f5d43d0) at siptrace.c:937
>>>> #7 0x00007f481721e8b2 in run_trans_callbacks (type=1024,
>>>> trans=0x7f4794eba310, req=<optimized out>, rpl=<optimized out>,
>>>> code=<optimized out>) at t_hooks.c:212
>>>> #8 0x00007f481721d76d in t_forward_nonack (t=0x7f4794eba310,
>>>> p_msg=0x7f4817464340, proxy=<optimized out>) at t_fwd.c:753
>>>> #9 0x00007f481723c248 in w_t_relay (p_msg=0x7f4817464340,
>>>> proxy=0x0, flags=<optimized out>) at tm.c:1160
>>>> #10 0x0000000000418b47 in do_action (a=0x7f4818d8ea88,
>>>> msg=0x7f4817464340) at action.c:1714
>>>> #11 0x000000000041deee in run_action_list (a=<optimized out>,
>>>> msg=0x7f4817464340) at action.c:170
>>>> #12 0x0000000000499d9e in eval_elem (e=0x7f4818d8eb60,
>>>> msg=0x7f4817464340, val=0x0) at route.c:1499
>>>> #13 0x00000000004998bd in eval_expr (e=0x7f4818d8eb60,
>>>> msg=0x7f4817464340, val=0x0) at route.c:1844
>>>> #14 0x0000000000499974 in eval_expr (e=0x7f4818d8ebb0,
>>>> msg=0x7f4817464340, val=0x0) at route.c:1860
>>>> #15 0x00000000004998aa in eval_expr (e=0x7f4818d8ec00,
>>>> msg=0x7f4817464340, val=0x0) at route.c:1865
>>>> #16 0x000000000041875a in do_action (a=0x7f4818d8eef0,
>>>> msg=0x7f4817464340) at action.c:992
>>>> #17 0x000000000041deee in run_action_list (a=<optimized out>,
>>>> msg=0x7f4817464340) at action.c:170
>>>> #18 0x000000000041b7f0 in do_action (a=0x7f4818d8f418,
>>>> msg=0x7f4817464340) at action.c:1009
>>>> #19 0x000000000041deee in run_action_list (a=<optimized out>,
>>>> msg=0x7f4817464340) at action.c:170
>>>> #20 0x000000000041b7f0 in do_action (a=0x7f4818d8f4f0,
>>>> msg=0x7f4817464340) at action.c:1009
>>>> #21 0x000000000041deee in run_action_list (a=<optimized out>,
>>>> msg=0x7f4817464340) at action.c:170
>>>> #22 0x000000000041e420 in run_actions (msg=0x7f4817464340,
>>>> a=0x7f4818d8c3c0) at action.c:136
>>>> #23 run_actions (msg=0x7f4817464340, a=0x7f4818d8c3c0) at action.c:189
>>>> #24 run_top_route (a=0x7f4818d8c3c0, msg=0x7f4817464340) at
>>>> action.c:210
>>>> #25 0x00007f4817232f22 in run_failure_handlers (t=0x7f4794eba310)
>>>> at t_reply.c:657
>>>> #26 t_should_relay_response (Trans=0x7f4794eba310,
>>>> new_code=<optimized out>, branch=0, should_store=0x7fff9f5d6480,
>>>> should_relay=<optimized out>, cancel_bitmap=<optimized out>,
>>>> reply=0xffffffffffffffff) at t_reply.c:956
>>>> #27 0x00007f4817232fb9 in relay_reply (t=0x7f4794eba310,
>>>> p_msg=0xffffffffffffffff, branch=0, msg_status=408,
>>>> cancel_bitmap=0x7fff9f5d6520) at t_reply.c:1170
>>>> #28 0x00007f4817237a75 in fake_reply (branch=<optimized out>,
>>>> t=0x7f4794eba310, code=<optimized out>) at timer.c:259
>>>> #29 final_response_handler (fr_tl=<optimized out>) at timer.c:370
>>>> #30 timer_routine (ticks=84, attr=<optimized out>) at timer.c:1011
>>>> #31 0x00000000004d8cf2 in timer_ticker (drift=<synthetic pointer>,
>>>> timer_list=<optimized out>) at timer.c:384
>>>> #32 run_timer_process (tpl=<optimized out>) at timer.c:500
>>>> #33 start_timer_processes () at timer.c:610
>>>> #34 0x000000000041523a in main_loop () at main.c:945
>>>> #35 main (argc=<optimized out>, argv=<optimized out>) at main.c:1541
>>>>
>>>> On 2/6/2013 2:27 PM, Bogdan-Andrei Iancu wrote:
>>>>> That's because you need to have "root" permissions to write into
>>>>> /proc/sys/kernel/core_pattern (used for forcing the core file
>>>>> pattern). You should comment in the init.d file the line for
>>>>> writting into that file.
>>>>>
>>>>> Regards,
>>>>>
>>>>> Bogdan-Andrei Iancu
>>>>> OpenSIPS Founder and Developer
>>>>> http://www.opensips-solutions.com
>>>>>
>>>>>
>>>>> On 02/06/2013 08:52 PM, Seth Schultz wrote:
>>>>>> Unfortunately I am having trouble getting the system to dump a
>>>>>> core file. Here is the error message I am getting once I enable
>>>>>> core dumps.
>>>>>>
>>>>>> /etc/init.d/opensips: 103: /etc/init.d/opensips: cannot create
>>>>>> /proc/sys/kernel/core_pattern: Permission denied
>>>>>>
>>>>>> I have also tried starting opensips as the root user, but it
>>>>>> still throws this error.
>>>>>>
>>>>>> Here is my /etc/defaults/opensips:
>>>>>> RUN_OPENSIPS=yes
>>>>>> USER=opensips
>>>>>> GROUP=opensips
>>>>>> S_MEMORY=1024
>>>>>> P_MEMORY=32
>>>>>> DUMP_CORE=yes
>>>>>>
>>>>>> And here are the relevant lines in /etc/init.d/opensips:
>>>>>> if test "$DUMP_CORE" = "yes" ; then
>>>>>> # set proper ulimit
>>>>>> ulimit -c unlimited
>>>>>>
>>>>>> # directory for the core dump files
>>>>>> COREDIR=/home/corefiles
>>>>>> [ -d $COREDIR ] || mkdir $COREDIR
>>>>>> chmod 777 $COREDIR
>>>>>> echo "$COREDIR/core.%e.sig%s.%p" > /proc/sys/kernel/core_pattern
>>>>>> fi
>>>>>>
>>>>>> Thanks,
>>>>>> Seth
>>>>>> On 2/6/2013 12:27 PM, Bogdan-Andrei Iancu wrote:
>>>>>>> yes, you have to, if using the debian init.d files.
>>>>>>>
>>>>>>> The core will be dumped into the opensips working directory - if
>>>>>>> not configured one, it will be in root file system "/".
>>>>>>>
>>>>>>> Regards,
>>>>>>>
>>>>>>> Bogdan-Andrei Iancu
>>>>>>> OpenSIPS Founder and Developer
>>>>>>> http://www.opensips-solutions.com
>>>>>>>
>>>>>>>
>>>>>>> On 02/06/2013 07:02 PM, Seth Schultz wrote:
>>>>>>>> I assume I also need to set the following variable in
>>>>>>>> /etc/default/opensips.
>>>>>>>>
>>>>>>>> change
>>>>>>>> DUMP_CORE=no
>>>>>>>> to
>>>>>>>> DUMP_CORE=yes
>>>>>>>>
>>>>>>>> This may be a silly question, but where will it dump the core
>>>>>>>> file to?
>>>>>>>>
>>>>>>>> Thanks,
>>>>>>>> Seth
>>>>>>>>
>>>>>>>>
>>>>>>>> On 2/6/2013 11:56 AM, Bogdan-Andrei Iancu wrote:
>>>>>>>>> Where you changed the LM_ERR() in code, after it, simply put :
>>>>>>>>> abort(); . Recompile and run again -> when you get the error,
>>>>>>>>> opensips should stop by itself with a core dump. Once you get
>>>>>>>>> the core file, use gdb to get a backtrace (run "bt" on gdb).
>>>>>>>>>
>>>>>>>>> Regards,
>>>>>>>>>
>>>>>>>>> Bogdan-Andrei Iancu
>>>>>>>>> OpenSIPS Founder and Developer
>>>>>>>>> http://www.opensips-solutions.com
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> On 02/06/2013 06:23 PM, Seth Schultz wrote:
>>>>>>>>>> Bogdan-Andrei,
>>>>>>>>>>
>>>>>>>>>> Thank you for the reply. I have seen this error occur in
>>>>>>>>>> both 1.8.2 and 1.9.0. Would you please explain exactly how I
>>>>>>>>>> can catch the error and call abort()? Also, is there anything
>>>>>>>>>> else I can enable which would help us track down the cause?
>>>>>>>>>>
>>>>>>>>>> Thanks,
>>>>>>>>>> Seth
>>>>>>>>>>
>>>>>>>>>> Seth Schultz
>>>>>>>>>> E-Mail: sschultz at scholarchip.com
>>>>>>>>>> Phone: 212.255.8005 x 124
>>>>>>>>>> Fax: 212.255.8091
>>>>>>>>>>
>>>>>>>>>> On 2/6/2013 11:09 AM, Bogdan-Andrei Iancu wrote:
>>>>>>>>>>> Hi Seth,
>>>>>>>>>>>
>>>>>>>>>>> That is really strange - using 1.9 or 1.8 ?
>>>>>>>>>>>
>>>>>>>>>>> Do make it short, could you put an "abort()" when the error
>>>>>>>>>>> is triggered ? -> we could look into backtrace to see where
>>>>>>>>>>> the faulty string comes from.
>>>>>>>>>>>
>>>>>>>>>>> Regards,
>>>>>>>>>>>
>>>>>>>>>>> Bogdan-Andrei Iancu
>>>>>>>>>>> OpenSIPS Founder and Developer
>>>>>>>>>>> http://www.opensips-solutions.com
>>>>>>>>>>>
>>>>>>>>>>>
>>>>>>>>>>> On 02/06/2013 01:09 AM, Seth Schultz wrote:
>>>>>>>>>>>> Hello,
>>>>>>>>>>>>
>>>>>>>>>>>> Could someone please help me resolve the following error
>>>>>>>>>>>> message "ERROR:siptrace:pipport2su: no port specified".
>>>>>>>>>>>> This error only happens on some of the sip packets, but I
>>>>>>>>>>>> can't determine why. When this error occurs, the trace for
>>>>>>>>>>>> those packets never make it to my homer capture server (I
>>>>>>>>>>>> have to use ngrep to see them).
>>>>>>>>>>>>
>>>>>>>>>>>> Furthermore, I modified siptrace.c to output the value of
>>>>>>>>>>>> pipport and the error message returned this
>>>>>>>>>>>> "ERROR:siptrace:pipport2su: udp:172.16.1.115 no port
>>>>>>>>>>>> specified". I am just not sure where it is getting the
>>>>>>>>>>>> udp:172.16.1.115 value from.
>>>>>>>>>>>>
>>>>>>>>>>>> Thanks in advance,
>>>>>>>>>>>> Seth
>>>>>>>>>>>>
>>>>>>>>>>>> Here are my module parameters.
>>>>>>>>>>>> ...
>>>>>>>>>>>> port=5060
>>>>>>>>>>>> listen=udp:172.16.1.115:5060
>>>>>>>>>>>> ...
>>>>>>>>>>>>
>>>>>>>>>>>> loadmodule "siptrace.so"
>>>>>>>>>>>> modparam("siptrace", "enable_ack_trace", 1)
>>>>>>>>>>>> modparam("siptrace", "trace_flag", "TRACE")
>>>>>>>>>>>> modparam("siptrace", "trace_on", 1)
>>>>>>>>>>>> modparam("siptrace", "trace_to_database", 0)
>>>>>>>>>>>> modparam("siptrace", "traced_user_avp", "$avp(called)")
>>>>>>>>>>>> modparam("siptrace", "hep_version", 2)
>>>>>>>>>>>> modparam("siptrace", "hep_capture_id", 338)
>>>>>>>>>>>> modparam("siptrace", "duplicate_uri", "sip:172.16.1.99:9060")
>>>>>>>>>>>> modparam("siptrace", "duplicate_with_hep", 1)
>>>>>>>>>>>>
>>>>>>>>>>>> and here is how I am using siptrace in my script.
>>>>>>>>>>>>
>>>>>>>>>>>> route{
>>>>>>>>>>>> ...
>>>>>>>>>>>> setflag(TRACE);
>>>>>>>>>>>> sip_trace();
>>>>>>>>>>>> ...
>>>>>>>>>>>>
>>>>>>>>>>>> }
>>>>>>>>>>>>
>>>>>>>>>>>> Below is a capture (from ngrep) of a packet that through
>>>>>>>>>>>> this error.
>>>>>>>>>>>>
>>>>>>>>>>>> INVITE sip:12063430011 at yyy.yyy.yyy.yyy SIP/2.0.
>>>>>>>>>>>> Record-Route:
>>>>>>>>>>>> <sip:xxx.xxx.xxx.xxx;lr;ftag=0m15597FNecKe;schip=d4c.b840a454>.
>>>>>>>>>>>>
>>>>>>>>>>>> Via: SIP/2.0/UDP
>>>>>>>>>>>> xxx.xxx.xxx.xxx:5060;branch=z9hG4bK0533.69b5df66.1.
>>>>>>>>>>>> Via: SIP/2.0/UDP
>>>>>>>>>>>> 172.16.1.105;received=172.16.1.105;rport=5060;branch=z9hG4bK3Uj0ye5ve15SK.
>>>>>>>>>>>> Max-Forwards: 69.
>>>>>>>>>>>> From: "Unknown"
>>>>>>>>>>>> <sip:9999999999 at 172.16.1.115>;tag=0m15597FNecKe.
>>>>>>>>>>>> To: <sip:19999999999 at 172.16.1.115>.
>>>>>>>>>>>> Call-ID: a7747eca-ea88-1230-e489-57cd493474a3.
>>>>>>>>>>>> CSeq: 39716116 INVITE.
>>>>>>>>>>>> Contact:
>>>>>>>>>>>> <sip:gw+opensips at 172.16.1.105:5060;transport=udp;gw=opensips>.
>>>>>>>>>>>> User-Agent: FS.
>>>>>>>>>>>> Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, UPDATE,
>>>>>>>>>>>> INFO, REGISTER, REFER, NOTIFY.
>>>>>>>>>>>> Supported: timer, precondition, path, replaces.
>>>>>>>>>>>> Allow-Events: talk, hold, refer.
>>>>>>>>>>>> Session-Expires: 120;refresher=uac.
>>>>>>>>>>>> Min-SE: 120.
>>>>>>>>>>>> Content-Type: application/sdp.
>>>>>>>>>>>> Content-Disposition: session.
>>>>>>>>>>>> Content-Length: 247.
>>>>>>>>>>>> P-Call-Type: Notification.
>>>>>>>>>>>> X-FS-Support: update_display,send_info.
>>>>>>>>>>>> Remote-Party-ID: "Unknown"
>>>>>>>>>>>> <sip:9999999999 at 172.16.1.115>;party=calling;screen=yes;privacy=off.
>>>>>>>>>>>> .
>>>>>>>>>>>> v=0.
>>>>>>>>>>>> o=FreeSWITCH 1360080758 1360080759 IN IP4 zzz.zzz.zzz.zzz.
>>>>>>>>>>>> s=FreeSWITCH.
>>>>>>>>>>>> c=IN IP4 zzz.zzz.zzz.zzz.
>>>>>>>>>>>> t=0 0.
>>>>>>>>>>>> m=audio 29516 RTP/AVP 0 8 3 101.
>>>>>>>>>>>> a=rtpmap:101 telephone-event/8000.
>>>>>>>>>>>> a=fmtp:101 0-16.
>>>>>>>>>>>> a=silenceSupp:off - - - -.
>>>>>>>>>>>> a=ptime:20.
>>>>>>>>>>>> a=schipmangled:yes.
>>>>>>>>>>>>
>>>>>>>>>>>> _______________________________________________
>>>>>>>>>>>> Users mailing list
>>>>>>>>>>>> Users at lists.opensips.org
>>>>>>>>>>>> http://lists.opensips.org/cgi-bin/mailman/listinfo/users
>>>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>
>>>>>>
>>>>
>>
More information about the Users
mailing list