Fusion Inbound Calls not Completing

Hello Fusion fam,
I have been banging my head on the wall for the past weeks on getting inbound calls to work. outbound works successfully. I have searched this entire site for anything to help me resolve, however i am still working pass being a new on learning fusion. I have created my inbound routes, also added my carrier ip in my ACL. i have attached screen shots ans logs for all I mentioned. My fusion is NATTING so I changed the external rtp ans sip IP's to a public IP. i also changed it on the variables, and internal and external profiles. the first logs are for inbound call. the second is if i call my IVR, in which if i call internally it is dead air.



Code:
2019-12-02 12:08:41.754071 [WARNING] sofia_reg.c:2906 Can't find user [4045853518@96.70.2.142] from 64.154.41.177
You must define a domain called '96.70.2.142' in your directory and add a user with the id="4045853518" attribute
and you must configure your device to use the proper domain in it's authentication credentials.
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.754071 [NOTICE] sofia.c:2332 Hangup sofia/external/9182707000@64.154.41.177 [CS_NEW] [CALL_REJECTED]
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] sofia.c:1453 Channel is already hungup.
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9182707000@64.154.41.177) Running State Change CS_HANGUP (Cur 1 Tot 167)
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:850 (sofia/external/9182707000@64.154.41.177) Callstate Change DOWN -> HANGUP
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:852 (sofia/external/9182707000@64.154.41.177) State HANGUP
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] mod_sofia.c:438 Channel sofia/external/9182707000@64.154.41.177 hanging up, cause: CALL_REJECTED
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:60 sofia/external/9182707000@64.154.41.177 Standard HANGUP, cause: CALL_REJECTED
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:852 (sofia/external/9182707000@64.154.41.177) State HANGUP going to sleep
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:619 (sofia/external/9182707000@64.154.41.177) State Change CS_HANGUP -> CS_REPORTING
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:584 (sofia/external/9182707000@64.154.41.177) Running State Change CS_REPORTING (Cur 1 Tot 167)
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:938 (sofia/external/9182707000@64.154.41.177) State REPORTING
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:174 sofia/external/9182707000@64.154.41.177 Standard REPORTING, cause: CALL_REJECTED
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:938 (sofia/external/9182707000@64.154.41.177) State REPORTING going to sleep
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:610 (sofia/external/9182707000@64.154.41.177) State Change CS_REPORTING -> CS_DESTROY
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_session.c:1665 Session 167 (sofia/external/9182707000@64.154.41.177) Locked, Waiting on external entities
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [NOTICE] switch_core_session.c:1683 Session 167 (sofia/external/9182707000@64.154.41.177) Ended
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/9182707000@64.154.41.177 [CS_DESTROY]
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:741 (sofia/external/9182707000@64.154.41.177) Running State Change CS_DESTROY (Cur 0 Tot 167)
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:751 (sofia/external/9182707000@64.154.41.177) State DESTROY
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] mod_sofia.c:343 sofia/external/9182707000@64.154.41.177 SOFIA DESTROY
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:181 sofia/external/9182707000@64.154.41.177 Standard DESTROY
63e4ec12-1526-11ea-a3d8-855aaeba9100 2019-12-02 12:08:41.774119 [DEBUG] switch_core_state_machine.c:751 (sofia/external/9182707000@64.154.41.177) State DESTROY going to sleep
2019-12-02 12:30:35.954117 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [*97@10.1.10.94] from ip 10.1.10.87
 

Attached Files:

Last edited:
Code:
For IVR calling.
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.334145 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1001@10.1.10.94:5060 [7710462a-152f-11ea-a3de-855aaeba9100]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.334145 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.1.10.94:5060) Running State Change CS_NEW (Cur 1 Tot 168)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.334145 [DEBUG] sofia.c:9873 sofia/internal/1001@10.1.10.94:5060 receiving invite from 10.1.10.87:5060 version: 1.6.20 64bit
2019-12-02 13:13:39.334145 [DEBUG] sofia.c:10044 IP 10.1.10.87 Rejected by acl "domains". Falling back to Digest auth.
2019-12-02 13:13:39.334145 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [3000@10.1.10.94] from ip 10.1.10.87
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.334145 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1001@10.1.10.94:5060) State NEW
2019-12-02 13:13:39.334145 [DEBUG] sofia.c:2334 detaching session 7710462a-152f-11ea-a3de-855aaeba9100
2019-12-02 13:13:39.354073 [DEBUG] sofia.c:2442 Re-attaching to session 7710462a-152f-11ea-a3de-855aaeba9100
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] sofia.c:9873 sofia/internal/1001@10.1.10.94:5060 receiving invite from 10.1.10.87:5060 version: 1.6.20 64bit
2019-12-02 13:13:39.374122 [DEBUG] sofia.c:10044 IP 10.1.10.87 Rejected by acl "domains". Falling back to Digest auth.
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@10.1.10.94:5060 entering state [received][100]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] sofia.c:7094 Remote SDP:
7710462a-152f-11ea-a3de-855aaeba9100 v=0
7710462a-152f-11ea-a3de-855aaeba9100 o=- 20003 20003 IN IP4 10.1.10.87
7710462a-152f-11ea-a3de-855aaeba9100 s=SDP data
7710462a-152f-11ea-a3de-855aaeba9100 c=IN IP4 10.1.10.87
7710462a-152f-11ea-a3de-855aaeba9100 t=0 0
7710462a-152f-11ea-a3de-855aaeba9100 m=audio 12188 RTP/AVP 0 8 18 9 101
7710462a-152f-11ea-a3de-855aaeba9100 a=rtpmap:0 PCMU/8000
7710462a-152f-11ea-a3de-855aaeba9100 a=rtpmap:8 PCMA/8000
7710462a-152f-11ea-a3de-855aaeba9100 a=rtpmap:18 G729/8000
7710462a-152f-11ea-a3de-855aaeba9100 a=fmtp:18 mode=20
7710462a-152f-11ea-a3de-855aaeba9100 a=rtpmap:9 G722/8000
7710462a-152f-11ea-a3de-855aaeba9100 a=rtpmap:101 telephone-event/8000
7710462a-152f-11ea-a3de-855aaeba9100 a=fmtp:101 0-15
7710462a-152f-11ea-a3de-855aaeba9100 a=altc:1 IP4 10.1.10.87 12188
7710462a-152f-11ea-a3de-855aaeba9100 a=altc:2 IP6 2603:3001:2bb7:2000:215:65ff:feb1:75d5 12188
7710462a-152f-11ea-a3de-855aaeba9100 a=ptime:20
7710462a-152f-11ea-a3de-855aaeba9100
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G7221:115:32000:20:48000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G7221:107:16000:20:32000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G7221:115:32000:20:48000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G7221:107:16000:20:32000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/1001@10.1.10.94:5060 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_codec.c:111 sofia/internal/1001@10.1.10.94:5060 Original read codec set to PCMU:0
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_media.c:4767 sofia/internal/1001@10.1.10.94:5060 Set 2833 dtmf send payload to 101 recv payload to 101
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] sofia.c:7507 (sofia/internal/1001@10.1.10.94:5060) State Change CS_NEW -> CS_INIT
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.1.10.94:5060) Running State Change CS_INIT (Cur 1 Tot 168)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@10.1.10.94:5060) State INIT
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] mod_sofia.c:90 sofia/internal/1001@10.1.10.94:5060 SOFIA INIT
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1001@10.1.10.94:5060 Standard INIT
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1001@10.1.10.94:5060) State Change CS_INIT -> CS_ROUTING
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1001@10.1.10.94:5060) State INIT going to sleep
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.1.10.94:5060) Running State Change CS_ROUTING (Cur 1 Tot 168)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_channel.c:2249 (sofia/internal/1001@10.1.10.94:5060) Callstate Change DOWN -> RINGING
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@10.1.10.94:5060) State ROUTING
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] mod_sofia.c:143 sofia/internal/1001@10.1.10.94:5060 SOFIA ROUTING
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1001@10.1.10.94:5060 Standard ROUTING
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.374122 [INFO] mod_dialplan_xml.c:637 Processing Priscilla Nunn <1001>->3000 in context 10.1.10.94
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->user_exists] continue=true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [user_exists] () =~ // break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
2019-12-02 13:13:39.394074 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7ff4f407e2c0 Connected.
2019-12-02 13:13:39.394074 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7ff4f407e2c0 released.
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(user_exists=false)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [user_exists]=[false]
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(from_user_exists=true)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [from_user_exists]=[true]
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->caller-details] continue=true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(caller_destination=${destination_number}) INLINE
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(caller_destination=3000)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [caller_destination]=[3000]
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(caller_id_name=${caller_id_name}) INLINE
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(caller_id_name=1001)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [caller_id_name]=[1001]
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(caller_id_number=${caller_id_number})
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->call-direction] continue=true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 ANTI-Action export(call_direction=local) INLINE
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 export(call_direction=local)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[local]
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->variables] continue=true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [variables] () =~ // break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action export(origination_callee_id_name=${destination_number})
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->is_loopback] continue=true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->user_record] continue=true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(from_user_record=)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [from_user_record]=[UNDEF]
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->redial] continue=true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [redial] destination_number(3000) =~ /^(redial|\*870)$/ break=on-true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [redial] () =~ // break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->speed_dial] continue=false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [speed_dial] destination_number(3000) =~ /^\*0(.*)$/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->default_caller_id] continue=true
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(emergency_caller_id_name=)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [emergency_caller_id_name]=[UNDEF]
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(emergency_caller_id_number=)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [emergency_caller_id_number]=[UNDEF]
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(4045853528) =~ /^$/ break=never
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->ipcomms.10d] continue=false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [ipcomms.10d] ${user_exists}(false) =~ /false/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [ipcomms.10d] destination_number(3000) =~ /^(\d{10})$/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->ipcomms.11d] continue=false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [ipcomms.11d] ${user_exists}(false) =~ /false/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (FAIL) [ipcomms.11d] destination_number(3000) =~ /^\+?(\d{11})$/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 parsing [10.1.10.94->Auto Attendant] continue=false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Regex (PASS) [Auto Attendant] destination_number(3000) =~ /^3000$/ break=on-false
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action ring_ready()
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action answer()
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action sleep(1000)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(hangup_after_bridge=true)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(ringback=local_stream://default)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(presence_id=3000@10.1.10.94)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(default_language=en)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(default_dialect=us)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(default_voice=callie)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(transfer_ringback=local_stream://default)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action set(ivr_menu_uuid=4c862d4f-67d6-4cbd-aab1-7e3a54f9c54a)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action ivr(4c862d4f-67d6-4cbd-aab1-7e3a54f9c54a)
7710462a-152f-11ea-a3de-855aaeba9100 Dialplan: sofia/internal/1001@10.1.10.94:5060 Action hangup()
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/1001@10.1.10.94:5060) State Change CS_ROUTING -> CS_EXECUTE
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1001@10.1.10.94:5060) State ROUTING going to sleep
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1001@10.1.10.94:5060) Running State Change CS_EXECUTE (Cur 1 Tot 168)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/1001@10.1.10.94:5060) State EXECUTE
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_sofia.c:198 sofia/internal/1001@10.1.10.94:5060 SOFIA EXECUTE
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_state_machine.c:328 sofia/internal/1001@10.1.10.94:5060 Standard EXECUTE
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(caller_id_number=1001)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [caller_id_number]=[1001]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 export(origination_callee_id_name=3000)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[3000]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(RFC2822_DATE=Mon, 02 Dec 2019 13:13:39 -0500)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [RFC2822_DATE]=[Mon, 02 Dec 2019 13:13:39 -0500]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 hash(insert/10.1.10.94-last_dial/1001/3000)
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 ring_ready()
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/internal/1001@10.1.10.94:5060!
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@10.1.10.94:5060 entering state [early][180]
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [NOTICE] mod_dptools.c:1028 Ring Ready sofia/internal/1001@10.1.10.94:5060!
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 answer()
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/internal/1001@10.1.10.94:5060] 10.1.10.94 port 21668 -> 10.1.10.87 port 12188 codec: 0 ms: 20
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_rtp.c:4137 Starting timer [soft] 160 bytes per 20ms
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_media.c:7180 sofia/internal/1001@10.1.10.94:5060 Set 2833 dtmf send payload to 101
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_media.c:7187 sofia/internal/1001@10.1.10.94:5060 Set 2833 dtmf receive payload to 101
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_core_media.c:7210 sofia/internal/1001@10.1.10.94:5060 Set rtp dtmf delay to 40
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] mod_sofia.c:850 Local SDP sofia/internal/1001@10.1.10.94:5060:
7710462a-152f-11ea-a3de-855aaeba9100 v=0
7710462a-152f-11ea-a3de-855aaeba9100 o=FreeSWITCH 1575288751 1575288752 IN IP4 10.1.10.94
7710462a-152f-11ea-a3de-855aaeba9100 s=FreeSWITCH
7710462a-152f-11ea-a3de-855aaeba9100 c=IN IP4 10.1.10.94
7710462a-152f-11ea-a3de-855aaeba9100 t=0 0
7710462a-152f-11ea-a3de-855aaeba9100 m=audio 21668 RTP/AVP 0 101
7710462a-152f-11ea-a3de-855aaeba9100 a=rtpmap:0 PCMU/8000
7710462a-152f-11ea-a3de-855aaeba9100 a=rtpmap:101 telephone-event/8000
7710462a-152f-11ea-a3de-855aaeba9100 a=fmtp:101 0-16
7710462a-152f-11ea-a3de-855aaeba9100 a=ptime:20
7710462a-152f-11ea-a3de-855aaeba9100 a=sendrecv
7710462a-152f-11ea-a3de-855aaeba9100
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [NOTICE] mod_dptools.c:1312 Channel [sofia/internal/1001@10.1.10.94:5060] has been answered
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] switch_channel.c:3773 (sofia/internal/1001@10.1.10.94:5060) Callstate Change RINGING -> ACTIVE
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.394074 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@10.1.10.94:5060 entering state [completed][200]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 sleep(1000)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.954108 [DEBUG] switch_rtp.c:7308 Correct audio ip/port confirmed.
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:39.954108 [DEBUG] sofia.c:7084 Channel sofia/internal/1001@10.1.10.94:5060 entering state [ready][200]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(hangup_after_bridge=true)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.394145 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [hangup_after_bridge]=[true]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(ringback=local_stream://default)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.394145 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [ringback]=[local_stream://default]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(presence_id=3000@10.1.10.94)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.394145 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [presence_id]=[3000@10.1.10.94]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(default_language=en)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.394145 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [default_language]=[en]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(default_dialect=us)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.394145 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [default_dialect]=[us]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(default_voice=callie)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.394145 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [default_voice]=[callie]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(transfer_ringback=local_stream://default)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.394145 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [transfer_ringback]=[local_stream://default]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 set(ivr_menu_uuid=4c862d4f-67d6-4cbd-aab1-7e3a54f9c54a)
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.394145 [DEBUG] mod_dptools.c:1548 SET sofia/internal/1001@10.1.10.94:5060 [ivr_menu_uuid]=[4c862d4f-67d6-4cbd-aab1-7e3a54f9c54a]
7710462a-152f-11ea-a3de-855aaeba9100 EXECUTE sofia/internal/1001@10.1.10.94:5060 ivr(4c862d4f-67d6-4cbd-aab1-7e3a54f9c54a)
2019-12-02 13:13:40.394145 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7ff4f407e2c0 Connected.
2019-12-02 13:13:40.414072 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7ff4f407e2c0 released.
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-exit'
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-sub'
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-exec-app'
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-play-sound'
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-back'
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:743 switch_ivr_menu_stack_xml_add binding 'menu-top'
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:880 building menu '4c862d4f-67d6-4cbd-aab1-7e3a54f9c54a'
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '1'
2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:964 binding menu action 'menu-exec-app' to '2'
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:483 Executing IVR menu 4c862d4f-67d6-4cbd-aab1-7e3a54f9c54a
2019-12-02 13:13:40.414072 [ERR] switch_core_speech.c:62 Invalid speech module [flite]!
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.414072 [ERR] switch_ivr_play_say.c:3008 Invalid TTS module!
7710462a-152f-11ea-a3de-855aaeba9100 2019-12-02 13:13:40.414072 [DEBUG] switch_ivr_menu.c:377 waiting for 5/5 digits t/o 2000