Internal calls are not working

MrGlasspoole · Nov 11, 2017

Hi,

i had FreeSwitch running for ~2 years and thought i want a GUI and a forum that can help me solve problems, so i switched to Fusion.

Problem is that i cant get the simplest thing running.
I made some extensions 1000 - 1005 and the phones are registered.
I can dial *9170 and get the time.
But dialing 1002 from 1001 just gives me 404.

Code:

e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1002@10.1.0.11) State DESTROY going to sleep
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] switch_core_state_machine.c:181 sofia/internal/1002@10.1.0.11 Standard DESTROY
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] mod_sofia.c:343 sofia/internal/1002@10.1.0.11 SOFIA DESTROY
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/1002@10.1.0.11) State DESTROY
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/1002@10.1.0.11) Running State Change CS_DESTROY (Cur 0 Tot 55)
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/1002@10.1.0.11 [CS_DESTROY]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [NOTICE] switch_core_session.c:1683 Session 55 (sofia/internal/1002@10.1.0.11) Ended
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] switch_core_session.c:1665 Session 55 (sofia/internal/1002@10.1.0.11) Locked, Waiting on external entities
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/1002@10.1.0.11) State Change CS_REPORTING -> CS_DESTROY
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1002@10.1.0.11) State REPORTING going to sleep
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.200628 [DEBUG] switch_core_state_machine.c:174 sofia/internal/1002@10.1.0.11 Standard REPORTING, cause: NO_ROUTE_DESTINATION
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/1002@10.1.0.11) State REPORTING
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@10.1.0.11) Running State Change CS_REPORTING (Cur 1 Tot 55)
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/1002@10.1.0.11) State Change CS_HANGUP -> CS_REPORTING
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1002@10.1.0.11) State HANGUP going to sleep
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:60 sofia/internal/1002@10.1.0.11 Standard HANGUP, cause: NO_ROUTE_DESTINATION
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] mod_sofia.c:438 Channel sofia/internal/1002@10.1.0.11 hanging up, cause: NO_ROUTE_DESTINATION
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/1002@10.1.0.11) State HANGUP
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/1002@10.1.0.11) Callstate Change RINGING -> HANGUP
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@10.1.0.11) Running State Change CS_HANGUP (Cur 1 Tot 55)
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@10.1.0.11) State ROUTING going to sleep
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/internal/1002@10.1.0.11 [CS_ROUTING] [NO_ROUTE_DESTINATION]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [INFO] switch_core_state_machine.c:311 No Route, Aborting
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 Regex (FAIL) [talking clock date] destination_number(1001) =~ /^\*9171$/ break=on-false
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 parsing [default->talking clock date] continue=true
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 Regex (FAIL) [talking clock time] destination_number(1001) =~ /^\*9170$/ break=on-false
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 parsing [default->talking clock time] continue=true
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 Regex (FAIL) [talking clock date and time] destination_number(1001) =~ /^\*9172$/ break=on-false
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 parsing [default->talking clock date and time] continue=true
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 Regex (FAIL) [call forward all] ${user_exists}() =~ /^true/ break=on-false
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 parsing [default->call forward all] continue=false
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 Regex (FAIL) [intercept-ext-polycom] destination_number(1001) =~ /^\*97(\d+)$/ break=on-false
e2795138-4430-4542-8a36-11a5f01c3a1c Dialplan: sofia/internal/1002@10.1.0.11 parsing [default->intercept-ext-polycom] continue=false
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [INFO] mod_dialplan_xml.c:637 Processing Dietzel <1002>->1001 in context default
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:236 sofia/internal/1002@10.1.0.11 Standard ROUTING
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] mod_sofia.c:143 sofia/internal/1002@10.1.0.11 SOFIA ROUTING
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/1002@10.1.0.11) State ROUTING
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_channel.c:2249 (sofia/internal/1002@10.1.0.11) Callstate Change DOWN -> RINGING
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@10.1.0.11) Running State Change CS_ROUTING (Cur 1 Tot 55)
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@10.1.0.11) State INIT going to sleep
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/1002@10.1.0.11) State Change CS_INIT -> CS_ROUTING
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:40 sofia/internal/1002@10.1.0.11 Standard INIT
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] mod_sofia.c:90 sofia/internal/1002@10.1.0.11 SOFIA INIT
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/1002@10.1.0.11) State INIT
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@10.1.0.11) Running State Change CS_INIT (Cur 1 Tot 55)
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] sofia.c:7507 (sofia/internal/1002@10.1.0.11) State Change CS_NEW -> CS_INIT
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4767 sofia/internal/1002@10.1.0.11 Set 2833 dtmf send payload to 101 recv payload to 101
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_codec.c:111 sofia/internal/1002@10.1.0.11 Original read codec set to G722:9
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/1002@10.1.0.11 G722/8000 20 ms 160 samples 64000 bits 1 channels
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[GSM:3:8000:20:13200:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[GSM:3:8000:20:13200:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:2:8000:20:0:1]/[G722:9:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [AAL2-G726-32:97:8000:20:0:1]/[GSM:3:8000:20:13200:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [AAL2-G726-32:97:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [AAL2-G726-32:97:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [AAL2-G726-32:97:8000:20:0:1]/[G722:9:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:96:8000:20:0:1]/[GSM:3:8000:20:13200:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:96:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:96:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G726-32:96:8000:20:0:1]/[G722:9:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1]
e2795138-4430-4542-8a36-11a5f01c3a1c
e2795138-4430-4542-8a36-11a5f01c3a1c a=ptime:20
e2795138-4430-4542-8a36-11a5f01c3a1c a=fmtp:101 0-16
e2795138-4430-4542-8a36-11a5f01c3a1c a=rtpmap:101 telephone-event/8000
e2795138-4430-4542-8a36-11a5f01c3a1c a=fmtp:18 annexb=no
e2795138-4430-4542-8a36-11a5f01c3a1c a=rtpmap:18 G729/8000
e2795138-4430-4542-8a36-11a5f01c3a1c a=rtpmap:2 G726-32/8000
e2795138-4430-4542-8a36-11a5f01c3a1c a=rtpmap:97 AAL2-G726-32/8000
e2795138-4430-4542-8a36-11a5f01c3a1c a=rtpmap:96 G726-32/8000
e2795138-4430-4542-8a36-11a5f01c3a1c a=rtpmap:0 PCMU/8000
e2795138-4430-4542-8a36-11a5f01c3a1c a=rtpmap:8 PCMA/8000
e2795138-4430-4542-8a36-11a5f01c3a1c a=rtpmap:9 G722/8000
e2795138-4430-4542-8a36-11a5f01c3a1c m=audio 16398 RTP/AVP 9 8 0 96 97 2 18 101
e2795138-4430-4542-8a36-11a5f01c3a1c t=0 0
e2795138-4430-4542-8a36-11a5f01c3a1c c=IN IP4 10.1.0.4
e2795138-4430-4542-8a36-11a5f01c3a1c s=Mapping
e2795138-4430-4542-8a36-11a5f01c3a1c o=1002 16398 51 IN IP4 10.1.0.4
e2795138-4430-4542-8a36-11a5f01c3a1c v=0
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] sofia.c:7094 Remote SDP:
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.060642 [DEBUG] sofia.c:7084 Channel sofia/internal/1002@10.1.0.11 entering state [received][100]
2017-11-11 02:57:05.020621 [DEBUG] sofia.c:10044 IP 10.1.0.4 Rejected by acl "domains". Falling back to Digest auth.
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:05.020621 [DEBUG] sofia.c:9873 sofia/internal/1002@10.1.0.11 receiving invite from 10.1.0.4:16410 version: 1.6.19 -36-7a77e0b 64bit
2017-11-11 02:57:05.000648 [DEBUG] sofia.c:2442 Re-attaching to session e2795138-4430-4542-8a36-11a5f01c3a1c
2017-11-11 02:57:04.940655 [DEBUG] sofia.c:2334 detaching session e2795138-4430-4542-8a36-11a5f01c3a1c
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:04.940655 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/1002@10.1.0.11) State NEW
2017-11-11 02:57:04.940655 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [1001@10.1.0.11] from ip 10.1.0.4
2017-11-11 02:57:04.940655 [DEBUG] sofia.c:10044 IP 10.1.0.4 Rejected by acl "domains". Falling back to Digest auth.
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:04.940655 [DEBUG] sofia.c:9873 sofia/internal/1002@10.1.0.11 receiving invite from 10.1.0.4:16410 version: 1.6.19 -36-7a77e0b 64bit
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:04.940655 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/1002@10.1.0.11) Running State Change CS_NEW (Cur 1 Tot 55)
e2795138-4430-4542-8a36-11a5f01c3a1c 2017-11-11 02:57:04.940655 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/1002@10.1.0.11 [e2795138-4430-4542-8a36-11a5f01c3a1c]
2017-11-11 02:56:00.200658 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [1002@10.1.0.11] from ip 10.1.0.4
2017-11-11 02:55:41.960695 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [1001@10.1.0.11] from ip 10.1.0.4

EDIT:
I did setup now a gateway and tried calling from outside but no luck:

Code:

2017-11-11 05:23:52.449190 [NOTICE] switch_channel.c:1104 New Channel sofia/external/xxxxxxxx4284@sip.easybell.de [3fb1bb0d-9348-47ba-b039-755c97cfad7e]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx4284@sip.easybell.de) Running State Change CS_NEW (Cur 1 Tot 8)
2017-11-11 05:23:52.449190 [DEBUG] sofia.c:9873 sofia/external/xxxxxxxx4284@sip.easybell.de receiving invite from 195.185.37.60:5060 version: 1.6.19 -36-7a77e0b 64bit
2017-11-11 05:23:52.449190 [DEBUG] sofia.c:7084 Channel sofia/external/xxxxxxxx4284@sip.easybell.de entering state [received][100]
2017-11-11 05:23:52.449190 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 1630628590 1 IN IP4 195.185.37.60
s=-
c=IN IP4 195.185.37.60
t=0 0
m=audio 37476 RTP/AVP 8 100 118
a=rtpmap:8 PCMA/8000
a=fmtp:8 vad=no
a=rtpmap:100 telephone-event/8000
a=fmtp:100 0-15
a=rtpmap:118 PCMA/8000
a=direction:active
a=gpmd:118 vbd=yes

2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 100@8000
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:118:8000:20:0:1]/[G722:9:8000:20:64000:1]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:118:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:118:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:118:8000:20:0:1]/[GSM:3:8000:20:13200:1]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/xxxxxxxx4284@sip.easybell.de PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2017-11-11 05:23:52.449190 [DEBUG] switch_core_codec.c:111 sofia/external/xxxxxxxx4284@sip.easybell.de Original read codec set to PCMA:8
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 100@8000
2017-11-11 05:23:52.449190 [DEBUG] switch_core_media.c:4767 sofia/external/xxxxxxxx4284@sip.easybell.de Set 2833 dtmf send payload to 100 recv payload to 100
2017-11-11 05:23:52.449190 [DEBUG] sofia.c:7507 (sofia/external/xxxxxxxx4284@sip.easybell.de) State Change CS_NEW -> CS_INIT
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:603 (sofia/external/xxxxxxxx4284@sip.easybell.de) State NEW
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx4284@sip.easybell.de) Running State Change CS_INIT (Cur 1 Tot 8)
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:627 (sofia/external/xxxxxxxx4284@sip.easybell.de) State INIT
2017-11-11 05:23:52.449190 [DEBUG] mod_sofia.c:90 sofia/external/xxxxxxxx4284@sip.easybell.de SOFIA INIT
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:40 sofia/external/xxxxxxxx4284@sip.easybell.de Standard INIT
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:48 (sofia/external/xxxxxxxx4284@sip.easybell.de) State Change CS_INIT -> CS_ROUTING
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:627 (sofia/external/xxxxxxxx4284@sip.easybell.de) State INIT going to sleep
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx4284@sip.easybell.de) Running State Change CS_ROUTING (Cur 1 Tot 8)
2017-11-11 05:23:52.449190 [DEBUG] switch_channel.c:2249 (sofia/external/xxxxxxxx4284@sip.easybell.de) Callstate Change DOWN -> RINGING
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:643 (sofia/external/xxxxxxxx4284@sip.easybell.de) State ROUTING
2017-11-11 05:23:52.449190 [DEBUG] mod_sofia.c:143 sofia/external/xxxxxxxx4284@sip.easybell.de SOFIA ROUTING
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:236 sofia/external/xxxxxxxx4284@sip.easybell.de Standard ROUTING
2017-11-11 05:23:52.449190 [INFO] mod_dialplan_xml.c:637 Processing xxxxxxxx4284 <xxxxxxxx4284>->xxxxxxxx4385 in context public
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de parsing [public->xxxxxxxx4385] continue=false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Regex (PASS) [xxxxxxxx4385] destination_number(xxxxxxxx4385) =~ /^(xxxxxxxx4385)$/ break=on-false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Action set(call_direction=inbound) INLINE
EXECUTE sofia/external/xxxxxxxx4284@sip.easybell.de set(call_direction=inbound)
2017-11-11 05:23:52.449190 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx4284@sip.easybell.de [call_direction]=[inbound]
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Action set(domain_uuid=6d2ae5e6-bc75-4ee5-bcea-779486b18899) INLINE
EXECUTE sofia/external/xxxxxxxx4284@sip.easybell.de set(domain_uuid=6d2ae5e6-bc75-4ee5-bcea-779486b18899)
2017-11-11 05:23:52.449190 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx4284@sip.easybell.de [domain_uuid]=[6d2ae5e6-bc75-4ee5-bcea-779486b18899]
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Action set(domain_name=10.1.0.11) INLINE
EXECUTE sofia/external/xxxxxxxx4284@sip.easybell.de set(domain_name=10.1.0.11)
2017-11-11 05:23:52.449190 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx4284@sip.easybell.de [domain_name]=[10.1.0.11]
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Action transfer(1001 XML default)
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:286 (sofia/external/xxxxxxxx4284@sip.easybell.de) State Change CS_ROUTING -> CS_EXECUTE
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:643 (sofia/external/xxxxxxxx4284@sip.easybell.de) State ROUTING going to sleep
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx4284@sip.easybell.de) Running State Change CS_EXECUTE (Cur 1 Tot 8)
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:650 (sofia/external/xxxxxxxx4284@sip.easybell.de) State EXECUTE
2017-11-11 05:23:52.449190 [DEBUG] mod_sofia.c:198 sofia/external/xxxxxxxx4284@sip.easybell.de SOFIA EXECUTE
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:328 sofia/external/xxxxxxxx4284@sip.easybell.de Standard EXECUTE
EXECUTE sofia/external/xxxxxxxx4284@sip.easybell.de transfer(1001 XML default)
2017-11-11 05:23:52.449190 [DEBUG] switch_ivr.c:2165 (sofia/external/xxxxxxxx4284@sip.easybell.de) State Change CS_EXECUTE -> CS_ROUTING
2017-11-11 05:23:52.449190 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/xxxxxxxx4284@sip.easybell.de to XML[1001@default]
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:650 (sofia/external/xxxxxxxx4284@sip.easybell.de) State EXECUTE going to sleep
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx4284@sip.easybell.de) Running State Change CS_ROUTING (Cur 1 Tot 8)
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:643 (sofia/external/xxxxxxxx4284@sip.easybell.de) State ROUTING
2017-11-11 05:23:52.449190 [DEBUG] mod_sofia.c:143 sofia/external/xxxxxxxx4284@sip.easybell.de SOFIA ROUTING
2017-11-11 05:23:52.449190 [DEBUG] switch_core_state_machine.c:236 sofia/external/xxxxxxxx4284@sip.easybell.de Standard ROUTING
2017-11-11 05:23:52.449190 [INFO] mod_dialplan_xml.c:637 Processing xxxxxxxx4284 <xxxxxxxx4284>->1001 in context default
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de parsing [default->intercept-ext-polycom] continue=false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Regex (FAIL) [intercept-ext-polycom] destination_number(1001) =~ /^\*97(\d+)$/ break=on-false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de parsing [default->call forward all] continue=false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Regex (FAIL) [call forward all] ${user_exists}() =~ /^true/ break=on-false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de parsing [default->talking clock date and time] continue=true
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Regex (FAIL) [talking clock date and time] destination_number(1001) =~ /^\*9172$/ break=on-false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de parsing [default->talking clock time] continue=true
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Regex (FAIL) [talking clock time] destination_number(1001) =~ /^\*9170$/ break=on-false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de parsing [default->talking clock date] continue=true
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Regex (FAIL) [talking clock date] destination_number(1001) =~ /^\*9171$/ break=on-false
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de parsing [default->local_extension] continue=true
Dialplan: sofia/external/xxxxxxxx4284@sip.easybell.de Regex (FAIL) [local_extension] ${user_exists}() =~ /true/ break=on-false
2017-11-11 05:23:52.469161 [INFO] switch_core_state_machine.c:311 No Route, Aborting
2017-11-11 05:23:52.469161 [NOTICE] switch_core_state_machine.c:312 Hangup sofia/external/xxxxxxxx4284@sip.easybell.de [CS_ROUTING] [NO_ROUTE_DESTINATION]
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:643 (sofia/external/xxxxxxxx4284@sip.easybell.de) State ROUTING going to sleep
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx4284@sip.easybell.de) Running State Change CS_HANGUP (Cur 1 Tot 8)
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:850 (sofia/external/xxxxxxxx4284@sip.easybell.de) Callstate Change RINGING -> HANGUP
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:852 (sofia/external/xxxxxxxx4284@sip.easybell.de) State HANGUP
2017-11-11 05:23:52.469161 [DEBUG] mod_sofia.c:438 Channel sofia/external/xxxxxxxx4284@sip.easybell.de hanging up, cause: NO_ROUTE_DESTINATION
2017-11-11 05:23:52.469161 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:60 sofia/external/xxxxxxxx4284@sip.easybell.de Standard HANGUP, cause: NO_ROUTE_DESTINATION
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:852 (sofia/external/xxxxxxxx4284@sip.easybell.de) State HANGUP going to sleep
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:619 (sofia/external/xxxxxxxx4284@sip.easybell.de) State Change CS_HANGUP -> CS_REPORTING
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx4284@sip.easybell.de) Running State Change CS_REPORTING (Cur 1 Tot 8)
2017-11-11 05:23:52.469161 [DEBUG] switch_core_state_machine.c:938 (sofia/external/xxxxxxxx4284@sip.easybell.de) State REPORTING
2017-11-11 05:23:52.629420 [DEBUG] switch_core_state_machine.c:174 sofia/external/xxxxxxxx4284@sip.easybell.de Standard REPORTING, cause: NO_ROUTE_DESTINATION
2017-11-11 05:23:52.629420 [DEBUG] switch_core_state_machine.c:938 (sofia/external/xxxxxxxx4284@sip.easybell.de) State REPORTING going to sleep
2017-11-11 05:23:52.629420 [DEBUG] switch_core_state_machine.c:610 (sofia/external/xxxxxxxx4284@sip.easybell.de) State Change CS_REPORTING -> CS_DESTROY
2017-11-11 05:23:52.629420 [DEBUG] switch_core_session.c:1665 Session 8 (sofia/external/xxxxxxxx4284@sip.easybell.de) Locked, Waiting on external entities
2017-11-11 05:23:52.629420 [NOTICE] switch_core_session.c:1683 Session 8 (sofia/external/xxxxxxxx4284@sip.easybell.de) Ended
2017-11-11 05:23:52.629420 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/xxxxxxxx4284@sip.easybell.de [CS_DESTROY]
2017-11-11 05:23:52.629420 [DEBUG] switch_core_state_machine.c:741 (sofia/external/xxxxxxxx4284@sip.easybell.de) Running State Change CS_DESTROY (Cur 0 Tot 8)
2017-11-11 05:23:52.629420 [DEBUG] switch_core_state_machine.c:751 (sofia/external/xxxxxxxx4284@sip.easybell.de) State DESTROY
2017-11-11 05:23:52.629420 [DEBUG] mod_sofia.c:343 sofia/external/xxxxxxxx4284@sip.easybell.de SOFIA DESTROY
2017-11-11 05:23:52.629420 [DEBUG] switch_core_state_machine.c:181 sofia/external/xxxxxxxx4284@sip.easybell.de Standard DESTROY
2017-11-11 05:23:52.629420 [DEBUG] switch_core_state_machine.c:751 (sofia/external/xxxxxxxx4284@sip.easybell.de) State DESTROY going to sleep

DigitalDaz · Nov 11, 2017

I suppose first question to ask is have you modified any xml files or access control lists.

You are aware that all config is delivered from the DB?

Its difficult from those logs to tell anything as there isn't a completed call from beginning to end.

NBT Teknoloji · Nov 11, 2017

Did you try to restart "sofia status profile internal" ?
You can find under "status" >>> "sip status" menu.

MrGlasspoole · Nov 11, 2017

This is killing me. I tried hours now.

I did not change any xml files.
Extension to extension should just work i guess? There is nothing i need to do that i missed?

I also tried it with Zoiper from laptop to workstation to make sure it is not my normal phone.

I thought this will be easier than the normal FreeSwitch

DigitalDaz · Nov 11, 2017

I see an error:
mod_dialplan_xml.c:637 Processing Dietzel <1002>->1001 in context default

There should be no default context.

How did you install? You using clean Debian 8 and these instructions?

https://www.fusionpbx.com/download.php

MrGlasspoole · Nov 11, 2017

Yes normal installation.

I did put default in there because it is a needed field (bold) and in the old installation in the xml was:

Code:

<variable name="user_context" value="default"/>

I never did understand what user_context is.

Edit:
I made a new extension and saw that normally the IP is in there.
So changed the field to the IP and internal calls work now.

Edit2:
I went through all the context settings. Is there a difference between 'user context' and 'context'?

Gateway 'context': puplic
Extension 'user context': 10.1.0.11
Destination 'context': puplic
Inbound Routes 'context': puplic
Outbound Routes 'context': 10.1.0.11

DigitalDaz · Nov 11, 2017

Where exactly did you put a value in the field?

MrGlasspoole · Nov 12, 2017

Sorry, i was talking about the extension field 'user context'.

My old FreeSwitch had this in the xml:

Code:

<variable name="user_context" value="default"/>

DigitalDaz · Nov 12, 2017

I must be missing something, I have just looked in the GUI and I find no user context anywhere.

MrGlasspoole · Nov 12, 2017

DigitalDaz · Nov 12, 2017

That's the regular context and should have automatically populated, if it didn't you have far more serious problems

MrGlasspoole · Nov 12, 2017

As i wrote: If i make a new extension it is populated with "10.1.0.11".
I just did put "default" in there because that is what was in the xml of the old installation.

DigitalDaz · Nov 12, 2017

So still no calls?

DigitalDaz · Nov 12, 2017

Give us a call log now that you have fixed contexts

MrGlasspoole · Nov 13, 2017

As i wrote it works now internal with the IP in the context field.
Calling from inside to outside also works.

Gateway: http://i66.tinypic.com/ephu7l.jpg
Extension: http://i67.tinypic.com/20tm3qs.jpg
Destination: http://i63.tinypic.com/zvqul5.jpg
Inpound Route Dialplan: http://i63.tinypic.com/b4sw9h.jpg
Outpound Route Dialplan: http://i67.tinypic.com/o7lo43.jpg

What does not work is calling from outside. I see a lot UNALLOCATED_NUMBER if i call from outside:

Code:

2017-11-13 13:23:07.120884 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 10)
2017-11-13 13:23:07.120884 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1001) State CONSUME_MEDIA
2017-11-13 13:23:07.120884 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1001) State CONSUME_MEDIA going to sleep
2017-11-13 13:23:08.180924 [DEBUG] sofia.c:7084 Channel sofia/external/1001 entering state [calling][0]
2017-11-13 13:23:09.900927 [DEBUG] sofia.c:7084 Channel sofia/external/1001 entering state [terminated][404]
2017-11-13 13:23:09.900927 [NOTICE] sofia.c:8273 Hangup sofia/external/1001 [CS_CONSUME_MEDIA] [UNALLOCATED_NUMBER]
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001) Running State Change CS_HANGUP (Cur 2 Tot 10)
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1001) Callstate Change DOWN -> HANGUP
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1001) State HANGUP
2017-11-13 13:23:09.900927 [DEBUG] mod_sofia.c:438 Channel sofia/external/1001 hanging up, cause: UNALLOCATED_NUMBER
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:60 sofia/external/1001 Standard HANGUP, cause: UNALLOCATED_NUMBER
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1001) State HANGUP going to sleep
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1001) State Change CS_HANGUP -> CS_REPORTING
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001) Running State Change CS_REPORTING (Cur 2 Tot 10)
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1001) State REPORTING
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:174 sofia/external/1001 Standard REPORTING, cause: UNALLOCATED_NUMBER
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1001) State REPORTING going to sleep
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1001) State Change CS_REPORTING -> CS_DESTROY
2017-11-13 13:23:09.900927 [DEBUG] switch_core_session.c:1665 Session 10 (sofia/external/1001) Locked, Waiting on external entities
2017-11-13 13:23:09.900927 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 1 [UNALLOCATED_NUMBER]
2017-11-13 13:23:09.900927 [NOTICE] switch_core_session.c:1683 Session 10 (sofia/external/1001) Ended
2017-11-13 13:23:09.900927 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/1001 [CS_DESTROY]
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1001) Running State Change CS_DESTROY (Cur 1 Tot 10)
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1001) State DESTROY
2017-11-13 13:23:09.900927 [DEBUG] mod_sofia.c:343 sofia/external/1001 SOFIA DESTROY
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:181 sofia/external/1001 Standard DESTROY
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1001) State DESTROY going to sleep
2017-11-13 13:23:09.900927 [INFO] mod_dptools.c:3436 Originate Failed.  Cause: UNALLOCATED_NUMBER
2017-11-13 13:23:09.900927 [NOTICE] switch_core_state_machine.c:385 sofia/external/xxxxxxxxx495@sip.easybell.de has executed the last dialplan instruction, hanging up.
2017-11-13 13:23:09.900927 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/xxxxxxxxx495@sip.easybell.de [CS_EXECUTE] [NORMAL_CLEARING]
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:650 (sofia/external/xxxxxxxxx495@sip.easybell.de) State EXECUTE going to sleep
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxxx495@sip.easybell.de) Running State Change CS_HANGUP (Cur 1 Tot 10)
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:850 (sofia/external/xxxxxxxxx495@sip.easybell.de) Callstate Change RINGING -> HANGUP
2017-11-13 13:23:09.900927 [DEBUG] switch_core_state_machine.c:852 (sofia/external/xxxxxxxxx495@sip.easybell.de) State HANGUP
2017-11-13 13:23:09.900927 [DEBUG] mod_sofia.c:432 sofia/external/xxxxxxxxx495@sip.easybell.de Overriding SIP cause 480 with 404 from the other leg

DigitalDaz · Nov 13, 2017

Again, the log is useless, all you are confirming is that it is hanging up, where is the log of it hunting through the dialplan?

MrGlasspoole · Nov 13, 2017

What exactly to you mean?

I thought you can confirm the settings are right?

DigitalDaz · Nov 13, 2017

Setting look right, hence the need for a log of a call

DigitalDaz · Nov 13, 2017

Theres something looks wrong though:
sofia/external/1001

MrGlasspoole · Nov 13, 2017

Ok a complete log:

Code:

2017-11-13 16:52:43.220916 [NOTICE] switch_channel.c:1104 New Channel sofia/external/xxxxxxxx5495@sip.easybell.de [b34037bd-8ddc-4a72-ac03-ee463c76c06b]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_NEW (Cur 1 Tot 11)
2017-11-13 16:52:43.220916 [DEBUG] sofia.c:9873 sofia/external/xxxxxxxx5495@sip.easybell.de receiving invite from 195.185.37.60:5060 version: 1.6.19 -36-7a77e0b 64bit
2017-11-13 16:52:43.220916 [DEBUG] sofia.c:7084 Channel sofia/external/xxxxxxxx5495@sip.easybell.de entering state [received][100]
2017-11-13 16:52:43.220916 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=- 3245533788 1 IN IP4 195.185.37.60
s=-
c=IN IP4 195.185.37.60
t=0 0
m=audio 32046 RTP/AVP 8 100 118
a=rtpmap:8 PCMA/8000
a=fmtp:8 vad=no
a=rtpmap:100 telephone-event/8000
a=fmtp:100 0-15
a=rtpmap:118 PCMA/8000
a=direction:active
a=gpmd:118 vbd=yes

2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[GSM:3:8000:20:13200:1]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 100@8000
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:118:8000:20:0:1]/[G722:9:8000:20:64000:1]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:118:8000:20:0:1]/[PCMU:0:8000:20:64000:1]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:118:8000:20:0:1]/[PCMA:8:8000:20:64000:1]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:118:8000:20:0:1]/[GSM:3:8000:20:13200:1]
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/xxxxxxxx5495@sip.easybell.de PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2017-11-13 16:52:43.220916 [DEBUG] switch_core_codec.c:111 sofia/external/xxxxxxxx5495@sip.easybell.de Original read codec set to PCMA:8
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 100@8000
2017-11-13 16:52:43.220916 [DEBUG] switch_core_media.c:4767 sofia/external/xxxxxxxx5495@sip.easybell.de Set 2833 dtmf send payload to 100 recv payload to 100
2017-11-13 16:52:43.220916 [DEBUG] sofia.c:7507 (sofia/external/xxxxxxxx5495@sip.easybell.de) State Change CS_NEW -> CS_INIT
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:603 (sofia/external/xxxxxxxx5495@sip.easybell.de) State NEW
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_INIT (Cur 1 Tot 11)
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:627 (sofia/external/xxxxxxxx5495@sip.easybell.de) State INIT
2017-11-13 16:52:43.220916 [DEBUG] mod_sofia.c:90 sofia/external/xxxxxxxx5495@sip.easybell.de SOFIA INIT
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:40 sofia/external/xxxxxxxx5495@sip.easybell.de Standard INIT
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:48 (sofia/external/xxxxxxxx5495@sip.easybell.de) State Change CS_INIT -> CS_ROUTING
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:627 (sofia/external/xxxxxxxx5495@sip.easybell.de) State INIT going to sleep
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_ROUTING (Cur 1 Tot 11)
2017-11-13 16:52:43.220916 [DEBUG] switch_channel.c:2249 (sofia/external/xxxxxxxx5495@sip.easybell.de) Callstate Change DOWN -> RINGING
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:643 (sofia/external/xxxxxxxx5495@sip.easybell.de) State ROUTING
2017-11-13 16:52:43.220916 [DEBUG] mod_sofia.c:143 sofia/external/xxxxxxxx5495@sip.easybell.de SOFIA ROUTING
2017-11-13 16:52:43.220916 [DEBUG] switch_core_state_machine.c:236 sofia/external/xxxxxxxx5495@sip.easybell.de Standard ROUTING
2017-11-13 16:52:43.220916 [INFO] mod_dialplan_xml.c:637 Processing xxxxxxxx5495 <xxxxxxxx5495>->xxxxxxxxxxx4385 in context public
2017-11-13 16:52:43.260891 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f1bb00871a0 Connected.
2017-11-13 16:52:43.280906 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f1bb00871a0 released.
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de parsing [public->xxxxxxxxxxx4385] continue=false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [xxxxxxxxxxx4385] destination_number(xxxxxxxxxxx4385) =~ /^(xxxxxxxxxxx4385)$/ break=on-false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(call_direction=inbound) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(call_direction=inbound)
2017-11-13 16:52:43.280906 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [call_direction]=[inbound]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(domain_uuid=6d2ae5e6-bc75-4ee5-bcea-779486b18899) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(domain_uuid=6d2ae5e6-bc75-4ee5-bcea-779486b18899)
2017-11-13 16:52:43.280906 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [domain_uuid]=[6d2ae5e6-bc75-4ee5-bcea-779486b18899]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(domain_name=10.1.0.11) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(domain_name=10.1.0.11)
2017-11-13 16:52:43.280906 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [domain_name]=[10.1.0.11]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action transfer(1001 XML 10.1.0.11)
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:286 (sofia/external/xxxxxxxx5495@sip.easybell.de) State Change CS_ROUTING -> CS_EXECUTE
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:643 (sofia/external/xxxxxxxx5495@sip.easybell.de) State ROUTING going to sleep
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_EXECUTE (Cur 1 Tot 11)
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:650 (sofia/external/xxxxxxxx5495@sip.easybell.de) State EXECUTE
2017-11-13 16:52:43.280906 [DEBUG] mod_sofia.c:198 sofia/external/xxxxxxxx5495@sip.easybell.de SOFIA EXECUTE
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:328 sofia/external/xxxxxxxx5495@sip.easybell.de Standard EXECUTE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de transfer(1001 XML 10.1.0.11)
2017-11-13 16:52:43.280906 [DEBUG] switch_ivr.c:2165 (sofia/external/xxxxxxxx5495@sip.easybell.de) State Change CS_EXECUTE -> CS_ROUTING
2017-11-13 16:52:43.280906 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/xxxxxxxx5495@sip.easybell.de to XML[1001@10.1.0.11]
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:650 (sofia/external/xxxxxxxx5495@sip.easybell.de) State EXECUTE going to sleep
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_ROUTING (Cur 1 Tot 11)
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:643 (sofia/external/xxxxxxxx5495@sip.easybell.de) State ROUTING
2017-11-13 16:52:43.280906 [DEBUG] mod_sofia.c:143 sofia/external/xxxxxxxx5495@sip.easybell.de SOFIA ROUTING
2017-11-13 16:52:43.280906 [DEBUG] switch_core_state_machine.c:236 sofia/external/xxxxxxxx5495@sip.easybell.de Standard ROUTING
2017-11-13 16:52:43.280906 [INFO] mod_dialplan_xml.c:637 Processing xxxxxxxx5495 <xxxxxxxx5495>->1001 in context 10.1.0.11
2017-11-13 16:52:43.300908 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f1bb00871a0 Connected.
2017-11-13 16:52:43.320917 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f1bb00871a0 released.
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de parsing [10.1.0.11->user_exists] continue=true
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_exists] () =~ // break=on-false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(user_exists=true)
2017-11-13 16:52:43.340896 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [user_exists]=[true]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_exists] ${user_exists}(true) =~ /^true$/ break=on-false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(extension_uuid=${user_data ${destination_number}@${domain_name} var extension_uuid}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(extension_uuid=bf8d572e-a89a-475f-a02f-5f764f7b1280)
2017-11-13 16:52:43.340896 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [extension_uuid]=[bf8d572e-a89a-475f-a02f-5f764f7b1280]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(hold_music=${user_data ${destination_number}@${domain_name} var hold_music}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(hold_music=local_stream://default)
2017-11-13 16:52:43.340896 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [hold_music]=[local_stream://default]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(forward_all_enabled=)
2017-11-13 16:52:43.360886 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [forward_all_enabled]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(forward_all_destination=${user_data ${destination_number}@${domain_name} var forward_all_destination}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(forward_all_destination=)
2017-11-13 16:52:43.360886 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [forward_all_destination]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(forward_busy_enabled=${user_data ${destination_number}@${domain_name} var forward_busy_enabled}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(forward_busy_enabled=)
2017-11-13 16:52:43.360886 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [forward_busy_enabled]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(forward_busy_destination=${user_data ${destination_number}@${domain_name} var forward_busy_destination}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(forward_busy_destination=)
2017-11-13 16:52:43.380887 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [forward_busy_destination]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(forward_no_answer_enabled=${user_data ${destination_number}@${domain_name} var forward_no_answer_enabled}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(forward_no_answer_enabled=)
2017-11-13 16:52:43.380887 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [forward_no_answer_enabled]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(forward_no_answer_destination=${user_data ${destination_number}@${domain_name} var forward_no_answer_destination}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(forward_no_answer_destination=)
2017-11-13 16:52:43.380887 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [forward_no_answer_destination]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(forward_user_not_registered_enabled=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_enabled}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(forward_user_not_registered_enabled=)
2017-11-13 16:52:43.380887 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [forward_user_not_registered_enabled]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(forward_user_not_registered_destination=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_destination}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(forward_user_not_registered_destination=)
2017-11-13 16:52:43.400893 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [forward_user_not_registered_destination]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(do_not_disturb=${user_data ${destination_number}@${domain_name} var do_not_disturb}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(do_not_disturb=)
2017-11-13 16:52:43.400893 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [do_not_disturb]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(call_timeout=${user_data ${destination_number}@${domain_name} var call_timeout}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(call_timeout=10)
2017-11-13 16:52:43.400893 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [call_timeout]=[10]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(missed_call_app=${user_data ${destination_number}@${domain_name} var missed_call_app}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(missed_call_app=email)
2017-11-13 16:52:43.420888 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [missed_call_app]=[email]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(missed_call_data=${user_data ${destination_number}@${domain_name} var missed_call_data}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(missed_call_data=xxxxxxx@runbox.com)
2017-11-13 16:52:43.420888 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [missed_call_data]=[xxxxxx@runbox.com]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(toll_allow=${user_data ${destination_number}@${domain_name} var toll_allow}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(toll_allow=)
2017-11-13 16:52:43.420888 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [toll_allow]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(call_screen_enabled=${user_data ${destination_number}@${domain_name} var call_screen_enabled}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(call_screen_enabled=false)
2017-11-13 16:52:43.420888 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [call_screen_enabled]=[false]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de parsing [10.1.0.11->call-direction] continue=true
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de parsing [10.1.0.11->variables] continue=true
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [variables] () =~ // break=on-false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action export(origination_callee_id_name=${destination_number})
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de parsing [10.1.0.11->user_record] continue=true
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_record] () =~ // break=on-false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(user_record=)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [user_record]=[UNDEF]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE
2017-11-13 16:52:43.440892 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f1bb00871a0 Connected.
2017-11-13 16:52:43.440892 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f1bb00871a0 released.
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(from_user_exists=false)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [from_user_exists]=[false]
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [user_record] ${call_direction}(inbound) =~ /^inbound$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^outbound$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${call_direction}(inbound) =~ /^local$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de parsing [10.1.0.11->redial] continue=true
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [redial] destination_number(1001) =~ /^(redial|\*870)$/ break=on-true
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [redial] () =~ // break=never
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number})
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de parsing [10.1.0.11->speed_dial] continue=false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (FAIL) [speed_dial] destination_number(1001) =~ /^\*0(.*)$/ break=on-false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de parsing [10.1.0.11->Easybell_Bjoern.d] continue=false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Regex (PASS) [Easybell_Bjoern.d] destination_number(1001) =~ /^(\d+)$/ break=on-false
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(sip_h_X-accountcode=${accountcode})
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(call_direction=outbound)
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action unset(call_timeout)
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(hangup_after_bridge=true)
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(effective_caller_id_name=${outbound_caller_id_name})
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(effective_caller_id_number=${outbound_caller_id_number})
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(inherit_codec=true)
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(ignore_display_updates=true)
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(callee_id_number=1001)
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action set(continue_on_fail=true)
Dialplan: sofia/external/xxxxxxxx5495@sip.easybell.de Action bridge(sofia/gateway/210c332b-c488-43ba-9a1d-f68c810b7108/1001)
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:286 (sofia/external/xxxxxxxx5495@sip.easybell.de) State Change CS_ROUTING -> CS_EXECUTE
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:643 (sofia/external/xxxxxxxx5495@sip.easybell.de) State ROUTING going to sleep
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_EXECUTE (Cur 1 Tot 11)
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:650 (sofia/external/xxxxxxxx5495@sip.easybell.de) State EXECUTE
2017-11-13 16:52:43.440892 [DEBUG] mod_sofia.c:198 sofia/external/xxxxxxxx5495@sip.easybell.de SOFIA EXECUTE
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:328 sofia/external/xxxxxxxx5495@sip.easybell.de Standard EXECUTE
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de export(origination_callee_id_name=1001)
2017-11-13 16:52:43.440892 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [origination_callee_id_name]=[1001]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(RFC2822_DATE=Mon, 13 Nov 2017 16:52:43 +0100)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [RFC2822_DATE]=[Mon, 13 Nov 2017 16:52:43 +0100]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de hash(insert/10.1.0.11-last_dial/xxxxxxxx5495/1001)
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(sip_h_X-accountcode=)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [sip_h_X-accountcode]=[UNDEF]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(call_direction=outbound)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [call_direction]=[outbound]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de unset(call_timeout)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1693 UNSET [call_timeout]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(hangup_after_bridge=true)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [hangup_after_bridge]=[true]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(effective_caller_id_name=)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [effective_caller_id_name]=[UNDEF]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(effective_caller_id_number=)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [effective_caller_id_number]=[UNDEF]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(inherit_codec=true)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [inherit_codec]=[true]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(ignore_display_updates=true)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [ignore_display_updates]=[true]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(callee_id_number=1001)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [callee_id_number]=[1001]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de set(continue_on_fail=true)
2017-11-13 16:52:43.440892 [DEBUG] mod_dptools.c:1548 SET sofia/external/xxxxxxxx5495@sip.easybell.de [continue_on_fail]=[true]
EXECUTE sofia/external/xxxxxxxx5495@sip.easybell.de bridge(sofia/gateway/210c332b-c488-43ba-9a1d-f68c810b7108/1001)
2017-11-13 16:52:43.440892 [DEBUG] switch_channel.c:1250 sofia/external/xxxxxxxx5495@sip.easybell.de EXPORTING[export_vars] [origination_callee_id_name]=[1001] to event
2017-11-13 16:52:43.440892 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
2017-11-13 16:52:43.440892 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1001 [0c88d4a2-1402-45b2-a5c1-0389649da7d8]
2017-11-13 16:52:43.440892 [DEBUG] mod_sofia.c:4819 (sofia/external/1001) State Change CS_NEW -> CS_INIT
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001) Running State Change CS_INIT (Cur 2 Tot 12)
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1001) State INIT
2017-11-13 16:52:43.440892 [DEBUG] mod_sofia.c:90 sofia/external/1001 SOFIA INIT
2017-11-13 16:52:43.440892 [DEBUG] sofia_glue.c:1295 sofia/external/1001 sending invite version: 1.6.19 -36-7a77e0b 64bit
Local SDP:
v=0
o=FreeSWITCH 1510563449 1510563450 IN IP4 10.1.0.11
s=FreeSWITCH
c=IN IP4 10.1.0.11
t=0 0
m=audio 24914 RTP/AVP 8 0 3 101 13
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:3 GSM/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtpmap:13 CN/8000
a=ptime:20
a=sendrecv

2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:40 sofia/external/1001 Standard INIT
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1001) State Change CS_INIT -> CS_ROUTING
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1001) State INIT going to sleep
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001) Running State Change CS_ROUTING (Cur 2 Tot 12)
2017-11-13 16:52:43.440892 [DEBUG] sofia.c:7084 Channel sofia/external/1001 entering state [calling][0]
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1001) State ROUTING
2017-11-13 16:52:43.440892 [DEBUG] mod_sofia.c:143 sofia/external/1001 SOFIA ROUTING
2017-11-13 16:52:43.440892 [DEBUG] switch_ivr_originate.c:67 (sofia/external/1001) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1001) State ROUTING going to sleep
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 12)
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1001) State CONSUME_MEDIA
2017-11-13 16:52:43.440892 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1001) State CONSUME_MEDIA going to sleep
2017-11-13 16:52:43.480876 [DEBUG] sofia.c:7084 Channel sofia/external/1001 entering state [calling][0]
2017-11-13 16:52:45.540923 [DEBUG] sofia.c:7084 Channel sofia/external/1001 entering state [terminated][404]
2017-11-13 16:52:45.540923 [NOTICE] sofia.c:8273 Hangup sofia/external/1001 [CS_CONSUME_MEDIA] [UNALLOCATED_NUMBER]
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001) Running State Change CS_HANGUP (Cur 2 Tot 12)
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1001) Callstate Change DOWN -> HANGUP
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1001) State HANGUP
2017-11-13 16:52:45.540923 [DEBUG] mod_sofia.c:438 Channel sofia/external/1001 hanging up, cause: UNALLOCATED_NUMBER
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:60 sofia/external/1001 Standard HANGUP, cause: UNALLOCATED_NUMBER
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1001) State HANGUP going to sleep
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1001) State Change CS_HANGUP -> CS_REPORTING
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001) Running State Change CS_REPORTING (Cur 2 Tot 12)
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1001) State REPORTING
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:174 sofia/external/1001 Standard REPORTING, cause: UNALLOCATED_NUMBER
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1001) State REPORTING going to sleep
2017-11-13 16:52:45.540923 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1001) State Change CS_REPORTING -> CS_DESTROY
2017-11-13 16:52:45.540923 [DEBUG] switch_core_session.c:1665 Session 12 (sofia/external/1001) Locked, Waiting on external entities
2017-11-13 16:52:45.560898 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 1 [UNALLOCATED_NUMBER]
2017-11-13 16:52:45.560898 [NOTICE] switch_core_session.c:1683 Session 12 (sofia/external/1001) Ended
2017-11-13 16:52:45.560898 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/1001 [CS_DESTROY]
2017-11-13 16:52:45.560898 [INFO] mod_dptools.c:3436 Originate Failed.  Cause: UNALLOCATED_NUMBER
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1001) Running State Change CS_DESTROY (Cur 1 Tot 12)
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1001) State DESTROY
2017-11-13 16:52:45.560898 [DEBUG] mod_sofia.c:343 sofia/external/1001 SOFIA DESTROY
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:181 sofia/external/1001 Standard DESTROY
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1001) State DESTROY going to sleep
2017-11-13 16:52:45.560898 [NOTICE] switch_core_state_machine.c:385 sofia/external/xxxxxxxx5495@sip.easybell.de has executed the last dialplan instruction, hanging up.
2017-11-13 16:52:45.560898 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/xxxxxxxx5495@sip.easybell.de [CS_EXECUTE] [NORMAL_CLEARING]
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:650 (sofia/external/xxxxxxxx5495@sip.easybell.de) State EXECUTE going to sleep
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_HANGUP (Cur 1 Tot 12)
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:850 (sofia/external/xxxxxxxx5495@sip.easybell.de) Callstate Change RINGING -> HANGUP
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:852 (sofia/external/xxxxxxxx5495@sip.easybell.de) State HANGUP
2017-11-13 16:52:45.560898 [DEBUG] mod_sofia.c:432 sofia/external/xxxxxxxx5495@sip.easybell.de Overriding SIP cause 480 with 404 from the other leg
2017-11-13 16:52:45.560898 [DEBUG] mod_sofia.c:438 Channel sofia/external/xxxxxxxx5495@sip.easybell.de hanging up, cause: NORMAL_CLEARING
2017-11-13 16:52:45.560898 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 404
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:60 sofia/external/xxxxxxxx5495@sip.easybell.de Standard HANGUP, cause: NORMAL_CLEARING
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:852 (sofia/external/xxxxxxxx5495@sip.easybell.de) State HANGUP going to sleep
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:619 (sofia/external/xxxxxxxx5495@sip.easybell.de) State Change CS_HANGUP -> CS_REPORTING
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:584 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_REPORTING (Cur 1 Tot 12)
2017-11-13 16:52:45.560898 [DEBUG] switch_core_state_machine.c:938 (sofia/external/xxxxxxxx5495@sip.easybell.de) State REPORTING
2017-11-13 16:52:45.640933 [DEBUG] switch_core_state_machine.c:174 sofia/external/xxxxxxxx5495@sip.easybell.de Standard REPORTING, cause: NORMAL_CLEARING
2017-11-13 16:52:45.640933 [DEBUG] switch_core_state_machine.c:938 (sofia/external/xxxxxxxx5495@sip.easybell.de) State REPORTING going to sleep
2017-11-13 16:52:45.640933 [DEBUG] switch_core_state_machine.c:610 (sofia/external/xxxxxxxx5495@sip.easybell.de) State Change CS_REPORTING -> CS_DESTROY
2017-11-13 16:52:45.640933 [DEBUG] switch_core_session.c:1665 Session 11 (sofia/external/xxxxxxxx5495@sip.easybell.de) Locked, Waiting on external entities
2017-11-13 16:52:45.640933 [NOTICE] switch_core_session.c:1683 Session 11 (sofia/external/xxxxxxxx5495@sip.easybell.de) Ended
2017-11-13 16:52:45.640933 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/xxxxxxxx5495@sip.easybell.de [CS_DESTROY]
2017-11-13 16:52:45.640933 [DEBUG] switch_core_state_machine.c:741 (sofia/external/xxxxxxxx5495@sip.easybell.de) Running State Change CS_DESTROY (Cur 0 Tot 12)
2017-11-13 16:52:45.640933 [DEBUG] switch_core_state_machine.c:751 (sofia/external/xxxxxxxx5495@sip.easybell.de) State DESTROY
2017-11-13 16:52:45.640933 [DEBUG] mod_sofia.c:343 sofia/external/xxxxxxxx5495@sip.easybell.de SOFIA DESTROY
2017-11-13 16:52:45.640933 [DEBUG] switch_core_state_machine.c:181 sofia/external/xxxxxxxx5495@sip.easybell.de Standard DESTROY
2017-11-13 16:52:45.640933 [DEBUG] switch_core_state_machine.c:751 (sofia/external/xxxxxxxx5495@sip.easybell.de) State DESTROY going to sleep

Internal calls are not working

Member

Administrator

New Member

Member

Administrator

Member

Administrator

Member

Administrator

Member

Administrator

Member

Administrator

Administrator

Member

Administrator

Member

Administrator

Administrator

Member