2020-09-17 10:35:49.759395 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->1001 in context default
Dialplan: sofia/internal/1000@example.com:5060 parsing [default->Local_Extensions] continue=false
Dialplan: sofia/internal/1000@example.com:5060 Regex (PASS) [Local_Extensions] destination_number(1001) =~ /(^1[0-1]..)$/ break=on-false
Dialplan: sofia/internal/1000@example.com:5060 Action log(INFO the dialed_domain is: ${dialed_domain})
Dialplan: sofia/internal/1000@example.com:5060 Action bridge(${sofia_contact(1001@example.com)})
2020-09-17 10:35:49.759395 [DEBUG] switch_core_state_machine.c:287 (sofia/internal/1000@example.com:5060) State Change CS_ROUTING -> CS_EXECUTE
2020-09-17 10:35:49.759395 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/1000@example.com:5060) State ROUTING going to sleep
2020-09-17 10:35:49.759395 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/1000@example.com:5060) Running State Change CS_EXECUTE (Cur 1 Tot 3)
2020-09-17 10:35:49.759395 [DEBUG] switch_core_state_machine.c:651 (sofia/internal/1000@example.com:5060) State EXECUTE
2020-09-17 10:35:49.759395 [DEBUG] mod_sofia.c:209 sofia/internal/1000@example.com:5060 SOFIA EXECUTE
2020-09-17 10:35:49.759395 [DEBUG] switch_core_state_machine.c:329 sofia/internal/1000@example.com:5060 Standard EXECUTE
EXECUTE [depth=0] sofia/internal/1000@example.com:5060 log(INFO the dialed_domain is: )
2020-09-17 10:35:49.759395 [INFO] mod_dptools.c:1866 the dialed_domain is:
EXECUTE [depth=0] sofia/internal/1000@example.com:5060 bridge(sofia/internal/sip:u0ganh4l@5e31ohha33s0.invalid;transport=ws)
2020-09-17 10:35:49.759395 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
2020-09-17 10:35:49.759395 [NOTICE] switch_channel.c:1118 New Channel sofia/internal/u0ganh4l@5e31ohha33s0.invalid [c7dee696-2213-4188-8cfd-efd0c8da6fe6]
2020-09-17 10:35:49.759395 [DEBUG] mod_sofia.c:5089 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) State Change CS_NEW -> CS_INIT
2020-09-17 10:35:49.779423 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) Running State Change CS_INIT (Cur 2 Tot 4)
2020-09-17 10:35:49.779423 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) State INIT
2020-09-17 10:35:49.779423 [DEBUG] mod_sofia.c:93 sofia/internal/u0ganh4l@5e31ohha33s0.invalid SOFIA INIT
2020-09-17 10:35:49.779423 [DEBUG] sofia_glue.c:1618 sofia/internal/u0ganh4l@5e31ohha33s0.invalid sending invite version: 1.10.4-release git 133fc2c 2020-08-05 11:01:19Z 64bit
Local SDP:
v=0
o=FreeSWITCH 1600318899 1600318900 IN IP4 192.168.40.60
s=FreeSWITCH
c=IN IP4 192.168.40.60
t=0 0
a=msid-semantic: WMS RC9kmjAves5RNBlTJaWvzaHkvWjbTmOB
m=audio 20050 RTP/SAVPF 0 101
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fingerprint:sha-256 15:7F:D5:8F:FA:52:82:AA:C6:6F:A9:87:3C:A0:5F:CF:65:9C:20:F5:32:65:C1:8E:D4:99:BB:4D:26:37:27:75
a=setup:actpass
a=rtcp-mux
a=rtcp:20050 IN IP4 192.168.40.60
a=ssrc:3010043693 cname:PNL2Wco1ukJ8LURl
a=ssrc:3010043693 msid:RC9kmjAves5RNBlTJaWvzaHkvWjbTmOB a0
a=ssrc:3010043693 mslabel:RC9kmjAves5RNBlTJaWvzaHkvWjbTmOB
a=ssrc:3010043693 label:RC9kmjAves5RNBlTJaWvzaHkvWjbTmOBa0
a=ice-ufrag:VDHlEev00E1KRGbx
a=ice-pwd:jNp6QDYaNx8piQA3j7fObAE2
a=candidate:9877831763 1 udp 659136 192.168.40.60 20050 typ host generation 0
a=candidate:9877831763 2 udp 659136 192.168.40.60 20050 typ host generation 0
a=ptime:20
a=sendrecv

2020-09-17 10:35:49.779423 [DEBUG] switch_core_state_machine.c:40 sofia/internal/u0ganh4l@5e31ohha33s0.invalid Standard INIT
2020-09-17 10:35:49.779423 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) State Change CS_INIT -> CS_ROUTING
2020-09-17 10:35:49.779423 [DEBUG] switch_core_state_machine.c:628 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) State INIT going to sleep
2020-09-17 10:35:49.779423 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) Running State Change CS_ROUTING (Cur 2 Tot 4)
2020-09-17 10:35:49.779423 [DEBUG] sofia.c:7325 Channel sofia/internal/u0ganh4l@5e31ohha33s0.invalid entering state [calling][0]
2020-09-17 10:35:49.799388 [DEBUG] sofia.c:7325 Channel sofia/internal/u0ganh4l@5e31ohha33s0.invalid entering state [terminated][503]
2020-09-17 10:35:49.799388 [NOTICE] sofia.c:8558 Hangup sofia/internal/u0ganh4l@5e31ohha33s0.invalid [CS_ROUTING] [NORMAL_TEMPORARY_FAILURE]
2020-09-17 10:35:49.799388 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) State ROUTING
2020-09-17 10:35:49.799388 [DEBUG] mod_sofia.c:154 sofia/internal/u0ganh4l@5e31ohha33s0.invalid SOFIA ROUTING
2020-09-17 10:35:49.799388 [DEBUG] switch_core_state_machine.c:644 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) State ROUTING going to sleep
2020-09-17 10:35:49.799388 [DEBUG] switch_core_state_machine.c:585 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) Running State Change CS_HANGUP (Cur 2 Tot 4)
2020-09-17 10:35:49.799388 [DEBUG] switch_ivr_originate.c:3995 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2020-09-17 10:35:49.799388 [DEBUG] switch_core_state_machine.c:848 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) Callstate Change DOWN -> HANGUP
2020-09-17 10:35:49.799388 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/u0ganh4l@5e31ohha33s0.invalid) State HANGUP
2020-09-17 10:35:49.799388 [DEBUG] mod_sofia.c:453 Channel sofia/internal/u0ganh4l@5e31ohha33s0.invalid hanging up, cause: NORMAL_TEMPORARY_FAILURE
2020-09-17 10:35:49.799388 [INFO] mod_dptools.c:3631 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
2020-09-17 10:35:49.799388 [NOTICE] switch_channel.c:4941 Hangup sofia/internal/1000@example.com:5060 [CS_EXECUTE] [NORMAL_TEMPORARY_FAILURE]