recv 1249 bytes from udp/[IP1]:5060 at 11:41:43.585794: ------------------------------------------------------------------------ INVITE sip:5010@IP_2:5060 SIP/2.0 Record-Route: Via: SIP/2.0/UDP freeswitch-gateway-10x-test.com:5060;branch=z9hG4bKe765.ebe2be53.0 Via: SIP/2.0/UDP IP_3:55731;received=IP_3;rport=55731;branch=z9hG4bKPjdbd1d546ee694046bd6c75ce9ab5380f Max-Forwards: 69 From: ;tag=5d2685b30c0646b585d6f1f4cf613ff5 To: Contact: ;+sip.ice Call-ID: a8076632ec184cfbacfe34a74269c4ae CSeq: 23209 INVITE Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS Supported: replaces, 100rel, timer, norefersub Session-Expires: 1800 Min-SE: 90 User-Agent: MicroSIP/3.15.10 Content-Type: application/sdp Content-Length: 329 v=0 o=- 3810993081 3810993081 IN IP4 IP_4 s=pjmedia b=AS:84 t=0 0 a=X-nat:0 m=audio 25536 RTP/AVP 8 0 3 9 101 c=IN IP4 IP_4 b=TIAS:64000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=sendrecv a=rtcp:25537 2020-10-06 11:41:43.574620 [NOTICE] switch_channel.c:1118 New Channel sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com [3fc3ef11-71ea-44d6-96bc-90e41af6a295] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:585 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) Running State Change CS_NEW (Cur 1 Tot 11) 2020-10-06 11:41:43.574620 [DEBUG] sofia.c:10280 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com receiving invite from IP1:5060 version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit 2020-10-06 11:41:43.574620 [DEBUG] sofia.c:7326 Channel sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com entering state [received][100] 2020-10-06 11:41:43.574620 [DEBUG] sofia.c:7336 Remote SDP: v=0 o=- 3810993081 3810993081 IN IP4 IP_4 s=pjmedia b=AS:84 t=0 0 a=X-nat:0 m=audio 25536 RTP/AVP 8 0 3 9 101 c=IN IP4 IP_4 b=TIAS:64000 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:9 G722/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtcp:25537 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5649 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5594 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5510 Set telephone-event payload to 101@8000 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:3839 Set Codec sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com PCMA/8000 20 ms 160 samples 64000 bits 1 channels 2020-10-06 11:41:43.574620 [DEBUG] switch_core_codec.c:111 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com Original read codec set to PCMA:8 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5853 Set telephone-event payload to 101@8000 2020-10-06 11:41:43.574620 [DEBUG] switch_core_media.c:5911 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com Set 2833 dtmf send payload to 101 recv payload to 101 2020-10-06 11:41:43.574620 [DEBUG] sofia.c:7760 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State Change CS_NEW -> CS_INIT 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:604 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State NEW 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:585 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) Running State Change CS_INIT (Cur 1 Tot 11) 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:628 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State INIT 2020-10-06 11:41:43.574620 [DEBUG] mod_sofia.c:93 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com SOFIA INIT 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:40 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com Standard INIT 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:48 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State Change CS_INIT -> CS_ROUTING 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:628 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State INIT going to sleep 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:585 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) Running State Change CS_ROUTING (Cur 1 Tot 11) 2020-10-06 11:41:43.574620 [DEBUG] switch_channel.c:2332 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) Callstate Change DOWN -> RINGING 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:644 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State ROUTING 2020-10-06 11:41:43.574620 [DEBUG] mod_sofia.c:154 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com SOFIA ROUTING 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:236 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com Standard ROUTING 2020-10-06 11:41:43.574620 [INFO] mod_dialplan_xml.c:637 Processing 2001 <2001>->5010 in context 3clogic send 460 bytes to udp/[IP1]:5060 at 11:41:43.587321: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP freeswitch-gateway-10x-test.com:5060;branch=z9hG4bKe765.ebe2be53.0;received=IP1 From: ;tag=5d2685b30c0646b585d6f1f4cf613ff5 To: Call-ID: a8076632ec184cfbacfe34a74269c4ae CSeq: 23209 INVITE User-Agent: FreeSWITCH-mod_sofia/1.10.5-release+git~20200818T185121Z~25569c1631~64bit Content-Length: 0 Dialplan: sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com parsing [3clogic->302] continue=false Dialplan: sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com Regex (PASS) [302] destination_number(5010) =~ /^(5010)$/ break=on-false Dialplan: sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com Action bridge(sofia/3clogic_external/5010@IP_5:6060) 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:287 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State Change CS_ROUTING -> CS_EXECUTE 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:644 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State ROUTING going to sleep 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:585 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) Running State Change CS_EXECUTE (Cur 1 Tot 11) 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:651 (sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com) State EXECUTE 2020-10-06 11:41:43.574620 [DEBUG] mod_sofia.c:209 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com SOFIA EXECUTE 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:329 sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com Standard EXECUTE EXECUTE [depth=0] sofia/3clogic_internal/2001@freeswitch-gateway-10x-test.com bridge(sofia/3clogic_external/5010@IP_5:6060) 2020-10-06 11:41:43.574620 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables 2020-10-06 11:41:43.574620 [NOTICE] switch_channel.c:1118 New Channel sofia/3clogic_external/5010@IP_5:6060 [cf769a64-bd16-4d39-b4db-50b5134a78dd] 2020-10-06 11:41:43.574620 [DEBUG] mod_sofia.c:5089 (sofia/3clogic_external/5010@IP_5:6060) State Change CS_NEW -> CS_INIT 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:585 (sofia/3clogic_external/5010@IP_5:6060) Running State Change CS_INIT (Cur 2 Tot 12) 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:628 (sofia/3clogic_external/5010@IP_5:6060) State INIT 2020-10-06 11:41:43.574620 [DEBUG] mod_sofia.c:93 sofia/3clogic_external/5010@IP_5:6060 SOFIA INIT 2020-10-06 11:41:43.574620 [DEBUG] sofia_glue.c:1618 sofia/3clogic_external/5010@IP_5:6060 sending invite version: 1.10.5-release git 25569c1 2020-08-18 18:51:21Z 64bit Local SDP: v=0 o=FreeSWITCH 1601953887 1601953888 IN IP4 IP_2 s=FreeSWITCH c=IN IP4 IP_2 t=0 0 m=audio 30616 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:40 sofia/3clogic_external/5010@IP_5:6060 Standard INIT 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:48 (sofia/3clogic_external/5010@IP_5:6060) State Change CS_INIT -> CS_ROUTING 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:628 (sofia/3clogic_external/5010@IP_5:6060) State INIT going to sleep 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:585 (sofia/3clogic_external/5010@IP_5:6060) Running State Change CS_ROUTING (Cur 2 Tot 12) 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:644 (sofia/3clogic_external/5010@IP_5:6060) State ROUTING 2020-10-06 11:41:43.574620 [DEBUG] mod_sofia.c:154 sofia/3clogic_external/5010@IP_5:6060 SOFIA ROUTING 2020-10-06 11:41:43.574620 [DEBUG] switch_ivr_originate.c:67 (sofia/3clogic_external/5010@IP_5:6060) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:644 (sofia/3clogic_external/5010@IP_5:6060) State ROUTING going to sleep 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:585 (sofia/3clogic_external/5010@IP_5:6060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 12) send 1033 bytes to udp/[IP_5]:6060 at 11:41:43.589096: ------------------------------------------------------------------------ INVITE sip:5010@IP_5:6060 SIP/2.0 Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD Max-Forwards: 68 From: "2001" ;tag=Z4emg8tZm8vBr To: Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.10.5-release+git~20200818T185121Z~25569c1631~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 222 X-FS-Support: update_display,send_info Remote-Party-ID: "2001" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1601953887 1601953888 IN IP4 IP_2 s=FreeSWITCH c=IN IP4 IP_2 t=0 0 m=audio 30616 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 2020-10-06 11:41:43.574620 [DEBUG] sofia.c:7326 Channel sofia/3clogic_external/5010@IP_5:6060 entering state [calling][0] 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:663 (sofia/3clogic_external/5010@IP_5:6060) State CONSUME_MEDIA 2020-10-06 11:41:43.574620 [DEBUG] switch_core_state_machine.c:663 (sofia/3clogic_external/5010@IP_5:6060) State CONSUME_MEDIA going to sleep recv 333 bytes from udp/[IP_5]:6060 at 11:41:43.596653: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD From: "2001" ;tag=Z4emg8tZm8vBr To: ;tag=1 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:41:43.596713: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:41:44.098236: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:41:45.100887: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:41:47.102417: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:41:51.103709: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:41:55.104938: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:41:59.106755: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:42:03.109130: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:42:07.111738: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0 recv 287 bytes from udp/[IP_5]:6060 at 11:42:11.114713: ------------------------------------------------------------------------ SIP/2.0 302 Moved Temporarily Via: SIP/2.0/UDP IP_2:5080;rport;branch=z9hG4bKZggUpN43c84BD To: ;tag=2791SIPpTag011 Call-ID: bf98145b-826b-1239-6d9d-02ca9187de1d CSeq: 26438459 INVITE Contact: <5010@IP_6:5507> Content-Length: 0