2018-03-21 09:57:02.939258 [NOTICE] mod_logfile.c:192 New log started.
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.839258 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@192.168.150.3 [a0ca0a7f-9131-4c40-96e8-987fede99823]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.839258 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_NEW (Cur 1 Tot 68)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.839258 [DEBUG] sofia.c:10072 sofia/internal/1001@192.168.150.3 receiving invite from 192.168.150.38:61063 version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
2018-03-21 09:57:06.839258 [DEBUG] sofia_reg.c:1788 Send challenge for [1000@192.168.150.3]
2018-03-21 09:57:06.839258 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [1000@192.168.150.3] from ip 192.168.150.38
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.839258 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1001@192.168.150.3) State NEW
2018-03-21 09:57:06.839258 [DEBUG] sofia.c:2405 detaching session a0ca0a7f-9131-4c40-96e8-987fede99823
2018-03-21 09:57:06.889256 [DEBUG] sofia.c:2514 Re-attaching to session a0ca0a7f-9131-4c40-96e8-987fede99823
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] sofia.c:10072 sofia/internal/1001@192.168.150.3 receiving invite from 192.168.150.38:61063 version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'record_stereo' = 'true'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'default_areacode' = '918'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'transfer_fallback_extension' = 'operator'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'toll_allow' = 'domestic,international,local'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'accountcode' = '1001'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'user_context' = 'default'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'outbound_caller_id_name' = 'FreeSWITCH'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'outbound_caller_id_number' = '0000000000'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'callgroup' = 'sales'
2018-03-21 09:57:06.899228 [DEBUG] sofia_reg.c:3162 event_add_header -> 'user_1001_chan_var' = 'value_1001'
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [received][100]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] sofia.c:7293 Remote SDP:
a0ca0a7f-9131-4c40-96e8-987fede99823 v=0
a0ca0a7f-9131-4c40-96e8-987fede99823 o=- 13166114225392269 1 IN IP4 192.168.150.38
a0ca0a7f-9131-4c40-96e8-987fede99823 s=Bria 5 release 5.0.3 stamp 88308
a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.38
a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 51268 RTP/AVP 9 8 85 18 120 0 84 121 122 123 3 101
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:85 speex/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:18 G729/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:18 annexb=yes
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:120 opus/48000/2
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:84 speex/16000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:121 SILK/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:122 SILK/16000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:123 SILK/24000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-15
a0ca0a7f-9131-4c40-96e8-987fede99823 
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] sofia.c:7687 (sofia/internal/1001@192.168.150.3) State Change CS_NEW -> CS_INIT
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_INIT (Cur 1 Tot 68)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.150.3) State INIT
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_sofia.c:93 sofia/internal/1001@192.168.150.3 SOFIA INIT
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@192.168.150.3 Standard INIT
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@192.168.150.3) State Change CS_INIT -> CS_ROUTING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@192.168.150.3) State INIT going to sleep
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_ROUTING (Cur 1 Tot 68)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_channel.c:2249 (sofia/internal/1001@192.168.150.3) Callstate Change DOWN -> RINGING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.150.3) State ROUTING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_sofia.c:154 sofia/internal/1001@192.168.150.3 SOFIA ROUTING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1001@192.168.150.3 Standard ROUTING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] mod_dialplan_xml.c:637 Processing 1001 <1001>->1000 in context default
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->record silence energy] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [record silence energy] ${destination_number}(1000) =~ /^311$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->flowroute.com] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [flowroute.com] destination_number(1000) =~ /^f?3?\+?(1?\d{10})$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->telnyx] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [telnyx] destination_number(1000) =~ /^t?8?\+?(1?\d{10})$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->domestic.twilio.short] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [domestic.twilio.short] destination_number(1000) =~ /^t?w?(1?\d{10})$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->park] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [park] destination_number(1000) =~ /^park|7275$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->delay_echo] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [delay_echo] destination_number(1000) =~ /^delay_echo|33246$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->echo] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [echo] destination_number(1000) =~ /^echo|3246$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->shout test] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [shout test] destination_number(1000) =~ /^shout|74688$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->watson_ws TTS test] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [watson_ws TTS test] destination_number(1000) =~ /^watson_ws|980$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->watson ASR test] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [watson ASR test] destination_number(1000) =~ /^watson|981$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call center customer] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call center customer] destination_number(1000) =~ /996/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call center agent stuff] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call center agent stuff] destination_number(1000) =~ /^(997)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call center login] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call center login] destination_number(1000) =~ /^agent-login|998$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call center logout] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call center logout] destination_number(1000) =~ /^agent-logout|999$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->gentones] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [gentones] destination_number(1000) =~ /^(gentones|1998)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->no_more_funds] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [no_more_funds] destination_number(1000) =~ /^(no_more_funds)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->add_funds] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [add_funds] destination_number(1000) =~ /^(add_funds)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->test-json-cdr] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [test-json-cdr] destination_number(1000) =~ /^(3533)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->g722 EncoreGroup test] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [g722 EncoreGroup test] destination_number(1000) =~ /^1999$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->applicant interview] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [applicant interview] destination_number(1000) =~ /^2010$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->8x8 test] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [8x8 test] destination_number(1000) =~ /^2001$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->ascii YY ZZZ - to play ascii wav files] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [ascii YY ZZZ - to play ascii wav files] destination_number(1000) =~ /^ascii (\d{2}|\d{3}) (\d{2}|\d{3})$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->speak something] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [speak something] destination_number(1000) =~ /^speakthis$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->say something] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [say something] destination_number(1000) =~ /^saythis$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->phrase something] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [phrase something] destination_number(1000) =~ /^phrasethis$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->P-Asserted-Identity] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [P-Asserted-Identity] destination_number(1000) =~ /pidtest/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->channel variable test] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [channel variable test] destination_number(1000) =~ /^1020$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->bridge simultaneous blegs - ringall group] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [bridge simultaneous blegs - ringall group] destination_number(1000) =~ /^1021$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->bridge sequential blegs - hunt/round-robin group] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [bridge sequential blegs - hunt/round-robin group] destination_number(1000) =~ /^1022$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->bridge enterprise blegs] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [bridge enterprise blegs] destination_number(1000) =~ /^1023$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->group_test] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [group_test] destination_number(1000) =~ /^99$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->sales] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [sales] destination_number(1000) =~ /sales|200/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->play_and_get_digits example] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [play_and_get_digits example] destination_number(1000) =~ /^(1888)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->notworking] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [notworking] destination_number(1000) =~ /^996$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->working] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [working] destination_number(1000) =~ /^997$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->local stream] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [local stream] destination_number(1000) =~ /^787|local_stream$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->fifo agent] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [fifo agent] destination_number(1000) =~ /^777$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->fifo customer] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [fifo customer] destination_number(1000) =~ /^(778)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->cryptconf.com] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [cryptconf.com] destination_number(1000) =~ /^9(10[01][0-9])$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->perl_test] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [perl_test] destination_number(1000) =~ /^(595)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->test flac play] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [test flac play] destination_number(1000) =~ /^(596)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->test flac record] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [test flac record] destination_number(1000) =~ /^(597)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->test lua] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [test lua] destination_number(1000) =~ /^(598)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->123_screen] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [123_screen] destination_number(1000) =~ /^(3600)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->conf_bridger] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [conf_bridger] destination_number(1000) =~ /^599$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->cdquality_stereo_conferences] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [cdquality_stereo_conferences] destination_number(1000) =~ /^599-screen$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->unloop] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->tod_example] continue=true
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Date/Time Match (PASS) [tod_example] break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(open=true)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->holiday_example] continue=true
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Date/TimeMatch (FAIL) [holiday_example] break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->global-intercept] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global-intercept] destination_number(1000) =~ /^886$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->group-intercept] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [group-intercept] destination_number(1000) =~ /^\*8$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->intercept-ext] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [intercept-ext] destination_number(1000) =~ /^\*\*(\d+)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->redial] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [redial] destination_number(1000) =~ /^(redial|870)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->global] continue=true
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global] ${default_password}(j0sh3b0sh) =~ /^1234$/ break=never
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 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
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^((sip:dtls:)?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
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (PASS) [global] ${endpoint_disposition}(DELAYED NEGOTIATION) =~ /^(DELAYED NEGOTIATION)/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [global] ${switch_r_sdp}(v=0
a0ca0a7f-9131-4c40-96e8-987fede99823 o=- 13166114225392269 1 IN IP4 192.168.150.38
a0ca0a7f-9131-4c40-96e8-987fede99823 s=Bria 5 release 5.0.3 stamp 88308
a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.38
a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 51268 RTP/AVP 9 8 85 18 120 0 84 121 122 123 3 101
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:85 speex/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:18 G729/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:18 annexb=yes
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:120 opus/48000/2
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:84 speex/16000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:121 SILK/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:122 SILK/16000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:123 SILK/24000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-15
a0ca0a7f-9131-4c40-96e8-987fede99823 ) =~ /(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)/ break=never
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Absolute Condition [global]
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-spymap/${caller_id_number}/${uuid})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial/global/${uuid})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->snom-demo-2] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [snom-demo-2] destination_number(1000) =~ /^9001$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->snom-demo-1] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [snom-demo-1] destination_number(1000) =~ /^9000$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->eavesdrop] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->eavesdrop] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [eavesdrop] destination_number(1000) =~ /^779$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call_return] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call_return] destination_number(1000) =~ /^\*69$|^869$|^lcr$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->del-group] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [del-group] destination_number(1000) =~ /^80(\d{2})$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->add-group] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [add-group] destination_number(1000) =~ /^81(\d{2})$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call-group-simo] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call-group-simo] destination_number(1000) =~ /^82(\d{2})$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->call-group-order] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [call-group-order] destination_number(1000) =~ /^83(\d{2})$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->extension-intercom] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (FAIL) [extension-intercom] destination_number(1000) =~ /^8(10[01][0-9])$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 parsing [default->Local_Extension] continue=false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Regex (PASS) [Local_Extension] destination_number(1000) =~ /^(10[01][0-9])$/ break=on-false
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action export(dialed_extension=1000)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(1 b s execute_extension::dx XML features)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(3 b s execute_extension::cf XML features)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(4 b s execute_extension::att_xfer XML features)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bind_meta_app(5 ab s playback::${sounds_dir}/joshebosh/Answering_Machine.wav)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action pre_answer()
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(ringback=${us-ring})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(transfer_ringback=/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(call_timeout=30)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(hangup_after_bridge=true)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(continue_on_fail=false)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(record_concat_video=true)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(record_filename=/var/www/html/fs/${strftime(%Y-%m-%d-%H-%M-%S)}_${uuid}.mp4) INLINE
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(record_filename=/var/www/html/fs/2018-03-21-09-57-06_a0ca0a7f-9131-4c40-96e8-987fede99823.mp4)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [record_filename]=[/var/www/html/fs/2018-03-21-09-57-06_a0ca0a7f-9131-4c40-96e8-987fede99823.mp4]
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(RECORD_MIN_SEC=2)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action set(RECORD_STEREO=true)
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bridge(user/${dialed_extension}@${domain_name})
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action hangup()
a0ca0a7f-9131-4c40-96e8-987fede99823 Dialplan: sofia/internal/1001@192.168.150.3 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension})
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1001@192.168.150.3) State Change CS_ROUTING -> CS_EXECUTE
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@192.168.150.3) State ROUTING going to sleep
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_EXECUTE (Cur 1 Tot 68)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@192.168.150.3) State EXECUTE
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_sofia.c:209 sofia/internal/1001@192.168.150.3 SOFIA EXECUTE
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001@192.168.150.3 Standard EXECUTE
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(open=true)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [open]=[true]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-spymap/1001/a0ca0a7f-9131-4c40-96e8-987fede99823)
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial/1001/1000)
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial/global/a0ca0a7f-9131-4c40-96e8-987fede99823)
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 export(RFC2822_DATE=Wed, 21 Mar 2018 09:57:06 -0400)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 21 Mar 2018 09:57:06 -0400]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 export(dialed_extension=1000)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1000]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(1 b s execute_extension::dx XML features)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *1 execute_extension::dx XML features
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/1001.2018-03-21-09-57-06.wav)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/1001.2018-03-21-09-57-06.wav
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(3 b s execute_extension::cf XML features)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *3 execute_extension::cf XML features
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(4 b s execute_extension::att_xfer XML features)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *4 execute_extension::att_xfer XML features
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bind_meta_app(5 ab s playback::/usr/local/freeswitch/sounds/joshebosh/Answering_Machine.wav)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4265 Bound A-Leg: *5 playback::/usr/local/freeswitch/sounds/joshebosh/Answering_Machine.wav
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.899228 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *5 playback::/usr/local/freeswitch/sounds/joshebosh/Answering_Machine.wav
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 pre_answer()
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [INFO] mod_dptools.c:1395 Sending early media
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5368 Set telephone-event payload to 101@8000
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:3767 Set Codec sofia/internal/1001@192.168.150.3 G722/8000 20 ms 160 samples 64000 bits 1 channels
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@192.168.150.3 Original read codec set to G722:9
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5711 Set telephone-event payload to 101@8000
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:5769 sofia/internal/1001@192.168.150.3 Set 2833 dtmf send payload to 101 recv payload to 101
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8486 AUDIO RTP [sofia/internal/1001@192.168.150.3] 192.168.150.3 port 16422 -> 192.168.150.38 port 51268 codec: 9 ms: 20
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_rtp.c:4276 Starting timer [soft] 160 bytes per 20ms
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8790 sofia/internal/1001@192.168.150.3 Set 2833 dtmf send payload to 101
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8797 sofia/internal/1001@192.168.150.3 Set 2833 dtmf receive payload to 101
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8820 sofia/internal/1001@192.168.150.3 Set rtp dtmf delay to 40
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [NOTICE] sofia_media.c:92 Pre-Answer sofia/internal/1001@192.168.150.3!
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_channel.c:3482 (sofia/internal/1001@192.168.150.3) Callstate Change RINGING -> EARLY
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] switch_core_media.c:8469 Audio params are unchanged for sofia/internal/1001@192.168.150.3.
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_sofia.c:2514 Ring SDP:
a0ca0a7f-9131-4c40-96e8-987fede99823 v=0
a0ca0a7f-9131-4c40-96e8-987fede99823 o=FreeSWITCH 1521624204 1521624205 IN IP4 192.168.150.3
a0ca0a7f-9131-4c40-96e8-987fede99823 s=FreeSWITCH
a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.3
a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 16422 RTP/AVP 9 101
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:9 G722/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-16
a0ca0a7f-9131-4c40-96e8-987fede99823 a=ptime:20
a0ca0a7f-9131-4c40-96e8-987fede99823 a=sendrecv
a0ca0a7f-9131-4c40-96e8-987fede99823 
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(ringback=%(2000,4000,440,480))
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [early][183]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [ringback]=[%(2000,4000,440,480)]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(transfer_ringback=/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [transfer_ringback]=[/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(call_timeout=30)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [call_timeout]=[30]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(hangup_after_bridge=true)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [hangup_after_bridge]=[true]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(continue_on_fail=false)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [continue_on_fail]=[false]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-call_return/1000/1001)
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial_ext/1000/a0ca0a7f-9131-4c40-96e8-987fede99823)
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(called_party_callgroup=sales)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [called_party_callgroup]=[sales]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial_ext/sales/a0ca0a7f-9131-4c40-96e8-987fede99823)
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial_ext/global/a0ca0a7f-9131-4c40-96e8-987fede99823)
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 hash(insert/192.168.150.3-last_dial/sales/a0ca0a7f-9131-4c40-96e8-987fede99823)
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(record_concat_video=true)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [record_concat_video]=[true]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(RECORD_MIN_SEC=2)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.909232 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [RECORD_MIN_SEC]=[2]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 set(RECORD_STEREO=true)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] mod_dptools.c:1588 SET sofia/internal/1001@192.168.150.3 [RECORD_STEREO]=[true]
a0ca0a7f-9131-4c40-96e8-987fede99823 EXECUTE sofia/internal/1001@192.168.150.3 bridge(user/1000@192.168.150.3)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.3 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 21 Mar 2018 09:57:06 -0400] to event
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.3 EXPORTING[export_vars] [dialed_extension]=[1000] to event
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.3 EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 21 Mar 2018 09:57:06 -0400] to event
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_channel.c:1250 sofia/internal/1001@192.168.150.3 EXPORTING[export_vars] [dialed_extension]=[1000] to event
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.150.44:46118 [1a8b93af-e2fa-4189-a0e2-c6a94f451f45]
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@192.168.150.44:46118) State Change CS_NEW -> CS_INIT
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_INIT (Cur 2 Tot 69)
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.150.44:46118) State INIT
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.1.131:46140 [cff610de-5d42-482d-877c-c2748850a999]
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.150.44:46118 SOFIA INIT
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@192.168.1.131:46140) State Change CS_NEW -> CS_INIT
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@192.168.150.44:46118 sending invite version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 Local SDP:
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 v=0
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 o=FreeSWITCH 1521624232 1521624233 IN IP4 192.168.150.3
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 s=FreeSWITCH
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 c=IN IP4 192.168.150.3
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 t=0 0
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 m=audio 16394 RTP/AVP 9 102 0 8
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:9 G722/8000
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:102 opus/48000/2
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:0 PCMU/8000
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:8 PCMA/8000
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=ptime:20
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=sendrecv
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 m=video 16396 RTP/AVP 103 104
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 b=AS:1024
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:103 VP8/90000
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtpmap:104 H264/90000
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=sendrecv
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:103 ccm fir
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:103 ccm tmmbr
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:103 nack
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:103 nack pli
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:104 ccm fir
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:104 ccm tmmbr
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:104 nack
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 a=rtcp-fb:104 nack pli
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.150.44:46118 Standard INIT
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.150.44:46118) State Change CS_INIT -> CS_ROUTING
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.150.44:46118) State INIT going to sleep
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_ROUTING (Cur 3 Tot 70)
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_INIT (Cur 3 Tot 70)
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.131:46140) State INIT
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:46118 entering state [calling][0]
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.150.44:46118) State ROUTING
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.1.131:46140 SOFIA INIT
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.1.131:46155 [a8d951e0-0282-4239-921e-4b5e7604c783]
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.150.44:46118 SOFIA ROUTING
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.150.44:46118) State Change CS_ROUTING -> CS_CONSUME_MEDIA
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.150.44:46118) State ROUTING going to sleep
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@192.168.1.131:46155) State Change CS_NEW -> CS_INIT
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_CONSUME_MEDIA (Cur 4 Tot 71)
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.150.44:46118) State CONSUME_MEDIA
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.150.44:46118) State CONSUME_MEDIA going to sleep
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@192.168.1.131:46140 sending invite version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
cff610de-5d42-482d-877c-c2748850a999 Local SDP:
cff610de-5d42-482d-877c-c2748850a999 v=0
cff610de-5d42-482d-877c-c2748850a999 o=FreeSWITCH 1521624212 1521624213 IN IP4 166.130.120.33
cff610de-5d42-482d-877c-c2748850a999 s=FreeSWITCH
cff610de-5d42-482d-877c-c2748850a999 c=IN IP4 166.130.120.33
cff610de-5d42-482d-877c-c2748850a999 t=0 0
cff610de-5d42-482d-877c-c2748850a999 m=audio 16414 RTP/AVP 9 102 0 8
cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:9 G722/8000
cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:102 opus/48000/2
cff610de-5d42-482d-877c-c2748850a999 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:0 PCMU/8000
cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:8 PCMA/8000
cff610de-5d42-482d-877c-c2748850a999 a=ptime:20
cff610de-5d42-482d-877c-c2748850a999 a=sendrecv
cff610de-5d42-482d-877c-c2748850a999 m=video 16480 RTP/AVP 103 104
cff610de-5d42-482d-877c-c2748850a999 b=AS:1024
cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:103 VP8/90000
cff610de-5d42-482d-877c-c2748850a999 a=rtpmap:104 H264/90000
cff610de-5d42-482d-877c-c2748850a999 a=sendrecv
cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:103 ccm fir
cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:103 ccm tmmbr
cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:103 nack
cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:103 nack pli
cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:104 ccm fir
cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:104 ccm tmmbr
cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:104 nack
cff610de-5d42-482d-877c-c2748850a999 a=rtcp-fb:104 nack pli
cff610de-5d42-482d-877c-c2748850a999 
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.1.131:46140 Standard INIT
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.1.131:46140) State Change CS_INIT -> CS_ROUTING
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.131:46140) State INIT going to sleep
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_INIT (Cur 4 Tot 71)
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.131:46155) State INIT
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_ROUTING (Cur 5 Tot 72)
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1000@192.168.150.44:56245 [614ff42b-3e4b-4dd8-8413-012b87f773d4]
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.1.131:46155 SOFIA INIT
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:5028 (sofia/internal/1000@192.168.150.44:56245) State Change CS_NEW -> CS_INIT
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.1.131:46140 entering state [calling][0]
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.131:46140) State ROUTING
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.1.131:46140 SOFIA ROUTING
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.1.131:46140) State Change CS_ROUTING -> CS_CONSUME_MEDIA
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.131:46140) State ROUTING going to sleep
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 72)
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@192.168.1.131:46155 sending invite version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
a8d951e0-0282-4239-921e-4b5e7604c783 Local SDP:
a8d951e0-0282-4239-921e-4b5e7604c783 v=0
a8d951e0-0282-4239-921e-4b5e7604c783 o=FreeSWITCH 1521624236 1521624237 IN IP4 166.130.120.33
a8d951e0-0282-4239-921e-4b5e7604c783 s=FreeSWITCH
a8d951e0-0282-4239-921e-4b5e7604c783 c=IN IP4 166.130.120.33
a8d951e0-0282-4239-921e-4b5e7604c783 t=0 0
a8d951e0-0282-4239-921e-4b5e7604c783 m=audio 16390 RTP/AVP 9 102 0 8
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:9 G722/8000
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:102 opus/48000/2
a8d951e0-0282-4239-921e-4b5e7604c783 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:0 PCMU/8000
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:8 PCMA/8000
a8d951e0-0282-4239-921e-4b5e7604c783 a=ptime:20
a8d951e0-0282-4239-921e-4b5e7604c783 a=sendrecv
a8d951e0-0282-4239-921e-4b5e7604c783 m=video 16384 RTP/AVP 103 104
a8d951e0-0282-4239-921e-4b5e7604c783 b=AS:1024
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:103 VP8/90000
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtpmap:104 H264/90000
a8d951e0-0282-4239-921e-4b5e7604c783 a=sendrecv
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:103 ccm fir
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:103 ccm tmmbr
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:103 nack
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:103 nack pli
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:104 ccm fir
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:104 ccm tmmbr
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:104 nack
a8d951e0-0282-4239-921e-4b5e7604c783 a=rtcp-fb:104 nack pli
a8d951e0-0282-4239-921e-4b5e7604c783 
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.1.131:46155 Standard INIT
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.1.131:46155) State Change CS_INIT -> CS_ROUTING
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.1.131:46155) State INIT going to sleep
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.1.131:46140) State CONSUME_MEDIA
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.1.131:46140) State CONSUME_MEDIA going to sleep
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_ROUTING (Cur 5 Tot 72)
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_INIT (Cur 5 Tot 72)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:06.919229 [NOTICE] switch_ivr_originate.c:2868 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.150.44:56245) State INIT
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:93 sofia/internal/1000@192.168.150.44:56245 SOFIA INIT
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.1.131:46155 entering state [calling][0]
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.131:46155) State ROUTING
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.1.131:46155 SOFIA ROUTING
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.1.131:46155) State Change CS_ROUTING -> CS_CONSUME_MEDIA
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.1.131:46155) State ROUTING going to sleep
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 72)
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.1.131:46155) State CONSUME_MEDIA
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.1.131:46155) State CONSUME_MEDIA going to sleep
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] sofia_glue.c:1299 sofia/internal/1000@192.168.150.44:56245 sending invite version: 1.9.0 git c093b2d 2018-03-20 14:32:52Z 64bit
614ff42b-3e4b-4dd8-8413-012b87f773d4 Local SDP:
614ff42b-3e4b-4dd8-8413-012b87f773d4 v=0
614ff42b-3e4b-4dd8-8413-012b87f773d4 o=FreeSWITCH 1521624228 1521624229 IN IP4 192.168.150.3
614ff42b-3e4b-4dd8-8413-012b87f773d4 s=FreeSWITCH
614ff42b-3e4b-4dd8-8413-012b87f773d4 c=IN IP4 192.168.150.3
614ff42b-3e4b-4dd8-8413-012b87f773d4 t=0 0
614ff42b-3e4b-4dd8-8413-012b87f773d4 m=audio 16398 RTP/AVP 9 102 0 8
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:9 G722/8000
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:102 opus/48000/2
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:0 PCMU/8000
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:8 PCMA/8000
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=ptime:20
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=sendrecv
614ff42b-3e4b-4dd8-8413-012b87f773d4 m=video 16476 RTP/AVP 103 104
614ff42b-3e4b-4dd8-8413-012b87f773d4 b=AS:1024
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:103 VP8/90000
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:104 H264/90000
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=sendrecv
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:103 ccm fir
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:103 ccm tmmbr
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:103 nack
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:103 nack pli
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:104 ccm fir
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:104 ccm tmmbr
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:104 nack
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:104 nack pli
614ff42b-3e4b-4dd8-8413-012b87f773d4 
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1000@192.168.150.44:56245 Standard INIT
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1000@192.168.150.44:56245) State Change CS_INIT -> CS_ROUTING
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1000@192.168.150.44:56245) State INIT going to sleep
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_ROUTING (Cur 5 Tot 72)
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:56245 entering state [calling][0]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.150.44:56245) State ROUTING
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] mod_sofia.c:154 sofia/internal/1000@192.168.150.44:56245 SOFIA ROUTING
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1000@192.168.150.44:56245) State Change CS_ROUTING -> CS_CONSUME_MEDIA
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1000@192.168.150.44:56245) State ROUTING going to sleep
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_CONSUME_MEDIA (Cur 5 Tot 72)
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.150.44:56245) State CONSUME_MEDIA
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.919229 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1000@192.168.150.44:56245) State CONSUME_MEDIA going to sleep
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.999230 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:56245 entering state [proceeding][180]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.999230 [NOTICE] sofia.c:7393 Ring-Ready sofia/internal/1000@192.168.150.44:56245!
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:06.999230 [DEBUG] switch_channel.c:3354 (sofia/internal/1000@192.168.150.44:56245) Callstate Change DOWN -> RINGING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:07.009229 [DEBUG] switch_rtp.c:7484 Correct audio ip/port confirmed.
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:07.029232 [DEBUG] switch_ivr_originate.c:1278 Raw Codec Activation Success L16@16000hz 1 channel 20ms
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:07.029232 [DEBUG] switch_core_codec.c:223 sofia/internal/1001@192.168.150.3 Push codec L16:100
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:07.029232 [DEBUG] switch_ivr_originate.c:1347 Play Ringback Tone [%(2000,4000,440,480)]
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.1.131:46140 entering state [terminated][503]
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [NOTICE] sofia.c:8476 Hangup sofia/internal/1000@192.168.1.131:46140 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.1.131:46155 entering state [terminated][503]
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [NOTICE] sofia.c:8476 Hangup sofia/internal/1000@192.168.1.131:46155 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_HANGUP (Cur 5 Tot 72)
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_HANGUP (Cur 5 Tot 72)
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.1.131:46155) Callstate Change DOWN -> HANGUP
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.1.131:46155) State HANGUP
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.1.131:46140) Callstate Change DOWN -> HANGUP
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@192.168.1.131:46155 hanging up, cause: NORMAL_TEMPORARY_FAILURE
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.1.131:46140) State HANGUP
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@192.168.1.131:46140 hanging up, cause: NORMAL_TEMPORARY_FAILURE
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.1.131:46155 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.1.131:46155) State HANGUP going to sleep
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@192.168.1.131:46155) State Change CS_HANGUP -> CS_REPORTING
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_REPORTING (Cur 5 Tot 72)
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.1.131:46140 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.1.131:46140) State HANGUP going to sleep
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.1.131:46155) State REPORTING
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@192.168.1.131:46140) State Change CS_HANGUP -> CS_REPORTING
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_REPORTING (Cur 5 Tot 72)
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.1.131:46140) State REPORTING
2018-03-21 09:57:09.999259 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","","2018-03-21 09:57:09",3,0,"NORMAL_TEMPORARY_FAILURE","a8d951e0-0282-4239-921e-4b5e7604c783","","")
2018-03-21 09:57:09.999259 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","","2018-03-21 09:57:09",3,0,"NORMAL_TEMPORARY_FAILURE","cff610de-5d42-482d-877c-c2748850a999","","")
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.1.131:46140 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.1.131:46140) State REPORTING going to sleep
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@192.168.1.131:46140) State Change CS_REPORTING -> CS_DESTROY
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:09.999259 [DEBUG] switch_core_session.c:1713 Session 70 (sofia/internal/1000@192.168.1.131:46140) Locked, Waiting on external entities
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:56245 entering state [completing][200]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] sofia.c:7293 Remote SDP:
614ff42b-3e4b-4dd8-8413-012b87f773d4 v=0
614ff42b-3e4b-4dd8-8413-012b87f773d4 o=- 3874730898 3 IN IP4 192.168.1.131
614ff42b-3e4b-4dd8-8413-012b87f773d4 s=Cpc session
614ff42b-3e4b-4dd8-8413-012b87f773d4 c=IN IP4 166.130.120.33
614ff42b-3e4b-4dd8-8413-012b87f773d4 t=0 0
614ff42b-3e4b-4dd8-8413-012b87f773d4 m=audio 62112 RTP/AVP 9 102 0 8
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:102 opus/48000/2
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=fmtp:102 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
614ff42b-3e4b-4dd8-8413-012b87f773d4 m=video 55568 RTP/AVP 103 104
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:103 VP8/90000
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtpmap:104 H264/90000
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=fmtp:104 profile-level-id=42800b;packetization-mode=0
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:* nack
614ff42b-3e4b-4dd8-8413-012b87f773d4 a=rtcp-fb:* nack pli
614ff42b-3e4b-4dd8-8413-012b87f773d4 
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [NOTICE] sofia.c:7296 Pre-Answer sofia/internal/1000@192.168.150.44:56245!
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_channel.c:3482 (sofia/internal/1000@192.168.150.44:56245) Callstate Change RINGING -> EARLY
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] sofia.c:7283 Channel sofia/internal/1000@192.168.150.44:56245 entering state [ready][200]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:102:48000:20:0:1]/[G722:9:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:102:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:3767 Set Codec sofia/internal/1000@192.168.150.44:56245 G722/8000 20 ms 160 samples 64000 bits 1 channels
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_codec.c:111 sofia/internal/1000@192.168.150.44:56245 Original read codec set to G722:9
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5740 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:5769 sofia/internal/1000@192.168.150.44:56245 Set 2833 dtmf send payload to 101 recv payload to 101
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:103]/[VP8:99]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6084 Video Codec Compare [VP8:103] +++ is saved as a match
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:103]/[H264:99]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:104]/[VP8:99]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:104]/[H264:99]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:6084 Video Codec Compare [H264:104] +++ is saved as a match
2018-03-21 09:57:10.029257 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-03-21 09:57:10.029257 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:3577 Set VIDEO Codec sofia/internal/1000@192.168.150.44:56245 VP8/90000 0 ms
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:8486 AUDIO RTP [sofia/internal/1000@192.168.150.44:56245] 192.168.150.3 port 16398 -> 166.130.120.33 port 62112 codec: 9 ms: 20
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_rtp.c:4276 Starting timer [soft] 160 bytes per 20ms
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:8790 sofia/internal/1000@192.168.150.44:56245 Set 2833 dtmf send payload to 101
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:8797 sofia/internal/1000@192.168.150.44:56245 Set 2833 dtmf receive payload to 101
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:8820 sofia/internal/1000@192.168.150.44:56245 Set rtp dtmf delay to 40
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_rtp.c:4291 Starting video timer.
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:9315 VIDEO RTP [sofia/internal/1000@192.168.150.44:56245] 192.168.150.3:16476->166.130.120.33:55568 codec: 103 ms: 0 [SUCCESS]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:7478 sofia/internal/1000@192.168.150.44:56245 Starting Video thread
2018-03-21 09:57:10.029257 [DEBUG] switch_core_media.c:7344 sofia/internal/1000@192.168.150.44:56245 Video thread started. Echo is off
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [INFO] switch_core_media.c:9395 Activating VIDEO RTCP PORT 55569 interval 1000 mux -1
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_rtp.c:4672 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 55569
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 166.130.120.33:55569 2
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.029257 [NOTICE] sofia.c:8421 Channel [sofia/internal/1000@192.168.150.44:56245] has been answered
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.039230 [DEBUG] switch_channel.c:3781 (sofia/internal/1000@192.168.150.44:56245) Callstate Change EARLY -> ACTIVE
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_core_codec.c:248 sofia/internal/1001@192.168.150.3 Restore previous codec G722:9.
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [NOTICE] switch_ivr_originate.c:3629 Hangup sofia/internal/1000@192.168.150.44:46118 [CS_CONSUME_MEDIA] [LOSE_RACE]
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_HANGUP (Cur 5 Tot 72)
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.150.44:46118) Callstate Change DOWN -> HANGUP
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.150.44:46118) State HANGUP
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@192.168.150.44:46118 hanging up, cause: LOSE_RACE
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_core_media.c:8469 Audio params are unchanged for sofia/internal/1001@192.168.150.3.
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:881 Local SDP sofia/internal/1001@192.168.150.3:
a0ca0a7f-9131-4c40-96e8-987fede99823 v=0
a0ca0a7f-9131-4c40-96e8-987fede99823 o=FreeSWITCH 1521624204 1521624206 IN IP4 192.168.150.3
a0ca0a7f-9131-4c40-96e8-987fede99823 s=FreeSWITCH
a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.3
a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 16422 RTP/AVP 9 101
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:9 G722/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-16
a0ca0a7f-9131-4c40-96e8-987fede99823 a=ptime:20
a0ca0a7f-9131-4c40-96e8-987fede99823 a=sendrecv
a0ca0a7f-9131-4c40-96e8-987fede99823 
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:513 Sending CANCEL to sofia/internal/1000@192.168.150.44:46118
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.150.44:46118 Standard HANGUP, cause: LOSE_RACE
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.150.44:46118) State HANGUP going to sleep
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@192.168.150.44:46118) State Change CS_HANGUP -> CS_REPORTING
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_REPORTING (Cur 5 Tot 72)
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.150.44:46118) State REPORTING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [NOTICE] switch_ivr_originate.c:3664 Channel [sofia/internal/1001@192.168.150.3] has been answered
2018-03-21 09:57:10.049256 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","","2018-03-21 09:57:10",4,0,"LOSE_RACE","1a8b93af-e2fa-4189-a0e2-c6a94f451f45","","")
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.150.44:46118 Standard REPORTING, cause: LOSE_RACE
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.150.44:46118) State REPORTING going to sleep
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@192.168.150.44:46118) State Change CS_REPORTING -> CS_DESTROY
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_session.c:1713 Session 69 (sofia/internal/1000@192.168.150.44:46118) Locked, Waiting on external entities
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_channel.c:3781 (sofia/internal/1001@192.168.150.3) Callstate Change EARLY -> ACTIVE
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [completed][200]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1000@192.168.150.44:56245]
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [NOTICE] switch_core_session.c:1731 Session 69 (sofia/internal/1000@192.168.150.44:46118) Ended
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@192.168.150.44:46118 [CS_DESTROY]
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [NOTICE] switch_core_session.c:1731 Session 70 (sofia/internal/1000@192.168.1.131:46140) Ended
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@192.168.1.131:46140 [CS_DESTROY]
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@192.168.1.131:46140) Running State Change CS_DESTROY (Cur 3 Tot 72)
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@192.168.150.44:46118) Running State Change CS_DESTROY (Cur 3 Tot 72)
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.1.131:46140) State DESTROY
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:354 sofia/internal/1000@192.168.1.131:46140 SOFIA DESTROY
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.1.131:46140 Standard DESTROY
cff610de-5d42-482d-877c-c2748850a999 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.1.131:46140) State DESTROY going to sleep
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.150.44:46118) State DESTROY
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] mod_sofia.c:354 sofia/internal/1000@192.168.150.44:46118 SOFIA DESTROY
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.150.44:46118 Standard DESTROY
1a8b93af-e2fa-4189-a0e2-c6a94f451f45 2018-03-21 09:57:10.049256 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.150.44:46118) State DESTROY going to sleep
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.049256 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1000@192.168.150.44:56245]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.059226 [DEBUG] switch_ivr_bridge.c:1744 (sofia/internal/1000@192.168.150.44:56245) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.059226 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_EXCHANGE_MEDIA (Cur 3 Tot 72)
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.059226 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1000@192.168.150.44:56245) State EXCHANGE_MEDIA
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.059226 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.059226 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [ready][200]
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.1.131:46155 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.1.131:46155) State REPORTING going to sleep
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@192.168.1.131:46155) State Change CS_REPORTING -> CS_DESTROY
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_session.c:1713 Session 71 (sofia/internal/1000@192.168.1.131:46155) Locked, Waiting on external entities
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [NOTICE] switch_core_session.c:1731 Session 71 (sofia/internal/1000@192.168.1.131:46155) Ended
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@192.168.1.131:46155 [CS_DESTROY]
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@192.168.1.131:46155) Running State Change CS_DESTROY (Cur 2 Tot 72)
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.1.131:46155) State DESTROY
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] mod_sofia.c:354 sofia/internal/1000@192.168.1.131:46155 SOFIA DESTROY
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.1.131:46155 Standard DESTROY
a8d951e0-0282-4239-921e-4b5e7604c783 2018-03-21 09:57:10.099234 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.1.131:46155) State DESTROY going to sleep
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:10.109255 [DEBUG] switch_rtp.c:7484 Correct audio ip/port confirmed.
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.139258 [NOTICE] switch_vpx.c:410 VPX reset encoder picture from 320x240 to 352x288 1024 BW
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.139258 [INFO] switch_rtp.c:6903 Auto Changing video RTCP port from 166.130.120.33:55569 to 192.168.150.44:55569
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:10.139258 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 192.168.150.44:55569 2
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:57:11.289256 [INFO] switch_rtp.c:7444 Auto Changing audio port from 166.130.120.33:62112 to 192.168.150.44:62112
2018-03-21 09:57:30.729257 [CRIT] mod_commands.c:6925 windows calling android
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [received][100]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] sofia.c:7293 Remote SDP:
a0ca0a7f-9131-4c40-96e8-987fede99823 v=0
a0ca0a7f-9131-4c40-96e8-987fede99823 o=- 13166114225392269 2 IN IP4 192.168.150.38
a0ca0a7f-9131-4c40-96e8-987fede99823 s=Bria 5 release 5.0.3 stamp 88308
a0ca0a7f-9131-4c40-96e8-987fede99823 c=IN IP4 192.168.150.38
a0ca0a7f-9131-4c40-96e8-987fede99823 t=0 0
a0ca0a7f-9131-4c40-96e8-987fede99823 m=audio 51268 RTP/AVP 9 8 85 18 120 0 84 121 122 123 3 101
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:85 speex/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:18 G729/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:18 annexb=yes
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:120 opus/48000/2
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:120 useinbandfec=1; usedtx=1; maxaveragebitrate=64000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:84 speex/16000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:121 SILK/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:122 SILK/16000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:123 SILK/24000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:101 telephone-event/8000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:101 0-15
a0ca0a7f-9131-4c40-96e8-987fede99823 m=video 53822 RTP/AVP 100 127 126
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:100 VP8/90000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:127 H264/90000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:127 profile-level-id=42800c;packetization-mode=0
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtpmap:126 H264/90000
a0ca0a7f-9131-4c40-96e8-987fede99823 a=fmtp:126 profile-level-id=42800c;packetization-mode=1
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtcp-fb:* nack
a0ca0a7f-9131-4c40-96e8-987fede99823 a=rtcp-fb:* nack pli
a0ca0a7f-9131-4c40-96e8-987fede99823 
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:85:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [opus:120:48000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5507 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [speex:84:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:121:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:122:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [SILK:123:24000:20:0:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[opus:116:48000:20:0:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5452 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5368 Set telephone-event payload to 101@8000
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5711 Set telephone-event payload to 101@8000
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:5769 sofia/internal/1001@192.168.150.3 Set 2833 dtmf send payload to 101 recv payload to 101
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6095 No matches with FTMP, fallback to ignoring FMTP
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6103 No matches with inherit_codec, fallback to ignoring PT
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6084 Video Codec Compare [VP8:100] +++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [VP8:100]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:127]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6084 Video Codec Compare [H264:127] +++ is saved as a match
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[VP8:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6052 Video Codec Compare [H264:126]/[H264:99]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:6084 Video Codec Compare [H264:126] +++ is saved as a match
2018-03-21 09:57:48.349233 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
2018-03-21 09:57:48.349233 [DEBUG] switch_vpx.c:636 VPX VER:v1.6.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:7
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:3577 Set VIDEO Codec sofia/internal/1001@192.168.150.3 VP8/90000 0 ms
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:8469 Audio params are unchanged for sofia/internal/1001@192.168.150.3.
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_rtp.c:4291 Starting video timer.
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:9315 VIDEO RTP [sofia/internal/1001@192.168.150.3] 192.168.150.3:16478->192.168.150.38:53822 codec: 100 ms: 0 [SUCCESS]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:7478 sofia/internal/1001@192.168.150.3 Starting Video thread
2018-03-21 09:57:48.349233 [DEBUG] switch_core_media.c:7344 sofia/internal/1001@192.168.150.3 Video thread started. Echo is off
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [INFO] switch_core_media.c:9395 Activating VIDEO RTCP PORT 53823 interval 1000 mux -1
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_rtp.c:4672 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 53823
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] switch_rtp.c:2567 Setting RTCP remote addr to 192.168.150.38:53823 2
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.349233 [DEBUG] sofia.c:8200 Processing updated SDP
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.369257 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [completed][200]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.369257 [DEBUG] sofia.c:7283 Channel sofia/internal/1001@192.168.150.3 entering state [ready][200]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:48.469257 [DEBUG] switch_rtp.c:6924 Correct video RTCP ip/port confirmed.
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:50.399260 [DEBUG] switch_rtp.c:1885 rtcp_stats_init: video ssrc[1582063745] base_seq[14807]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:57:50.469256 [DEBUG] switch_rtp.c:7484 Correct video ip/port confirmed.
2018-03-21 09:58:22.619259 [WARNING] switch_core_file.c:380 File has 2 channels, muxing to 1 channel will occur.
2018-03-21 09:58:36.909256 [CRIT] mod_commands.c:6925 windows sends video, but android cannot see
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:58:41.549257 [DEBUG] switch_rtp.c:1885 rtcp_stats_init: video ssrc[129502379] base_seq[14498]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:58:41.729245 [INFO] switch_rtp.c:7444 Auto Changing video port from 166.130.120.33:55568 to 192.168.150.44:55568
2018-03-21 09:58:58.189257 [DEBUG] mod_commands.c:6925 android send video, not both can see eachother
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [NOTICE] sofia.c:1079 Hangup sofia/internal/1000@192.168.150.44:56245 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [DEBUG] switch_ivr_bridge.c:848 Ending video thread.
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [DEBUG] switch_ivr_bridge.c:906 Ending video thread.
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [DEBUG] switch_ivr_bridge.c:255 sofia/internal/1000@192.168.150.44:56245 video thread ended.
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.789257 [DEBUG] switch_ivr_bridge.c:257 sofia/internal/1000@192.168.150.44:56245 skip receive message [DISPLAY] (channel is hungup already)
2018-03-21 09:59:15.789257 [DEBUG] switch_core_media.c:7445 sofia/internal/1000@192.168.150.44:56245 Video thread ended
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1000@192.168.150.44:56245]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1000@192.168.150.44:56245) State EXCHANGE_MEDIA going to sleep
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_HANGUP (Cur 2 Tot 72)
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1000@192.168.150.44:56245) Callstate Change ACTIVE -> HANGUP
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.150.44:56245) State HANGUP
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1000@192.168.150.44:56245 hanging up, cause: NORMAL_CLEARING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.799258 [DEBUG] switch_ivr_bridge.c:825 sofia/internal/1000@192.168.150.44:56245 ending bridge by request from write function
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.799258 [DEBUG] switch_ivr_bridge.c:848 Ending video thread.
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1000@192.168.150.44:56245 Standard HANGUP, cause: NORMAL_CLEARING
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1000@192.168.150.44:56245) State HANGUP going to sleep
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1000@192.168.150.44:56245) State Change CS_HANGUP -> CS_REPORTING
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_REPORTING (Cur 2 Tot 72)
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.150.44:56245) State REPORTING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.799258 [DEBUG] switch_ivr_bridge.c:906 Ending video thread.
2018-03-21 09:59:15.799258 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","2018-03-21 09:57:10","2018-03-21 09:59:15",129,125,"NORMAL_CLEARING","614ff42b-3e4b-4dd8-8413-012b87f773d4","","1000")
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1000@192.168.150.44:56245 Standard REPORTING, cause: NORMAL_CLEARING
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1000@192.168.150.44:56245) State REPORTING going to sleep
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1000@192.168.150.44:56245) State Change CS_REPORTING -> CS_DESTROY
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.799258 [DEBUG] switch_core_session.c:1713 Session 72 (sofia/internal/1000@192.168.150.44:56245) Locked, Waiting on external entities
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.819248 [DEBUG] switch_ivr_bridge.c:255 sofia/internal/1001@192.168.150.3 video thread ended.
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.829239 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1001@192.168.150.3]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [NOTICE] switch_ivr_bridge.c:1895 Hangup sofia/internal/1001@192.168.150.3 [CS_EXECUTE] [NORMAL_CLEARING]
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [NOTICE] switch_core_session.c:1731 Session 72 (sofia/internal/1000@192.168.150.44:56245) Ended
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1000@192.168.150.44:56245 [CS_DESTROY]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_session.c:2885 sofia/internal/1001@192.168.150.3 skip receive message [PHONE_EVENT] (channel is hungup already)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@192.168.150.3) State EXECUTE going to sleep
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_HANGUP (Cur 1 Tot 72)
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1000@192.168.150.44:56245) Running State Change CS_DESTROY (Cur 1 Tot 72)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1001@192.168.150.3) Callstate Change ACTIVE -> HANGUP
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.150.44:56245) State DESTROY
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] mod_sofia.c:354 sofia/internal/1000@192.168.150.44:56245 SOFIA DESTROY
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.150.3) State HANGUP
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1000@192.168.150.44:56245 Standard DESTROY
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] mod_sofia.c:443 sofia/internal/1001@192.168.150.3 Overriding SIP cause 480 with 200 from the other leg
614ff42b-3e4b-4dd8-8413-012b87f773d4 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1000@192.168.150.44:56245) State DESTROY going to sleep
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1001@192.168.150.3 hanging up, cause: NORMAL_CLEARING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/internal/1001@192.168.150.3
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1001@192.168.150.3 Standard HANGUP, cause: NORMAL_CLEARING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1001@192.168.150.3) State HANGUP going to sleep
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1001@192.168.150.3) State Change CS_HANGUP -> CS_REPORTING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@192.168.150.3) Running State Change CS_REPORTING (Cur 1 Tot 72)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.150.3) State REPORTING
2018-03-21 09:59:15.839233 [DEBUG] mod_cdr_sqlite.c:102 Writing SQL to DB: INSERT INTO cdr VALUES ("1001","1001","1000","default","2018-03-21 09:57:06","2018-03-21 09:57:10","2018-03-21 09:59:15",129,125,"NORMAL_CLEARING","a0ca0a7f-9131-4c40-96e8-987fede99823","614ff42b-3e4b-4dd8-8413-012b87f773d4","1001")
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1001@192.168.150.3 Standard REPORTING, cause: NORMAL_CLEARING
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1001@192.168.150.3) State REPORTING going to sleep
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1001@192.168.150.3) State Change CS_REPORTING -> CS_DESTROY
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.839233 [DEBUG] switch_core_session.c:1713 Session 68 (sofia/internal/1001@192.168.150.3) Locked, Waiting on external entities
2018-03-21 09:59:15.879233 [DEBUG] switch_core_media.c:7445 sofia/internal/1001@192.168.150.3 Video thread ended
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [NOTICE] switch_core_session.c:1731 Session 68 (sofia/internal/1001@192.168.150.3) Ended
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1001@192.168.150.3 [CS_DESTROY]
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1001@192.168.150.3) Running State Change CS_DESTROY (Cur 0 Tot 72)
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.150.3) State DESTROY
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] mod_sofia.c:354 sofia/internal/1001@192.168.150.3 SOFIA DESTROY
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1001@192.168.150.3 Standard DESTROY
a0ca0a7f-9131-4c40-96e8-987fede99823 2018-03-21 09:59:15.879233 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1001@192.168.150.3) State DESTROY going to sleep
2018-03-21 09:59:26.559258 [NOTICE] sofia_reg.c:448 Registering flowroute
2018-03-21 09:59:26.829256 [DEBUG] sofia_reg.c:2435 Changing expire time to 546 by request of proxy sip:sip.flowroute.com
2018-03-21 09:59:42.769257 [WARNING] switch_core_file.c:380 File has 2 channels, muxing to 1 channel will occur.