2017-11-22 22:24:03.781011 [CONSOLE] mod_voicemail.c:4092 Event Thread Started
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [NOTICE] switch_channel.c:1104 New Channel sofia/external/+12404373728@telnyxlab.com [f8076148-256d-4892-890c-8c4b133c0a27]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+12404373728@telnyxlab.com) Running State Change CS_NEW (Cur 1 Tot 4)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] sofia.c:10070 sofia/external/+12404373728@telnyxlab.com receiving invite from 169.55.36.24:59400 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] sofia.c:7283 Channel sofia/external/+12404373728@telnyxlab.com entering state [received][100]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] sofia.c:7293 Remote SDP:
f8076148-256d-4892-890c-8c4b133c0a27 v=0
f8076148-256d-4892-890c-8c4b133c0a27 o=- 177 1 IN IP4 169.55.36.24
f8076148-256d-4892-890c-8c4b133c0a27 s=session
f8076148-256d-4892-890c-8c4b133c0a27 c=IN IP4 169.55.36.24
f8076148-256d-4892-890c-8c4b133c0a27 b=CT:1000
f8076148-256d-4892-890c-8c4b133c0a27 t=0 0
f8076148-256d-4892-890c-8c4b133c0a27 m=audio 50638 RTP/SAVP 97 101 13 0 8
f8076148-256d-4892-890c-8c4b133c0a27 c=IN IP4 169.55.36.24
f8076148-256d-4892-890c-8c4b133c0a27 a=rtpmap:97 RED/8000
f8076148-256d-4892-890c-8c4b133c0a27 a=rtpmap:101 telephone-event/8000
f8076148-256d-4892-890c-8c4b133c0a27 a=fmtp:101 0-16
f8076148-256d-4892-890c-8c4b133c0a27 a=rtpmap:13 CN/8000
f8076148-256d-4892-890c-8c4b133c0a27 a=rtpmap:0 PCMU/8000
f8076148-256d-4892-890c-8c4b133c0a27 a=rtpmap:8 PCMA/8000
f8076148-256d-4892-890c-8c4b133c0a27 a=rtcp:50639
f8076148-256d-4892-890c-8c4b133c0a27 a=label:Audio
f8076148-256d-4892-890c-8c4b133c0a27 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1
f8076148-256d-4892-890c-8c4b133c0a27 a=crypto:2 AES_CM_128_HMAC_SHA1_80 inline:HSC2fkk7oSQ+a1JgmdhWpMoDmFDfILC+Z248whUE|2^31
f8076148-256d-4892-890c-8c4b133c0a27 a=ptime:20
f8076148-256d-4892-890c-8c4b133c0a27 
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] sofia.c:7685 (sofia/external/+12404373728@telnyxlab.com) State Change CS_NEW -> CS_INIT
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:603 (sofia/external/+12404373728@telnyxlab.com) State NEW
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+12404373728@telnyxlab.com) Running State Change CS_INIT (Cur 1 Tot 4)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+12404373728@telnyxlab.com) State INIT
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] mod_sofia.c:93 sofia/external/+12404373728@telnyxlab.com SOFIA INIT
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:40 sofia/external/+12404373728@telnyxlab.com Standard INIT
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+12404373728@telnyxlab.com) State Change CS_INIT -> CS_ROUTING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:627 (sofia/external/+12404373728@telnyxlab.com) State INIT going to sleep
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+12404373728@telnyxlab.com) Running State Change CS_ROUTING (Cur 1 Tot 4)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_channel.c:2249 (sofia/external/+12404373728@telnyxlab.com) Callstate Change DOWN -> RINGING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+12404373728@telnyxlab.com) State ROUTING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] mod_sofia.c:154 sofia/external/+12404373728@telnyxlab.com SOFIA ROUTING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:236 sofia/external/+12404373728@telnyxlab.com Standard ROUTING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [INFO] mod_dialplan_xml.c:637 Processing Test02 <+12404373728>->0012404373253 in context public
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com parsing [public->unloop] continue=false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com parsing [public->outside_call] continue=true
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Absolute Condition [outside_call]
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Action set(outside_call=true)
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com parsing [public->call_debug] continue=true
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com parsing [public->public_extensions] continue=false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Regex (FAIL) [public_extensions] destination_number(0012404373253) =~ /^(10[01][0-9])$/ break=on-false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com parsing [public->telnyx_test_1] continue=false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Regex (FAIL) [telnyx_test_1] destination_number(0012404373253) =~ /^\+(\d{0,2})(0012025550104|12025550104|0012404373255|12404373255)$/ break=on-false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com parsing [public->telnyx_test_1_2] continue=false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Regex (PASS) [telnyx_test_1_2] destination_number(0012404373253) =~ /^(0012404373253)$/ break=on-false
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Action answer()
f8076148-256d-4892-890c-8c4b133c0a27 Dialplan: sofia/external/+12404373728@telnyxlab.com Action bridge(user/1004@${domain_name})
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:286 (sofia/external/+12404373728@telnyxlab.com) State Change CS_ROUTING -> CS_EXECUTE
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:643 (sofia/external/+12404373728@telnyxlab.com) State ROUTING going to sleep
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+12404373728@telnyxlab.com) Running State Change CS_EXECUTE (Cur 1 Tot 4)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+12404373728@telnyxlab.com) State EXECUTE
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] mod_sofia.c:209 sofia/external/+12404373728@telnyxlab.com SOFIA EXECUTE
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_state_machine.c:328 sofia/external/+12404373728@telnyxlab.com Standard EXECUTE
f8076148-256d-4892-890c-8c4b133c0a27 EXECUTE sofia/external/+12404373728@telnyxlab.com set(outside_call=true)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] mod_dptools.c:1588 SET sofia/external/+12404373728@telnyxlab.com [outside_call]=[true]
f8076148-256d-4892-890c-8c4b133c0a27 EXECUTE sofia/external/+12404373728@telnyxlab.com export(RFC2822_DATE=Wed, 22 Nov 2017 22:24:09 +0000)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Wed, 22 Nov 2017 22:24:09 +0000]
f8076148-256d-4892-890c-8c4b133c0a27 EXECUTE sofia/external/+12404373728@telnyxlab.com answer()
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5339 MKI Core session check incoming crypto (audio) 1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1810 looking for crypto suite [AEAD_AES_256_GCM_8] in [1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1810 looking for crypto suite [AEAD_AES_128_GCM_8] in [1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1810 looking for crypto suite [AES_CM_256_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1810 looking for crypto suite [AES_CM_192_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1810 looking for crypto suite [AES_CM_128_HMAC_SHA1_80] in [1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1815 Found suite AES_CM_128_HMAC_SHA1_80
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1889 Set Remote Key [1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1163 MKI Core media build crypto 4 SEND
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:1211 Set Local audio crypto Key [1 AES_CM_128_HMAC_SHA1_80 inline:w/QnivoTLqXSzWSp/gM6DSNO07XTwIcOkBXqRedB|2^31|1:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [RED:97:8000:20:0:1]/[opus:116:48000:20:0:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [RED:97:8000:20:0:1]/[G722:9:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [RED:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [RED:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5382 Set telephone-event payload to 101@8000
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5521 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5521 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:3778 Set Codec sofia/external/+12404373728@telnyxlab.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_codec.c:111 sofia/external/+12404373728@telnyxlab.com Original read codec set to PCMU:0
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5725 Set telephone-event payload to 101@8000
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:09.881008 [DEBUG] switch_core_media.c:5783 sofia/external/+12404373728@telnyxlab.com Set 2833 dtmf send payload to 101 recv payload to 101
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.741006 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/00@86.153.193.35 [e62f9305-b782-44ab-9344-14f9753b9332]
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.741006 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_NEW (Cur 2 Tot 5)
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.741006 [DEBUG] sofia.c:10070 sofia/internal/00@86.153.193.35 receiving invite from 195.154.183.114:62348 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:24:11.741006 [DEBUG] sofia.c:10241 IP 195.154.183.114 Rejected by acl "domains". Falling back to Digest auth.
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.741006 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/00@86.153.193.35) State NEW
2017-11-22 22:24:11.741006 [DEBUG] sofia.c:2405 detaching session e62f9305-b782-44ab-9344-14f9753b9332
2017-11-22 22:24:11.840981 [DEBUG] sofia.c:2514 Re-attaching to session e62f9305-b782-44ab-9344-14f9753b9332
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.840981 [DEBUG] sofia.c:10070 sofia/internal/00@86.153.193.35 receiving invite from 195.154.183.114:62348 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:24:11.840981 [DEBUG] sofia.c:10241 IP 195.154.183.114 Rejected by acl "domains". Falling back to Digest auth.
2017-11-22 22:24:11.860981 [WARNING] sofia_reg.c:2906 Can't find user [00@192.168.1.104] from 195.154.183.114
You must define a domain called '192.168.1.104' in your directory and add a user with the id="00" attribute
and you must configure your device to use the proper domain in it's authentication credentials.
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.860981 [NOTICE] sofia.c:2403 Hangup sofia/internal/00@86.153.193.35 [CS_NEW] [CALL_REJECTED]
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] sofia.c:1521 Channel is already hungup.
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_HANGUP (Cur 2 Tot 5)
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/00@86.153.193.35) Callstate Change DOWN -> HANGUP
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/00@86.153.193.35) State HANGUP
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] mod_sofia.c:449 Channel sofia/internal/00@86.153.193.35 hanging up, cause: CALL_REJECTED
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:60 sofia/internal/00@86.153.193.35 Standard HANGUP, cause: CALL_REJECTED
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/00@86.153.193.35) State HANGUP going to sleep
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/00@86.153.193.35) State Change CS_HANGUP -> CS_REPORTING
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_REPORTING (Cur 2 Tot 5)
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/00@86.153.193.35) State REPORTING
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:174 sofia/internal/00@86.153.193.35 Standard REPORTING, cause: CALL_REJECTED
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/00@86.153.193.35) State REPORTING going to sleep
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/00@86.153.193.35) State Change CS_REPORTING -> CS_DESTROY
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_session.c:1713 Session 5 (sofia/internal/00@86.153.193.35) Locked, Waiting on external entities
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [NOTICE] switch_core_session.c:1731 Session 5 (sofia/internal/00@86.153.193.35) Ended
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/00@86.153.193.35 [CS_DESTROY]
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/00@86.153.193.35) Running State Change CS_DESTROY (Cur 1 Tot 5)
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/00@86.153.193.35) State DESTROY
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] mod_sofia.c:354 sofia/internal/00@86.153.193.35 SOFIA DESTROY
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:181 sofia/internal/00@86.153.193.35 Standard DESTROY
e62f9305-b782-44ab-9344-14f9753b9332 2017-11-22 22:24:11.880983 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/00@86.153.193.35) State DESTROY going to sleep
2017-11-22 22:24:12.901010 [DEBUG] switch_nat.c:508 mapped public port 16658 protocol UDP to localport 16658
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:8504 AUDIO RTP [sofia/external/+12404373728@telnyxlab.com] 192.168.1.104 port 16658 -> 169.55.36.24 port 50638 codec: 0 ms: 20
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_rtp.c:4303 Starting timer [soft] 160 bytes per 20ms
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:8724 Activating RTCP PORT 50639
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_rtp.c:4699 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 50639
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_rtp.c:2578 Setting RTCP remote addr to 169.55.36.24:50639 2
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:8808 sofia/external/+12404373728@telnyxlab.com Set 2833 dtmf send payload to 101
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:8815 sofia/external/+12404373728@telnyxlab.com Set 2833 dtmf receive payload to 101
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:8838 sofia/external/+12404373728@telnyxlab.com Set rtp dtmf delay to 40
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:8849 MKI Core session apply crypto (audio)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:1669 MKI Core media add crypto 1 AES_CM_128_HMAC_SHA1_80 inline:zl7kZCox/PtpvvL87wX9N2HyPSS7Lph4HftGQWBQ|2^31|1:1 (RECV)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:1423 MKI Core media add crypto SEND
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:1524 LIFETIME found in |2^31|1:1, base 2 exp 31
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:1530 MKI found in |2^31|1:1, id 1 size 1
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:1423 MKI Core media add crypto RECV
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:1524 LIFETIME found in |2^31|1:1, base 2 exp 31
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:1530 MKI found in |2^31|1:1, id 1 size 1
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [INFO] switch_rtp.c:4107 Activating audio Secure RTP SEND (with MKI)
2017-11-22 22:24:12.901010 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [INFO] switch_rtp.c:4085 Activating audio Secure RTP RECV (with MKI)
2017-11-22 22:24:12.901010 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:sdes:AES_CM_128_HMAC_SHA1_80
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/+12404373728@telnyxlab.com!
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_channel.c:3482 (sofia/external/+12404373728@telnyxlab.com) Callstate Change RINGING -> EARLY
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_core_media.c:8487 Audio params are unchanged for sofia/external/+12404373728@telnyxlab.com.
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] mod_sofia.c:881 Local SDP sofia/external/+12404373728@telnyxlab.com:
f8076148-256d-4892-890c-8c4b133c0a27 v=0
f8076148-256d-4892-890c-8c4b133c0a27 o=FreeSWITCH 1511372794 1511372795 IN IP4 86.153.193.35
f8076148-256d-4892-890c-8c4b133c0a27 s=FreeSWITCH
f8076148-256d-4892-890c-8c4b133c0a27 c=IN IP4 86.153.193.35
f8076148-256d-4892-890c-8c4b133c0a27 t=0 0
f8076148-256d-4892-890c-8c4b133c0a27 m=audio 16658 RTP/SAVP 0 101
f8076148-256d-4892-890c-8c4b133c0a27 a=rtpmap:0 PCMU/8000
f8076148-256d-4892-890c-8c4b133c0a27 a=rtpmap:101 telephone-event/8000
f8076148-256d-4892-890c-8c4b133c0a27 a=fmtp:101 0-16
f8076148-256d-4892-890c-8c4b133c0a27 a=ptime:20
f8076148-256d-4892-890c-8c4b133c0a27 a=sendrecv
f8076148-256d-4892-890c-8c4b133c0a27 a=rtcp:16659 IN IP4 86.153.193.35
f8076148-256d-4892-890c-8c4b133c0a27 a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:w/QnivoTLqXSzWSp/gM6DSNO07XTwIcOkBXqRedB|2^31|1:1
f8076148-256d-4892-890c-8c4b133c0a27 
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [NOTICE] mod_dptools.c:1352 Channel [sofia/external/+12404373728@telnyxlab.com] has been answered
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_channel.c:3781 (sofia/external/+12404373728@telnyxlab.com) Callstate Change EARLY -> ACTIVE
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] sofia.c:7283 Channel sofia/external/+12404373728@telnyxlab.com entering state [completed][200]
f8076148-256d-4892-890c-8c4b133c0a27 EXECUTE sofia/external/+12404373728@telnyxlab.com bridge(user/1004@192.168.1.104)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_channel.c:1823 (sofia/external/+12404373728@telnyxlab.com) Callstate Change ACTIVE -> RING_WAIT
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_channel.c:1250 sofia/external/+12404373728@telnyxlab.com EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 22 Nov 2017 22:24:09 +0000] to event
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.901010 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.920982 [DEBUG] switch_channel.c:1250 sofia/external/+12404373728@telnyxlab.com EXPORTING[export_vars] [RFC2822_DATE]=[Wed, 22 Nov 2017 22:24:09 +0000] to event
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.920982 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1004@192.168.1.103:64283 [554560c0-c3ee-4954-a175-84acf13cf1c9]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] mod_sofia.c:5026 (sofia/internal/1004@192.168.1.103:64283) State Change CS_NEW -> CS_INIT
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:12.920982 [NOTICE] switch_ivr_originate.c:2868 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1004@192.168.1.103:64283) Running State Change CS_INIT (Cur 2 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1004@192.168.1.103:64283) State INIT
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] mod_sofia.c:93 sofia/internal/1004@192.168.1.103:64283 SOFIA INIT
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] sofia_glue.c:1299 sofia/internal/1004@192.168.1.103:64283 sending invite version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
554560c0-c3ee-4954-a175-84acf13cf1c9 Local SDP:
554560c0-c3ee-4954-a175-84acf13cf1c9 v=0
554560c0-c3ee-4954-a175-84acf13cf1c9 o=FreeSWITCH 1511371540 1511371541 IN IP4 192.168.1.104
554560c0-c3ee-4954-a175-84acf13cf1c9 s=FreeSWITCH
554560c0-c3ee-4954-a175-84acf13cf1c9 c=IN IP4 192.168.1.104
554560c0-c3ee-4954-a175-84acf13cf1c9 t=0 0
554560c0-c3ee-4954-a175-84acf13cf1c9 m=audio 17912 RTP/AVP 0 101
554560c0-c3ee-4954-a175-84acf13cf1c9 a=rtpmap:0 PCMU/8000
554560c0-c3ee-4954-a175-84acf13cf1c9 a=rtpmap:101 telephone-event/8000
554560c0-c3ee-4954-a175-84acf13cf1c9 a=fmtp:101 0-16
554560c0-c3ee-4954-a175-84acf13cf1c9 a=ptime:20
554560c0-c3ee-4954-a175-84acf13cf1c9 a=sendrecv
554560c0-c3ee-4954-a175-84acf13cf1c9 
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1004@192.168.1.103:64283 Standard INIT
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1004@192.168.1.103:64283) State Change CS_INIT -> CS_ROUTING
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1004@192.168.1.103:64283) State INIT going to sleep
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1004@192.168.1.103:64283) Running State Change CS_ROUTING (Cur 2 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] sofia.c:7283 Channel sofia/internal/1004@192.168.1.103:64283 entering state [calling][0]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1004@192.168.1.103:64283) State ROUTING
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] mod_sofia.c:154 sofia/internal/1004@192.168.1.103:64283 SOFIA ROUTING
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/1004@192.168.1.103:64283) State Change CS_ROUTING -> CS_CONSUME_MEDIA
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1004@192.168.1.103:64283) State ROUTING going to sleep
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1004@192.168.1.103:64283) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1004@192.168.1.103:64283) State CONSUME_MEDIA
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:12.920982 [DEBUG] switch_core_state_machine.c:662 (sofia/internal/1004@192.168.1.103:64283) State CONSUME_MEDIA going to sleep
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:13.041011 [DEBUG] sofia.c:7283 Channel sofia/internal/1004@192.168.1.103:64283 entering state [proceeding][180]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:13.041011 [NOTICE] sofia.c:7391 Ring-Ready sofia/internal/1004@192.168.1.103:64283!
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:13.041011 [DEBUG] switch_channel.c:3354 (sofia/internal/1004@192.168.1.103:64283) Callstate Change DOWN -> RINGING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:13.100992 [DEBUG] sofia.c:7283 Channel sofia/external/+12404373728@telnyxlab.com entering state [ready][200]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:13.401008 [DEBUG] switch_rtp.c:1892 rtcp_stats_init: audio ssrc[784644774] base_seq[20601]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:13.401008 [DEBUG] switch_rtp.c:7535 Correct audio ip/port confirmed.
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:17.621010 [DEBUG] switch_rtp.c:6975 Correct audio RTCP ip/port confirmed.
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] sofia.c:7283 Channel sofia/internal/1004@192.168.1.103:64283 entering state [completing][200]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] sofia.c:7293 Remote SDP:
554560c0-c3ee-4954-a175-84acf13cf1c9 v=0
554560c0-c3ee-4954-a175-84acf13cf1c9 o=- 8612313 3 IN IP4 192.168.1.103
554560c0-c3ee-4954-a175-84acf13cf1c9 s=X-Lite release 5.0.3 stamp 88254
554560c0-c3ee-4954-a175-84acf13cf1c9 c=IN IP4 192.168.1.103
554560c0-c3ee-4954-a175-84acf13cf1c9 t=0 0
554560c0-c3ee-4954-a175-84acf13cf1c9 m=audio 59440 RTP/AVP 0 101
554560c0-c3ee-4954-a175-84acf13cf1c9 a=rtpmap:101 telephone-event/8000
554560c0-c3ee-4954-a175-84acf13cf1c9 a=fmtp:101 0-15
554560c0-c3ee-4954-a175-84acf13cf1c9 
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] sofia.c:7283 Channel sofia/internal/1004@192.168.1.103:64283 entering state [ready][200]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:5466 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:5521 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:5382 Set telephone-event payload to 101@8000
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:3778 Set Codec sofia/internal/1004@192.168.1.103:64283 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_codec.c:111 sofia/internal/1004@192.168.1.103:64283 Original read codec set to PCMU:0
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:5725 Set telephone-event payload to 101@8000
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:5783 sofia/internal/1004@192.168.1.103:64283 Set 2833 dtmf send payload to 101 recv payload to 101
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:8504 AUDIO RTP [sofia/internal/1004@192.168.1.103:64283] 192.168.1.104 port 17912 -> 192.168.1.103 port 59440 codec: 0 ms: 20
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_rtp.c:4303 Starting timer [soft] 160 bytes per 20ms
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:8808 sofia/internal/1004@192.168.1.103:64283 Set 2833 dtmf send payload to 101
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:8815 sofia/internal/1004@192.168.1.103:64283 Set 2833 dtmf receive payload to 101
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:8838 sofia/internal/1004@192.168.1.103:64283 Set rtp dtmf delay to 40
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_media.c:8849 MKI Core session apply crypto (audio)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [NOTICE] sofia.c:8419 Channel [sofia/internal/1004@192.168.1.103:64283] has been answered
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_channel.c:3781 (sofia/internal/1004@192.168.1.103:64283) Callstate Change RINGING -> ACTIVE
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:18.560999 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1004@192.168.1.103:64283]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:18.560999 [DEBUG] switch_channel.c:2047 (sofia/external/+12404373728@telnyxlab.com) Callstate Change RING_WAIT -> ACTIVE
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:18.560999 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [sofia/internal/1004@192.168.1.103:64283]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_ivr_bridge.c:1744 (sofia/internal/1004@192.168.1.103:64283) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1004@192.168.1.103:64283) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1004@192.168.1.103:64283) State EXCHANGE_MEDIA
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.560999 [DEBUG] mod_sofia.c:645 SOFIA EXCHANGE_MEDIA
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:18.620999 [DEBUG] switch_rtp.c:7535 Correct audio ip/port confirmed.
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.661009 [NOTICE] sofia.c:1079 Hangup sofia/external/+12404373728@telnyxlab.com [CS_EXECUTE] [NORMAL_CLEARING]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.661009 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/external/+12404373728@telnyxlab.com]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_ivr_bridge.c:825 sofia/external/+12404373728@telnyxlab.com ending bridge by request from write function
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [sofia/internal/1004@192.168.1.103:64283]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [NOTICE] switch_ivr_bridge.c:1034 Hangup sofia/internal/1004@192.168.1.103:64283 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:653 (sofia/internal/1004@192.168.1.103:64283) State EXCHANGE_MEDIA going to sleep
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1004@192.168.1.103:64283) Running State Change CS_HANGUP (Cur 2 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1004@192.168.1.103:64283) Callstate Change ACTIVE -> HANGUP
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1004@192.168.1.103:64283) State HANGUP
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] mod_sofia.c:443 sofia/internal/1004@192.168.1.103:64283 Overriding SIP cause 480 with 200 from the other leg
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] mod_sofia.c:449 Channel sofia/internal/1004@192.168.1.103:64283 hanging up, cause: NORMAL_CLEARING
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_ivr_bridge.c:1843 sofia/internal/1004@192.168.1.103:64283 skip receive message [TRANSFER] (channel is hungup already)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_ivr_bridge.c:1846 sofia/external/+12404373728@telnyxlab.com skip receive message [TRANSFER] (channel is hungup already)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_session.c:2885 sofia/external/+12404373728@telnyxlab.com skip receive message [PHONE_EVENT] (channel is hungup already)
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:650 (sofia/external/+12404373728@telnyxlab.com) State EXECUTE going to sleep
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+12404373728@telnyxlab.com) Running State Change CS_HANGUP (Cur 2 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] mod_sofia.c:502 Sending BYE to sofia/internal/1004@192.168.1.103:64283
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1004@192.168.1.103:64283 Standard HANGUP, cause: NORMAL_CLEARING
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1004@192.168.1.103:64283) State HANGUP going to sleep
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+12404373728@telnyxlab.com) Callstate Change ACTIVE -> HANGUP
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:852 (sofia/external/+12404373728@telnyxlab.com) State HANGUP
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1004@192.168.1.103:64283) State Change CS_HANGUP -> CS_REPORTING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] mod_sofia.c:449 Channel sofia/external/+12404373728@telnyxlab.com hanging up, cause: NORMAL_CLEARING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:60 sofia/external/+12404373728@telnyxlab.com Standard HANGUP, cause: NORMAL_CLEARING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:852 (sofia/external/+12404373728@telnyxlab.com) State HANGUP going to sleep
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:619 (sofia/external/+12404373728@telnyxlab.com) State Change CS_HANGUP -> CS_REPORTING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:584 (sofia/external/+12404373728@telnyxlab.com) Running State Change CS_REPORTING (Cur 2 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1004@192.168.1.103:64283) Running State Change CS_REPORTING (Cur 2 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1004@192.168.1.103:64283) State REPORTING
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1004@192.168.1.103:64283 Standard REPORTING, cause: NORMAL_CLEARING
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1004@192.168.1.103:64283) State REPORTING going to sleep
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:938 (sofia/external/+12404373728@telnyxlab.com) State REPORTING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:174 sofia/external/+12404373728@telnyxlab.com Standard REPORTING, cause: NORMAL_CLEARING
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:938 (sofia/external/+12404373728@telnyxlab.com) State REPORTING going to sleep
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1004@192.168.1.103:64283) State Change CS_REPORTING -> CS_DESTROY
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_session.c:1713 Session 6 (sofia/internal/1004@192.168.1.103:64283) Locked, Waiting on external entities
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [NOTICE] switch_core_session.c:1731 Session 6 (sofia/internal/1004@192.168.1.103:64283) Ended
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/1004@192.168.1.103:64283 [CS_DESTROY]
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:610 (sofia/external/+12404373728@telnyxlab.com) State Change CS_REPORTING -> CS_DESTROY
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_session.c:1713 Session 4 (sofia/external/+12404373728@telnyxlab.com) Locked, Waiting on external entities
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [NOTICE] switch_core_session.c:1731 Session 4 (sofia/external/+12404373728@telnyxlab.com) Ended
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [NOTICE] switch_core_session.c:1735 Close Channel sofia/external/+12404373728@telnyxlab.com [CS_DESTROY]
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1004@192.168.1.103:64283) Running State Change CS_DESTROY (Cur 0 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1004@192.168.1.103:64283) State DESTROY
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] mod_sofia.c:354 sofia/internal/1004@192.168.1.103:64283 SOFIA DESTROY
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:741 (sofia/external/+12404373728@telnyxlab.com) Running State Change CS_DESTROY (Cur 0 Tot 6)
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1004@192.168.1.103:64283 Standard DESTROY
554560c0-c3ee-4954-a175-84acf13cf1c9 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1004@192.168.1.103:64283) State DESTROY going to sleep
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] switch_core_state_machine.c:751 (sofia/external/+12404373728@telnyxlab.com) State DESTROY
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:39.681010 [DEBUG] mod_sofia.c:354 sofia/external/+12404373728@telnyxlab.com SOFIA DESTROY
2017-11-22 22:24:42.781009 [DEBUG] switch_nat.c:568 unmapped public port 16658 protocol UDP to localport 16658
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:43.960985 [DEBUG] switch_core_state_machine.c:181 sofia/external/+12404373728@telnyxlab.com Standard DESTROY
f8076148-256d-4892-890c-8c4b133c0a27 2017-11-22 22:24:43.960985 [DEBUG] switch_core_state_machine.c:751 (sofia/external/+12404373728@telnyxlab.com) State DESTROY going to sleep
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.321011 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/00@86.153.193.35 [f1d44685-43ba-422c-b80b-c7d6120bdffd]
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.321011 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_NEW (Cur 1 Tot 7)
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.321011 [DEBUG] sofia.c:10070 sofia/internal/00@86.153.193.35 receiving invite from 195.154.183.114:59688 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:26:05.321011 [DEBUG] sofia.c:10241 IP 195.154.183.114 Rejected by acl "domains". Falling back to Digest auth.
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.321011 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/00@86.153.193.35) State NEW
2017-11-22 22:26:05.321011 [DEBUG] sofia.c:2405 detaching session f1d44685-43ba-422c-b80b-c7d6120bdffd
2017-11-22 22:26:05.400995 [DEBUG] sofia.c:2514 Re-attaching to session f1d44685-43ba-422c-b80b-c7d6120bdffd
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.400995 [DEBUG] sofia.c:10070 sofia/internal/00@86.153.193.35 receiving invite from 195.154.183.114:59688 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:26:05.400995 [DEBUG] sofia.c:10241 IP 195.154.183.114 Rejected by acl "domains". Falling back to Digest auth.
2017-11-22 22:26:05.400995 [WARNING] sofia_reg.c:2906 Can't find user [00@192.168.1.104] from 195.154.183.114
You must define a domain called '192.168.1.104' in your directory and add a user with the id="00" attribute
and you must configure your device to use the proper domain in it's authentication credentials.
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.400995 [NOTICE] sofia.c:2403 Hangup sofia/internal/00@86.153.193.35 [CS_NEW] [CALL_REJECTED]
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] sofia.c:1521 Channel is already hungup.
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_HANGUP (Cur 1 Tot 7)
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/00@86.153.193.35) Callstate Change DOWN -> HANGUP
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/00@86.153.193.35) State HANGUP
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] mod_sofia.c:449 Channel sofia/internal/00@86.153.193.35 hanging up, cause: CALL_REJECTED
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:60 sofia/internal/00@86.153.193.35 Standard HANGUP, cause: CALL_REJECTED
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/00@86.153.193.35) State HANGUP going to sleep
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/00@86.153.193.35) State Change CS_HANGUP -> CS_REPORTING
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_REPORTING (Cur 1 Tot 7)
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/00@86.153.193.35) State REPORTING
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:174 sofia/internal/00@86.153.193.35 Standard REPORTING, cause: CALL_REJECTED
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/00@86.153.193.35) State REPORTING going to sleep
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/00@86.153.193.35) State Change CS_REPORTING -> CS_DESTROY
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_session.c:1713 Session 7 (sofia/internal/00@86.153.193.35) Locked, Waiting on external entities
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [NOTICE] switch_core_session.c:1731 Session 7 (sofia/internal/00@86.153.193.35) Ended
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/00@86.153.193.35 [CS_DESTROY]
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/00@86.153.193.35) Running State Change CS_DESTROY (Cur 0 Tot 7)
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/00@86.153.193.35) State DESTROY
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] mod_sofia.c:354 sofia/internal/00@86.153.193.35 SOFIA DESTROY
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:181 sofia/internal/00@86.153.193.35 Standard DESTROY
f1d44685-43ba-422c-b80b-c7d6120bdffd 2017-11-22 22:26:05.420996 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/00@86.153.193.35) State DESTROY going to sleep
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:15.281007 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/43003@86.153.193.35 [45aad512-5a1a-428f-841a-e16051a1efe1]
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:15.281007 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/43003@86.153.193.35) Running State Change CS_NEW (Cur 1 Tot 8)
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:15.281007 [DEBUG] sofia.c:10070 sofia/internal/43003@86.153.193.35 receiving invite from 185.40.4.130:5070 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:26:15.281007 [DEBUG] sofia.c:10241 IP 185.40.4.130 Rejected by acl "domains". Falling back to Digest auth.
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:15.281007 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/43003@86.153.193.35) State NEW
2017-11-22 22:26:15.281007 [DEBUG] sofia.c:2405 detaching session 45aad512-5a1a-428f-841a-e16051a1efe1
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [WARNING] switch_core_state_machine.c:687 45aad512-5a1a-428f-841a-e16051a1efe1 sofia/internal/43003@86.153.193.35 Abandoned
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/internal/43003@86.153.193.35 [CS_NEW] [WRONG_CALL_STATE]
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/43003@86.153.193.35) Running State Change CS_HANGUP (Cur 1 Tot 8)
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/43003@86.153.193.35) Callstate Change DOWN -> HANGUP
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/43003@86.153.193.35) State HANGUP
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] mod_sofia.c:449 Channel sofia/internal/43003@86.153.193.35 hanging up, cause: WRONG_CALL_STATE
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:60 sofia/internal/43003@86.153.193.35 Standard HANGUP, cause: WRONG_CALL_STATE
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/43003@86.153.193.35) State HANGUP going to sleep
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/43003@86.153.193.35) State Change CS_HANGUP -> CS_REPORTING
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/43003@86.153.193.35) Running State Change CS_REPORTING (Cur 1 Tot 8)
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/43003@86.153.193.35) State REPORTING
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:174 sofia/internal/43003@86.153.193.35 Standard REPORTING, cause: WRONG_CALL_STATE
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/43003@86.153.193.35) State REPORTING going to sleep
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/43003@86.153.193.35) State Change CS_REPORTING -> CS_DESTROY
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_session.c:1713 Session 8 (sofia/internal/43003@86.153.193.35) Locked, Waiting on external entities
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [NOTICE] switch_core_session.c:1731 Session 8 (sofia/internal/43003@86.153.193.35) Ended
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/43003@86.153.193.35 [CS_DESTROY]
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/43003@86.153.193.35) Running State Change CS_DESTROY (Cur 0 Tot 8)
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/43003@86.153.193.35) State DESTROY
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] mod_sofia.c:354 sofia/internal/43003@86.153.193.35 SOFIA DESTROY
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:181 sofia/internal/43003@86.153.193.35 Standard DESTROY
45aad512-5a1a-428f-841a-e16051a1efe1 2017-11-22 22:26:25.301008 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/43003@86.153.193.35) State DESTROY going to sleep
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.281007 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/00@86.153.193.35 [ae1a1ec2-7be9-4a74-97df-93eb60271dfd]
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.281007 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_NEW (Cur 1 Tot 9)
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.281007 [DEBUG] sofia.c:10070 sofia/internal/00@86.153.193.35 receiving invite from 195.154.183.114:56989 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:27:40.281007 [DEBUG] sofia.c:10241 IP 195.154.183.114 Rejected by acl "domains". Falling back to Digest auth.
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.281007 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/00@86.153.193.35) State NEW
2017-11-22 22:27:40.281007 [DEBUG] sofia.c:2405 detaching session ae1a1ec2-7be9-4a74-97df-93eb60271dfd
2017-11-22 22:27:40.340993 [DEBUG] sofia.c:2514 Re-attaching to session ae1a1ec2-7be9-4a74-97df-93eb60271dfd
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.361008 [DEBUG] sofia.c:10070 sofia/internal/00@86.153.193.35 receiving invite from 195.154.183.114:56989 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:27:40.361008 [DEBUG] sofia.c:10241 IP 195.154.183.114 Rejected by acl "domains". Falling back to Digest auth.
2017-11-22 22:27:40.361008 [WARNING] sofia_reg.c:2906 Can't find user [00@192.168.1.104] from 195.154.183.114
You must define a domain called '192.168.1.104' in your directory and add a user with the id="00" attribute
and you must configure your device to use the proper domain in it's authentication credentials.
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.361008 [NOTICE] sofia.c:2403 Hangup sofia/internal/00@86.153.193.35 [CS_NEW] [CALL_REJECTED]
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] sofia.c:1521 Channel is already hungup.
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_HANGUP (Cur 1 Tot 9)
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/00@86.153.193.35) Callstate Change DOWN -> HANGUP
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/00@86.153.193.35) State HANGUP
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] mod_sofia.c:449 Channel sofia/internal/00@86.153.193.35 hanging up, cause: CALL_REJECTED
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:60 sofia/internal/00@86.153.193.35 Standard HANGUP, cause: CALL_REJECTED
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/00@86.153.193.35) State HANGUP going to sleep
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/00@86.153.193.35) State Change CS_HANGUP -> CS_REPORTING
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_REPORTING (Cur 1 Tot 9)
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/00@86.153.193.35) State REPORTING
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:174 sofia/internal/00@86.153.193.35 Standard REPORTING, cause: CALL_REJECTED
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/00@86.153.193.35) State REPORTING going to sleep
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/00@86.153.193.35) State Change CS_REPORTING -> CS_DESTROY
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_session.c:1713 Session 9 (sofia/internal/00@86.153.193.35) Locked, Waiting on external entities
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [NOTICE] switch_core_session.c:1731 Session 9 (sofia/internal/00@86.153.193.35) Ended
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/00@86.153.193.35 [CS_DESTROY]
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/00@86.153.193.35) Running State Change CS_DESTROY (Cur 0 Tot 9)
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/00@86.153.193.35) State DESTROY
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] mod_sofia.c:354 sofia/internal/00@86.153.193.35 SOFIA DESTROY
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:181 sofia/internal/00@86.153.193.35 Standard DESTROY
ae1a1ec2-7be9-4a74-97df-93eb60271dfd 2017-11-22 22:27:40.380992 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/00@86.153.193.35) State DESTROY going to sleep
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.760983 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/00@86.153.193.35 [b2e868a6-0588-460a-95e8-05ac6c7bb126]
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.760983 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_NEW (Cur 1 Tot 10)
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.760983 [DEBUG] sofia.c:10070 sofia/internal/00@86.153.193.35 receiving invite from 195.154.183.114:65495 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:29:04.760983 [DEBUG] sofia.c:10241 IP 195.154.183.114 Rejected by acl "domains". Falling back to Digest auth.
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.760983 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/00@86.153.193.35) State NEW
2017-11-22 22:29:04.760983 [DEBUG] sofia.c:2405 detaching session b2e868a6-0588-460a-95e8-05ac6c7bb126
2017-11-22 22:29:04.840983 [DEBUG] sofia.c:2514 Re-attaching to session b2e868a6-0588-460a-95e8-05ac6c7bb126
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.860984 [DEBUG] sofia.c:10070 sofia/internal/00@86.153.193.35 receiving invite from 195.154.183.114:65495 version: 1.9.0 git 0de68cc 2017-11-21 22:50:40Z 64bit
2017-11-22 22:29:04.860984 [DEBUG] sofia.c:10241 IP 195.154.183.114 Rejected by acl "domains". Falling back to Digest auth.
2017-11-22 22:29:04.860984 [WARNING] sofia_reg.c:2906 Can't find user [00@192.168.1.104] from 195.154.183.114
You must define a domain called '192.168.1.104' in your directory and add a user with the id="00" attribute
and you must configure your device to use the proper domain in it's authentication credentials.
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.860984 [NOTICE] sofia.c:2403 Hangup sofia/internal/00@86.153.193.35 [CS_NEW] [CALL_REJECTED]
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] sofia.c:1521 Channel is already hungup.
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_HANGUP (Cur 1 Tot 10)
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/00@86.153.193.35) Callstate Change DOWN -> HANGUP
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/00@86.153.193.35) State HANGUP
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] mod_sofia.c:449 Channel sofia/internal/00@86.153.193.35 hanging up, cause: CALL_REJECTED
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:60 sofia/internal/00@86.153.193.35 Standard HANGUP, cause: CALL_REJECTED
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/00@86.153.193.35) State HANGUP going to sleep
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/00@86.153.193.35) State Change CS_HANGUP -> CS_REPORTING
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/00@86.153.193.35) Running State Change CS_REPORTING (Cur 1 Tot 10)
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/00@86.153.193.35) State REPORTING
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:174 sofia/internal/00@86.153.193.35 Standard REPORTING, cause: CALL_REJECTED
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/00@86.153.193.35) State REPORTING going to sleep
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/00@86.153.193.35) State Change CS_REPORTING -> CS_DESTROY
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_session.c:1713 Session 10 (sofia/internal/00@86.153.193.35) Locked, Waiting on external entities
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [NOTICE] switch_core_session.c:1731 Session 10 (sofia/internal/00@86.153.193.35) Ended
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [NOTICE] switch_core_session.c:1735 Close Channel sofia/internal/00@86.153.193.35 [CS_DESTROY]
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/00@86.153.193.35) Running State Change CS_DESTROY (Cur 0 Tot 10)
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/00@86.153.193.35) State DESTROY
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] mod_sofia.c:354 sofia/internal/00@86.153.193.35 SOFIA DESTROY
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:181 sofia/internal/00@86.153.193.35 Standard DESTROY
b2e868a6-0588-460a-95e8-05ac6c7bb126 2017-11-22 22:29:04.880994 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/00@86.153.193.35) State DESTROY going to sleep