SOLVED Cause: NORMAL_TEMPORARY_FAILURE

Status
Not open for further replies.
R

rjunaid

Member
Oct 18, 2019
35
0
6
25
Hey experts, i am trying outbound call with TWILIO i have configured my Gateway and outbound route but when i try to call i get this "Normal_Temporary_Failure", i have attched call logs down below.
Any idea what it could be??


Local SDP:
v=0
o=FreeSWITCH 1582497704 1582497705 IN IP4 147.135.59.15
s=FreeSWITCH
c=IN IP4 147.135.59.15
t=0 0
m=audio 27560 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:eek:ff - - - -
a=ptime:20
a=sendrecv

2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:40 sofia/external/$1 Standard INIT
2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:48 (sofia/external/$1) State Change CS_INIT -> CS_ROUTING
2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:628 (sofia/external/$1) State INIT going to sleep
2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:585 (sofia/external/$1) Running State Change CS_ROUTING (Cur 2 Tot 908)
2020-02-24 01:21:04.727110 [DEBUG] sofia.c:7301 Channel sofia/external/$1 entering state [calling][0]
2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:644 (sofia/external/$1) State ROUTING
2020-02-24 01:21:04.727110 [DEBUG] mod_sofia.c:154 sofia/external/$1 SOFIA ROUTING
2020-02-24 01:21:04.727110 [DEBUG] switch_ivr_originate.c:67 (sofia/external/$1) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:644 (sofia/external/$1) State ROUTING going to sleep
2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:585 (sofia/external/$1) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 908)
2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:663 (sofia/external/$1) State CONSUME_MEDIA
2020-02-24 01:21:04.727110 [DEBUG] switch_core_state_machine.c:663 (sofia/external/$1) State CONSUME_MEDIA going to sleep
2020-02-24 01:21:04.967167 [DEBUG] sofia.c:7301 Channel sofia/external/$1 entering state [calling][0]
2020-02-24 01:21:05.087128 [DEBUG] sofia.c:7301 Channel sofia/external/$1 entering state [terminated][400]
2020-02-24 01:21:05.087128 [NOTICE] sofia.c:8534 Hangup sofia/external/$1 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:585 (sofia/external/$1) Running State Change CS_HANGUP (Cur 2 Tot 908)
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:848 (sofia/external/$1) Callstate Change DOWN -> HANGUP
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:850 (sofia/external/$1) State HANGUP
2020-02-24 01:21:05.087128 [DEBUG] mod_sofia.c:453 Channel sofia/external/$1 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:60 sofia/external/$1 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:850 (sofia/external/$1) State HANGUP going to sleep
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:620 (sofia/external/$1) State Change CS_HANGUP -> CS_REPORTING
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:585 (sofia/external/$1) Running State Change CS_REPORTING (Cur 2 Tot 908)
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:936 (sofia/external/$1) State REPORTING
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:174 sofia/external/$1 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:936 (sofia/external/$1) State REPORTING going to sleep
2020-02-24 01:21:05.087128 [DEBUG] switch_core_state_machine.c:611 (sofia/external/$1) State Change CS_REPORTING -> CS_DESTROY
2020-02-24 01:21:05.087128 [DEBUG] switch_core_session.c:1726 Session 908 (sofia/external/$1) Locked, Waiting on external entities
2020-02-24 01:21:05.107158 [DEBUG] switch_ivr_originate.c:3952 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2020-02-24 01:21:05.107158 [INFO] mod_dptools.c:3631 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE
2020-02-24 01:21:05.107158 [NOTICE] switch_core_state_machine.c:386 sofia/external/100@147.135.59.15 has executed the last dialplan instruction, hanging up.
2020-02-24 01:21:05.107158 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/external/100@147.135.59.15 [CS_EXECUTE] [NORMAL_CLEARING]
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@147.135.59.15) State EXECUTE going to sleep
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@147.135.59.15) Running State Change CS_HANGUP (Cur 2 Tot 908)
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:848 (sofia/external/100@147.135.59.15) Callstate Change RINGING -> HANGUP
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@147.135.59.15) State HANGUP
2020-02-24 01:21:05.107158 [DEBUG] mod_sofia.c:447 sofia/external/100@147.135.59.15 Overriding SIP cause 480 with 400 from the other leg
2020-02-24 01:21:05.107158 [DEBUG] mod_sofia.c:453 Channel sofia/external/100@147.135.59.15 hanging up, cause: NORMAL_CLEARING
2020-02-24 01:21:05.107158 [DEBUG] mod_sofia.c:598 Responding to INVITE with: 400
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:60 sofia/external/100@147.135.59.15 Standard HANGUP, cause: NORMAL_CLEARING
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@147.135.59.15) State HANGUP going to sleep
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:620 (sofia/external/100@147.135.59.15) State Change CS_HANGUP -> CS_REPORTING
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@147.135.59.15) Running State Change CS_REPORTING (Cur 2 Tot 908)
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@147.135.59.15) State REPORTING
2020-02-24 01:21:05.107158 [NOTICE] switch_core_session.c:1744 Session 908 (sofia/external/$1) Ended
2020-02-24 01:21:05.107158 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/$1 [CS_DESTROY]
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:739 (sofia/external/$1) Running State Change CS_DESTROY (Cur 1 Tot 908)
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:749 (sofia/external/$1) State DESTROY
2020-02-24 01:21:05.107158 [DEBUG] mod_sofia.c:364 sofia/external/$1 SOFIA DESTROY
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:181 sofia/external/$1 Standard DESTROY
2020-02-24 01:21:05.107158 [DEBUG] switch_core_state_machine.c:749 (sofia/external/$1) State DESTROY going to sleep
2020-02-24 01:21:05.187145 [DEBUG] switch_core_state_machine.c:174 sofia/external/100@147.135.59.15 Standard REPORTING, cause: NORMAL_CLEARING
2020-02-24 01:21:05.187145 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@147.135.59.15) State REPORTING going to sleep
2020-02-24 01:21:05.187145 [DEBUG] switch_core_state_machine.c:611 (sofia/external/100@147.135.59.15) State Change CS_REPORTING -> CS_DESTROY
2020-02-24 01:21:05.187145 [DEBUG] switch_core_session.c:1726 Session 907 (sofia/external/100@147.135.59.15) Locked, Waiting on external entities
2020-02-24 01:21:05.187145 [NOTICE] switch_core_session.c:1744 Session 907 (sofia/external/100@147.135.59.15) Ended
2020-02-24 01:21:05.187145 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/100@147.135.59.15 [CS_DESTROY]
2020-02-24 01:21:05.187145 [DEBUG] switch_core_state_machine.c:739 (sofia/external/100@147.135.59.15) Running State Change CS_DESTROY (Cur 0 Tot 908)
2020-02-24 01:21:05.187145 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@147.135.59.15) State DESTROY
2020-02-24 01:21:05.187145 [DEBUG] mod_sofia.c:364 sofia/external/100@147.135.59.15 SOFIA DESTROY
2020-02-24 01:21:05.187145 [DEBUG] switch_core_state_machine.c:181 sofia/external/100@147.135.59.15 Standard DESTROY
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
Dunno what you have set there but looks like your $1 isn't being expanded. Also... have you modified your ACL, there is not enough log there to understand whats going on, you have only shown part of the call.
 
R

rjunaid

Member
Oct 18, 2019
35
0
6
25
Thanks Daz for replying no i've not add any ACL yet do you think it could be ACL? and also $1 sign isn't expanded what's that mean is? On my softphone screen when i dial DID i get Call failed bad request
Btw here's full logs

2020-02-24 01:40:09.127128 [NOTICE] switch_channel.c:1118 New Channel sofia/external/100@147.135.59.15 [2658a087-95f4-46a5-b564-6981b8e97829]
2020-02-24 01:40:09.127128 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@147.135.59.15) Running State Change CS_NEW (Cur 1 Tot 994)
2020-02-24 01:40:09.127128 [DEBUG] sofia.c:10255 sofia/external/100@147.135.59.15 receiving invite from 122.129.75.131:23485 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-02-24 01:40:09.127128 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port 122.129.75.131:0.
2020-02-24 01:40:09.127128 [DEBUG] sofia.c:2434 detaching session 2658a087-95f4-46a5-b564-6981b8e97829
2020-02-24 01:40:09.127128 [DEBUG] switch_core_state_machine.c:604 (sofia/external/100@147.135.59.15) State NEW
2020-02-24 01:40:09.507154 [DEBUG] sofia.c:2544 Re-attaching to session 2658a087-95f4-46a5-b564-6981b8e97829
2020-02-24 01:40:09.527193 [DEBUG] sofia.c:10255 sofia/external/100@147.135.59.15 receiving invite from 122.129.75.131:23485 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-02-24 01:40:09.527193 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port 122.129.75.131:0.
2020-02-24 01:40:09.527193 [DEBUG] sofia.c:11452 Setting NAT mode based on nat.auto
2020-02-24 01:40:09.527193 [DEBUG] sofia.c:7301 Channel sofia/external/100@147.135.59.15 entering state [received][100]
2020-02-24 01:40:09.527193 [DEBUG] sofia.c:7311 Remote SDP:
v=0
o=- 0 2 IN IP4 192.168.1.203
s=CounterPath X-Lite 3.0
c=IN IP4 192.168.1.203
t=0 0
m=audio 3692 RTP/AVP 107 119 0 98 8 3 101
a=rtpmap:107 BV32/16000
a=rtpmap:119 BV32-FEC/16000
a=rtpmap:98 iLBC/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=alt:1 2 : G1kfXqQD 6qnULmAZ 192.168.175.1 3692
a=alt:2 1 : JP5xp/AB yylxuUCE 192.168.1.203 3692

2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [BV32:107:16000:20:0:1]/[G722:9:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [BV32:107:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [BV32:107:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[G722:9:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[PCMU:0:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[PCMA:8:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[G722:9:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[PCMU:0:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[PCMA:8:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5647 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [GSM:3:8000:20:13200:1]/[G722:9:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5592 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1]
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5508 Set telephone-event payload to 101@8000
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:3837 Set Codec sofia/external/100@147.135.59.15 PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2020-02-24 01:40:09.527193 [DEBUG] switch_core_codec.c:111 sofia/external/100@147.135.59.15 Original read codec set to PCMU:0
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5851 Set telephone-event payload to 101@8000
2020-02-24 01:40:09.527193 [DEBUG] switch_core_media.c:5909 sofia/external/100@147.135.59.15 Set 2833 dtmf send payload to 101 recv payload to 101
2020-02-24 01:40:09.527193 [DEBUG] sofia.c:7735 (sofia/external/100@147.135.59.15) State Change CS_NEW -> CS_INIT
2020-02-24 01:40:09.527193 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@147.135.59.15) Running State Change CS_INIT (Cur 1 Tot 994)
2020-02-24 01:40:09.527193 [DEBUG] switch_core_state_machine.c:628 (sofia/external/100@147.135.59.15) State INIT
2020-02-24 01:40:09.527193 [DEBUG] mod_sofia.c:93 sofia/external/100@147.135.59.15 SOFIA INIT
2020-02-24 01:40:09.527193 [DEBUG] switch_core_state_machine.c:40 sofia/external/100@147.135.59.15 Standard INIT
2020-02-24 01:40:09.527193 [DEBUG] switch_core_state_machine.c:48 (sofia/external/100@147.135.59.15) State Change CS_INIT -> CS_ROUTING
2020-02-24 01:40:09.527193 [DEBUG] switch_core_state_machine.c:628 (sofia/external/100@147.135.59.15) State INIT going to sleep
2020-02-24 01:40:09.527193 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@147.135.59.15) Running State Change CS_ROUTING (Cur 1 Tot 994)
2020-02-24 01:40:09.527193 [DEBUG] switch_channel.c:2332 (sofia/external/100@147.135.59.15) Callstate Change DOWN -> RINGING
2020-02-24 01:40:09.527193 [DEBUG] switch_core_state_machine.c:644 (sofia/external/100@147.135.59.15) State ROUTING
2020-02-24 01:40:09.527193 [DEBUG] mod_sofia.c:154 sofia/external/100@147.135.59.15 SOFIA ROUTING
2020-02-24 01:40:09.527193 [DEBUG] switch_core_state_machine.c:236 sofia/external/100@147.135.59.15 Standard ROUTING
2020-02-24 01:40:09.527193 [INFO] mod_dialplan_xml.c:637 Processing 100 <100>->12012673350 in context 147.135.59.15
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->user_exists] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_exists] ${loopback_leg}() =~ /^B$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/external/100@147.135.59.15 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(user_exists=false)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [user_exists]=[false]
Dialplan: sofia/external/100@147.135.59.15 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(from_user_exists=true)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [from_user_exists]=[true]
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_exists] ${user_exists}(false) =~ /^true$/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->caller-details] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Action set(caller_destination=${destination_number}) INLINE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(caller_destination=12012673350)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [caller_destination]=[12012673350]
Dialplan: sofia/external/100@147.135.59.15 Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(caller_id_name=100)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [caller_id_name]=[100]
Dialplan: sofia/external/100@147.135.59.15 Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->domain-variables] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [domain-variables] () =~ // break=on-false
Dialplan: sofia/external/100@147.135.59.15 Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->global-variables] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [global-variables] () =~ // break=on-false
Dialplan: sofia/external/100@147.135.59.15 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->call-direction] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/external/100@147.135.59.15 ANTI-Action export(call_direction=local) INLINE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 export(call_direction=local)
2020-02-24 01:40:09.547126 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local]
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->is_loopback] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->user_record] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Action set(from_user_record=${user_data ${sip_from_user}@${sip_from_host} var user_record}) INLINE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(from_user_record=)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [from_user_record]=[UNDEF]
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [user_record] ${from_user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->redial] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [redial] destination_number(12012673350) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/external/100@147.135.59.15 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->speed_dial] continue=false
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [speed_dial] destination_number(12012673350) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->default_caller_id] continue=true
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never
Dialplan: sofia/external/100@147.135.59.15 Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(emergency_caller_id_name=)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [emergency_caller_id_name]=[UNDEF]
Dialplan: sofia/external/100@147.135.59.15 Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(emergency_caller_id_number=)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [emergency_caller_id_number]=[UNDEF]
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [default_caller_id] ${outbound_caller_id_number}(100) =~ /^$/ break=never
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->Twilio Trunk.International] continue=false
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [Twilio Trunk.International] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [Twilio Trunk.International] destination_number(12012673350) =~ /^(\d{12,20})$/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->Twilio Trunk.888d11] continue=false
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [Twilio Trunk.888d11] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 Regex (FAIL) [Twilio Trunk.888d11] destination_number(12012673350) =~ /^888(\d{11})$/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 parsing [147.135.59.15->Twilio Trunk.11d] continue=false
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [Twilio Trunk.11d] ${user_exists}(false) =~ /false/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 Regex (PASS) [Twilio Trunk.11d] destination_number(12012673350) =~ /^\+?(\d{11})$/ break=on-false
Dialplan: sofia/external/100@147.135.59.15 Action set(sip_h_X-accountcode=${accountcode})
Dialplan: sofia/external/100@147.135.59.15 Action export(call_direction=outbound)
Dialplan: sofia/external/100@147.135.59.15 Action unset(call_timeout)
Dialplan: sofia/external/100@147.135.59.15 Action set(hangup_after_bridge=true)
Dialplan: sofia/external/100@147.135.59.15 Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/external/100@147.135.59.15 Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/external/100@147.135.59.15 Action set(inherit_codec=true)
Dialplan: sofia/external/100@147.135.59.15 Action set(ignore_display_updates=true)
Dialplan: sofia/external/100@147.135.59.15 Action set(callee_id_number=12012673350)
Dialplan: sofia/external/100@147.135.59.15 Action set(continue_on_fail=true)
Dialplan: sofia/external/100@147.135.59.15 Action sleep(${sleep})
Dialplan: sofia/external/100@147.135.59.15 Action bridge(sofia/gateway/d56ece6d-9407-49c8-bfdc-bbbc352e669d/12012673350)
2020-02-24 01:40:09.547126 [DEBUG] switch_core_state_machine.c:287 (sofia/external/100@147.135.59.15) State Change CS_ROUTING -> CS_EXECUTE
2020-02-24 01:40:09.547126 [DEBUG] switch_core_state_machine.c:644 (sofia/external/100@147.135.59.15) State ROUTING going to sleep
2020-02-24 01:40:09.547126 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@147.135.59.15) Running State Change CS_EXECUTE (Cur 1 Tot 994)
2020-02-24 01:40:09.547126 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@147.135.59.15) State EXECUTE
2020-02-24 01:40:09.547126 [DEBUG] mod_sofia.c:209 sofia/external/100@147.135.59.15 SOFIA EXECUTE
2020-02-24 01:40:09.547126 [DEBUG] switch_core_state_machine.c:329 sofia/external/100@147.135.59.15 Standard EXECUTE
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(caller_id_number=100)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [caller_id_number]=[100]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 export(origination_callee_id_name=12012673350)
2020-02-24 01:40:09.547126 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[12012673350]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(RFC2822_DATE=Mon, 24 Feb 2020 01:40:09 -0500)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [RFC2822_DATE]=[Mon, 24 Feb 2020 01:40:09 -0500]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 hash(insert/147.135.59.15-last_dial/100/12012673350)
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(sip_h_X-accountcode=)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [sip_h_X-accountcode]=[UNDEF]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 export(call_direction=outbound)
2020-02-24 01:40:09.547126 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[outbound]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 unset(call_timeout)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1817 UNSET [call_timeout]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(hangup_after_bridge=true)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [hangup_after_bridge]=[true]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(effective_caller_id_name=100)
2020-02-24 01:40:09.547126 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [effective_caller_id_name]=[100]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(effective_caller_id_number=100)
2020-02-24 01:40:09.567115 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [effective_caller_id_number]=[100]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(inherit_codec=true)
2020-02-24 01:40:09.567115 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [inherit_codec]=[true]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(ignore_display_updates=true)
2020-02-24 01:40:09.567115 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [ignore_display_updates]=[true]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(callee_id_number=12012673350)
2020-02-24 01:40:09.567115 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [callee_id_number]=[12012673350]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 set(continue_on_fail=true)
2020-02-24 01:40:09.567115 [DEBUG] mod_dptools.c:1672 SET sofia/external/100@147.135.59.15 [continue_on_fail]=[true]
EXECUTE [depth=0] sofia/external/100@147.135.59.15 sleep(0)
EXECUTE [depth=0] sofia/external/100@147.135.59.15 bridge(sofia/gateway/d56ece6d-9407-49c8-bfdc-bbbc352e669d/12012673350)
2020-02-24 01:40:09.567115 [DEBUG] switch_channel.c:1264 sofia/external/100@147.135.59.15 EXPORTING[export_vars] [domain_name]=[147.135.59.15] to event
2020-02-24 01:40:09.567115 [DEBUG] switch_channel.c:1264 sofia/external/100@147.135.59.15 EXPORTING[export_vars] [call_direction]=[outbound] to event
2020-02-24 01:40:09.567115 [DEBUG] switch_channel.c:1264 sofia/external/100@147.135.59.15 EXPORTING[export_vars] [origination_callee_id_name]=[12012673350] to event
2020-02-24 01:40:09.567115 [DEBUG] switch_channel.c:1264 sofia/external/100@147.135.59.15 EXPORTING[export_vars] [call_direction]=[outbound] to event
2020-02-24 01:40:09.567115 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables
2020-02-24 01:40:09.567115 [NOTICE] switch_channel.c:1118 New Channel sofia/external/12012673350 [d53342ef-93a6-4d8c-91fb-bca4cf5aff0e]
2020-02-24 01:40:09.567115 [DEBUG] mod_sofia.c:5089 (sofia/external/12012673350) State Change CS_NEW -> CS_INIT
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:585 (sofia/external/12012673350) Running State Change CS_INIT (Cur 2 Tot 995)
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:628 (sofia/external/12012673350) State INIT
2020-02-24 01:40:09.567115 [DEBUG] mod_sofia.c:93 sofia/external/12012673350 SOFIA INIT
2020-02-24 01:40:09.567115 [DEBUG] sofia_glue.c:1618 sofia/external/12012673350 sending invite version: 1.10.2 -release-14-f7bdd3845a 64bit
Local SDP:
v=0
o=FreeSWITCH 1582497735 1582497736 IN IP4 147.135.59.15
s=FreeSWITCH
c=IN IP4 147.135.59.15
t=0 0
m=audio 28674 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:eek:ff - - - -
a=ptime:20
a=sendrecv

2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:40 sofia/external/12012673350 Standard INIT
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:48 (sofia/external/12012673350) State Change CS_INIT -> CS_ROUTING
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:628 (sofia/external/12012673350) State INIT going to sleep
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:585 (sofia/external/12012673350) Running State Change CS_ROUTING (Cur 2 Tot 995)
2020-02-24 01:40:09.567115 [DEBUG] sofia.c:7301 Channel sofia/external/12012673350 entering state [calling][0]
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:644 (sofia/external/12012673350) State ROUTING
2020-02-24 01:40:09.567115 [DEBUG] mod_sofia.c:154 sofia/external/12012673350 SOFIA ROUTING
2020-02-24 01:40:09.567115 [DEBUG] switch_ivr_originate.c:67 (sofia/external/12012673350) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:644 (sofia/external/12012673350) State ROUTING going to sleep
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:585 (sofia/external/12012673350) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 995)
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:663 (sofia/external/12012673350) State CONSUME_MEDIA
2020-02-24 01:40:09.567115 [DEBUG] switch_core_state_machine.c:663 (sofia/external/12012673350) State CONSUME_MEDIA going to sleep
2020-02-24 01:40:09.627146 [DEBUG] sofia.c:7301 Channel sofia/external/12012673350 entering state [calling][0]
2020-02-24 01:40:09.747133 [DEBUG] sofia.c:7301 Channel sofia/external/12012673350 entering state [terminated][400]
2020-02-24 01:40:09.747133 [NOTICE] sofia.c:8534 Hangup sofia/external/12012673350 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:585 (sofia/external/12012673350) Running State Change CS_HANGUP (Cur 2 Tot 995)
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:848 (sofia/external/12012673350) Callstate Change DOWN -> HANGUP
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:850 (sofia/external/12012673350) State HANGUP
2020-02-24 01:40:09.747133 [DEBUG] mod_sofia.c:453 Channel sofia/external/12012673350 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:60 sofia/external/12012673350 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:850 (sofia/external/12012673350) State HANGUP going to sleep
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:620 (sofia/external/12012673350) State Change CS_HANGUP -> CS_REPORTING
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:585 (sofia/external/12012673350) Running State Change CS_REPORTING (Cur 2 Tot 995)
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:936 (sofia/external/12012673350) State REPORTING
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:174 sofia/external/12012673350 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:936 (sofia/external/12012673350) State REPORTING going to sleep
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:611 (sofia/external/12012673350) State Change CS_REPORTING -> CS_DESTROY
2020-02-24 01:40:09.747133 [DEBUG] switch_core_session.c:1726 Session 995 (sofia/external/12012673350) Locked, Waiting on external entities
2020-02-24 01:40:09.747133 [DEBUG] switch_ivr_originate.c:3952 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2020-02-24 01:40:09.747133 [INFO] mod_dptools.c:3631 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE
2020-02-24 01:40:09.747133 [NOTICE] switch_core_state_machine.c:386 sofia/external/100@147.135.59.15 has executed the last dialplan instruction, hanging up.
2020-02-24 01:40:09.747133 [NOTICE] switch_core_state_machine.c:388 Hangup sofia/external/100@147.135.59.15 [CS_EXECUTE] [NORMAL_CLEARING]
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:651 (sofia/external/100@147.135.59.15) State EXECUTE going to sleep
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@147.135.59.15) Running State Change CS_HANGUP (Cur 2 Tot 995)
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:848 (sofia/external/100@147.135.59.15) Callstate Change RINGING -> HANGUP
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@147.135.59.15) State HANGUP
2020-02-24 01:40:09.747133 [DEBUG] mod_sofia.c:447 sofia/external/100@147.135.59.15 Overriding SIP cause 480 with 400 from the other leg
2020-02-24 01:40:09.747133 [DEBUG] mod_sofia.c:453 Channel sofia/external/100@147.135.59.15 hanging up, cause: NORMAL_CLEARING
2020-02-24 01:40:09.747133 [DEBUG] mod_sofia.c:598 Responding to INVITE with: 400
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:60 sofia/external/100@147.135.59.15 Standard HANGUP, cause: NORMAL_CLEARING
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:850 (sofia/external/100@147.135.59.15) State HANGUP going to sleep
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:620 (sofia/external/100@147.135.59.15) State Change CS_HANGUP -> CS_REPORTING
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:585 (sofia/external/100@147.135.59.15) Running State Change CS_REPORTING (Cur 2 Tot 995)
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@147.135.59.15) State REPORTING
2020-02-24 01:40:09.747133 [NOTICE] switch_core_session.c:1744 Session 995 (sofia/external/12012673350) Ended
2020-02-24 01:40:09.747133 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/12012673350 [CS_DESTROY]
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:739 (sofia/external/12012673350) Running State Change CS_DESTROY (Cur 1 Tot 995)
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:749 (sofia/external/12012673350) State DESTROY
2020-02-24 01:40:09.747133 [DEBUG] mod_sofia.c:364 sofia/external/12012673350 SOFIA DESTROY
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:181 sofia/external/12012673350 Standard DESTROY
2020-02-24 01:40:09.747133 [DEBUG] switch_core_state_machine.c:749 (sofia/external/12012673350) State DESTROY going to sleep
2020-02-24 01:40:09.907123 [DEBUG] switch_core_state_machine.c:174 sofia/external/100@147.135.59.15 Standard REPORTING, cause: NORMAL_CLEARING
2020-02-24 01:40:09.907123 [DEBUG] switch_core_state_machine.c:936 (sofia/external/100@147.135.59.15) State REPORTING going to sleep
2020-02-24 01:40:09.907123 [DEBUG] switch_core_state_machine.c:611 (sofia/external/100@147.135.59.15) State Change CS_REPORTING -> CS_DESTROY
2020-02-24 01:40:09.907123 [DEBUG] switch_core_session.c:1726 Session 994 (sofia/external/100@147.135.59.15) Locked, Waiting on external entities
2020-02-24 01:40:09.907123 [NOTICE] switch_core_session.c:1744 Session 994 (sofia/external/100@147.135.59.15) Ended
2020-02-24 01:40:09.907123 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/100@147.135.59.15 [CS_DESTROY]
2020-02-24 01:40:09.907123 [DEBUG] switch_core_state_machine.c:739 (sofia/external/100@147.135.59.15) Running State Change CS_DESTROY (Cur 0 Tot 995)
2020-02-24 01:40:09.907123 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@147.135.59.15) State DESTROY
2020-02-24 01:40:09.907123 [DEBUG] mod_sofia.c:364 sofia/external/100@147.135.59.15 SOFIA DESTROY
2020-02-24 01:40:09.907123 [DEBUG] switch_core_state_machine.c:181 sofia/external/100@147.135.59.15 Standard DESTROY
2020-02-24 01:40:09.907123 [DEBUG] switch_core_state_machine.c:749 (sofia/external/100@147.135.59.15) State DESTROY going to sleep
2020-02-24 01:40:12.567116 [NOTICE] switch_channel.c:1118 New Channel sofia/external/10019@147.135.59.15 [bcc2fac6-ad90-4f37-971b-9b62297a0dc4]
2020-02-24 01:40:12.567116 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_NEW (Cur 1 Tot 996)
2020-02-24 01:40:12.567116 [DEBUG] sofia.c:10255 sofia/external/10019@147.135.59.15 receiving invite from 46.105.236.208:59116 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-02-24 01:40:12.567116 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port 46.105.236.208:0.
2020-02-24 01:40:12.567116 [DEBUG] sofia.c:2434 detaching session bcc2fac6-ad90-4f37-971b-9b62297a0dc4
2020-02-24 01:40:12.567116 [DEBUG] switch_core_state_machine.c:604 (sofia/external/10019@147.135.59.15) State NEW
2020-02-24 01:40:12.727166 [DEBUG] sofia.c:2544 Re-attaching to session bcc2fac6-ad90-4f37-971b-9b62297a0dc4
2020-02-24 01:40:12.747147 [DEBUG] sofia.c:10255 sofia/external/10019@147.135.59.15 receiving invite from 46.105.236.208:59116 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-02-24 01:40:12.747147 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port 46.105.236.208:0.
2020-02-24 01:40:12.747147 [WARNING] sofia_reg.c:2929 Can't find user [10019@147.135.59.15] from 46.105.236.208
You must define a domain called '147.135.59.15' in your directory and add a user with the id="10019" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2020-02-24 01:40:12.747147 [NOTICE] sofia.c:2432 Hangup sofia/external/10019@147.135.59.15 [CS_NEW] [CALL_REJECTED]
2020-02-24 01:40:12.747147 [DEBUG] sofia.c:1548 Channel is already hungup.
2020-02-24 01:40:12.747147 [DEBUG] sofia.c:1548 Channel is already hungup.
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_HANGUP (Cur 1 Tot 996)
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:848 (sofia/external/10019@147.135.59.15) Callstate Change DOWN -> HANGUP
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:850 (sofia/external/10019@147.135.59.15) State HANGUP
2020-02-24 01:40:12.747147 [DEBUG] mod_sofia.c:453 Channel sofia/external/10019@147.135.59.15 hanging up, cause: CALL_REJECTED
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:60 sofia/external/10019@147.135.59.15 Standard HANGUP, cause: CALL_REJECTED
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:850 (sofia/external/10019@147.135.59.15) State HANGUP going to sleep
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:620 (sofia/external/10019@147.135.59.15) State Change CS_HANGUP -> CS_REPORTING
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_REPORTING (Cur 1 Tot 996)
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:936 (sofia/external/10019@147.135.59.15) State REPORTING
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:174 sofia/external/10019@147.135.59.15 Standard REPORTING, cause: CALL_REJECTED
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:936 (sofia/external/10019@147.135.59.15) State REPORTING going to sleep
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:611 (sofia/external/10019@147.135.59.15) State Change CS_REPORTING -> CS_DESTROY
2020-02-24 01:40:12.747147 [DEBUG] switch_core_session.c:1726 Session 996 (sofia/external/10019@147.135.59.15) Locked, Waiting on external entities
2020-02-24 01:40:12.747147 [NOTICE] switch_core_session.c:1744 Session 996 (sofia/external/10019@147.135.59.15) Ended
2020-02-24 01:40:12.747147 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/10019@147.135.59.15 [CS_DESTROY]
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:739 (sofia/external/10019@147.135.59.15) Running State Change CS_DESTROY (Cur 0 Tot 996)
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:749 (sofia/external/10019@147.135.59.15) State DESTROY
2020-02-24 01:40:12.747147 [DEBUG] mod_sofia.c:364 sofia/external/10019@147.135.59.15 SOFIA DESTROY
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:181 sofia/external/10019@147.135.59.15 Standard DESTROY
2020-02-24 01:40:12.747147 [DEBUG] switch_core_state_machine.c:749 (sofia/external/10019@147.135.59.15) State DESTROY going to sleep
2020-02-24 01:40:21.927131 [NOTICE] switch_channel.c:1118 New Channel sofia/external/10019@147.135.59.15 [e401ffac-a900-41ee-b56a-3dbcbec39b5f]
2020-02-24 01:40:21.927131 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_NEW (Cur 1 Tot 997)
2020-02-24 01:40:21.927131 [DEBUG] sofia.c:10255 sofia/external/10019@147.135.59.15 receiving invite from 46.105.236.208:60176 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-02-24 01:40:21.927131 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port 46.105.236.208:0.
2020-02-24 01:40:21.927131 [DEBUG] sofia.c:2434 detaching session e401ffac-a900-41ee-b56a-3dbcbec39b5f
2020-02-24 01:40:21.927131 [DEBUG] switch_core_state_machine.c:604 (sofia/external/10019@147.135.59.15) State NEW
2020-02-24 01:40:22.087211 [DEBUG] sofia.c:2544 Re-attaching to session e401ffac-a900-41ee-b56a-3dbcbec39b5f
2020-02-24 01:40:22.087211 [DEBUG] sofia.c:10255 sofia/external/10019@147.135.59.15 receiving invite from 46.105.236.208:60176 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-02-24 01:40:22.087211 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port 46.105.236.208:0.
2020-02-24 01:40:22.087211 [WARNING] sofia_reg.c:2929 Can't find user [10019@147.135.59.15] from 46.105.236.208
You must define a domain called '147.135.59.15' in your directory and add a user with the id="10019" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2020-02-24 01:40:22.087211 [NOTICE] sofia.c:2432 Hangup sofia/external/10019@147.135.59.15 [CS_NEW] [CALL_REJECTED]
2020-02-24 01:40:22.087211 [DEBUG] sofia.c:1548 Channel is already hungup.
2020-02-24 01:40:22.087211 [DEBUG] sofia.c:1548 Channel is already hungup.
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_HANGUP (Cur 1 Tot 997)
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:848 (sofia/external/10019@147.135.59.15) Callstate Change DOWN -> HANGUP
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:850 (sofia/external/10019@147.135.59.15) State HANGUP
2020-02-24 01:40:22.087211 [DEBUG] mod_sofia.c:453 Channel sofia/external/10019@147.135.59.15 hanging up, cause: CALL_REJECTED
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:60 sofia/external/10019@147.135.59.15 Standard HANGUP, cause: CALL_REJECTED
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:850 (sofia/external/10019@147.135.59.15) State HANGUP going to sleep
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:620 (sofia/external/10019@147.135.59.15) State Change CS_HANGUP -> CS_REPORTING
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_REPORTING (Cur 1 Tot 997)
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:936 (sofia/external/10019@147.135.59.15) State REPORTING
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:174 sofia/external/10019@147.135.59.15 Standard REPORTING, cause: CALL_REJECTED
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:936 (sofia/external/10019@147.135.59.15) State REPORTING going to sleep
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:611 (sofia/external/10019@147.135.59.15) State Change CS_REPORTING -> CS_DESTROY
2020-02-24 01:40:22.087211 [DEBUG] switch_core_session.c:1726 Session 997 (sofia/external/10019@147.135.59.15) Locked, Waiting on external entities
2020-02-24 01:40:22.087211 [NOTICE] switch_core_session.c:1744 Session 997 (sofia/external/10019@147.135.59.15) Ended
2020-02-24 01:40:22.087211 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/10019@147.135.59.15 [CS_DESTROY]
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:739 (sofia/external/10019@147.135.59.15) Running State Change CS_DESTROY (Cur 0 Tot 997)
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:749 (sofia/external/10019@147.135.59.15) State DESTROY
2020-02-24 01:40:22.087211 [DEBUG] mod_sofia.c:364 sofia/external/10019@147.135.59.15 SOFIA DESTROY
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:181 sofia/external/10019@147.135.59.15 Standard DESTROY
2020-02-24 01:40:22.087211 [DEBUG] switch_core_state_machine.c:749 (sofia/external/10019@147.135.59.15) State DESTROY going to sleep
2020-02-24 01:40:31.287184 [NOTICE] switch_channel.c:1118 New Channel sofia/external/10019@147.135.59.15 [3c163939-f119-4389-8d5f-495ce27a9361]
2020-02-24 01:40:31.287184 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_NEW (Cur 1 Tot 998)
2020-02-24 01:40:31.287184 [DEBUG] sofia.c:10255 sofia/external/10019@147.135.59.15 receiving invite from 46.105.236.208:61258 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-02-24 01:40:31.287184 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port 46.105.236.208:0.
2020-02-24 01:40:31.287184 [DEBUG] sofia.c:2434 detaching session 3c163939-f119-4389-8d5f-495ce27a9361
2020-02-24 01:40:31.287184 [DEBUG] switch_core_state_machine.c:604 (sofia/external/10019@147.135.59.15) State NEW
2020-02-24 01:40:31.447128 [DEBUG] sofia.c:2544 Re-attaching to session 3c163939-f119-4389-8d5f-495ce27a9361
2020-02-24 01:40:31.467138 [DEBUG] sofia.c:10255 sofia/external/10019@147.135.59.15 receiving invite from 46.105.236.208:61258 version: 1.10.2 -release-14-f7bdd3845a 64bit
2020-02-24 01:40:31.467138 [DEBUG] sofia.c:10349 verifying acl "domains" for ip/port 46.105.236.208:0.
2020-02-24 01:40:31.467138 [WARNING] sofia_reg.c:2929 Can't find user [10019@147.135.59.15] from 46.105.236.208
You must define a domain called '147.135.59.15' in your directory and add a user with the id="10019" attribute
and you must configure your device to use the proper domain in its authentication credentials.
2020-02-24 01:40:31.467138 [NOTICE] sofia.c:2432 Hangup sofia/external/10019@147.135.59.15 [CS_NEW] [CALL_REJECTED]
2020-02-24 01:40:31.467138 [DEBUG] sofia.c:1548 Channel is already hungup.
2020-02-24 01:40:31.467138 [DEBUG] sofia.c:1548 Channel is already hungup.
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_HANGUP (Cur 1 Tot 998)
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:848 (sofia/external/10019@147.135.59.15) Callstate Change DOWN -> HANGUP
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:850 (sofia/external/10019@147.135.59.15) State HANGUP
2020-02-24 01:40:31.467138 [DEBUG] mod_sofia.c:453 Channel sofia/external/10019@147.135.59.15 hanging up, cause: CALL_REJECTED
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:60 sofia/external/10019@147.135.59.15 Standard HANGUP, cause: CALL_REJECTED
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:850 (sofia/external/10019@147.135.59.15) State HANGUP going to sleep
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:620 (sofia/external/10019@147.135.59.15) State Change CS_HANGUP -> CS_REPORTING
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:585 (sofia/external/10019@147.135.59.15) Running State Change CS_REPORTING (Cur 1 Tot 998)
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:936 (sofia/external/10019@147.135.59.15) State REPORTING
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:174 sofia/external/10019@147.135.59.15 Standard REPORTING, cause: CALL_REJECTED
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:936 (sofia/external/10019@147.135.59.15) State REPORTING going to sleep
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:611 (sofia/external/10019@147.135.59.15) State Change CS_REPORTING -> CS_DESTROY
2020-02-24 01:40:31.467138 [DEBUG] switch_core_session.c:1726 Session 998 (sofia/external/10019@147.135.59.15) Locked, Waiting on external entities
2020-02-24 01:40:31.467138 [NOTICE] switch_core_session.c:1744 Session 998 (sofia/external/10019@147.135.59.15) Ended
2020-02-24 01:40:31.467138 [NOTICE] switch_core_session.c:1748 Close Channel sofia/external/10019@147.135.59.15 [CS_DESTROY]
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:739 (sofia/external/10019@147.135.59.15) Running State Change CS_DESTROY (Cur 0 Tot 998)
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:749 (sofia/external/10019@147.135.59.15) State DESTROY
2020-02-24 01:40:31.467138 [DEBUG] mod_sofia.c:364 sofia/external/10019@147.135.59.15 SOFIA DESTROY
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:181 sofia/external/10019@147.135.59.15 Standard DESTROY
2020-02-24 01:40:31.467138 [DEBUG] switch_core_state_machine.c:749 (sofia/external/10019@147.135.59.15) State DESTROY going to sleep
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
There definitely looks like a problem with your ACL there:

sofia/external/100@147.135.59.15

Why is it putting you in the external profile?

Also, just another nag, why are you using IP address instead of a domain name, it is terrible for security.
 
R

rjunaid

Member
Oct 18, 2019
35
0
6
25
I installed fusionpbx with automatic script i don't know much about this sofia external with same configurtion am using Fusionpbx with Flowroute SIP but this time i've tried to to use TWILIO Trunk but am getting this "
40041NORMAL_TEMPORARY_FAILURETemporary failure [Q.850]
"
I have no idea which part am doing wrong and after this reply am gonna add ACL maybe then it will work, but i have tried with ACL before and it wasn't working, so i removed it and tried something else
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
No, do not mess with the acl, only carriers should go in there, post a screenshot of your domains acl
 
R

rjunaid

Member
Oct 18, 2019
35
0
6
25
Twilio didn't provide me any IP they just me provided me termination and orignation URI
 
R

rjunaid

Member
Oct 18, 2019
35
0
6
25
What's the reason for this error code??

02:06:41.567153 [DEBUG] switch_ivr_originate.c:3952 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
a4b04055-1149-4d7e-a2fa-e34c522c0008 2020-02-24 02:06:41.567153 [INFO] mod_dptools.c:3631 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
I'm not sure on this but it is possible its because you are not using a domain but rather the IP. I'd need to test further. You have got your phone registering to port 5060 right?
 
R

rjunaid

Member
Oct 18, 2019
35
0
6
25
Ahan so what you suggest? yes phone is registered on 5060 and i have two extension and they are able to call each other but not outside the pbx
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
Maybe this is no more than a misconfiguration of Twilio, I can see it trying to go out.

I have a working twilio gateway on a server somewhere. I just have no idea where. I'll see if I can find it.
 
DigitalDaz

DigitalDaz

Administrator
Staff member
Sep 29, 2016
3,070
577
113
Just noticed on my outbound route I have +$1 so it looks like you need to send the +. Try that in your outbound route on the bridge, change it from $1 to +$1
 
Status
Not open for further replies.
Top Bottom