[OpenSIPS-Devel] Core dump when using b2b_init

[Anca Vamanu]

Hi Saul,

I have worked with B2BUA today and made two more fixes. Could you please 
update and use the new version?

Thanks and regards,
Anca

Saúl Ibarra wrote:
> Oops, it seems like I'm getting core dump again. I happens just after
> I answer the call with 200 OK:
>
> Aug 14 02:03:52 [1475] DBG:core:parse_msg: SIP Request:
> Aug 14 02:03:52 [1475] DBG:core:parse_msg:  method:  <INVITE>
> Aug 14 02:03:52 [1475] DBG:core:parse_msg:  uri:
> <sip:pjsua at 192.168.1.113:5060>
> Aug 14 02:03:52 [1475] DBG:core:parse_msg:  version: <SIP/2.0>
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=2
> Aug 14 02:03:52 [1475] DBG:core:parse_via_param: found param type 232,
> <branch> = <z9hG4bK1f6e.aafef655.0>; state=16
> Aug 14 02:03:52 [1475] DBG:core:parse_via: end of header reached,
> state=5
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: via found, flags=2
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: this is the first via
> Aug 14 02:03:52 [1475] DBG:core:receive_msg: After parse_msg...
> Aug 14 02:03:52 [1475] DBG:core:receive_msg: preparing to run routing
> scripts...
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:03:52 [1475] DBG:core:parse_via_param: found param type 234,
> <received> = <192.168.1.53>; state=6
> Aug 14 02:03:52 [1475] DBG:core:parse_via_param: found param type 235,
> <rport> = <5060>; state=6
> Aug 14 02:03:52 [1475] DBG:core:parse_via_param: found param type 232,
> <branch> = <z9hG4bKPjLrmzjTIXr5qgG54bs7Xkz1aOTIzp73SG>; state=16
> Aug 14 02:03:52 [1475] DBG:core:parse_via: end of header reached,
> state=5
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: via found,
> flags=ffffffffffffffff
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: parse_headers: this is
> the second via
> Aug 14 02:03:52 [1475] DBG:core:parse_to: end of header reached,
> state=9
> Aug 14 02:03:52 [1475] DBG:core:parse_to: display={},
> ruri={sip:pjsua at sipproxy.saghul.lan}
> Aug 14 02:03:52 [1475] DBG:core:get_hdr_field: <To> [31];
> uri=[sip:pjsua at sipproxy.saghul.lan]
> Aug 14 02:03:52 [1475] DBG:core:get_hdr_field: to body
> [sip:pjsua at sipproxy.saghul.lan
> ]
> Aug 14 02:03:52 [1475] DBG:core:get_hdr_field: cseq <CSeq>: <8582>
> <INVITE>
> Aug 14 02:03:52 [1475] DBG:core:get_hdr_field: content_length=459
> Aug 14 02:03:52 [1475] DBG:core:get_hdr_field: found end of header
> Aug 14 02:03:52 [1475] DBG:b2b_entities:b2b_prescript_f: Not an inside
> dialog request - not interested.
> Aug 14 02:03:52 [1475] DBG:maxfwd:is_maxfwd_present: value = 69
> [ ha llegado algoooooo -- ]
>
> Aug 14 02:03:52 [1475] DBG:core:parse_to_param:
> tag=7uLz6.G2NlFFyFMAw7FIhIqrGixTuBnd
> Aug 14 02:03:52 [1475] DBG:core:parse_to: end of header reached,
> state=29
> Aug 14 02:03:52 [1475] DBG:core:parse_to: display={},
> ruri={sip:saghul at sipproxy.saghul.lan}
> [New-Req][ INVITE  sip:pjsua at 192.168.1.113:5060 -- Contact:
> <sip:saghul at 192.168.1.53:5060> -- ]
>
> Aug 14 02:03:52 [1475] DBG:tm:t_newtran: transaction on entrance=0xffffffff
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=78
> Aug 14 02:03:52 [1475] DBG:tm:t_lookup_request: start searching:
> hash=59121, isACK=0
> Aug 14 02:03:52 [1475] DBG:tm:matching_3261: RFC3261 transaction
> matching failed
> Aug 14 02:03:52 [1475] DBG:tm:t_lookup_request: no transaction found
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:03:52 [1475] DBG:core:check_via_address: params
> 192.168.1.115, 192.168.1.115, 0
> [ empezamos con b2buismo -- ]
>
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:03:52 [1475] DBG:b2b_logic:b2b_init_request: 'To' header
> ALREADY PARSED: <sip:pjsua at sipproxy.saghul.lan>
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:03:52 [1475] DBG:b2b_entities:b2b_new_dlg: 'To' header
> ALREADY PARSED: <sip:pjsua at sipproxy.saghul.lan>
> Aug 14 02:03:52 [1475] DBG:core:print_rr_body: current rr is
> <sip:192.168.1.115;lr=on;ftag=7uLz6.G2NlFFyFMAw7FIhIqrGixTuBnd>
> Aug 14 02:03:52 [1475] DBG:core:print_rr_body: out rr
> [<sip:192.168.1.115;lr=on;ftag=7uLz6.G2NlFFyFMAw7FIhIqrGixTuBnd>]
> Aug 14 02:03:52 [1475] DBG:core:print_rr_body: we have 1 records
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:03:52 [1475] DBG:b2b_logic:create_top_hiding_entities: body
> = v=0
> o=- 3459195029 3459195029 IN IP4 192.168.1.53
> s=pjmedia
> c=IN IP4 192.168.1.53
> t=0 0
> a=X-nat:0
> m=audio 4002 RTP/AVP 103 102 104 117 3 0 8 9 101
> a=rtcp:4003 IN IP4 192.168.1.53
> a=rtpmap:103 speex/16000
> a=rtpmap:102 speex/8000
> a=rtpmap:104 speex/32000
> a=rtpmap:117 iLBC/8000
> a=fmtp:117 mode=30
> a=rtpmap:3 GSM/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:9 G722/8000
> a=sendrecv
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
>  - len = 459
> Aug 14 02:03:52 [1475] DBG:b2b_entities:client_new: New client - key =
> B2B.465.0.1250208232
> Aug 14 02:03:52 [1475] DBG:b2b_entities:client_new: extra_header =
> Content-Type: application/sdp
> Supported: replaces, 100rel, norefersub
> Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, SUBSCRIBE, NOTIFY,
> REFER, MESSAGE, OPTIONS
> Contact: <sip:b2b at sipproxy.saghul.lan:5065>
>
> Aug 14 02:03:52 [1475] DBG:b2b_entities:client_new: body = v=0
> o=- 3459195029 3459195029 IN IP4 192.168.1.53
> s=pjmedia
> c=IN IP4 192.168.1.53
> t=0 0
> a=X-nat:0
> m=audio 4002 RTP/AVP 103 102 104 117 3 0 8 9 101
> a=rtcp:4003 IN IP4 192.168.1.53
> a=rtpmap:103 speex/16000
> a=rtpmap:102 speex/8000
> a=rtpmap:104 speex/32000
> a=rtpmap:117 iLBC/8000
> a=fmtp:117 mode=30
> a=rtpmap:3 GSM/8000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:9 G722/8000
> a=sendrecv
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
>
> Aug 14 02:03:52 [1475] DBG:core:MD5StringArray: MD5 calculated:
> 8ac40e0aac45dd7c975f40bdad200267
> Aug 14 02:03:52 [1475] DBG:b2b_entities:generate_tag: from_tag =
> 8ac40e0aac45dd7c975f40bdad200267-63b4
> Aug 14 02:03:52 [1475] DBG:b2b_entities:client_new: generated tag =
> [8ac40e0aac45dd7c975f40bdad200267-63b4]
> Aug 14 02:03:52 [1475] DBG:tm:t_uac:
> next_hop=<sip:pjsua at sipproxy.saghul.lan>
> Aug 14 02:03:52 [1475] DBG:core:mk_proxy: doing DNS lookup...
> Aug 14 02:03:52 [1475] DBG:core:sip_resolvehost: no port, no proto ->
> do NAPTR lookup!
> Aug 14 02:03:52 [1475] DBG:core:get_record:
> lookup(sipproxy.saghul.lan, 35) failed
> Aug 14 02:03:52 [1475] DBG:core:sip_resolvehost: no valid NAPTR record
> found for sipproxy.saghul.lan, trying direct SRV lookup...
> Aug 14 02:03:52 [1475] DBG:core:get_record:
> lookup(_sip._udp.sipproxy.saghul.lan, 33) failed
> Aug 14 02:03:52 [1475] DBG:core:sip_resolvehost: no valid SRV record
> found for _sip._udp.sipproxy.saghul.lan, trying A record lookup...
> Aug 14 02:03:52 [1475] DBG:tm:dlg2hash: 37795
> Aug 14 02:03:52 [1475] DBG:tm:print_request_uri:
> sip:pjsua at sipproxy.saghul.lan
> Aug 14 02:03:52 [1475] DBG:tm:t_uac: REF_UNSAFE: after is 1
> Aug 14 02:03:52 [1475] DBG:tm:set_timer: relative timeout is 500000
> Aug 14 02:03:52 [1475] DBG:tm:insert_timer_unsafe: [4]: 0xb5d06ba4
> (19200000)
> Aug 14 02:03:52 [1475] DBG:tm:set_timer: relative timeout is 30
> Aug 14 02:03:52 [1475] DBG:tm:insert_timer_unsafe: [0]: 0xb5d06bc0
> (48)
> Aug 14 02:03:52 [1475] DBG:tm:cleanup_uac_timers: RETR/FR timers reset
> Aug 14 02:03:52 [1475] DBG:tm:insert_timer_unsafe: [2]: 0xb5d04780
> (23)
> Aug 14 02:03:52 [1475] DBG:tm:t_unref: UNREF_UNSAFE: after is 0
> Aug 14 02:03:52 [1475] DBG:core:destroy_avp_list: destroying list
> (nil)
> Aug 14 02:03:52 [1475] DBG:core:receive_msg: cleaning up
> Aug 14 02:03:52 [1475] DBG:core:parse_msg: SIP Reply  (status):
> Aug 14 02:03:52 [1475] DBG:core:parse_msg:  version: <SIP/2.0>
> Aug 14 02:03:52 [1475] DBG:core:parse_msg:  status:  <100>
> Aug 14 02:03:52 [1475] DBG:core:parse_msg:  reason:  <Trying>
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=2
> Aug 14 02:03:52 [1475] DBG:core:parse_via_param: found param type 232,
> <branch> = <z9hG4bK3a39.acebe734.0>; state=16
> Aug 14 02:03:52 [1475] DBG:core:parse_via: end of header reached,
> state=5
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: via found, flags=2
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: this is the first via
> Aug 14 02:03:52 [1475] DBG:core:receive_msg: After parse_msg...
> Aug 14 02:03:52 [1475] DBG:core:forward_reply: found module tm,
> passing reply to it
> Aug 14 02:03:52 [1475] DBG:tm:t_check: start=0xffffffff
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=22
> Aug 14 02:03:52 [1475] DBG:core:parse_to: end of header reached,
> state=9
> Aug 14 02:03:52 [1475] DBG:core:parse_to: display={},
> ruri={sip:pjsua at sipproxy.saghul.lan}
> Aug 14 02:03:52 [1475] DBG:core:get_hdr_field: <To> [31];
> uri=[sip:pjsua at sipproxy.saghul.lan]
> Aug 14 02:03:52 [1475] DBG:core:get_hdr_field: to body
> [sip:pjsua at sipproxy.saghul.lan
> ]
> Aug 14 02:03:52 [1475] DBG:core:get_hdr_field: cseq <CSeq>: <2>
> <INVITE>
> Aug 14 02:03:52 [1475] DBG:core:parse_headers: flags=8
> Aug 14 02:03:52 [1475] DBG:tm:t_reply_matching: hash 37795 label
> 1132379850 branch 0
> Aug 14 02:03:52 [1475] DBG:tm:t_reply_matching: REF_UNSAFE: after is 2
> Aug 14 02:03:52 [1475] DBG:tm:t_reply_matching: reply matched
> (T=0xb5d06a58)!
> Aug 14 02:03:52 [1475] DBG:tm:t_check: end=0xb5d06a58
> Aug 14 02:03:52 [1475] DBG:tm:reply_received: org. status uas=0,
> uac[0]=0 local=2 is_invite=1)
> Aug 14 02:03:52 [1475] DBG:tm:t_should_relay_response: T_code=0,
> new_code=100
> Aug 14 02:03:52 [1475] DBG:tm:local_reply: branch=0, save=0, winner=-1
> Aug 14 02:03:52 [1475] DBG:tm:set_timer: relative timeout is 120
> Aug 14 02:03:52 [1475] DBG:tm:insert_timer_unsafe: [1]: 0xb5d06bc0
> (138)
> Aug 14 02:03:52 [1475] DBG:tm:t_unref: UNREF_UNSAFE: after is 1
> Aug 14 02:03:52 [1475] DBG:core:destroy_avp_list: destroying list
> (nil)
> Aug 14 02:03:52 [1475] DBG:core:receive_msg: cleaning up
> Aug 14 02:03:52 [1477] DBG:tm:utimer_routine: timer
> routine:4,tl=0xb5d06ba4 next=(nil), timeout=19200000
> Aug 14 02:03:56 [1477] DBG:tm:timer_routine: timer
> routine:2,tl=0xb5d04780 next=(nil), timeout=23
> Aug 14 02:03:56 [1477] DBG:tm:wait_handler: removing 0xb5d04738 from
> table
> Aug 14 02:03:56 [1477] DBG:tm:delete_cell: delete transaction
> 0xb5d04738
> Aug 14 02:03:56 [1477] DBG:tm:wait_handler: done
> Aug 14 02:04:01 [1475] DBG:core:parse_msg: SIP Reply  (status):
> Aug 14 02:04:01 [1475] DBG:core:parse_msg:  version: <SIP/2.0>
> Aug 14 02:04:01 [1475] DBG:core:parse_msg:  status:  <200>
> Aug 14 02:04:01 [1475] DBG:core:parse_msg:  reason:  <OK>
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: flags=2
> Aug 14 02:04:01 [1475] DBG:core:parse_via_param: found param type 232,
> <branch> = <z9hG4bK3a39.acebe734.0>; state=16
> Aug 14 02:04:01 [1475] DBG:core:parse_via: end of header reached,
> state=5
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: via found, flags=2
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: this is the first via
> Aug 14 02:04:01 [1475] DBG:core:receive_msg: After parse_msg...
> Aug 14 02:04:01 [1475] DBG:core:forward_reply: found module tm,
> passing reply to it
> Aug 14 02:04:01 [1475] DBG:tm:t_check: start=0xffffffff
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: flags=22
> Aug 14 02:04:01 [1475] DBG:core:parse_to_param:
> tag=jwkEyvBN0y59AXyRNYLIJ2YERQZZFHmR
> Aug 14 02:04:01 [1475] DBG:core:parse_to: end of header reached,
> state=29
> Aug 14 02:04:01 [1475] DBG:core:parse_to: display={},
> ruri={sip:pjsua at sipproxy.saghul.lan}
> Aug 14 02:04:01 [1475] DBG:core:get_hdr_field: <To> [70];
> uri=[sip:pjsua at sipproxy.saghul.lan]
> Aug 14 02:04:01 [1475] DBG:core:get_hdr_field: to body
> [<sip:pjsua at sipproxy.saghul.lan>]
> Aug 14 02:04:01 [1475] DBG:core:get_hdr_field: cseq <CSeq>: <2>
> <INVITE>
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: flags=8
> Aug 14 02:04:01 [1475] DBG:tm:t_reply_matching: hash 37795 label
> 1132379850 branch 0
> Aug 14 02:04:01 [1475] DBG:tm:t_reply_matching: REF_UNSAFE: after is 2
> Aug 14 02:04:01 [1475] DBG:tm:t_reply_matching: reply matched
> (T=0xb5d06a58)!
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: flags=8
> Aug 14 02:04:01 [1475] DBG:tm:t_check: end=0xb5d06a58
> Aug 14 02:04:01 [1475] DBG:tm:reply_received: org. status uas=0,
> uac[0]=100 local=2 is_invite=1)
> Aug 14 02:04:01 [1475] DBG:tm:t_should_relay_response: T_code=0,
> new_code=200
> Aug 14 02:04:01 [1475] DBG:tm:local_reply: branch=0, save=0, winner=0
> Aug 14 02:04:01 [1475] DBG:tm:local_reply: local transaction completed
> Aug 14 02:04:01 [1475] DBG:tm:run_trans_callbacks: trans=0xb5d06a58,
> callback type 512, id 0 entered
> Aug 14 02:04:01 [1475] DBG:b2b_entities:b2b_parse_key: hash_index =
> [465]  - local_index= [0]
> Aug 14 02:04:01 [1475] DBG:b2b_entities:b2b_tm_cback: Received a reply
> with statuscode = 200
> Aug 14 02:04:01 [1475] DBG:b2b_entities:b2b_tm_cback: DLG state = 1
> Aug 14 02:04:01 [1475] DBG:b2b_entities:b2b_tm_cback: switched the
> state CONFIRMED
> Aug 14 02:04:01 [1475] DBG:tm:t_unref_cell: UNREF_UNSAFE: after is 1
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:04:01 [1475] DBG:core:get_hdr_field: content_length=260
> Aug 14 02:04:01 [1475] DBG:core:get_hdr_field: found end of header
> Aug 14 02:04:01 [1475] DBG:b2b_entities:b2b_new_dlg: 'To' header
> ALREADY PARSED: <sip:pjsua at sipproxy.saghul.lan>
> Aug 14 02:04:01 [1475] DBG:b2b_entities:b2b_new_dlg: Not an initial
> request
> Aug 14 02:04:01 [1475] DBG:core:parse_to_param:
> tag=8ac40e0aac45dd7c975f40bdad200267-63b4
> Aug 14 02:04:01 [1475] DBG:core:parse_to: end of header reached,
> state=29
> Aug 14 02:04:01 [1475] DBG:core:parse_to: display={},
> ruri={sip:saghul at sipproxy.saghul.lan}
> Aug 14 02:04:01 [1475] DBG:core:print_rr_body: current rr is
> <sip:192.168.1.115;lr;ftag=8ac40e0aac45dd7c975f40bdad200267-63b4>
> Aug 14 02:04:01 [1475] DBG:core:print_rr_body: out rr
> [<sip:192.168.1.115;lr;ftag=8ac40e0aac45dd7c975f40bdad200267-63b4>]
> Aug 14 02:04:01 [1475] DBG:core:print_rr_body: we have 1 records
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:04:01 [1475] DBG:b2b_logic:b2bl_parse_key: hash_index =
> [465]  - local_index= [0]
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:04:01 [1475] DBG:core:parse_headers: flags=ffffffffffffffff
> Aug 14 02:04:01 [1475] DBG:b2b_entities:b2b_parse_key: hash_index =
> [179]  - local_index= [0]
> Violación de segmento (core dumped)
>
>
> Please let me know if you need any further information.
>
> Regards,
>
>
> PS: I'm using trunk r5949.
>
>
>