[Spce-user] RV: v2.8 - Session Timers
Robert Cuaresma
rcuaresma at telcon.es
Wed Jan 25 02:18:38 EST 2017
Arrggg!! Sorry Jon, I had attached a Debug with incorrect data.... now, you have a complete debug call with an outgoing call session and a 200 OK with
#012Session-Expires: 1800;refresher=uac#015
Thanks!!
Saludos,
Robert Cuaresma
-----Mensaje original-----
De: Jon Bonilla (Manwe) [mailto:manwe at sipdoc.net] Enviado el: lunes, 23 de enero de 2017 11:43
Para: Robert Cuaresma <rcuaresma at telcon.es>
Asunto: Re: [Spce-user] v2.8 - Session Timers
El Mon, 23 Jan 2017 07:37:27 +0000
Robert Cuaresma <rcuaresma at telcon.es> escribió:
> Hi Jon,
>
> I attached you the correct Sems Debug that include the sip trace with
> an outgoing call.
>
Hi Robert
Again, in this capture I see "#012Session-Expires: 1800;refresher=uas#015" in te 200OK. It's te carrier the one who has to refresh the session.
You need an example with refresher=uac to check is sems does not refresh in outgoing calls.
If you do not receive an update or invite before the bye the carrier is doing wrong.
You could also try to disable session timers in your gateway configuration loose that functionality.
cheers,
Jon
> Saludos,
> Robert Cuaresma
>
> -----Mensaje original-----
> De: Jon Bonilla (Manwe) [mailto:manwe at sipdoc.net] Enviado el:
> miércoles, 18 de enero de 2017 10:00
> Para: Robert Cuaresma <rcuaresma at telcon.es>
> CC: spce-user at lists.sipwise.com
> Asunto: Re: [Spce-user] v2.8 - Session Timers
>
> El Wed, 18 Jan 2017 08:15:12 +0000
> Robert Cuaresma <rcuaresma at telcon.es> escribió:
>
> > 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
>
>
> Hi Robert
>
> When sending a capture please send the SIP headers, not a capture.
>
> From the sems log of this particular call I can see this:
>
>
> 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=di
> rection:active#015#012a=oldmediaip:192.168.2.18#015#012--++--
>
>
>
> In the 200 OK the refresher is set to "uas" which means that the one
> receiving the call is responsible of updating it. This time sems is
> not the one responsible as this is an outgoing call and the carrier should refresh.
>
> On previous traces it was uac. We would need a sems debug and sip
> trace where sems is responsible of updating the session.
>
>
> cheers,
>
> Jon
>
>
>
>
>
>
> >
> >
> > -----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:DEST_NUMBER at 172.16.20.2>#015
#012Contact: <sip:FROM_NUMBER 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:FROM_NUMBER 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:DEST_NUMBER 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:DEST_NUMBER 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#01
5#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:DEST_NUMBER 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
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:FROM_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012To: <sip:DEST_NUMBER at VOIP_CARRIER>;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: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#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#015
#012s=SIP Media Capabilities#015
#012c=IN IP4 VOIP_CARRIER_MEDIA#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:+34FROM_NUMBER at 172.16.20.2>;tag=as6e3c234e#015
#012To: <sip:DEST_NUMBER 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_MEDIA#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_MEDIA#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:+34FROM_NUMBER at 172.16.20.2>;tag=as6e3c234e#015
#012To: <sip:DEST_NUMBER at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015
#012Contact: <sip:FROM_NUMBER 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#01
5#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:FROM_NUMBER 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:+34FROM_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:DEST_NUMBER 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_MEDIA: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_MEDIA: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_MEDIA:5060 SIP/2.0#015#012Via: SIP/2.0/UDP 127.0.0.1:5080;branch=z9hG4bKX6HNoaQU;rport#015#012From: <sip:+34FROM_NUMBER at 172.16.20.2>;tag=1BEFF4D6-587F148F000E69C5-60596700#015#012To: <sip:DEST_NUMBER at VOIP_CARRIER_MEDIA>;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: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:DEST_NUMBER 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:DEST_NUMBER at 172.16.20.2>;tag=4F756AE7-587F148F000E672F-5FC8D700#015
#012Contact: <sip:FROM_NUMBER 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:FROM_NUMBER 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:DEST_NUMBER 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:FROM_NUMBER 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:FROM_NUMBER 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:FROM_NUMBER 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:DEST_NUMBER 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:DEST_NUMBER 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:DEST_NUMBER 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
More information about the Spce-user
mailing list