[Spce-user] v2.8 - Session Timers

Wed Jan 18 03:15:12 EST 2017

Hello Jon, I have attached the log of sems at debug level and a screenshot of sngrep where you can see the times of the call.

Thanks for all.

Saludos, 
Robert Cuaresma

-----Mensaje original-----
De: Jon Bonilla (Manwe) [mailto:manwe at sipdoc.net] 
Enviado el: martes, 17 de enero de 2017 21:04
Para: Robert Cuaresma <rcuaresma at telcon.es>
CC: spce-user at lists.sipwise.com
Asunto: Re: [Spce-user] v2.8 - Session Timers

El Tue, 17 Jan 2017 17:07:07 +0000
Robert Cuaresma <rcuaresma at telcon.es> escribió:

Hi Robert

That's not sems log at debug level. I can't promise anything will show but you need to enable it and set it lo 3.

-------------- next part --------------
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012INVITE sip:DEST_NUMBER at VOIP_CARRIER_IP:5060;transport=udp SIP/2.0#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=as6e3c234e;did=b5f.f64;mpd=ii;ice_caller=strip;ice_callee=strip;vsf=Q3VqTEpmU1p2RTFTRAt5VhVxTXBDdmxMWFZ4ZA-->#015#012Record-Route: <sip:127.0.0.1:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKb2ed.d0f1e55bc6e308b7bd968a4b9ef1a310.0#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bKb2ed.9f055fc1a1cb8141aee76e4b0b909324.0#015#012Via: SIP/2.0/UDP 172.16.20.10:5060;branch=z9hG4bK39a4bbee;rport=5060#015#012Max-Forwards: 68#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=as6e3c234e#015#012To: <sip:690855255 at 172.16.20.2>#015#012Contact: <sip:931518327 at 172.16.20.10:5060>#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2#015#012CSeq: 103 INVITE#015#012Date: Wed, 18 Jan 2017 07:09:03 GMT#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE#015#012Supported: replaces, timer#015#012Content-Type: application/sdp#015#012Content-Length: 325#015#012P-Caller-UUID: 5871a408-b597-405d-bddf-7d37948e458e#015#012P-Callee-UUID: 0#015#012P-Asserted-Identity: <sip:SOURCE_NUMBER at 172.16.20.2>#015#012P-Called-Party-ID: <sip:DEST_NUMBER at VOIP_CARRIER_IP>#015#012P-App-Param: ;aleg_sst_enable=no;sst_enable=yes;sst_expires=1800;sst_min_timer=90;sst_max_timer=7200;sst_refresh_method=UPDATE#015#012P-App-Name: sbc#015#012P-D-Uri: sip:127.0.0.1:5060;received='sip:VOIP_CARRIER_IP:5060;transport=udp'#012#015#012v=0#015#012o=root 623685584 623685585 IN IP4 172.16.20.10#015#012s=Asterisk PBX 11.21.0#015#012c=IN IP4 172.16.20.10#015#012t=0 0#015#012m=audio 16354 RTP/AVP 18 0 8 101#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18 annexb=no#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=sendrecv#015#012a=direction:active#015#012--++--
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKb2ed.d0f1e55bc6e308b7bd968a4b9ef1a310.0
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 0
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [match_request, trans_table.cpp:68] DEBUG: Matching INVITE request
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:592] DEBUG: Received new request
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:595] DEBUG: req.method = <INVITE>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:598] DEBUG: req.r_uri = <sip:DEST_NUMBER at VOIP_CARRIER_IP:5060;transport=udp>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:599] DEBUG: req.from_uri = <sip:931518327 at 172.16.20.10:5060>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:600] DEBUG: req.from = <<sip:SOURCE_NUMBER at 172.16.20.2>>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:601] DEBUG: req.to = <<sip:690855255 at 172.16.20.2>>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:602] DEBUG: req.callid = <20300a157d500fd13ee211766a34b5d2 at 172.16.20.2>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:603] DEBUG: req.from_tag = <as6e3c234e>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:604] DEBUG: req.to_tag = <>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:605] DEBUG: cseq = <103>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:606] DEBUG: req.route = <<sip:127.0.0.1:5062;lr=on;ftag=as6e3c234e;did=b5f.f64;mpd=ii;ice_caller=strip;ice_callee=strip;vsf=Q3VqTEpmU1p2RTFTRAt5VhVxTXBDdmxMWFZ4ZA-->, <sip:127.0.0.1:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:607] DEBUG: hdrs = <Max-Forwards: 68#015#012Date: Wed, 18 Jan 2017 07:09:03 GMT#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE#015#012Supported: replaces, timer#015#012P-Caller-UUID: 5871a408-b597-405d-bddf-7d37948e458e#015#012P-Callee-UUID: 0#015#012P-Asserted-Identity: <sip:SOURCE_NUMBER at 172.16.20.2>#015#012P-Called-Party-ID: <sip:DEST_NUMBER at VOIP_CARRIER_IP>#015#012P-App-Param: ;aleg_sst_enable=no;sst_enable=yes;sst_expires=1800;sst_min_timer=90;sst_max_timer=7200;sst_refresh_method=UPDATE#015#012P-App-Name: sbc#015#012P-D-Uri: sip:127.0.0.1:5060;received='sip:VOIP_CARRIER_IP:5060;transport=udp'#015#012>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:608] DEBUG: body = <v=0#015#012o=root 623685584 623685585 IN IP4 172.16.20.10#015#012s=Asterisk PBX 11.21.0#015#012c=IN IP4 172.16.20.10#015#012t=0 0#015#012m=audio 16354 RTP/AVP 18 0 8 101#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18 annexb=no#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=sendrecv#015#012a=direction:active#015#012>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handleSipMsg, AmSipDispatcher.cpp:88] DEBUG: method: `INVITE' [6].
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [onInvite, SBC.cpp:192] DEBUG: using call profile 'ngcp' (from matching active_profile rule 'ngcp')
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [setInbandDetector, AmDtmfDetector.cpp:209] DEBUG: Setting internal DTMF detector
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [setLocalTag, AmSession.cpp:230] DEBUG: AmSession::setLocalTag() - session id set to 4F756AE7-587F148F000E672F-5FC8D700
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:614] DEBUG: ^^ M [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|] Ru SIP request INVITE handled ^^
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:112] DEBUG: starting up 1 sessions
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:119] DEBUG: starting up [|4F756AE7-587F148F000E672F-5FC8D700]: [0x7f2d580a06f0]
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [|4F756AE7-587F148F000E672F-5FC8D700] Disconnected, running, 0 UACTransPending vv
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [updateStatus, AmSipDialog.cpp:90] DEBUG: AmSipDialog::updateStatus(req = INVITE)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onSipRequest, AmSession.cpp:840] DEBUG: onSipRequest: method = INVITE
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onInvite, SBC.cpp:525] DEBUG: processing initial INVITE
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [updateStatusReply, AmSipDialog.cpp:274] DEBUG: reply: transaction found!
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [send_reply, trans_layer.cpp:215] DEBUG: reply_len = 969
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [send_reply, trans_layer.cpp:383] DEBUG: Sending to 127.0.0.1:5062 <SIP/2.0 100 Connecting#015#012Record-Route: <sip:127.0.0...>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012SIP/2.0 100 Connecting#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=as6e3c234e;did=b5f.f64;mpd=ii;ice_caller=strip;ice_callee=strip;vsf=Q3VqTEpmU1p2RTFTRAt5VhVxTXBDdmxMWFZ4ZA-->#015#012Record-Route: <sip:127.0.0.1:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKb2ed.d0f1e55bc6e308b7bd968a4b9ef1a310.0;received=127.0.0.1#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bKb2ed.9f055fc1a1cb8141aee76e4b0b909324.0#015#012Via: SIP/2.0/UDP 172.16.20.10:5060;branch=z9hG4bK39a4bbee;rport=5060#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=as6e3c234e#015#012To: <sip:690855255 at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2#015#012CSeq: 103 INVITE#015#012Server: Sipwise NGCP Application Server#015#012Contact: <sip:DEST_NUMBER at 127.0.0.1:5080>#015#012Content-Length: 0#015#012#015#012--++--
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [update_uas_reply, trans_layer.cpp:1522] DEBUG: update_uas_reply(t=0x7f2d58089180)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [replaceParameters, ParamReplacer.cpp:341] DEBUG: RURI pattern replace: '$r' -> 'sip:DEST_NUMBER at VOIP_CARRIER_IP:5060;transport=udp'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [replaceParameters, ParamReplacer.cpp:341] DEBUG: From pattern replace: '$f' -> '<sip:SOURCE_NUMBER at 172.16.20.2>'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [replaceParameters, ParamReplacer.cpp:341] DEBUG: To pattern replace: '$H(P-Called-Party-ID)' -> '<sip:DEST_NUMBER at VOIP_CARRIER_IP>'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [replaceParameters, ParamReplacer.cpp:341] DEBUG: Call-ID pattern replace: '$ci_b2b-1' -> '20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [replaceParameters, ParamReplacer.cpp:341] DEBUG: outbound_proxy pattern replace: '$H(P-D-Uri)' -> 'sip:127.0.0.1:5060;received='sip:VOIP_CARRIER_IP:5060;transport=udp''
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onInvite, SBC.cpp:548] DEBUG: set outbound proxy to 'sip:127.0.0.1:5060;received='sip:VOIP_CARRIER_IP:5060;transport=udp''
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Max-Forwards'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Date'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-Caller-UUID'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-Callee-UUID'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-Called-Party-ID'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [replaceParameters, ParamReplacer.cpp:341] DEBUG: auth_user pattern replace: '$P(u)' -> ''
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [replaceParameters, ParamReplacer.cpp:341] DEBUG: auth_pwd pattern replace: '$P(p)' -> ''
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onInvite, SBC.cpp:735] DEBUG: SBC: connecting to 'sip:DEST_NUMBER at VOIP_CARRIER_IP:5060;transport=udp'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onInvite, SBC.cpp:736] DEBUG:      From:  '<sip:SOURCE_NUMBER at 172.16.20.2>'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onInvite, SBC.cpp:737] DEBUG:      To:  '<sip:DEST_NUMBER at VOIP_CARRIER_IP>'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [setInbandDetector, AmDtmfDetector.cpp:209] DEBUG: Setting internal DTMF detector
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [createCalleeSession, SBC.cpp:1063] DEBUG: uac auth enabled for callee session.
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [createCalleeSession, SBC.cpp:1121] DEBUG: Created B2BUA callee leg, From: <sip:SOURCE_NUMBER at 172.16.20.2>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [addCall, SBCCallRegistry.cpp:37] DEBUG: SBCCallRegistry: Added call '4F756AE7-587F148F000E672F-5FC8D700' - mapped to: '1BEFF4D6-587F148F000E69C5-60596700'/''/'20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [addCall, SBCCallRegistry.cpp:37] DEBUG: SBCCallRegistry: Added call '1BEFF4D6-587F148F000E69C5-60596700' - mapped to: '4F756AE7-587F148F000E672F-5FC8D700'/'as6e3c234e'/'20300a157d500fd13ee211766a34b5d2 at 172.16.20.2'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='1BEFF4D6-587F148F000E69C5-60596700'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onSipRequest, AmSession.cpp:868] DEBUG: no audio input and output set. Session will not be attached to MediaProcessor.
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Max-Forwards'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Date'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-Caller-UUID'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-Callee-UUID'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-Called-Party-ID'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-App-Param'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-App-Name'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='1BEFF4D6-587F148F000E69C5-60596700'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Pending, running, 0 UACTransPending ^^
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:112] DEBUG: starting up 1 sessions
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:119] DEBUG: starting up [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700]: [0x1492080]
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Disconnected, running, 0 UACTransPending vv
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [onSendRequest, SBC.cpp:1307] DEBUG: auth->onSendRequest cseq = 10
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [onSendRequest, UACAuth.cpp:244] DEBUG: adding 10 to list of sent requests.
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [set_next_hop, trans_layer.cpp:672] DEBUG: next_hop:next_port is <127.0.0.1:5060>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [set_destination_ip, trans_layer.cpp:683] DEBUG: checking whether '127.0.0.1' is IP address...
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [set_destination_ip, trans_layer.cpp:725] DEBUG: set destination to 127.0.0.1:5060
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [send_request, trans_layer.cpp:851] DEBUG: send_request to R-URI <sip:DEST_NUMBER at VOIP_CARRIER_IP:5060;transport=udp>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKnUILCa9A
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [send_request, trans_layer.cpp:920] DEBUG: Sending to 127.0.0.1:5060 <INVITE sip:DEST_NUMBER at VOIP_CARRIER_IP:5060;transpo...>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012INVITE sip:DEST_NUMBER at VOIP_CARRIER_IP:5060;transport=udp SIP/2.0#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKnUILCa9A;rport#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012To: <sip:DEST_NUMBER at VOIP_CARRIER_IP>#015#012CSeq: 10 INVITE#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1#015#012Contact: <sip:127.0.0.1:5080>#015#012Route: <sip:127.0.0.1:5060;received='sip:VOIP_CARRIER_IP:5060;transport=udp';lr>#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE#015#012Supported: replaces, timer#015#012P-Asserted-Identity: <sip:SOURCE_NUMBER at 172.16.20.2>#015#012P-D-Uri: sip:127.0.0.1:5060;received='sip:VOIP_CARRIER_IP:5060;transport=udp'#015#012Content-Type: application/sdp#015#012Content-Length: 325#015#012#015#012v=0#015#012o=root 623685584 623685585 IN IP4 172.16.20.10#015#012s=Asterisk PBX 11.21.0#015#012c=IN IP4 172.16.20.10#015#012t=0 0#015#012m=audio 16354 RTP/AVP 18 0 8 101#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18 annexb=no#015#012a=rtpmap:0 PCMU/8000#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-16#015#012a=ptime:20#015#012a=sendrecv#015#012a=direction:active#015#012--++--
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [send_request, trans_layer.cpp:932] DEBUG: update_uac_request tt->_t =(nil)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [update_uac_request, trans_layer.cpp:1466] DEBUG: update_uac_request(t=0x7f2d50091680)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type A at time=477074008 (repeated=0)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type B at time=477074283 (repeated=0)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type M at time=477074383 (repeated=0)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [saveSessionDescription, AmB2BSession.cpp:538] DEBUG: saving session description (application/sdp, v=0#015#012o=root 623685584 623685585 IN IP4 172.16.20.1...)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Disconnected, running, 1 UACTransPending ^^
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012SIP/2.0 100 Trying#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKnUILCa9A;rport=5080#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012To: <sip:DEST_NUMBER at VOIP_CARRIER_IP>;tag=gK04f938c9#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1#015#012CSeq: 10 INVITE#015#012Content-Length: 0#015#012P-NGCP-Src-Ip: VOIP_CARRIER_IP#015#012P-NGCP-Src-Port: 5060#015#012P-NGCP-Src-Proto: udp#015#012P-NGCP-Src-Af: 4#015#012#015#012--++--
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKnUILCa9A
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [received_msg, trans_layer.cpp:1235] DEBUG: Reply matched an existing transaction
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [update_uac_reply, trans_layer.cpp:1286] DEBUG: update_uac_reply(reply code = 100, trans=0x7f2d50091680)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type A (this=0x7f2d50019bc0)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type M (this=0x7f2d5000b230)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type B (this=0x7f2d50037210)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type C at time=477082983 (repeated=0)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:627] DEBUG: Received reply: 100 Trying
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:628] DEBUG: reply.callid = <20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:629] DEBUG: reply.local_tag = <1BEFF4D6-587F148F000E69C5-60596700>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:630] DEBUG: reply.remote_tag = <gK04f938c9>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:631] DEBUG: cseq = <10>
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:637] DEBUG: ^^ M [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] ru SIP reply 100 Trying handled ^^
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Disconnected, running, 1 UACTransPending vv
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [updateStatus, AmSipDialog.cpp:331] DEBUG: updateStatus(rep = 100 Trying): transaction found!
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [onSipReply, SBC.cpp:1268] DEBUG: onSipReply: 100 Trying (fwd=1)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [onSipReply, SBC.cpp:1269] DEBUG: onSipReply: content-type =
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [onSipReply, AmB2BSession.cpp:411] DEBUG: onSipReply: INVITE -> 100 Trying (fwd=false), c-t=
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [onSipReply, AmSession.cpp:908] DEBUG: Dialog status changed Disconnected -> Pending (stopped=false)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [onSipReply, AmSession.cpp:914] DEBUG: negotiate_onreply = false
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Ip'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Port'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Proto'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Af'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='4F756AE7-587F148F000E672F-5FC8D700'
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Pending, running, 1 UACTransPending ^^
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Pending, running, 0 UACTransPending vv
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:889] DEBUG: 100 reply received from other leg
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onOtherReply, SBC.cpp:905] DEBUG: Callee is trying... code 100
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:148] DEBUG: B2BSipReply: 100 Trying (fwd=false)
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:149] DEBUG: B2BSipReply: content-type =
Jan 18 08:09:03 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Pending, running, 0 UACTransPending ^^

Jan 18 08:09:05 softswitch sems[2317]: [#7f2d60596700] [update_uas_reply, trans_layer.cpp:1522] DEBUG: update_uas_reply(t=0x7f2d58089180)
Jan 18 08:09:05 softswitch sems[2317]: [#7f2d60596700] [saveSessionDescription, AmB2BSession.cpp:538] DEBUG: saving session description (application/sdp, v=0#015#012o=Sonus_UAC 16947 21729 IN IP4 VOIP_CARRIER_IP#015...)
Jan 18 08:09:05 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Pending, running, 0 UACTransPending ^^

Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012SIP/2.0 183 Session Progress#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKnUILCa9A;rport=5080#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012To: <sip:DEST_NUMBER at VOIP_CARRIER_IP>;tag=gK04f938c9#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1#015#012CSeq: 10 INVITE#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>#015#012Record-Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>#015#012Contact: <sip:DEST_NUMBER at VOIP_CARRIER_IP:5060>#015#012Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS#015#012Content-Length:  280#015#012Content-Disposition: session; handling=required#015#012Content-Type: application/sdp#015#012P-NGCP-Src-Ip: VOIP_CARRIER_IP#015#012P-NGCP-Src-Port: 5060#015#012P-NGCP-Src-Proto: udp#015#012P-NGCP-Src-Af: 4#015#012#015#012v=0#015#012o=Sonus_UAC 16947 21729 IN IP4 VOIP_CARRIER_IP#015#012s=SIP Media Capabilities#015#012c=IN IP4 213.27.162.75#015#012t=0 0#015#012m=audio 22254 RTP/AVP 18 101#015#012a=direction: passive#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18 annexb=no#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=ptime:20#015#012--++--
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKnUILCa9A
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [received_msg, trans_layer.cpp:1235] DEBUG: Reply matched an existing transaction
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [update_uac_reply, trans_layer.cpp:1286] DEBUG: update_uac_reply(reply code = 183, trans=0x7f2d50091680)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type C at time=477083252 (repeated=0)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type C (this=0x14eabd0)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [prepare_routes_uac, SipCtrlInterface.cpp:721] DEBUG: route_field = [<sip:127.0.0.1:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>]
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:627] DEBUG: Received reply: 183 Session Progress
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:628] DEBUG: reply.callid = <20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:629] DEBUG: reply.local_tag = <1BEFF4D6-587F148F000E69C5-60596700>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:630] DEBUG: reply.remote_tag = <gK04f938c9>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:631] DEBUG: cseq = <10>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:637] DEBUG: ^^ M [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] ru SIP reply 183 Session Progress handled ^^
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Pending, running, 1 UACTransPending vv
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [updateStatus, AmSipDialog.cpp:331] DEBUG: updateStatus(rep = 183 Session Progress): transaction found!
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [onSipReply, SBC.cpp:1268] DEBUG: onSipReply: 183 Session Progress (fwd=1)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [onSipReply, SBC.cpp:1269] DEBUG: onSipReply: content-type = application/sdp
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [onSipReply, AmB2BSession.cpp:411] DEBUG: onSipReply: INVITE -> 183 Session Progress (fwd=true), c-t=application/sdp
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Content-Disposition'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Ip'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Port'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Proto'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Af'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='4F756AE7-587F148F000E672F-5FC8D700'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Pending, running, 1 UACTransPending ^^
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Pending, running, 0 UACTransPending vv
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:889] DEBUG: 183 reply received from other leg
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [onOtherReply, SBC.cpp:905] DEBUG: Callee is trying... code 183
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:148] DEBUG: B2BSipReply: 183 Session Progress (fwd=true)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:149] DEBUG: B2BSipReply: content-type = application/sdp
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [updateStatusReply, AmSipDialog.cpp:274] DEBUG: reply: transaction found!
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [send, SipCtrlInterface.cpp:354] DEBUG: HT:14, ext:0, rseq:0.
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [send, SipCtrlInterface.cpp:354] DEBUG: HT:9, ext:0, rseq:0.
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [send_reply, trans_layer.cpp:215] DEBUG: reply_len = 1335
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [send_reply, trans_layer.cpp:383] DEBUG: Sending to 127.0.0.1:5062 <SIP/2.0 183 Session Progress#015#012Record-Route: <sip:1...>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012SIP/2.0 183 Session Progress#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=as6e3c234e;did=b5f.f64;mpd=ii;ice_caller=strip;ice_callee=strip;vsf=Q3VqTEpmU1p2RTFTRAt5VhVxTXBDdmxMWFZ4ZA-->#015#012Record-Route: <sip:127.0.0.1:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKb2ed.d0f1e55bc6e308b7bd968a4b9ef1a310.0;received=127.0.0.1#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bKb2ed.9f055fc1a1cb8141aee76e4b0b909324.0#015#012Via: SIP/2.0/UDP 172.16.20.10:5060;branch=z9hG4bK39a4bbee;rport=5060#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=as6e3c234e#015#012To: <sip:690855255 at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2#015#012CSeq: 103 INVITE#015#012Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS#015#012Contact: <sip:DEST_NUMBER at 127.0.0.1:5080>#015#012Content-Type: application/sdp#015#012Content-Length: 280#015#012#015#012v=0#015#012o=Sonus_UAC 16947 21729 IN IP4 VOIP_CARRIER_IP#015#012s=SIP Media Capabilities#015#012c=IN IP4 213.27.162.75#015#012t=0 0#015#012m=audio 22254 RTP/AVP 18 101#015#012a=direction: passive#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18 annexb=no#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=ptime:20#015#012--++--
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [update_uas_reply, trans_layer.cpp:1522] DEBUG: update_uas_reply(t=0x7f2d58089180)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [saveSessionDescription, AmB2BSession.cpp:538] DEBUG: saving session description (application/sdp, v=0#015#012o=Sonus_UAC 16947 21729 IN IP4 VOIP_CARRIER_IP#015...)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Pending, running, 0 UACTransPending ^^
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012SIP/2.0 200 OK#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;ftag=05EB3586-587F14920008B8C2-60394700;lr=on>#015#012Record-Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;ftag=05EB3586-587F14920008B8C2-60394700;lr=on>#015#012Content-Type: application/sdp#015#012Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, NOTIFY, UPDATE#015#012Contact: <sip:192 at 192.168.2.18;alias=80.32.126.246~5060~1;transport=UDP;user=phone>#015#012Require: timer#015#012Supported: timer,from-change#015#012User-Agent: OXO103/015.001 GW_103/049.001#015#012Session-Expires: 1800;refresher=uas#015#012P-Asserted-Identity: <sip:192 at 192.168.2.18;user=phone>#015#012To: <sip:936407085 at SIPWISE_PUBLIC_IP>;tag=8c60ecbf6dad76a71fdab7b0196f7ba0#015#012From: <sip:972261252 at SIPWISE_PUBLIC_IP>;tag=05EB3586-587F14920008B8C2-60394700#015#012Call-ID: 336471704_25220249 at VOIP_CARRIER_IP_b2b-1#015#012CSeq: 10 INVITE#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKG.Hmuavg;rport=5080#015#012Content-Length: 334#015#012P-NGCP-Src-Ip: 80.32.126.246#015#012P-NGCP-Src-Port: 5060#015#012P-NGCP-Src-Proto: udp#015#012P-NGCP-Src-Af: 4#015#012#015#012v=0#015#012o=OxO 1484723495 1484723495 IN IP4 192.168.2.18#015#012s=Alcatel-Lucent OXO103/049.001#015#012c=IN IP4 80.32.126.246#015#012t=0 0#015#012m=audio 32000 RTP/AVP 8 100#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:100 telephone-event/8000#015#012a=fmtp:100 0-15#015#012a=silenceSupp:off - - - -#015#012a=sendrecv#015#012a=ptime:20#015#012a=maxptime:90#015#012a=direction:active#015#012a=oldmediaip:192.168.2.18#015#012--++--
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKG.Hmuavg
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [received_msg, trans_layer.cpp:1235] DEBUG: Reply matched an existing transaction
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [update_uac_reply, trans_layer.cpp:1286] DEBUG: update_uac_reply(reply code = 200, trans=0x7f2d50056b60)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [update_uac_reply, trans_layer.cpp:1361] DEBUG: Positive final reply to INVITE transaction (state=3)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type C (this=0x7f2d500716e0)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type L at time=477075874 (repeated=0)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [prepare_routes_uac, SipCtrlInterface.cpp:721] DEBUG: route_field = [<sip:127.0.0.1:5060;ngcplb=yes;r2=on;ftag=05EB3586-587F14920008B8C2-60394700;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;ftag=05EB3586-587F14920008B8C2-60394700;lr=on>]
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [handle_sip_reply, SipCtrlInterface.cpp:627] DEBUG: Received reply: 200 OK
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [handle_sip_reply, SipCtrlInterface.cpp:628] DEBUG: reply.callid = <336471704_25220249 at VOIP_CARRIER_IP_b2b-1>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [handle_sip_reply, SipCtrlInterface.cpp:629] DEBUG: reply.local_tag = <05EB3586-587F14920008B8C2-60394700>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [handle_sip_reply, SipCtrlInterface.cpp:630] DEBUG: reply.remote_tag = <8c60ecbf6dad76a71fdab7b0196f7ba0>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [handle_sip_reply, SipCtrlInterface.cpp:631] DEBUG: cseq = <10>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fd8e700] [handle_sip_reply, SipCtrlInterface.cpp:637] DEBUG: ^^ M [336471704_25220249 at VOIP_CARRIER_IP_b2b-1|05EB3586-587F14920008B8C2-60394700] ru SIP reply 200 OK handled ^^
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [336471704_25220249 at VOIP_CARRIER_IP_b2b-1|05EB3586-587F14920008B8C2-60394700] Pending, running, 1 UACTransPending vv
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [updateStatus, AmSipDialog.cpp:331] DEBUG: updateStatus(rep = 200 OK): transaction found!
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [onInvite2xx, AmB2BSession.cpp:463] DEBUG: no 200 ACK now: waiting for the 200 ACK from the other side...
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [onSipReply, SBC.cpp:1268] DEBUG: onSipReply: 200 OK (fwd=1)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [onSipReply, SBC.cpp:1269] DEBUG: onSipReply: content-type = application/sdp
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [updateCall, SBCCallRegistry.cpp:50] DEBUG: SBCCallRegistry: Updated call '638A5A25-587F14920008B5CA-5FD8E700' - rtag to: '8c60ecbf6dad76a71fdab7b0196f7ba0'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [onSipReply, AmB2BSession.cpp:411] DEBUG: onSipReply: INVITE -> 200 OK (fwd=true), c-t=application/sdp
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Session-Expires'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Ip'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Port'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Proto'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Af'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='638A5A25-587F14920008B5CA-5FD8E700'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [onSipReply, AmB2BSession.cpp:437] DEBUG: not removing relayed INVITE transaction yet...
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [336471704_25220249 at VOIP_CARRIER_IP_b2b-1|05EB3586-587F14920008B8C2-60394700] Connected, running, 1 UACTransPending ^^
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [336471704_25220249 at VOIP_CARRIER_IP|638A5A25-587F14920008B5CA-5FD8E700] Pending, running, 0 UACTransPending vv
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [onB2BEvent, AmB2BSession.cpp:889] DEBUG: 200 reply received from other leg
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [startCallTimer, SBC.cpp:968] DEBUG: SBC: starting call timer of 21600 seconds
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [setTimer, AmSession.cpp:1310] DEBUG: setting timer 1 with timeout 21600
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [onB2BEvent, AmB2BSession.cpp:148] DEBUG: B2BSipReply: 200 OK (fwd=true)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [onB2BEvent, AmB2BSession.cpp:149] DEBUG: B2BSipReply: content-type = application/sdp
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [updateStatusReply, AmSipDialog.cpp:274] DEBUG: reply: transaction found!
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [updateStatusReply, AmSipDialog.cpp:311] DEBUG: req.method = INVITE; t.method = INVITE
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [send_reply, trans_layer.cpp:215] DEBUG: reply_len = 1489
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [send_reply, trans_layer.cpp:383] DEBUG: Sending to 127.0.0.1:5062 <SIP/2.0 200 OK#015#012Record-Route: <sip:127.0.0.1:5062;...>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012SIP/2.0 200 OK#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=gK0e15a5ec;did=8ef.e7d2;mpd=ii;ice_caller=strip;ice_callee=strip;rtpprx=yes;vsf=Q3VqTFJlXVNwTzNUSw16J2ZxSm1fc3BJQGVBVkM->#015#012Record-Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK0e15a5ec;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK0e15a5ec;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKffa1.c9497dda9075ed8cd503a6397d4a744a.0;received=127.0.0.1#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bKffa1.ef187f4210d23078dc233c04bebf62fc.0#015#012Via: SIP/2.0/UDP VOIP_CARRIER_IP:5060;rport=5060;branch=z9hG4bK0eB0ebb7f85fa4ea8ca#015#012From: <sip:972261252 at SIPWISE_PUBLIC_IP>;tag=gK0e15a5ec#015#012To: <sip:34936407085 at SIPWISE_PUBLIC_IP>;tag=638A5A25-587F14920008B5CA-5FD8E700#015#012Call-ID: 336471704_25220249 at VOIP_CARRIER_IP#015#012CSeq: 4193 INVITE#015#012Allow: INVITE, ACK, CANCEL, BYE, OPTIONS, NOTIFY, UPDATE#015#012Require: timer#015#012Supported: timer,from-change#015#012User-Agent: OXO103/015.001 GW_103/049.001#015#012P-Asserted-Identity: <sip:192 at 192.168.2.18;user=phone>#015#012Contact: <sip:936407085 at 127.0.0.1:5080>#015#012Content-Type: application/sdp#015#012Content-Length: 334#015#012#015#012v=0#015#012o=OxO 1484723495 1484723495 IN IP4 192.168.2.18#015#012s=Alcatel-Lucent OXO103/049.001#015#012c=IN IP4 80.32.126.246#015#012t=0 0#015#012m=audio 32000 RTP/AVP 8 100#015#012a=rtpmap:8 PCMA/8000#015#012a=rtpmap:100 telephone-event/8000#015#012a=fmtp:100 0-15#015#012a=silenceSupp:off - - - -#015#012a=sendrecv#015#012a=ptime:20#015#012a=maxptime:90#015#012a=direction:active#015#012a=oldmediaip:192.168.2.18#015#012--++--
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [update_uas_reply, trans_layer.cpp:1522] DEBUG: update_uas_reply(t=0x146cad0)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type G at time=477074299 (repeated=0)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type H at time=477075874 (repeated=0)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [336471704_25220249 at VOIP_CARRIER_IP|638A5A25-587F14920008B5CA-5FD8E700] Connected, running, 0 UACTransPending ^^
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012ACK sip:127.0.0.1:5080 SIP/2.0#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=gK0e15a5ec;rtpprx=yes>#015#012Record-Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK0e15a5ec;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK0e15a5ec;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKffa1.fe383d1899d35771e99170e0c1240d2b.0#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bKffa1.98d6c1c4074f8476be67a9559c13c6ca.0#015#012Via: SIP/2.0/UDP VOIP_CARRIER_IP:5060;rport=5060;branch=z9hG4bK0eB0ebd7f1ee0543cae#015#012From: <sip:972261252 at SIPWISE_PUBLIC_IP>;tag=gK0e15a5ec#015#012To: <sip:34936407085 at SIPWISE_PUBLIC_IP>;tag=638A5A25-587F14920008B5CA-5FD8E700#015#012Call-ID: 336471704_25220249 at VOIP_CARRIER_IP#015#012CSeq: 4193 ACK#015#012Max-Forwards: 68#015#012Content-Length: 0#015#012#015#012--++--
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5080) to int (5080)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKffa1.fe383d1899d35771e99170e0c1240d2b.0
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 0
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [match_request, trans_table.cpp:68] DEBUG: Matching ACK request
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [match_request, trans_table.cpp:87] DEBUG: do_3261_match = 1
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [received_msg, trans_layer.cpp:1143] DEBUG: ACK matched INVITE transaction 0x146cad0
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [update_uas_request, trans_layer.cpp:1590] DEBUG: update_uas_request(t=0x146cad0)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [received_msg, trans_layer.cpp:1146] DEBUG: update_uas_request(bucket,t=0x146cad0,msg) = 9
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [received_msg, trans_layer.cpp:1163] DEBUG: Passing ACK to the UA.
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:592] DEBUG: Received new request
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:595] DEBUG: req.method = <ACK>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:598] DEBUG: req.r_uri = <sip:127.0.0.1:5080>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:599] DEBUG: req.from_uri = <sip:972261252 at SIPWISE_PUBLIC_IP>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:600] DEBUG: req.from = <<sip:972261252 at SIPWISE_PUBLIC_IP>>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:601] DEBUG: req.to = <<sip:34936407085 at SIPWISE_PUBLIC_IP>;tag=638A5A25-587F14920008B5CA-5FD8E700>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:602] DEBUG: req.callid = <336471704_25220249 at VOIP_CARRIER_IP>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:603] DEBUG: req.from_tag = <gK0e15a5ec>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:604] DEBUG: req.to_tag = <638A5A25-587F14920008B5CA-5FD8E700>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:605] DEBUG: cseq = <4193>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:606] DEBUG: req.route = <<sip:127.0.0.1:5062;lr=on;ftag=gK0e15a5ec;rtpprx=yes>, <sip:127.0.0.1:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK0e15a5ec;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK0e15a5ec;lr=on>>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:607] DEBUG: hdrs = <Max-Forwards: 68#015#012>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:608] DEBUG: body = <>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:614] DEBUG: ^^ M [336471704_25220249 at VOIP_CARRIER_IP|638A5A25-587F14920008B5CA-5FD8E700] Ru SIP request ACK handled ^^
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [336471704_25220249 at VOIP_CARRIER_IP|638A5A25-587F14920008B5CA-5FD8E700] Connected, running, 0 UACTransPending vv
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [updateStatus, AmSipDialog.cpp:90] DEBUG: AmSipDialog::updateStatus(req = ACK)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Max-Forwards'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='05EB3586-587F14920008B8C2-60394700'
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60394700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [336471704_25220249 at VOIP_CARRIER_IP|638A5A25-587F14920008B5CA-5FD8E700] Connected, running, 0 UACTransPending ^^
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [336471704_25220249 at VOIP_CARRIER_IP_b2b-1|05EB3586-587F14920008B8C2-60394700] Connected, running, 1 UACTransPending vv
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [relaySip, AmB2BSession.cpp:697] DEBUG: sending relayed ACK
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [onSendRequest, SBC.cpp:1307] DEBUG: auth->onSendRequest cseq = 10
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [onSendRequest, UACAuth.cpp:244] DEBUG: adding 10 to list of sent requests.
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [set_next_hop, trans_layer.cpp:672] DEBUG: next_hop:next_port is <127.0.0.1:5060>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [set_destination_ip, trans_layer.cpp:683] DEBUG: checking whether '127.0.0.1' is IP address...
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [set_destination_ip, trans_layer.cpp:725] DEBUG: set destination to 127.0.0.1:5060
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [send_request, trans_layer.cpp:851] DEBUG: send_request to R-URI <sip:192 at 192.168.2.18;alias=80.32.126.246~5060~1;transport=UDP;user=phone>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port () to int (5060)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKufjmmaKE
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [send_request, trans_layer.cpp:920] DEBUG: Sending to 127.0.0.1:5060 <ACK sip:192 at 192.168.2.18;alias=80.32.126.246~5060~...>
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012ACK sip:192 at 192.168.2.18;alias=80.32.126.246~5060~1;transport=UDP;user=phone SIP/2.0#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKufjmmaKE;rport#015#012From: <sip:972261252 at SIPWISE_PUBLIC_IP>;tag=05EB3586-587F14920008B8C2-60394700#015#012To: <sip:936407085 at SIPWISE_PUBLIC_IP>;tag=8c60ecbf6dad76a71fdab7b0196f7ba0#015#012CSeq: 10 ACK#015#012Call-ID: 336471704_25220249 at VOIP_CARRIER_IP_b2b-1#015#012Contact: <sip:127.0.0.1:5080>#015#012Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;ftag=05EB3586-587F14920008B8C2-60394700;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;ftag=05EB3586-587F14920008B8C2-60394700;lr=on>#015#012Content-Length: 0#015#012#015#012--++--
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [send_request, trans_layer.cpp:932] DEBUG: update_uac_request tt->_t =(nil)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [match_request, trans_table.cpp:68] DEBUG: Matching ACK request
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [match_request, trans_table.cpp:87] DEBUG: do_3261_match = 1
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [update_uac_request, trans_layer.cpp:1475] DEBUG: update_uac_request(200 ACK, t=0x7f2d50056b60)
Jan 18 08:09:09 softswitch sems[2317]: [#7f2d60293700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [336471704_25220249 at VOIP_CARRIER_IP_b2b-1|05EB3586-587F14920008B8C2-60394700] Connected, running, 0 UACTransPending ^^

Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKnUILCa9A;rport=5080#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012To: <sip:DEST_NUMBER at VOIP_CARRIER_IP>;tag=gK04f938c9#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1#015#012CSeq: 10 INVITE#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>#015#012Record-Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>#015#012Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed#015#012Contact: <sip:DEST_NUMBER at VOIP_CARRIER_IP:5060>#015#012Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS#015#012Require: timer#015#012Supported: timer#015#012Session-Expires: 1800;refresher=uac#015#012Content-Length:  280#015#012Content-Disposition: session; handling=required#015#012Content-Type: application/sdp#015#012P-NGCP-Src-Ip: VOIP_CARRIER_IP#015#012P-NGCP-Src-Port: 5060#015#012P-NGCP-Src-Proto: udp#015#012P-NGCP-Src-Af: 4#015#012#015#012v=0#015#012o=Sonus_UAC 16947 21729 IN IP4 VOIP_CARRIER_IP#015#012s=SIP Media Capabilities#015#012c=IN IP4 213.27.162.75#015#012t=0 0#015#012m=audio 22254 RTP/AVP 18 101#015#012a=direction: passive#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18 annexb=no#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=ptime:20#015#012--++--
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKnUILCa9A
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [received_msg, trans_layer.cpp:1235] DEBUG: Reply matched an existing transaction
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [update_uac_reply, trans_layer.cpp:1286] DEBUG: update_uac_reply(reply code = 200, trans=0x7f2d50091680)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [update_uac_reply, trans_layer.cpp:1361] DEBUG: Positive final reply to INVITE transaction (state=3)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type C (this=0x14cae90)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type L at time=477075984 (repeated=0)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [prepare_routes_uac, SipCtrlInterface.cpp:721] DEBUG: route_field = [<sip:127.0.0.1:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>]
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:627] DEBUG: Received reply: 200 OK
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:628] DEBUG: reply.callid = <20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:629] DEBUG: reply.local_tag = <1BEFF4D6-587F148F000E69C5-60596700>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:630] DEBUG: reply.remote_tag = <gK04f938c9>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:631] DEBUG: cseq = <10>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:637] DEBUG: ^^ M [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] ru SIP reply 200 OK handled ^^
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Pending, running, 1 UACTransPending vv
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [updateStatus, AmSipDialog.cpp:331] DEBUG: updateStatus(rep = 200 OK): transaction found!
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [onInvite2xx, AmB2BSession.cpp:463] DEBUG: no 200 ACK now: waiting for the 200 ACK from the other side...
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [onSipReply, SBC.cpp:1268] DEBUG: onSipReply: 200 OK (fwd=1)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [onSipReply, SBC.cpp:1269] DEBUG: onSipReply: content-type = application/sdp
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [updateCall, SBCCallRegistry.cpp:50] DEBUG: SBCCallRegistry: Updated call '4F756AE7-587F148F000E672F-5FC8D700' - rtag to: 'gK04f938c9'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [onSipReply, AmB2BSession.cpp:411] DEBUG: onSipReply: INVITE -> 200 OK (fwd=true), c-t=application/sdp
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Session-Expires'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Content-Disposition'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Ip'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Port'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Proto'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Af'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='4F756AE7-587F148F000E672F-5FC8D700'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [onSipReply, AmB2BSession.cpp:437] DEBUG: not removing relayed INVITE transaction yet...
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Connected, running, 1 UACTransPending ^^
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Pending, running, 0 UACTransPending vv
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:889] DEBUG: 200 reply received from other leg
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [startCallTimer, SBC.cpp:968] DEBUG: SBC: starting call timer of 21600 seconds
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [setTimer, AmSession.cpp:1310] DEBUG: setting timer 1 with timeout 21600
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:148] DEBUG: B2BSipReply: 200 OK (fwd=true)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [onB2BEvent, AmB2BSession.cpp:149] DEBUG: B2BSipReply: content-type = application/sdp
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [updateStatusReply, AmSipDialog.cpp:274] DEBUG: reply: transaction found!
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [updateStatusReply, AmSipDialog.cpp:311] DEBUG: req.method = INVITE; t.method = INVITE
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [send_reply, trans_layer.cpp:215] DEBUG: reply_len = 1458
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [send_reply, trans_layer.cpp:383] DEBUG: Sending to 127.0.0.1:5062 <SIP/2.0 200 OK#015#012Record-Route: <sip:127.0.0.1:5062;...>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012SIP/2.0 200 OK#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=as6e3c234e;did=b5f.f64;mpd=ii;ice_caller=strip;ice_callee=strip;vsf=Q3VqTEpmU1p2RTFTRAt5VhVxTXBDdmxMWFZ4ZA-->#015#012Record-Route: <sip:127.0.0.1:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKb2ed.d0f1e55bc6e308b7bd968a4b9ef1a310.0;received=127.0.0.1#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bKb2ed.9f055fc1a1cb8141aee76e4b0b909324.0#015#012Via: SIP/2.0/UDP 172.16.20.10:5060;branch=z9hG4bK39a4bbee;rport=5060#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=as6e3c234e#015#012To: <sip:690855255 at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2#015#012CSeq: 103 INVITE#015#012Accept: application/sdp, application/isup, application/dtmf, application/dtmf-relay,  multipart/mixed#015#012Allow: INVITE,ACK,CANCEL,BYE,REGISTER,REFER,INFO,SUBSCRIBE,NOTIFY,PRACK,UPDATE,OPTIONS#015#012Require: timer#015#012Supported: timer#015#012Contact: <sip:DEST_NUMBER at 127.0.0.1:5080>#015#012Content-Type: application/sdp#015#012Content-Length: 280#015#012#015#012v=0#015#012o=Sonus_UAC 16947 21729 IN IP4 VOIP_CARRIER_IP#015#012s=SIP Media Capabilities#015#012c=IN IP4 213.27.162.75#015#012t=0 0#015#012m=audio 22254 RTP/AVP 18 101#015#012a=direction: passive#015#012a=rtpmap:18 G729/8000#015#012a=fmtp:18 annexb=no#015#012a=rtpmap:101 telephone-event/8000#015#012a=fmtp:101 0-15#015#012a=sendrecv#015#012a=ptime:20#015#012--++--
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [update_uas_reply, trans_layer.cpp:1522] DEBUG: update_uas_reply(t=0x7f2d58089180)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type G at time=477074409 (repeated=0)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type H at time=477075984 (repeated=0)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [saveSessionDescription, AmB2BSession.cpp:538] DEBUG: saving session description (application/sdp, v=0#015#012o=Sonus_UAC 16947 21729 IN IP4 VOIP_CARRIER_IP#015...)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Connected, running, 0 UACTransPending ^^
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012ACK sip:127.0.0.1:5080 SIP/2.0#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=as6e3c234e>#015#012Record-Route: <sip:127.0.0.1:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1:5062;branch=z9hG4bKb2ed.298c86681294e2f2d2e128dfddcba400.0#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bKb2ed.0cbf819f339b8b7c762285d64985a163.0#015#012Via: SIP/2.0/UDP 172.16.20.10:5060;branch=z9hG4bK3f5b81f9;rport=5060#015#012Max-Forwards: 68#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=as6e3c234e#015#012To: <sip:690855255 at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015#012Contact: <sip:931518327 at 172.16.20.10:5060>#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2#015#012CSeq: 103 ACK#015#012User-Agent: FPBX-2.11.0(11.21.0)#015#012Content-Length: 0#015#012#015#012--++--
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5080) to int (5080)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKb2ed.298c86681294e2f2d2e128dfddcba400.0
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 0
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [match_request, trans_table.cpp:68] DEBUG: Matching ACK request
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [match_request, trans_table.cpp:87] DEBUG: do_3261_match = 1
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [received_msg, trans_layer.cpp:1143] DEBUG: ACK matched INVITE transaction 0x7f2d58089180
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [update_uas_request, trans_layer.cpp:1590] DEBUG: update_uas_request(t=0x7f2d58089180)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [received_msg, trans_layer.cpp:1146] DEBUG: update_uas_request(bucket,t=0x7f2d58089180,msg) = 9
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [received_msg, trans_layer.cpp:1163] DEBUG: Passing ACK to the UA.
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:592] DEBUG: Received new request
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:595] DEBUG: req.method = <ACK>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:598] DEBUG: req.r_uri = <sip:127.0.0.1:5080>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:599] DEBUG: req.from_uri = <sip:931518327 at 172.16.20.10:5060>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:600] DEBUG: req.from = <<sip:SOURCE_NUMBER at 172.16.20.2>>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:601] DEBUG: req.to = <<sip:690855255 at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:602] DEBUG: req.callid = <20300a157d500fd13ee211766a34b5d2 at 172.16.20.2>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:603] DEBUG: req.from_tag = <as6e3c234e>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:604] DEBUG: req.to_tag = <4F756AE7-587F148F000E672F-5FC8D700>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:605] DEBUG: cseq = <103>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:606] DEBUG: req.route = <<sip:127.0.0.1:5062;lr=on;ftag=as6e3c234e>, <sip:127.0.0.1:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:607] DEBUG: hdrs = <Max-Forwards: 68#015#012User-Agent: FPBX-2.11.0(11.21.0)#015#012>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:608] DEBUG: body = <>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_request, SipCtrlInterface.cpp:614] DEBUG: ^^ M [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Ru SIP request ACK handled ^^
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Connected, running, 0 UACTransPending vv
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [updateStatus, AmSipDialog.cpp:90] DEBUG: AmSipDialog::updateStatus(req = ACK)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Max-Forwards'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='1BEFF4D6-587F148F000E69C5-60596700'
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Connected, running, 0 UACTransPending ^^
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Connected, running, 1 UACTransPending vv
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [relaySip, AmB2BSession.cpp:697] DEBUG: sending relayed ACK
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [onSendRequest, SBC.cpp:1307] DEBUG: auth->onSendRequest cseq = 10
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [onSendRequest, UACAuth.cpp:244] DEBUG: adding 10 to list of sent requests.
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [set_next_hop, trans_layer.cpp:672] DEBUG: next_hop:next_port is <127.0.0.1:5060>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [set_destination_ip, trans_layer.cpp:683] DEBUG: checking whether '127.0.0.1' is IP address...
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [set_destination_ip, trans_layer.cpp:725] DEBUG: set destination to 127.0.0.1:5060
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [send_request, trans_layer.cpp:851] DEBUG: send_request to R-URI <sip:DEST_NUMBER at VOIP_CARRIER_IP:5060>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKX6HNoaQU
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [send_request, trans_layer.cpp:920] DEBUG: Sending to 127.0.0.1:5060 <ACK sip:DEST_NUMBER at VOIP_CARRIER_IP:5060 SIP/2.0#015#012V...>
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012ACK sip:DEST_NUMBER at VOIP_CARRIER_IP:5060 SIP/2.0#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKX6HNoaQU;rport#015#012From: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012To: <sip:DEST_NUMBER at VOIP_CARRIER_IP>;tag=gK04f938c9#015#012CSeq: 10 ACK#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1#015#012Contact: <sip:127.0.0.1:5080>#015#012Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;ftag=1BEFF4D6-587F148F000E69C5-60596700;lr=on>#015#012User-Agent: FPBX-2.11.0(11.21.0)#015#012Content-Length: 0#015#012#015#012--++--
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [send_request, trans_layer.cpp:932] DEBUG: update_uac_request tt->_t =(nil)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [match_request, trans_table.cpp:68] DEBUG: Matching ACK request
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [match_request, trans_table.cpp:87] DEBUG: do_3261_match = 1
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [update_uac_request, trans_layer.cpp:1475] DEBUG: update_uac_request(200 ACK, t=0x7f2d50091680)
Jan 18 08:09:11 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Connected, running, 0 UACTransPending ^^

Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5ff90700] [trans_timer_cb, sip_trans.cpp:157] DEBUG: Transaction timer expired: type=J, trans=0x14eb490, eta=477164357, t=477164357
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5ff90700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type J (this=0x7f2d50084ec0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012BYE sip:sems at 127.0.0.1:5080 SIP/2.0#015#012Record-Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK04f938c9;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK04f938c9;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK6ed5.2e32e59aafce2b2766d75aec09e4af2a.0#015#012Via: SIP/2.0/UDP VOIP_CARRIER_IP:5060;rport=5060;branch=z9hG4bK04B668a1c930c3dc5e1#015#012From: <sip:DEST_NUMBER at VOIP_CARRIER_IP>;tag=gK04f938c9#015#012To: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1#015#012CSeq: 1066 BYE#015#012Max-Forwards: 69#015#012Reason: Q.850;cause=102#015#012Content-Length: 0#015#012P-NGCP-Src-Ip: VOIP_CARRIER_IP#015#012P-NGCP-Src-Port: 5060#015#012P-NGCP-Src-Proto: udp#015#012P-NGCP-Src-Af: 4#015#012P-Sock-Info: udp:172.16.20.2:5060#015#012#015#012--++--
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5080) to int (5080)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bK6ed5.2e32e59aafce2b2766d75aec09e4af2a.0
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 0
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [match_request, trans_table.cpp:68] DEBUG: Matching BYE request
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [match_request, trans_table.cpp:87] DEBUG: do_3261_match = 1
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:592] DEBUG: Received new request
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:595] DEBUG: req.method = <BYE>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:598] DEBUG: req.r_uri = <sip:sems at 127.0.0.1:5080>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:599] DEBUG: req.from_uri = <sip:DEST_NUMBER at VOIP_CARRIER_IP>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:600] DEBUG: req.from = <<sip:DEST_NUMBER at VOIP_CARRIER_IP>>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:601] DEBUG: req.to = <<sip:SOURCE_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:602] DEBUG: req.callid = <20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:603] DEBUG: req.from_tag = <gK04f938c9>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:604] DEBUG: req.to_tag = <1BEFF4D6-587F148F000E69C5-60596700>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:605] DEBUG: cseq = <1066>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:606] DEBUG: req.route = <<sip:127.0.0.1:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK04f938c9;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK04f938c9;lr=on>>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:607] DEBUG: hdrs = <Max-Forwards: 69#015#012Reason: Q.850;cause=102#015#012P-NGCP-Src-Ip: VOIP_CARRIER_IP#015#012P-NGCP-Src-Port: 5060#015#012P-NGCP-Src-Proto: udp#015#012P-NGCP-Src-Af: 4#015#012P-Sock-Info: udp:172.16.20.2:5060#015#012>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:608] DEBUG: body = <>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fc8d700] [handle_sip_request, SipCtrlInterface.cpp:614] DEBUG: ^^ M [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Ru SIP request BYE handled ^^
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Connected, running, 0 UACTransPending vv
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [updateStatus, AmSipDialog.cpp:90] DEBUG: AmSipDialog::updateStatus(req = BYE)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [onSipRequest, AmSession.cpp:840] DEBUG: onSipRequest: method = BYE
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [updateStatusReply, AmSipDialog.cpp:274] DEBUG: reply: transaction found!
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [updateStatusReply, AmSipDialog.cpp:311] DEBUG: req.method = BYE; t.method = BYE
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [send_reply, trans_layer.cpp:215] DEBUG: reply_len = 679
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [send_reply, trans_layer.cpp:383] DEBUG: Sending to 127.0.0.1:5060 <SIP/2.0 200 OK#015#012Record-Route: <sip:127.0.0.1:5060;...>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012SIP/2.0 200 OK#015#012Record-Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK04f938c9;lr=on>#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=gK04f938c9;lr=on>#015#012Via: SIP/2.0/UDP 127.0.0.1;branch=z9hG4bK6ed5.2e32e59aafce2b2766d75aec09e4af2a.0;received=127.0.0.1#015#012Via: SIP/2.0/UDP VOIP_CARRIER_IP:5060;rport=5060;branch=z9hG4bK04B668a1c930c3dc5e1#015#012From: <sip:DEST_NUMBER at VOIP_CARRIER_IP>;tag=gK04f938c9#015#012To: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1#015#012CSeq: 1066 BYE#015#012Server: Sipwise NGCP Application Server#015#012Content-Length: 0#015#012#015#012--++--
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [update_uas_reply, trans_layer.cpp:1522] DEBUG: update_uas_reply(t=0x146cad0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type J at time=477165974 (repeated=0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Max-Forwards'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Reason'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Ip'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Port'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Proto'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Af'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-Sock-Info'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='4F756AE7-587F148F000E672F-5FC8D700'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1|1BEFF4D6-587F148F000E69C5-60596700] Disconnected, stopped, 0 UACTransPending ^^
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:150] DEBUG: finalizing 1 sessions
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:154] DEBUG: finalizing session [0x1492080/20300a157d500fd13ee211766a34b5d2 at 172.16.20.2_b2b-1/1BEFF4D6-587F148F000E69C5-60596700]
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [finalize, AmSession.cpp:528] DEBUG: running finalize sequence...
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [destroy, AmSession.cpp:558] DEBUG: AmSession::destroy()
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [stop, AmSession.cpp:542] DEBUG: AmSession::stop()
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [clearAudio, AmSession.cpp:782] DEBUG: Audio cleared !!!
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [finalize, AmSession.cpp:534] DEBUG: session is stopped.
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60495700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Connected, running, 0 UACTransPending vv
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [stopCallTimer, SBC.cpp:977] DEBUG: SBC: removing call timer
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [removeTimer, AmSession.cpp:1327] DEBUG: removing timer 1
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onOtherBye, AmB2BSession.cpp:488] DEBUG: onOtherBye()
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5062) to int (5062)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [set_next_hop, trans_layer.cpp:672] DEBUG: next_hop:next_port is <127.0.0.1:5062>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [set_destination_ip, trans_layer.cpp:683] DEBUG: checking whether '127.0.0.1' is IP address...
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [set_destination_ip, trans_layer.cpp:725] DEBUG: set destination to 127.0.0.1:5062
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [send_request, trans_layer.cpp:851] DEBUG: send_request to R-URI <sip:931518327 at 172.16.20.10:5060>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [parse_sip_uri, parse_uri.cpp:332] DEBUG: Converted URI port (5060) to int (5060)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKOc10ra14
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [send_request, trans_layer.cpp:920] DEBUG: Sending to 127.0.0.1:5062 <BYE sip:931518327 at 172.16.20.10:5060 SIP/2.0#015#012Via: ...>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [send, transport.cpp:98] DEBUG: send  msg#012--++--#012BYE sip:931518327 at 172.16.20.10:5060 SIP/2.0#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKOc10ra14;rport#015#012From: <sip:690855255 at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015#012To: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=as6e3c234e#015#012CSeq: 10 BYE#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2#015#012Route: <sip:127.0.0.1:5062;lr=on;ftag=as6e3c234e;did=b5f.f64;mpd=ii;ice_caller=strip;ice_callee=strip;vsf=Q3VqTEpmU1p2RTFTRAt5VhVxTXBDdmxMWFZ4ZA-->, <sip:127.0.0.1:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;nat=yes;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=as6e3c234e;lr=on>#015#012Content-Length: 0#015#012#015#012--++--
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [send_request, trans_layer.cpp:932] DEBUG: update_uac_request tt->_t =(nil)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [update_uac_request, trans_layer.cpp:1466] DEBUG: update_uac_request(t=0x7f2d5800bb50)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type E at time=477164399 (repeated=0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type F at time=477164674 (repeated=0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type M at time=477164774 (repeated=0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Disconnecting, stopped, 1 UACTransPending ^^
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012SIP/2.0 100 Trying#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKOc10ra14;rport=5080#015#012From: <sip:690855255 at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015#012To: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=as6e3c234e#015#012CSeq: 10 BYE#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2#015#012Server: Sipwise NGCP Proxy 2.X#015#012Content-Length: 0#015#012#015#012--++--
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKOc10ra14
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [received_msg, trans_layer.cpp:1235] DEBUG: Reply matched an existing transaction
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [update_uac_reply, trans_layer.cpp:1286] DEBUG: update_uac_reply(reply code = 100, trans=0x7f2d5800bb50)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:627] DEBUG: Received reply: 100 Trying
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:628] DEBUG: reply.callid = <20300a157d500fd13ee211766a34b5d2 at 172.16.20.2>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:629] DEBUG: reply.local_tag = <4F756AE7-587F148F000E672F-5FC8D700>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:630] DEBUG: reply.remote_tag = <as6e3c234e>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:631] DEBUG: cseq = <10>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fe8f700] [handle_sip_reply, SipCtrlInterface.cpp:637] DEBUG: ^^ M [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] ru SIP reply 100 Trying handled ^^
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Disconnecting, stopped, 1 UACTransPending vv
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [updateStatus, AmSipDialog.cpp:331] DEBUG: updateStatus(rep = 100 Trying): transaction found!
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, SBC.cpp:890] DEBUG: onSipReply: 100 Trying (fwd=0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, SBC.cpp:891] DEBUG: onSipReply: content-type =
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, AmB2BSession.cpp:411] DEBUG: onSipReply: BYE -> 100 Trying (fwd=false), c-t=
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, AmSession.cpp:912] DEBUG: Dialog status stays Disconnecting (stopped=true)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, AmSession.cpp:914] DEBUG: negotiate_onreply = false
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Server'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='1BEFF4D6-587F148F000E69C5-60596700'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Disconnecting, stopped, 1 UACTransPending ^^
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [run, udp_trsp.cpp:213] DEBUG: vv M [|] u recvd msg via UDP vv#012--++--#012SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKOc10ra14;rport=5080#015#012Record-Route: <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=4F756AE7-587F148F000E672F-5FC8D700;lr=on>#015#012Record-Route: <sip:127.0.0.1:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=4F756AE7-587F148F000E672F-5FC8D700;lr=on>#015#012Record-Route: <sip:127.0.0.1:5062;lr=on;ftag=4F756AE7-587F148F000E672F-5FC8D700>#015#012From: <sip:690855255 at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015#012To: <sip:SOURCE_NUMBER at 172.16.20.2>;tag=as6e3c234e#015#012Call-ID: 20300a157d500fd13ee211766a34b5d2 at 172.16.20.2#015#012CSeq: 10 BYE#015#012Server: FPBX-2.11.0(11.21.0)#015#012Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE#015#012Supported: replaces, timer#015#012Content-Length: 0#015#012P-NGCP-Src-Ip: 172.16.20.10#015#012P-NGCP-Src-Port: 5060#015#012P-NGCP-Src-Proto: udp#015#012P-NGCP-Src-Af: 4#015#012#015#012--++--
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [parse_via_params, parse_via.cpp:525] DEBUG: parsed branch: z9hG4bKOc10ra14
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [parse_via_params, parse_via.cpp:548] DEBUG: has_rport: 1
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [received_msg, trans_layer.cpp:1235] DEBUG: Reply matched an existing transaction
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [update_uac_reply, trans_layer.cpp:1286] DEBUG: update_uac_reply(reply code = 200, trans=0x7f2d5800bb50)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type E (this=0x7f2d58047fe0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type M (this=0x7f2d580487d0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [reset_timer, sip_trans.cpp:140] DEBUG: Clearing old timer of type F (this=0x7f2d58048790)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [reset_timer, sip_trans.cpp:188] DEBUG: New timer of type K at time=477164624 (repeated=0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [prepare_routes_uac, SipCtrlInterface.cpp:721] DEBUG: route_field = [<sip:127.0.0.1:5062;lr=on;ftag=4F756AE7-587F148F000E672F-5FC8D700>, <sip:127.0.0.1:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=4F756AE7-587F148F000E672F-5FC8D700;lr=on>, <sip:SIPWISE_PUBLIC_IP:5060;ngcplb=yes;r2=on;socket=udp:172.16.20.2:5060;ftag=4F756AE7-587F148F000E672F-5FC8D700;lr=on>]
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:627] DEBUG: Received reply: 200 OK
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:628] DEBUG: reply.callid = <20300a157d500fd13ee211766a34b5d2 at 172.16.20.2>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:629] DEBUG: reply.local_tag = <4F756AE7-587F148F000E672F-5FC8D700>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:630] DEBUG: reply.remote_tag = <as6e3c234e>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:631] DEBUG: cseq = <10>
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d5fb8c700] [handle_sip_reply, SipCtrlInterface.cpp:637] DEBUG: ^^ M [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] ru SIP reply 200 OK handled ^^
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:450] DEBUG: vv S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Disconnecting, stopped, 1 UACTransPending vv
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [process, AmSession.cpp:790] DEBUG: AmSession processing event
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [updateStatus, AmSipDialog.cpp:331] DEBUG: updateStatus(rep = 200 OK): transaction found!
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, SBC.cpp:890] DEBUG: onSipReply: 200 OK (fwd=0)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, SBC.cpp:891] DEBUG: onSipReply: content-type =
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, AmB2BSession.cpp:411] DEBUG: onSipReply: BYE -> 200 OK (fwd=false), c-t=
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, AmSession.cpp:908] DEBUG: Dialog status changed Disconnecting -> Disconnected (stopped=true)
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [onSipReply, AmSession.cpp:914] DEBUG: negotiate_onreply = false
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'Server'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Ip'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Port'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Proto'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [inplaceHeaderFilter, HeaderFilter.cpp:161] DEBUG: erasing header 'P-NGCP-Src-Af'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [relayEvent, AmB2BSession.cpp:474] DEBUG: AmB2BSession::relayEvent: to other_id='1BEFF4D6-587F148F000E69C5-60596700'
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [processingCycle, AmSession.cpp:468] DEBUG: ^^ S [20300a157d500fd13ee211766a34b5d2 at 172.16.20.2|4F756AE7-587F148F000E672F-5FC8D700] Disconnected, stopped, 0 UACTransPending ^^
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:150] DEBUG: finalizing 1 sessions
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:154] DEBUG: finalizing session [0x7f2d580a06f0/20300a157d500fd13ee211766a34b5d2 at 172.16.20.2/4F756AE7-587F148F000E672F-5FC8D700]
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [finalize, AmSession.cpp:528] DEBUG: running finalize sequence...
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [destroy, AmSession.cpp:558] DEBUG: AmSession::destroy()
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [stop, AmSession.cpp:542] DEBUG: AmSession::stop()
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [clearAudio, AmSession.cpp:782] DEBUG: Audio cleared !!!
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [finalize, AmSession.cpp:534] DEBUG: session is stopped.
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:97] DEBUG: running processing loop
Jan 18 08:39:11 softswitch sems[2317]: [#7f2d60596700] [run, AmSessionProcessor.cpp:133] DEBUG: processing events for  up to 1 sessions
-------------- next part --------------
A non-text attachment was scrubbed...
Name: sngrep_call2.png
Type: image/png
Size: 33150 bytes
Desc: sngrep_call2.png
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20170118/4c80c6af/attachment-0001.png>