freeswitch@freeswitch> reloadxml
+OK [Success]

2017-05-09 13:48:15.073884 [INFO] mod_enum.c:879 ENUM Reloaded
2017-05-09 13:48:15.073884 [INFO] switch_time.c:1423 Timezone reloaded 1750 definitions
2017-05-09 13:48:27.024025 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1010@192.168.1.8 [16fdbe28-5f95-40da-9e47-5c9031bfcc9b]
2017-05-09 13:48:27.024025 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_NEW (Cur 1 Tot 23)
2017-05-09 13:48:27.024025 [DEBUG] sofia.c:9834 sofia/internal/1010@192.168.1.8 receiving invite from 192.168.1.213:5060 version: 1.6.17 -34-0fc0946 64bit
2017-05-09 13:48:27.024025 [DEBUG] sofia.c:10005 IP 192.168.1.213 Rejected by acl "domains". Falling back to Digest auth.
2017-05-09 13:48:27.024025 [DEBUG] sofia.c:2334 detaching session 16fdbe28-5f95-40da-9e47-5c9031bfcc9b
2017-05-09 13:48:27.024025 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1010@192.168.1.8) State NEW
2017-05-09 13:48:27.024025 [DEBUG] sofia.c:2442 Re-attaching to session 16fdbe28-5f95-40da-9e47-5c9031bfcc9b
2017-05-09 13:48:27.043538 [DEBUG] sofia.c:9834 sofia/internal/1010@192.168.1.8 receiving invite from 192.168.1.213:5060 version: 1.6.17 -34-0fc0946 64bit
2017-05-09 13:48:27.043538 [DEBUG] sofia.c:10005 IP 192.168.1.213 Rejected by acl "domains". Falling back to Digest auth.
2017-05-09 13:48:27.043538 [DEBUG] sofia.c:7048 Channel sofia/internal/1010@192.168.1.8 entering state [received][100]
2017-05-09 13:48:27.043538 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=1010 8000 8001 IN IP4 192.168.1.213
s=SIP Call
c=IN IP4 192.168.1.213
t=0 0
m=audio 5004 RTP/AVP 0 8 4 18 3 2
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=rtpmap:3 GSM/8000
a=rtpmap:2 G726-32/8000
a=ptime:20
m=video 5006 RTP/AVP 99 34 103
a=rtpmap:99 H264/90000
a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=2 MaxBR=1280
a=rtpmap:103 H263-1998/90000
a=fmtp:103 CIF=2 MaxBR=1280
a=framerate:15

2017-05-09 13:48:27.043538 [DEBUG] sofia.c:7450 (sofia/internal/1010@192.168.1.8) State Change CS_NEW -> CS_INIT
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_INIT (Cur 1 Tot 23)
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1010@192.168.1.8) State INIT
2017-05-09 13:48:27.043538 [DEBUG] mod_sofia.c:90 sofia/internal/1010@192.168.1.8 SOFIA INIT
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1010@192.168.1.8 Standard INIT
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1010@192.168.1.8) State Change CS_INIT -> CS_ROUTING
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1010@192.168.1.8) State INIT going to sleep
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_ROUTING (Cur 1 Tot 23)
2017-05-09 13:48:27.043538 [DEBUG] switch_channel.c:2249 (sofia/internal/1010@192.168.1.8) Callstate Change DOWN -> RINGING
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1010@192.168.1.8) State ROUTING
2017-05-09 13:48:27.043538 [DEBUG] mod_sofia.c:143 sofia/internal/1010@192.168.1.8 SOFIA ROUTING
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1010@192.168.1.8 Standard ROUTING
2017-05-09 13:48:27.043538 [INFO] mod_dialplan_xml.c:637 Processing 1010 <1010>->1001 in context default
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->unloop] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->tod_example] continue=true
Dialplan: sofia/internal/1010@192.168.1.8 Date/Time Match (PASS) [tod_example] break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 Action set(open=true)
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->holiday_example] continue=true
Dialplan: sofia/internal/1010@192.168.1.8 Date/TimeMatch (FAIL) [holiday_example] break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->global-intercept] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [global-intercept] destination_number(1001) =~ /^886$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->group-intercept] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [group-intercept] destination_number(1001) =~ /^\*8$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->intercept-ext] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [intercept-ext] destination_number(1001) =~ /^\*\*(\d+)$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->redial] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|870)$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->global] continue=true
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [global] ${default_password}(12345) =~ /^1234$/ break=never
Dialplan: sofia/internal/1010@192.168.1.8 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/1010@192.168.1.8 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [global] ${switch_r_sdp}(v=0
o=1010 8000 8001 IN IP4 192.168.1.213
s=SIP Call
c=IN IP4 192.168.1.213
t=0 0
m=audio 5004 RTP/AVP 0 8 4 18 3 2
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:4 G723/8000
a=rtpmap:18 G729/8000
a=rtpmap:3 GSM/8000
a=rtpmap:2 G726-32/8000
a=ptime:20
m=video 5006 RTP/AVP 99 34 103
a=rtpmap:99 H264/90000
a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==
a=rtpmap:34 H263/90000
a=fmtp:34 CIF=2 MaxBR=1280
a=rtpmap:103 H263-1998/90000
a=fmtp:103 CIF=2 MaxBR=1280
a=framerate:15
) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
Dialplan: sofia/internal/1010@192.168.1.8 Absolute Condition [global]
Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial/global/${uuid})
Dialplan: sofia/internal/1010@192.168.1.8 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->snom-demo-2] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [snom-demo-2] destination_number(1001) =~ /^9001$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->snom-demo-1] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [snom-demo-1] destination_number(1001) =~ /^9000$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->eavesdrop] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [eavesdrop] destination_number(1001) =~ /^779$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->call_return] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [call_return] destination_number(1001) =~ /^\*69$|^869$|^lcr$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->del-group] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [del-group] destination_number(1001) =~ /^80(\d{2})$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->add-group] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [add-group] destination_number(1001) =~ /^81(\d{2})$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->call-group-simo] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [call-group-simo] destination_number(1001) =~ /^82(\d{2})$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->call-group-order] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [call-group-order] destination_number(1001) =~ /^83(\d{2})$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->extension-intercom] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (FAIL) [extension-intercom] destination_number(1001) =~ /^8(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 parsing [default->Local_Extension] continue=false
Dialplan: sofia/internal/1010@192.168.1.8 Regex (PASS) [Local_Extension] destination_number(1001) =~ /^(10[01][0-9])$/ break=on-false
Dialplan: sofia/internal/1010@192.168.1.8 Action export(dialed_extension=1001)
Dialplan: sofia/internal/1010@192.168.1.8 Action bind_meta_app(1 b s execute_extension::dx XML features)
Dialplan: sofia/internal/1010@192.168.1.8 Action bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
Dialplan: sofia/internal/1010@192.168.1.8 Action bind_meta_app(3 b s execute_extension::cf XML features)
Dialplan: sofia/internal/1010@192.168.1.8 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
Dialplan: sofia/internal/1010@192.168.1.8 Action set(ringback=${us-ring})
Dialplan: sofia/internal/1010@192.168.1.8 Action set(transfer_ringback=local_stream://moh)
Dialplan: sofia/internal/1010@192.168.1.8 Action set(call_timeout=30)
Dialplan: sofia/internal/1010@192.168.1.8 Action set(hangup_after_bridge=true)
Dialplan: sofia/internal/1010@192.168.1.8 Action set(continue_on_fail=true)
Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
Dialplan: sofia/internal/1010@192.168.1.8 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
Dialplan: sofia/internal/1010@192.168.1.8 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
Dialplan: sofia/internal/1010@192.168.1.8 Action bridge(user/${dialed_extension}@${domain_name})
Dialplan: sofia/internal/1010@192.168.1.8 Action answer()
Dialplan: sofia/internal/1010@192.168.1.8 Action sleep(1000)
Dialplan: sofia/internal/1010@192.168.1.8 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1010@192.168.1.8) State Change CS_ROUTING -> CS_EXECUTE
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1010@192.168.1.8) State ROUTING going to sleep
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_EXECUTE (Cur 1 Tot 23)
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1010@192.168.1.8) State EXECUTE
2017-05-09 13:48:27.043538 [DEBUG] mod_sofia.c:198 sofia/internal/1010@192.168.1.8 SOFIA EXECUTE
2017-05-09 13:48:27.043538 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1010@192.168.1.8 Standard EXECUTE
EXECUTE sofia/internal/1010@192.168.1.8 set(open=true)
2017-05-09 13:48:27.043538 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [open]=[true]
EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-spymap/1010/16fdbe28-5f95-40da-9e47-5c9031bfcc9b)
EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial/1010/1001)
EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial/global/16fdbe28-5f95-40da-9e47-5c9031bfcc9b)
EXECUTE sofia/internal/1010@192.168.1.8 export(RFC2822_DATE=Tue, 09 May 2017 13:48:27 -0400)
2017-05-09 13:48:27.043538 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Tue, 09 May 2017 13:48:27 -0400]
EXECUTE sofia/internal/1010@192.168.1.8 export(dialed_extension=1001)
2017-05-09 13:48:27.043538 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1001]
EXECUTE sofia/internal/1010@192.168.1.8 bind_meta_app(1 b s execute_extension::dx XML features)
2017-05-09 13:48:27.043538 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *1 execute_extension::dx XML features
EXECUTE sofia/internal/1010@192.168.1.8 bind_meta_app(2 b s record_session::/var/lib/freeswitch/recordings/1010.2017-05-09-13-48-27.wav)
2017-05-09 13:48:27.043538 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *2 record_session::/var/lib/freeswitch/recordings/1010.2017-05-09-13-48-27.wav
EXECUTE sofia/internal/1010@192.168.1.8 bind_meta_app(3 b s execute_extension::cf XML features)
2017-05-09 13:48:27.043538 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *3 execute_extension::cf XML features
EXECUTE sofia/internal/1010@192.168.1.8 bind_meta_app(4 b s execute_extension::att_xfer XML features)
2017-05-09 13:48:27.043538 [INFO] switch_ivr_async.c:4171 Bound B-Leg: *4 execute_extension::att_xfer XML features
EXECUTE sofia/internal/1010@192.168.1.8 set(ringback=%(2000,4000,440,480))
2017-05-09 13:48:27.043538 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [ringback]=[%(2000,4000,440,480)]
EXECUTE sofia/internal/1010@192.168.1.8 set(transfer_ringback=local_stream://moh)
2017-05-09 13:48:27.043538 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [transfer_ringback]=[local_stream://moh]
EXECUTE sofia/internal/1010@192.168.1.8 set(call_timeout=30)
2017-05-09 13:48:27.043538 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [call_timeout]=[30]
EXECUTE sofia/internal/1010@192.168.1.8 set(hangup_after_bridge=true)
2017-05-09 13:48:27.043538 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [hangup_after_bridge]=[true]
EXECUTE sofia/internal/1010@192.168.1.8 set(continue_on_fail=true)
2017-05-09 13:48:27.043538 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [continue_on_fail]=[true]
EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-call_return/1001/1010)
EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial_ext/1001/16fdbe28-5f95-40da-9e47-5c9031bfcc9b)
EXECUTE sofia/internal/1010@192.168.1.8 set(called_party_callgroup=techsupport)
2017-05-09 13:48:27.043538 [DEBUG] mod_dptools.c:1530 SET sofia/internal/1010@192.168.1.8 [called_party_callgroup]=[techsupport]
EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial_ext/techsupport/16fdbe28-5f95-40da-9e47-5c9031bfcc9b)
EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial_ext/global/16fdbe28-5f95-40da-9e47-5c9031bfcc9b)
EXECUTE sofia/internal/1010@192.168.1.8 hash(insert/192.168.1.8-last_dial/techsupport/16fdbe28-5f95-40da-9e47-5c9031bfcc9b)
EXECUTE sofia/internal/1010@192.168.1.8 bridge(user/1001@192.168.1.8)
2017-05-09 13:48:27.053886 [DEBUG] switch_channel.c:1250 sofia/internal/1010@192.168.1.8 EXPORTING[export_vars] [RFC2822_DATE]=[Tue, 09 May 2017 13:48:27 -0400] to event
2017-05-09 13:48:27.053886 [DEBUG] switch_channel.c:1250 sofia/internal/1010@192.168.1.8 EXPORTING[export_vars] [dialed_extension]=[1001] to event
2017-05-09 13:48:27.053886 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-05-09 13:48:27.053886 [DEBUG] switch_channel.c:1250 sofia/internal/1010@192.168.1.8 EXPORTING[export_vars] [RFC2822_DATE]=[Tue, 09 May 2017 13:48:27 -0400] to event
2017-05-09 13:48:27.053886 [DEBUG] switch_channel.c:1250 sofia/internal/1010@192.168.1.8 EXPORTING[export_vars] [dialed_extension]=[1001] to event
2017-05-09 13:48:27.053886 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-05-09 13:48:27.053886 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@192.168.1.161:5060 [50182918-2e6f-4864-9d4a-bc5d764199e2]
2017-05-09 13:48:27.053886 [DEBUG] mod_sofia.c:4818 (sofia/internal/1001@192.168.1.161:5060) State Change CS_NEW -> CS_INIT
2017-05-09 13:48:27.053886 [NOTICE] switch_ivr_originate.c:2845 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_INIT (Cur 2 Tot 24)
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.1.161:5060) State INIT
2017-05-09 13:48:27.053886 [DEBUG] mod_sofia.c:90 sofia/internal/1001@192.168.1.161:5060 SOFIA INIT
2017-05-09 13:48:27.053886 [DEBUG] sofia_glue.c:1295 sofia/internal/1001@192.168.1.161:5060 sending invite version: 1.6.17 -34-0fc0946 64bit
Local SDP:
v=0
o=FreeSWITCH 1494330285 1494330286 IN IP4 192.168.1.8
s=FreeSWITCH
c=IN IP4 192.168.1.8
t=0 0
m=audio 21822 RTP/AVP 0 8 102 9 101 106
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:102 opus/48000/2
a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:106 telephone-event/48000
a=fmtp:106 0-16
a=ptime:20
a=sendrecv
m=video 28818 RTP/AVP 103 34 104 105
b=AS:1024
a=rtpmap:103 H264/90000
a=rtpmap:34 H263/90000
a=rtpmap:104 VP8/90000
a=rtpmap:105 H264/90000
a=rtcp-fb:103 ccm fir
a=rtcp-fb:103 ccm tmmbr
a=rtcp-fb:103 nack
a=rtcp-fb:103 nack pli
a=rtcp-fb:34 ccm fir
a=rtcp-fb:34 ccm tmmbr
a=rtcp-fb:34 nack
a=rtcp-fb:34 nack pli
a=rtcp-fb:104 ccm fir
a=rtcp-fb:104 ccm tmmbr
a=rtcp-fb:104 nack
a=rtcp-fb:104 nack pli
a=rtcp-fb:105 ccm fir
a=rtcp-fb:105 ccm tmmbr
a=rtcp-fb:105 nack
a=rtcp-fb:105 nack pli

2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.1.161:5060 Standard INIT
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.1.161:5060) State Change CS_INIT -> CS_ROUTING
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.1.161:5060) State INIT going to sleep
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_ROUTING (Cur 2 Tot 24)
2017-05-09 13:48:27.053886 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@192.168.1.161:5060 entering state [calling][0]
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.1.161:5060) State ROUTING
2017-05-09 13:48:27.053886 [DEBUG] mod_sofia.c:143 sofia/internal/1001@192.168.1.161:5060 SOFIA ROUTING
2017-05-09 13:48:27.053886 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1001@192.168.1.161:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.1.161:5060) State ROUTING going to sleep
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 24)
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@192.168.1.161:5060) State CONSUME_MEDIA
2017-05-09 13:48:27.053886 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1001@192.168.1.161:5060) State CONSUME_MEDIA going to sleep
2017-05-09 13:48:27.053886 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@192.168.1.161:5060 entering state [proceeding][180]
2017-05-09 13:48:27.053886 [NOTICE] sofia.c:7156 Ring-Ready sofia/internal/1001@192.168.1.161:5060!
2017-05-09 13:48:27.053886 [DEBUG] switch_channel.c:3345 (sofia/internal/1001@192.168.1.161:5060) Callstate Change DOWN -> RINGING
2017-05-09 13:48:27.073601 [INFO] switch_ivr_originate.c:1215 Sending early media
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G723:4:8000:20:6300:1]/[opus:116:48000:20:0:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G723:4:8000:20:6300:1]/[G722:9:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMU:0:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G723:4:8000:20:6300:1]/[PCMA:8:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-32:2:8000:20:0:1]/[opus:116:48000:20:0:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-32:2:8000:20:0:1]/[G722:9:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/1010@192.168.1.8 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-05-09 13:48:27.073601 [DEBUG] switch_core_codec.c:111 sofia/internal/1010@192.168.1.8 Original read codec set to PCMU:0
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4725 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4754 sofia/internal/1010@192.168.1.8 Set 2833 dtmf send payload to 101 recv payload to 101
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:99]/[VP8:99]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:99]/[H264:99]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4969 Video Codec Compare [H264:99] +++ is saved as a match
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H264:99]/[H263:34]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263:34]/[VP8:99]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263:34]/[H264:99]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263:34]/[H263:34]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4969 Video Codec Compare [H263:34] +++ is saved as a match
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[VP8:99]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H264:99]
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H263:34]
2017-05-09 13:48:27.073601 [NOTICE] avcodec.c:1011 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2017-05-09 13:48:27.073601 [NOTICE] avcodec.c:1011 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:2866 Set VIDEO Codec sofia/internal/1010@192.168.1.8 H264/90000 0 ms
2017-05-09 13:48:27.073601 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/1010@192.168.1.8] 192.168.1.8 port 24328 -> 192.168.1.213 port 5004 codec: 0 ms: 20
2017-05-09 13:48:27.073601 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
2017-05-09 13:48:27.083711 [DEBUG] switch_core_media.c:7166 sofia/internal/1010@192.168.1.8 Set 2833 dtmf send payload to 101
2017-05-09 13:48:27.083711 [DEBUG] switch_core_media.c:7173 sofia/internal/1010@192.168.1.8 Set 2833 dtmf receive payload to 101
2017-05-09 13:48:27.083711 [DEBUG] switch_core_media.c:7196 sofia/internal/1010@192.168.1.8 Set rtp dtmf delay to 40
2017-05-09 13:48:27.083711 [DEBUG] switch_rtp.c:4107 Starting video timer.
2017-05-09 13:48:27.083711 [DEBUG] switch_core_media.c:7385 VIDEO RTP [sofia/internal/1010@192.168.1.8] 192.168.1.8:25674->192.168.1.213:5006 codec: 99 ms: 0 [SUCCESS]
2017-05-09 13:48:27.083711 [DEBUG] switch_core_media.c:5990 sofia/internal/1010@192.168.1.8 Starting Video thread
2017-05-09 13:48:27.083711 [DEBUG] switch_core_media.c:5856 sofia/internal/1010@192.168.1.8 Video thread started. Echo is off
2017-05-09 13:48:27.083711 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1010@192.168.1.8!
2017-05-09 13:48:27.083711 [DEBUG] switch_channel.c:3473 (sofia/internal/1010@192.168.1.8) Callstate Change RINGING -> EARLY
2017-05-09 13:48:27.083711 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/1010@192.168.1.8.
2017-05-09 13:48:27.083711 [DEBUG] switch_core_media.c:7243 Video params are unchanged for sofia/internal/1010@192.168.1.8.
2017-05-09 13:48:27.083711 [DEBUG] mod_sofia.c:2363 Ring SDP:
v=0
o=FreeSWITCH 1494327779 1494327780 IN IP4 192.168.1.8
s=FreeSWITCH
c=IN IP4 192.168.1.8
t=0 0
m=audio 24328 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 25674 RTP/AVP 99
b=AS:1024
a=rtpmap:99 H264/90000
a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==

2017-05-09 13:48:27.083711 [DEBUG] sofia.c:7048 Channel sofia/internal/1010@192.168.1.8 entering state [early][183]
2017-05-09 13:48:27.083711 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2017-05-09 13:48:27.083711 [DEBUG] switch_core_codec.c:223 sofia/internal/1010@192.168.1.8 Push codec L16:100
2017-05-09 13:48:27.083711 [DEBUG] switch_ivr_originate.c:1342 Play Ringback Tone [%(2000,4000,440,480)]
2017-05-09 13:48:27.103734 [INFO] avcodec.c:1069 initializing encoder 352x288
2017-05-09 13:48:27.103734 [DEBUG] avcodec.c:831 NVENC HW CODEC NOT PRESENT
2017-05-09 13:48:27.133549 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
2017-05-09 13:48:27.723545 [DEBUG] switch_rtp.c:7229 Correct video ip/port confirmed.
2017-05-09 13:48:29.124312 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@192.168.1.161:5060 entering state [completing][200]
2017-05-09 13:48:29.124312 [DEBUG] sofia.c:7058 Remote SDP:
v=0
o=1001 8000 8000 IN IP4 192.168.1.161
s=SIP Call
c=IN IP4 192.168.1.161
t=0 0
m=audio 5004 RTP/AVP 0
a=rtpmap:0 PCMU/8000
a=ptime:20
m=video 5006 RTP/AVP 103
a=rtpmap:103 H263-1998/90000
a=fmtp:103 CIF=2 MaxBR=1280
a=framerate:15

2017-05-09 13:48:29.124312 [DEBUG] sofia.c:7048 Channel sofia/internal/1001@192.168.1.161:5060 entering state [ready][200]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4491 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4436 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:3056 Set Codec sofia/internal/1001@192.168.1.161:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2017-05-09 13:48:29.124312 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@192.168.1.161:5060 Original read codec set to PCMU:0
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4725 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4754 sofia/internal/1001@192.168.1.161:5060 Set 2833 dtmf send payload to 101 recv payload to 101
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H264:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H263:34]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[VP8:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H264:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H263:34]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4980 No matches with FTMP, fallback to ignoring FMTP
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H264:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H263:34]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[VP8:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H264:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H263:34]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4988 No matches with inherit_codec, fallback to ignoring PT
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H264:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H263:34]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[VP8:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H264:99]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:4937 Video Codec Compare [H263-1998:103]/[H263:34]
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:6865 AUDIO RTP [sofia/internal/1001@192.168.1.161:5060] 192.168.1.8 port 21822 -> 192.168.1.161 port 5004 codec: 0 ms: 20
2017-05-09 13:48:29.124312 [DEBUG] switch_rtp.c:4096 Starting timer [soft] 160 bytes per 20ms
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:7166 sofia/internal/1001@192.168.1.161:5060 Set 2833 dtmf send payload to 101
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:7173 sofia/internal/1001@192.168.1.161:5060 Set 2833 dtmf receive payload to 101
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:7196 sofia/internal/1001@192.168.1.161:5060 Set rtp dtmf delay to 40
2017-05-09 13:48:29.124312 [NOTICE] sofia.c:8182 Channel [sofia/internal/1001@192.168.1.161:5060] has been answered
2017-05-09 13:48:29.124312 [DEBUG] switch_channel.c:3772 (sofia/internal/1001@192.168.1.161:5060) Callstate Change RINGING -> ACTIVE
2017-05-09 13:48:29.124312 [DEBUG] switch_core_codec.c:248 sofia/internal/1010@192.168.1.8 Restore previous codec PCMU:0.
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:6848 Audio params are unchanged for sofia/internal/1010@192.168.1.8.
2017-05-09 13:48:29.124312 [DEBUG] switch_core_media.c:7243 Video params are unchanged for sofia/internal/1010@192.168.1.8.
2017-05-09 13:48:29.124312 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/1010@192.168.1.8:
v=0
o=FreeSWITCH 1494327779 1494327781 IN IP4 192.168.1.8
s=FreeSWITCH
c=IN IP4 192.168.1.8
t=0 0
m=audio 24328 RTP/AVP 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 25674 RTP/AVP 99
b=AS:1024
a=rtpmap:99 H264/90000
a=fmtp:99 profile-level-id=428014; packetization-mode=0; sprop-parameter-sets=Z0KADJWgUH5A,aM4Ecn==

2017-05-09 13:48:29.143816 [DEBUG] sofia.c:7048 Channel sofia/internal/1010@192.168.1.8 entering state [completed][200]
2017-05-09 13:48:29.143816 [NOTICE] switch_ivr_originate.c:3632 Channel [sofia/internal/1010@192.168.1.8] has been answered
2017-05-09 13:48:29.143816 [DEBUG] switch_channel.c:3772 (sofia/internal/1010@192.168.1.8) Callstate Change EARLY -> ACTIVE
2017-05-09 13:48:29.143816 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/1001@192.168.1.161:5060]
2017-05-09 13:48:29.143816 [DEBUG] switch_ivr_originate.c:3690 Originate Resulted in Success: [sofia/internal/1001@192.168.1.161:5060]
2017-05-09 13:48:29.143816 [DEBUG] switch_ivr_bridge.c:1601 (sofia/internal/1001@192.168.1.161:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2017-05-09 13:48:29.143816 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 24)
2017-05-09 13:48:29.143816 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1001@192.168.1.161:5060) State EXCHANGE_MEDIA
2017-05-09 13:48:29.143816 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
2017-05-09 13:48:29.143816 [DEBUG] sofia.c:7048 Channel sofia/internal/1010@192.168.1.8 entering state [ready][200]
2017-05-09 13:48:29.163669 [DEBUG] switch_rtp.c:7229 Correct video ip/port confirmed.
2017-05-09 13:48:29.183668 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
2017-05-09 13:48:29.193675 [DEBUG] switch_rtp.c:7229 Correct audio ip/port confirmed.
2017-05-09 13:48:42.553933 [NOTICE] sofia.c:1012 Hangup sofia/internal/1010@192.168.1.8 [CS_EXECUTE] [NORMAL_CLEARING]
2017-05-09 13:48:42.553933 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/1010@192.168.1.8]
2017-05-09 13:48:42.553933 [DEBUG] switch_core_media.c:11605 sofia/internal/1010@192.168.1.8 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already)
2017-05-09 13:48:42.553933 [DEBUG] switch_core_media.c:5957 sofia/internal/1010@192.168.1.8 Video thread ended
2017-05-09 13:48:42.553933 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/1010@192.168.1.8 ending bridge by request from write function
2017-05-09 13:48:42.553933 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/1001@192.168.1.161:5060]
2017-05-09 13:48:42.553933 [NOTICE] switch_ivr_bridge.c:891 Hangup sofia/internal/1001@192.168.1.161:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2017-05-09 13:48:42.553933 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1001@192.168.1.161:5060) State EXCHANGE_MEDIA going to sleep
2017-05-09 13:48:42.553933 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_HANGUP (Cur 2 Tot 24)
2017-05-09 13:48:42.553933 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1001@192.168.1.161:5060) Callstate Change ACTIVE -> HANGUP
2017-05-09 13:48:42.553933 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.1.161:5060) State HANGUP
2017-05-09 13:48:42.553933 [DEBUG] mod_sofia.c:432 sofia/internal/1001@192.168.1.161:5060 Overriding SIP cause 480 with 200 from the other leg
2017-05-09 13:48:42.553933 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1001@192.168.1.161:5060 hanging up, cause: NORMAL_CLEARING
2017-05-09 13:48:42.553933 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/1001@192.168.1.161:5060
2017-05-09 13:48:42.553933 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@192.168.1.161:5060 Standard HANGUP, cause: NORMAL_CLEARING
2017-05-09 13:48:42.553933 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.1.161:5060) State HANGUP going to sleep
2017-05-09 13:48:42.553933 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1001@192.168.1.161:5060) State Change CS_HANGUP -> CS_REPORTING
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_REPORTING (Cur 2 Tot 24)
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.1.161:5060) State REPORTING
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1001@192.168.1.161:5060 Standard REPORTING, cause: NORMAL_CLEARING
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.1.161:5060) State REPORTING going to sleep
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1001@192.168.1.161:5060) State Change CS_REPORTING -> CS_DESTROY
2017-05-09 13:48:42.574166 [DEBUG] switch_core_session.c:1664 Session 24 (sofia/internal/1001@192.168.1.161:5060) Locked, Waiting on external entities
2017-05-09 13:48:42.574166 [DEBUG] switch_ivr_bridge.c:1702 sofia/internal/1010@192.168.1.8 skip receive message [UNBRIDGE] (channel is hungup already)
2017-05-09 13:48:42.574166 [DEBUG] switch_core_session.c:2814 sofia/internal/1010@192.168.1.8 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1010@192.168.1.8) State EXECUTE going to sleep
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_HANGUP (Cur 2 Tot 24)
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1010@192.168.1.8) Callstate Change ACTIVE -> HANGUP
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1010@192.168.1.8) State HANGUP
2017-05-09 13:48:42.574166 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1010@192.168.1.8 hanging up, cause: NORMAL_CLEARING
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1010@192.168.1.8 Standard HANGUP, cause: NORMAL_CLEARING
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1010@192.168.1.8) State HANGUP going to sleep
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1010@192.168.1.8) State Change CS_HANGUP -> CS_REPORTING
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1010@192.168.1.8) Running State Change CS_REPORTING (Cur 2 Tot 24)
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1010@192.168.1.8) State REPORTING
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1010@192.168.1.8 Standard REPORTING, cause: NORMAL_CLEARING
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1010@192.168.1.8) State REPORTING going to sleep
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1010@192.168.1.8) State Change CS_REPORTING -> CS_DESTROY
2017-05-09 13:48:42.574166 [DEBUG] switch_core_session.c:1664 Session 23 (sofia/internal/1010@192.168.1.8) Locked, Waiting on external entities
2017-05-09 13:48:42.574166 [NOTICE] switch_core_session.c:1682 Session 23 (sofia/internal/1010@192.168.1.8) Ended
2017-05-09 13:48:42.574166 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/1010@192.168.1.8 [CS_DESTROY]
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1010@192.168.1.8) Running State Change CS_DESTROY (Cur 1 Tot 24)
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1010@192.168.1.8) State DESTROY
2017-05-09 13:48:42.574166 [DEBUG] mod_sofia.c:343 sofia/internal/1010@192.168.1.8 SOFIA DESTROY
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1010@192.168.1.8 Standard DESTROY
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1010@192.168.1.8) State DESTROY going to sleep
2017-05-09 13:48:42.574166 [NOTICE] switch_core_session.c:1682 Session 24 (sofia/internal/1001@192.168.1.161:5060) Ended
2017-05-09 13:48:42.574166 [NOTICE] switch_core_session.c:1686 Close Channel sofia/internal/1001@192.168.1.161:5060 [CS_DESTROY]
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001@192.168.1.161:5060) Running State Change CS_DESTROY (Cur 0 Tot 24)
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.1.161:5060) State DESTROY
2017-05-09 13:48:42.574166 [DEBUG] mod_sofia.c:343 sofia/internal/1001@192.168.1.161:5060 SOFIA DESTROY
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1001@192.168.1.161:5060 Standard DESTROY
2017-05-09 13:48:42.574166 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.1.161:5060) State DESTROY going to sleep
freeswitch@freeswitch>