[OpenSIPS-Devel] [ opensips-Bugs-3164711 ] CRITICAL:siptrace:ip_addr2a: unknown address family 0

SourceForge.net noreply at sourceforge.net
Fri Feb 18 15:25:47 CET 2011


Bugs item #3164711, was opened at 2011-01-24 14:52
Message generated for change (Comment added) made by bogdan_iancu
You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=3164711&group_id=232389

Please note that this message will contain a full copy of the comment thread,
including the initial issue submission, for this request,
not just the latest update.
Category: modules
Group: 1.6.x
>Status: Closed
>Resolution: Fixed
Priority: 7
Private: No
Submitted By: Nobody/Anonymous (nobody)
Assigned to: Bogdan-Andrei Iancu (bogdan_iancu)
Summary: CRITICAL:siptrace:ip_addr2a: unknown address family 0 

Initial Comment:
I added 
local_route {
	xlog("================LOCAL_ROUTE============\n");
	setflag(22);
	sip_trace();	
	if (is_method("BYE") ) {
		xlog("================BYE============\n");
	}
}

to the routing script in order to get BYE messages written into sip_trace when CallControl interrupts a session. When the sip_trace function is called for the BYE message that was sent to the caller, OpenSIPS crashes:


Jan 24 14:36:31 P4237 cdrtool[8306]: DebitBalance Duration=12 CallId=216034819 From=sip:1000 at localhost Gateway=127.0.0.1 To=sip:01234 at localhost
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: found newline before attr_separator--we have just the attribute's value 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: empty name, attr not quoted value <2246> found 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: 1 data->len is 17 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: 2 data->len is 12 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_tree: adding node <> ; val <2246> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_tree: the remaining datagram has 12 bytes 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: the remaining datagram to be parsed is 1988155359   and 12 in length  
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: the string is not just a quoted string 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: found newline before attr_separator--we have just the attribute's value 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: empty name, attr not quoted value <1988155359> found 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: 1 data->len is 12 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: 2 data->len is 1 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_tree: adding node <> ; val <1988155359> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_tree: the remaining datagram has 1 bytes 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_parse_node: the remaining datagram to be parsed is   and 1 in length  
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:mi_datagram:mi_datagram_server: done parsing the mi tree 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:dialog:mi_terminate_dlg: h_entry 2246 h_id 1988155359 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:dialog:lookup_dlg: ref dlg 0xb5c2157c with 1 -> 3 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:dialog:lookup_dlg: dialog id=1988155359 found on entry 2246 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:dialog:send_leg_bye: sending BYE to caller (0) 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:dialog:ref_dlg: ref dlg 0xb5c2157c with 1 -> 4 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:tm:t_uac: next_hop=<sip:1000 at 127.0.0.1:5061> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_uri: parsed uri:  type=1 user=<1000>(4)  passwd=<>(0)  host=<127.0.0.1>(9)  port=<5061>(4): 5061  params=<>(0)  headers=<>(0) 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_uri:  uri params:    transport=<>, val=<>, proto=0 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_uri:    user-param=<>, val=<> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_uri:    method=<>, val=<> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_uri:    ttl=<>, val=<> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_uri:    maddr=<>, val=<> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_uri:    lr=<>, val=<> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_uri:    r2=<>, val=<> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:mk_proxy: doing DNS lookup... 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:tm:dlg2hash: 36165 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:tm:print_request_uri: sip:1000 at 127.0.0.1:5061 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:tm:t_uac: building sip_msg from buffer 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_msg: SIP Request: 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_msg:  method:  <BYE> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_msg:  uri:     <sip:1000 at 127.0.0.1:5061> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_msg:  version: <SIP/2.0> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: flags=2 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_via_param: found param type 232, <branch> = <z9hG4bK54d8.7214f724.0>; state=16 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_via: end of header reached, state=5 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: via found, flags=2 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: this is the first via 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: header field type 1, name=<Via>, body=<SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK54d8.7214f724.0> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_msg:  first  via: <SIP/2.0/UDP> <127.0.0.1:(0)>
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_msg: ;<>
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_msg:  
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_msg: exiting 
Jan 24 14:36:31 P4237 cdrtool[8306]: ConnectFee=0.0000 CallId=216034819 Span=1 Duration=12 DestId=31 default Profile=grn_premium Period=weekday Rate=grn_premium Interval=0-24 Cost=0.1000/6 Price=0.2000 PriceIn=0.0000
Jan 24 14:36:31 P4237 ./opensips[8254]: INFO:core:buf_init: initializing... 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:pv_printf: final buffer length 40 
Jan 24 14:36:31 P4237 ./opensips[8254]: ================LOCAL_ROUTE============ 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: flags=10 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_to_param: tag=1058707960 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_to: end of header reached, state=29 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_to: display={}, ruri={sip:1000 at localhost} 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:get_hdr_field: <To> [37]; uri=[sip:1000 at localhost]  
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:get_hdr_field: to body [<sip:1000 at localhost>] 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: header field type 3, name=<To>, body=<<sip:1000 at localhost>;tag=1058707960> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: header field type 4, name=<From>, body=<<sip:01234 at localhost>;tag=994088071> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_to_param: tag=994088071 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_to: end of header reached, state=29 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_to: display={}, ruri={sip:01234 at localhost} 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: flags=40 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:get_hdr_field: cseq <CSeq>: <21> <BYE> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: header field type 5, name=<CSeq>, body=<21 BYE> 
Jan 24 14:36:31 P4237 ./opensips[8254]: DBG:core:parse_headers: header field type 6, name=<Call-ID>, body=<216034819> 
Jan 24 14:36:31 P4237 ./opensips[8254]: CRITICAL:siptrace:ip_addr2a: unknown address family 0 
Jan 24 14:36:31 P4237 kernel: [18005.607196] opensips[8254]: segfault at 0 ip b7f11bb9 sp bfe8fbf8 error 4 in libc-2.11.2.so[b7e9f000+140000]
Jan 24 14:36:31 P4237 cdrtool[8306]: Price=0.2000 Duration=12 CallId=216034819 BillingParty=1000 at localhost DestId=31 MaxSessionTime=0
Jan 24 14:36:31 P4237 call-control[3909]: Call id 216034819 of 1000 at localhost to sip:01234 at localhost disconnected by call control after 12 seconds, call price is 0.2000
Jan 24 14:36:31 P4237 ./opensips[8286]: CRITICAL:core:receive_fd: EOF on 11 
Jan 24 14:36:31 P4237 ./opensips[8286]: DBG:core:handle_ser_child: dead child 1, pid 8254 (shutting down?) 
Jan 24 14:36:31 P4237 ./opensips[8286]: DBG:core:io_watch_del: io_watch_del (0x8167a60, 11, -1, 0x0) fd_no=22 called 
Jan 24 14:36:31 P4237 ./opensips[8252]: INFO:core:handle_sigs: child process 8254 exited by a signal 11 
Jan 24 14:36:31 P4237 ./opensips[8252]: INFO:core:handle_sigs: core was generated 
Jan 24 14:36:31 P4237 ./opensips[8252]: INFO:core:handle_sigs: terminating due to SIGCHLD 
Jan 24 14:36:31 P4237 ./opensips[8255]: INFO:core:sig_usr: signal 15 received 
Jan 24 14:36:31 P4237 media-dispatcher[3885]: debug: Connection to OpenSIPS lost: Connection was closed cleanly

----------------------------------------------------------------------

>Comment By: Bogdan-Andrei Iancu (bogdan_iancu)
Date: 2011-02-18 16:25

Message:
Hi,

The fix is available on SVN (trunk and stable) - please update .

Regards,
Bogdan

----------------------------------------------------------------------

You can respond by visiting: 
https://sourceforge.net/tracker/?func=detail&atid=1086410&aid=3164711&group_id=232389



More information about the Devel mailing list