2018-05-10 17:23:43.788054 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_NEW (Cur 1 Tot 24)
2018-05-10 17:23:43.788054 [DEBUG] sofia.c:10080 sofia/internal/1003@icc-tech.com:5020 receiving invite from 106.76.206.134:64873 version: 1.9.0 git a139bbd 2018-05-09 16:08:24Z 64bit
2018-05-10 17:23:43.788054 [DEBUG] sofia.c:10251 IP 106.76.206.134 Rejected by acl "domains". Falling back to Digest auth.
2018-05-10 17:23:43.788054 [DEBUG] sofia.c:2413 detaching session a69c7ff7-bb25-45cb-9561-8f54e9819689
2018-05-10 17:23:43.788054 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1003@icc-tech.com:5020) State NEW
2018-05-10 17:23:43.998053 [DEBUG] sofia.c:2522 Re-attaching to session a69c7ff7-bb25-45cb-9561-8f54e9819689
2018-05-10 17:23:44.008064 [DEBUG] sofia.c:10080 sofia/internal/1003@icc-tech.com:5020 receiving invite from 106.76.206.134:64873 version: 1.9.0 git a139bbd 2018-05-09 16:08:24Z 64bit
2018-05-10 17:23:44.008064 [DEBUG] sofia.c:10251 IP 106.76.206.134 Rejected by acl "domains". Falling back to Digest auth.
2018-05-10 17:23:44.008064 [DEBUG] sofia.c:11388 Setting NAT mode based on nat.auto
2018-05-10 17:23:44.008064 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [received][100]
2018-05-10 17:23:44.008064 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=- 1525973020489858 1 IN IP4 100.67.7.149
s=Cpc session
c=IN IP4 100.67.7.149
t=0 0
m=audio 63094 RTP/AVP 120 18 0 8 101
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2018-05-10 17:23:44.008064 [DEBUG] sofia.c:7695 (sofia/internal/1003@icc-tech.com:5020) State Change CS_NEW -> CS_INIT
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_INIT (Cur 1 Tot 24)
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@icc-tech.com:5020) State INIT
2018-05-10 17:23:44.008064 [DEBUG] mod_sofia.c:93 sofia/internal/1003@icc-tech.com:5020 SOFIA INIT
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1003@icc-tech.com:5020 Standard INIT
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1003@icc-tech.com:5020) State Change CS_INIT -> CS_ROUTING
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1003@icc-tech.com:5020) State INIT going to sleep
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_ROUTING (Cur 1 Tot 24)
2018-05-10 17:23:44.008064 [DEBUG] switch_channel.c:2249 (sofia/internal/1003@icc-tech.com:5020) Callstate Change DOWN -> RINGING
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@icc-tech.com:5020) State ROUTING
2018-05-10 17:23:44.008064 [DEBUG] mod_sofia.c:154 sofia/internal/1003@icc-tech.com:5020 SOFIA ROUTING
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1003@icc-tech.com:5020 Standard ROUTING
2018-05-10 17:23:44.008064 [INFO] mod_dialplan_xml.c:637 Processing Brian West <1003>->1000 in context default
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->unloop] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->tod_example] continue=true
Dialplan: sofia/internal/1003@icc-tech.com:5020 Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(open=true)
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->holiday_example] continue=true
Dialplan: sofia/internal/1003@icc-tech.com:5020 Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global-intercept] destination_number(1000) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [group-intercept] destination_number(1000) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [intercept-ext] destination_number(1000) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->redial] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [redial] destination_number(1000) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->global] continue=true
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global] ${default_password}(12345) =~ /^1234$/ break=never
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [global] ${switch_r_sdp}(v=0
o=- 1525973020489858 1 IN IP4 100.67.7.149
s=Cpc session
c=IN IP4 100.67.7.149
t=0 0
m=audio 63094 RTP/AVP 120 18 0 8 101
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
Dialplan: sofia/internal/1003@icc-tech.com:5020 Absolute Condition [global]
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [snom-demo-2] destination_number(1000) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [snom-demo-1] destination_number(1000) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->call_return] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [call_return] destination_number(1000) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->del-group] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [del-group] destination_number(1000) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->add-group] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [add-group] destination_number(1000) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [call-group-simo] destination_number(1000) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [call-group-order] destination_number(1000) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (FAIL) [extension-intercom] destination_number(1000) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Regex (PASS) [Local_Extension] destination_number(1000) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action export(dialed_extension=1000)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bind_meta_app(1 b s execute_extension::dx XML features)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bind_meta_app(3 b s execute_extension::cf XML features)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(ringback=${us-ring})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(call_timeout=30)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(continue_on_fail=true)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action answer()
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action sleep(1000)
Dialplan: sofia/internal/1003@icc-tech.com:5020 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1003@icc-tech.com:5020) State Change CS_ROUTING -> CS_EXECUTE
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1003@icc-tech.com:5020) State ROUTING going to sleep
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1003@icc-tech.com:5020) Running State Change CS_EXECUTE (Cur 1 Tot 24)
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1003@icc-tech.com:5020) State EXECUTE
2018-05-10 17:23:44.008064 [DEBUG] mod_sofia.c:209 sofia/internal/1003@icc-tech.com:5020 SOFIA EXECUTE
2018-05-10 17:23:44.008064 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1003@icc-tech.com:5020 Standard EXECUTE
EXECUTE sofia/internal/1003@icc-tech.com:5020 set(open=true)
2018-05-10 17:23:44.008064 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [open]=[true]
EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-spymap/1003/a69c7ff7-bb25-45cb-9561-8f54e9819689)
EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial/1003/1000)
EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial/global/a69c7ff7-bb25-45cb-9561-8f54e9819689)
EXECUTE sofia/internal/1003@icc-tech.com:5020 export(RFC2822_DATE=Thu, 10 May 2018 17:23:44 +0000)
2018-05-10 17:23:44.008064 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Thu, 10 May 2018 17:23:44 +0000]
EXECUTE sofia/internal/1003@icc-tech.com:5020 export(dialed_extension=1000)
2018-05-10 17:23:44.008064 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1000]
EXECUTE sofia/internal/1003@icc-tech.com:5020 bind_meta_app(1 b s execute_extension::dx XML features)
2018-05-10 17:23:44.008064 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *1 execute_extension::dx XML features
EXECUTE sofia/internal/1003@icc-tech.com:5020 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1003.2018-05-10-17-23-44.wav)
2018-05-10 17:23:44.008064 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1003.2018-05-10-17-23-44.wav
EXECUTE sofia/internal/1003@icc-tech.com:5020 bind_meta_app(3 b s execute_extension::cf XML features)
2018-05-10 17:23:44.008064 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *3 execute_extension::cf XML features
EXECUTE sofia/internal/1003@icc-tech.com:5020 bind_meta_app(4 b s execute_extension::att_xfer XML features)
2018-05-10 17:23:44.008064 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *4 execute_extension::att_xfer XML features
EXECUTE sofia/internal/1003@icc-tech.com:5020 set(ringback=%(2000,4000,440,480))
2018-05-10 17:23:44.008064 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/internal/1003@icc-tech.com:5020 set(transfer_ringback=local_stream://moh)
2018-05-10 17:23:44.008064 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1003@icc-tech.com:5020 set(call_timeout=30)
2018-05-10 17:23:44.008064 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [call_timeout]=[30]
EXECUTE sofia/internal/1003@icc-tech.com:5020 set(hangup_after_bridge=true)
2018-05-10 17:23:44.018016 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1003@icc-tech.com:5020 set(continue_on_fail=true)
2018-05-10 17:23:44.018016 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [continue_on_fail]=[true]
EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-call_return/1000/1003)
EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial_ext/1000/a69c7ff7-bb25-45cb-9561-8f54e9819689)
EXECUTE sofia/internal/1003@icc-tech.com:5020 set(called_party_callgroup=techsupport)
2018-05-10 17:23:44.018016 [DEBUG] mod_dptools.c:1593 SET sofia/internal/1003@icc-tech.com:5020 [called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial_ext/techsupport/a69c7ff7-bb25-45cb-9561-8f54e9819689)
EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial_ext/global/a69c7ff7-bb25-45cb-9561-8f54e9819689)
EXECUTE sofia/internal/1003@icc-tech.com:5020 hash(insert/159.89.163.195-last_dial/techsupport/a69c7ff7-bb25-45cb-9561-8f54e9819689)
EXECUTE sofia/internal/1003@icc-tech.com:5020 bridge(user/1000@159.89.163.195)
2018-05-10 17:23:44.018016 [DEBUG] switch_channel.c:1250 sofia/internal/1003@icc-tech.com:5020 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 10 May 2018 17:23:44 +0000] to event
2018-05-10 17:23:44.018016 [DEBUG] switch_channel.c:1250 sofia/internal/1003@icc-tech.com:5020 EXPORTING[export_vars] [dialed_extension]=[1000] to event
2018-05-10 17:23:44.018016 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
2018-05-10 17:23:44.018016 [DEBUG] switch_channel.c:1250 sofia/internal/1003@icc-tech.com:5020 EXPORTING[export_vars] [RFC2822_DATE]=[Thu, 10 May 2018 17:23:44 +0000] to event
2018-05-10 17:23:44.018016 [DEBUG] switch_channel.c:1250 sofia/internal/1003@icc-tech.com:5020 EXPORTING[export_vars] [dialed_extension]=[1000] to event
2018-05-10 17:23:44.018016 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
2018-05-10 17:23:44.018016 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@124.123.68.233:21102 [774c95cf-5bb0-4424-85db-94818c591c94]
2018-05-10 17:23:44.018016 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@124.123.68.233:21102) State Change CS_NEW -> CS_INIT
2018-05-10 17:23:44.018016 [NOTICE] switch_ivr_originate.c:2868 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_INIT (Cur 2 Tot 25)
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@124.123.68.233:21102) State INIT
2018-05-10 17:23:44.018016 [DEBUG] mod_sofia.c:93 sofia/internal/1000@124.123.68.233:21102 SOFIA INIT
2018-05-10 17:23:44.018016 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@124.123.68.233:21102 sending invite version: 1.9.0 git a139bbd 2018-05-09 16:08:24Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1525942200 1525942201 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 30824 RTP/AVP 102 0 8 103 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@124.123.68.233:21102 Standard INIT
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@124.123.68.233:21102) State Change CS_INIT -> CS_ROUTING
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@124.123.68.233:21102) State INIT going to sleep
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_ROUTING (Cur 2 Tot 25)
2018-05-10 17:23:44.018016 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [calling][0]
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@124.123.68.233:21102) State ROUTING
2018-05-10 17:23:44.018016 [DEBUG] mod_sofia.c:154 sofia/internal/1000@124.123.68.233:21102 SOFIA ROUTING
2018-05-10 17:23:44.018016 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@124.123.68.233:21102) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@124.123.68.233:21102) State ROUTING going to sleep
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 25)
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@124.123.68.233:21102) State CONSUME_MEDIA
2018-05-10 17:23:44.018016 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@124.123.68.233:21102) State CONSUME_MEDIA going to sleep
2018-05-10 17:23:44.518061 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [proceeding][180]
2018-05-10 17:23:44.518061 [NOTICE] sofia.c:7401 Ring-Ready sofia/internal/1000@124.123.68.233:21102!
2018-05-10 17:23:44.518061 [DEBUG] switch_channel.c:3354 (sofia/internal/1000@124.123.68.233:21102) Callstate Change DOWN -> RINGING
2018-05-10 17:23:44.518061 [INFO] switch_ivr_originate.c:1220 Sending early media
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:120:48000:20:0:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
2018-05-10 17:23:44.528018 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps]
2018-05-10 17:23:44.528018 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps]
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:3773 Set Codec sofia/internal/1003@icc-tech.com:5020 opus/48000 20 ms 960 samples 0 bits 1 channels
2018-05-10 17:23:44.528018 [DEBUG] switch_core_codec.c:111 sofia/internal/1003@icc-tech.com:5020 Original read codec set to opus:116
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:5775 sofia/internal/1003@icc-tech.com:5020 Set 2833 dtmf send payload to 101 recv payload to 101
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:8491 AUDIO RTP [sofia/internal/1003@icc-tech.com:5020] 159.89.163.195 port 20540 -> 100.67.7.149 port 63094 codec: 120 ms: 20
2018-05-10 17:23:44.528018 [DEBUG] switch_rtp.c:4277 Starting timer [soft] 960 bytes per 20ms
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:8795 sofia/internal/1003@icc-tech.com:5020 Set 2833 dtmf send payload to 101
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:8802 sofia/internal/1003@icc-tech.com:5020 Set 2833 dtmf receive payload to 101
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:8825 sofia/internal/1003@icc-tech.com:5020 Set rtp dtmf delay to 40
2018-05-10 17:23:44.528018 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1003@icc-tech.com:5020!
2018-05-10 17:23:44.528018 [DEBUG] switch_channel.c:3482 (sofia/internal/1003@icc-tech.com:5020) Callstate Change RINGING -> EARLY
2018-05-10 17:23:44.528018 [DEBUG] switch_core_media.c:8474 Audio params are unchanged for sofia/internal/1003@icc-tech.com:5020.
2018-05-10 17:23:44.528018 [DEBUG] mod_sofia.c:2514 Ring SDP:
v=0
o=FreeSWITCH 1525952484 1525952485 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 20540 RTP/AVP 120 101
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2018-05-10 17:23:44.528018 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [early][183]
2018-05-10 17:23:44.528018 [DEBUG] switch_ivr_originate.c:1278 Raw Codec Activation Success L16@48000hz 1 channel 20ms
2018-05-10 17:23:44.528018 [DEBUG] switch_core_codec.c:223 sofia/internal/1003@icc-tech.com:5020 Push codec L16:100
2018-05-10 17:23:44.528018 [DEBUG] switch_ivr_originate.c:1347 Play Ringback Tone [%(2000,4000,440,480)]
2018-05-10 17:23:44.988075 [INFO] switch_rtp.c:7450 Auto Changing audio port from 100.67.7.149:63094 to 106.76.206.134:63094
2018-05-10 17:23:49.048039 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [completing][200]
2018-05-10 17:23:49.048039 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=- 2158280628 3 IN IP4 10.144.160.39
s=Bria Stretto release 5.2.0 stamp 90726
c=IN IP4 124.123.68.233
t=0 0
m=audio 21107 RTP/AVP 102 0 8 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15

2018-05-10 17:23:49.048039 [NOTICE] sofia.c:7304 Pre-Answer sofia/internal/1000@124.123.68.233:21102!
2018-05-10 17:23:49.048039 [DEBUG] switch_channel.c:3482 (sofia/internal/1000@124.123.68.233:21102) Callstate Change RINGING -> EARLY
2018-05-10 17:23:49.048039 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [ready][200]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:2]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:2]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
2018-05-10 17:23:49.048039 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps]
2018-05-10 17:23:49.048039 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps]
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:3773 Set Codec sofia/internal/1000@124.123.68.233:21102 opus/48000 20 ms 960 samples 0 bits 1 channels
2018-05-10 17:23:49.048039 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@124.123.68.233:21102 Original read codec set to opus:116
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:5775 sofia/internal/1000@124.123.68.233:21102 Set 2833 dtmf send payload to 101 recv payload to 101
2018-05-10 17:23:49.048039 [DEBUG] switch_core_media.c:8491 AUDIO RTP [sofia/internal/1000@124.123.68.233:21102] 159.89.163.195 port 30824 -> 124.123.68.233 port 21107 codec: 102 ms: 20
2018-05-10 17:23:49.048039 [DEBUG] switch_rtp.c:4277 Starting timer [soft] 960 bytes per 20ms
2018-05-10 17:23:49.058013 [DEBUG] switch_core_media.c:8795 sofia/internal/1000@124.123.68.233:21102 Set 2833 dtmf send payload to 101
2018-05-10 17:23:49.058013 [DEBUG] switch_core_media.c:8802 sofia/internal/1000@124.123.68.233:21102 Set 2833 dtmf receive payload to 101
2018-05-10 17:23:49.058013 [DEBUG] switch_core_media.c:8825 sofia/internal/1000@124.123.68.233:21102 Set rtp dtmf delay to 40
2018-05-10 17:23:49.058013 [NOTICE] sofia.c:8429 Channel [sofia/internal/1000@124.123.68.233:21102] has been answered
2018-05-10 17:23:49.058013 [DEBUG] switch_channel.c:3781 (sofia/internal/1000@124.123.68.233:21102) Callstate Change EARLY -> ACTIVE
2018-05-10 17:23:49.068023 [DEBUG] switch_core_codec.c:248 sofia/internal/1003@icc-tech.com:5020 Restore previous codec opus:116.
2018-05-10 17:23:49.068023 [DEBUG] switch_core_media.c:8474 Audio params are unchanged for sofia/internal/1003@icc-tech.com:5020.
2018-05-10 17:23:49.068023 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1003@icc-tech.com:5020:
v=0
o=FreeSWITCH 1525952484 1525952486 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 20540 RTP/AVP 120 101
a=rtpmap:120 opus/48000/2
a=fmtp:120 useinbandfec=1
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv

2018-05-10 17:23:49.068023 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [completed][200]
2018-05-10 17:23:49.068023 [NOTICE] switch_ivr_originate.c:3664 Channel [sofia/internal/1003@icc-tech.com:5020] has been answered
2018-05-10 17:23:49.068023 [DEBUG] switch_channel.c:3781 (sofia/internal/1003@icc-tech.com:5020) Callstate Change EARLY -> ACTIVE
2018-05-10 17:23:49.068023 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1000@124.123.68.233:21102]
2018-05-10 17:23:49.068023 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1000@124.123.68.233:21102]
2018-05-10 17:23:49.068023 [DEBUG] switch_ivr_bridge.c:1744 (sofia/internal/1000@124.123.68.233:21102) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2018-05-10 17:23:49.068023 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@124.123.68.233:21102) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 25)
2018-05-10 17:23:49.068023 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1000@124.123.68.233:21102) State EXCHANGE_MEDIA
2018-05-10 17:23:49.068023 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
2018-05-10 17:23:49.108064 [DEBUG] switch_rtp.c:7490 Correct audio ip/port confirmed.
2018-05-10 17:23:49.108064 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2018-05-10 17:23:49.108064 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2018-05-10 17:23:49.108064 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps]
2018-05-10 17:23:49.128022 [DEBUG] switch_rtp.c:7490 Correct audio ip/port confirmed.
2018-05-10 17:23:49.128022 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2018-05-10 17:23:49.128022 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0]
2018-05-10 17:23:49.128022 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [72000bps]
2018-05-10 17:23:49.248018 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [ready][200]
2018-05-10 17:23:57.478022 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [received][100]
2018-05-10 17:23:57.478022 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=- 2158280628 4 IN IP4 10.144.160.39
s=Bria Stretto release 5.2.0 stamp 90726
c=IN IP4 124.123.68.233
t=0 0
m=audio 21107 RTP/AVP 102 0 8 101 9 18
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=yes
m=video 21108 RTP/AVP 127 126 100
a=rtpmap:127 H264/90000
a=fmtp:127 profile-level-id=428016;packetization-mode=0
a=rtpmap:126 H264/90000
a=fmtp:126 profile-level-id=428016;packetization-mode=1
a=rtpmap:100 VP8/90000
a=rtcp-fb:* nack
a=rtcp-fb:* nack pli

2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:5775 sofia/internal/1000@124.123.68.233:21102 Set 2833 dtmf send payload to 101 recv payload to 101
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:6058 Video Codec Compare [H264:127]/[VP8:99]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:6058 Video Codec Compare [H264:126]/[VP8:99]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:6058 Video Codec Compare [VP8:100]/[VP8:99]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:6090 Video Codec Compare [VP8:100] +++ is saved as a match
2018-05-10 17:23:57.478022 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-05-10 17:23:57.478022 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:3583 Set VIDEO Codec sofia/internal/1000@124.123.68.233:21102 VP8/90000 0 ms
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:8474 Audio params are unchanged for sofia/internal/1000@124.123.68.233:21102.
2018-05-10 17:23:57.478022 [DEBUG] switch_rtp.c:4292 Starting video timer.
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:9320 VIDEO RTP [sofia/internal/1000@124.123.68.233:21102] 159.89.163.195:24688->124.123.68.233:21108 codec: 100 ms: 0 [SUCCESS]
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:7483 sofia/internal/1000@124.123.68.233:21102 Starting Video thread
2018-05-10 17:23:57.478022 [DEBUG] switch_core_media.c:7349 sofia/internal/1000@124.123.68.233:21102 Video thread started. Echo is off
2018-05-10 17:23:57.478022 [INFO] switch_core_media.c:9400 Activating VIDEO RTCP PORT 21109 interval 1000 mux -1
2018-05-10 17:23:57.478022 [DEBUG] switch_rtp.c:4673 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 21109
2018-05-10 17:23:57.478022 [DEBUG] switch_rtp.c:2568 Setting RTCP remote addr to 124.123.68.233:21109 2
2018-05-10 17:23:57.478022 [DEBUG] sofia.c:8208 Processing updated SDP
2018-05-10 17:23:57.488065 [DEBUG] sofia_glue.c:1299 sofia/internal/1003@icc-tech.com:5020 sending invite version: 1.9.0 git a139bbd 2018-05-09 16:08:24Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1525952484 1525952488 IN IP4 159.89.163.195
s=FreeSWITCH
c=IN IP4 159.89.163.195
t=0 0
m=audio 20540 RTP/AVP 102 9 0 8 103 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:103 telephone-event/48000
a=fmtp:103 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 26228 RTP/AVP 100
b=AS:1024
a=rtpmap:100 VP8/90000
a=sendrecv
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 ccm tmmbr
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli

2018-05-10 17:23:57.488065 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [calling][0]
2018-05-10 17:23:57.588056 [NOTICE] switch_vpx.c:410 VPX reset encoder picture from 320x240 to 352x288 1024 BW
2018-05-10 17:23:57.828056 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [completing][200]
2018-05-10 17:23:57.828056 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=- 1525973020489858 2 IN IP4 100.67.7.149
s=Cpc session
c=IN IP4 100.67.7.149
t=0 0
m=audio 63094 RTP/AVP 102 0 8 101
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=sendrecv
m=video 52762 RTP/AVP 100
a=rtpmap:100 VP8/90000
a=sendrecv
a=rtcp-fb:* nack
a=rtcp-fb:* nack pli

2018-05-10 17:23:57.828056 [DEBUG] sofia.c:7291 Channel sofia/internal/1003@icc-tech.com:5020 entering state [ready][200]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:2]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:2]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5458 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5513 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5374 Set telephone-event payload to 101@8000
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:5775 sofia/internal/1003@icc-tech.com:5020 Set 2833 dtmf send payload to 101 recv payload to 101
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:6058 Video Codec Compare [VP8:100]/[VP8:99]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:6090 Video Codec Compare [VP8:100] +++ is saved as a match
2018-05-10 17:23:57.828056 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-05-10 17:23:57.828056 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:3583 Set VIDEO Codec sofia/internal/1003@icc-tech.com:5020 VP8/90000 0 ms
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:8474 Audio params are unchanged for sofia/internal/1003@icc-tech.com:5020.
2018-05-10 17:23:57.828056 [DEBUG] switch_rtp.c:4292 Starting video timer.
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:9320 VIDEO RTP [sofia/internal/1003@icc-tech.com:5020] 159.89.163.195:26228->100.67.7.149:52762 codec: 100 ms: 0 [SUCCESS]
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:7483 sofia/internal/1003@icc-tech.com:5020 Starting Video thread
2018-05-10 17:23:57.828056 [DEBUG] switch_core_media.c:7349 sofia/internal/1003@icc-tech.com:5020 Video thread started. Echo is off
2018-05-10 17:23:57.828056 [INFO] switch_core_media.c:9400 Activating VIDEO RTCP PORT 52763 interval 1000 mux -1
2018-05-10 17:23:57.828056 [DEBUG] switch_rtp.c:4673 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 52763
2018-05-10 17:23:57.828056 [DEBUG] switch_rtp.c:2568 Setting RTCP remote addr to 100.67.7.149:52763 2
2018-05-10 17:23:57.828056 [INFO] switch_rtp.c:6909 Auto Changing video RTCP port from 100.67.7.149:52763 to 106.76.206.134:52763
2018-05-10 17:23:57.828056 [DEBUG] switch_rtp.c:2568 Setting RTCP remote addr to 106.76.206.134:52763 2
2018-05-10 17:23:57.838269 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [completed][200]
2018-05-10 17:23:57.868044 [DEBUG] sofia.c:7291 Channel sofia/internal/1000@124.123.68.233:21102 entering state [ready][200]
2018-05-10 17:23:57.958031 [DEBUG] switch_rtp.c:6930 Correct video RTCP ip/port confirmed.
2018-05-10 17:23:58.108038 [DEBUG] switch_rtp.c:1886 rtcp_stats_init: video ssrc[1151926955] base_seq[8960]
2018-05-10 17:23:58.158033 [DEBUG] switch_rtp.c:7490 Correct video ip/port confirmed.