I'm trying to provide a proprietary SIP server a trunk via a fusion extension(99999) for outbound only calling. The SIP servers IP is white listed as it is not capable of registration and that works good. I'm guessing the issue has something to do with sofia/internal/ but dont know what it is. Can someone point out the hopefully obvious error to me.
Yes this server does work with any standard provider and has for 8 years now.
Thanks!
Yes this server does work with any standard provider and has for 8 years now.
Thanks!
Code:
2018-09-01 13:59:22.624767 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/9722807286@27.116.60.99 [a2f53642-ed94-48fe-908d-17698297c331]
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9722807286@27.116.60.99) Running State Change CS_NEW (Cur 1 Tot 8532)
2018-09-01 13:59:22.624767 [DEBUG] sofia.c:9873 sofia/internal/9722807286@27.116.60.99 receiving invite from 27.116.60.99:5061 version: 1.6.20 -37-987c9b9 64bit
2018-09-01 13:59:22.624767 [DEBUG] sofia.c:9989 IP 27.116.60.99 Approved by acl "domains[]". Access Granted.
2018-09-01 13:59:22.624767 [DEBUG] sofia.c:11168 Setting NAT mode based on via port
2018-09-01 13:59:22.624767 [DEBUG] sofia.c:7084 Channel sofia/internal/9722807286@27.116.60.99 entering state [received][100]
2018-09-01 13:59:22.624767 [DEBUG] sofia.c:7094 Remote SDP:
v=0
o=root 0 0 IN IP4 27.116.60.99
s=session
c=IN IP4 27.116.60.99
t=0 0
m=audio 14072 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1]
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/9722807286@27.116.60.99 G729/8000 20 ms 160 samples 8000 bits 1 channels
2018-09-01 13:59:22.624767 [DEBUG] switch_core_codec.c:111 sofia/internal/9722807286@27.116.60.99 Original read codec set to G729:18
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
2018-09-01 13:59:22.624767 [DEBUG] switch_core_media.c:4767 sofia/internal/9722807286@27.116.60.99 Set 2833 dtmf send payload to 101 recv payload to 101
2018-09-01 13:59:22.624767 [DEBUG] sofia.c:7507 (sofia/internal/9722807286@27.116.60.99) State Change CS_NEW -> CS_INIT
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/9722807286@27.116.60.99) State NEW
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9722807286@27.116.60.99) Running State Change CS_INIT (Cur 1 Tot 8532)
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/9722807286@27.116.60.99) State INIT
2018-09-01 13:59:22.624767 [DEBUG] mod_sofia.c:90 sofia/internal/9722807286@27.116.60.99 SOFIA INIT
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:40 sofia/internal/9722807286@27.116.60.99 Standard INIT
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/9722807286@27.116.60.99) State Change CS_INIT -> CS_ROUTING
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/9722807286@27.116.60.99) State INIT going to sleep
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9722807286@27.116.60.99) Running State Change CS_ROUTING (Cur 1 Tot 8532)
2018-09-01 13:59:22.624767 [DEBUG] switch_channel.c:2249 (sofia/internal/9722807286@27.116.60.99) Callstate Change DOWN -> RINGING
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/9722807286@27.116.60.99) State ROUTING
2018-09-01 13:59:22.624767 [DEBUG] mod_sofia.c:143 sofia/internal/9722807286@27.116.60.99 SOFIA ROUTING
2018-09-01 13:59:22.624767 [DEBUG] switch_core_state_machine.c:236 sofia/internal/9722807286@27.116.60.99 Standard ROUTING
2018-09-01 13:59:22.624767 [INFO] mod_dialplan_xml.c:637 Processing 9722807286 <9722807286>->12142769999 in context public
2018-09-01 13:59:22.664604 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa63026a6d0 Connected.
2018-09-01 13:59:22.664604 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa63026a6d0 released.
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->caller-details] continue=true
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (PASS) [caller-details] () =~ // break=never
Dialplan: sofia/internal/9722807286@27.116.60.99 Action export(call_direction=inbound) INLINE
EXECUTE sofia/internal/9722807286@27.116.60.99 export(call_direction=inbound)
2018-09-01 13:59:22.664604 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/9722807286@27.116.60.99 Action set(caller_destination=${destination_number}) INLINE
EXECUTE sofia/internal/9722807286@27.116.60.99 set(caller_destination=12142769999)
2018-09-01 13:59:22.664604 [DEBUG] mod_dptools.c:1548 SET sofia/internal/9722807286@27.116.60.99 [caller_destination]=[12142769999]
Dialplan: sofia/internal/9722807286@27.116.60.99 Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE sofia/internal/9722807286@27.116.60.99 set(caller_id_name=9722807286)
2018-09-01 13:59:22.664604 [DEBUG] mod_dptools.c:1548 SET sofia/internal/9722807286@27.116.60.99 [caller_id_name]=[9722807286]
Dialplan: sofia/internal/9722807286@27.116.60.99 Action set(caller_id_number=${caller_id_number}) INLINE
EXECUTE sofia/internal/9722807286@27.116.60.99 set(caller_id_number=9722807286)
2018-09-01 13:59:22.664604 [DEBUG] mod_dptools.c:1548 SET sofia/internal/9722807286@27.116.60.99 [caller_id_number]=[9722807286]
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->18173805679] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [18173805679] destination_number(12142769999) =~ /^(18173805679)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->15128171362] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [15128171362] destination_number(12142769999) =~ /^\+(15128171362)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->14326948914] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [14326948914] destination_number(12142769999) =~ /^\+(14326948914)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->18178405588] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [18178405588] destination_number(12142769999) =~ /^\+(18178405588)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->18179935855] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [18179935855] destination_number(12142769999) =~ /^\+(18179935855)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->18173832211] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [18173832211] destination_number(12142769999) =~ /^\+(18173832211)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->18179934047] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [18179934047] destination_number(12142769999) =~ /^\+(18179934047)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->85523962698] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [85523962698] destination_number(12142769999) =~ /^\+(85523962698)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->12016958636] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [12016958636] destination_number(12142769999) =~ /nexmo_(\d+)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->18179935248] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [18179935248] destination_number(12142769999) =~ /^\+(18179935248)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->18009581356] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [18009581356] destination_number(12142769999) =~ /^\+(18009581356)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->18174396880] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (FAIL) [18174396880] destination_number(12142769999) =~ /^\+(18174396880)$/ break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 parsing [public->not-found] continue=false
Dialplan: sofia/internal/9722807286@27.116.60.99 Regex (PASS) [not-found] () =~ // break=on-false
Dialplan: sofia/internal/9722807286@27.116.60.99 Action export(call_direction=inbound) INLINE
EXECUTE sofia/internal/9722807286@27.116.60.99 export(call_direction=inbound)
2018-09-01 13:59:22.664604 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/9722807286@27.116.60.99 Action set(call_direction=inbound) INLINE
EXECUTE sofia/internal/9722807286@27.116.60.99 set(call_direction=inbound)
2018-09-01 13:59:22.664604 [DEBUG] mod_dptools.c:1548 SET sofia/internal/9722807286@27.116.60.99 [call_direction]=[inbound]
Dialplan: sofia/internal/9722807286@27.116.60.99 Action log([inbound routes] 404 not found ${sip_network_ip}) INLINE
EXECUTE sofia/internal/9722807286@27.116.60.99 log([inbound routes] 404 not found 27.116.60.99)
2018-09-01 13:59:22.664604 [DEBUG] mod_dptools.c:1742 routes] 404 not found 27.116.60.99
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/9722807286@27.116.60.99) State Change CS_ROUTING -> CS_EXECUTE
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/9722807286@27.116.60.99) State ROUTING going to sleep
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9722807286@27.116.60.99) Running State Change CS_EXECUTE (Cur 1 Tot 8532)
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/9722807286@27.116.60.99) State EXECUTE
2018-09-01 13:59:22.664604 [DEBUG] mod_sofia.c:198 sofia/internal/9722807286@27.116.60.99 SOFIA EXECUTE
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:328 sofia/internal/9722807286@27.116.60.99 Standard EXECUTE
2018-09-01 13:59:22.664604 [NOTICE] switch_core_state_machine.c:385 sofia/internal/9722807286@27.116.60.99 has executed the last dialplan instruction, hanging up.
2018-09-01 13:59:22.664604 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/9722807286@27.116.60.99 [CS_EXECUTE] [NORMAL_CLEARING]
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/9722807286@27.116.60.99) State EXECUTE going to sleep
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9722807286@27.116.60.99) Running State Change CS_HANGUP (Cur 1 Tot 8532)
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/9722807286@27.116.60.99) Callstate Change RINGING -> HANGUP
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/9722807286@27.116.60.99) State HANGUP
2018-09-01 13:59:22.664604 [DEBUG] mod_sofia.c:438 Channel sofia/internal/9722807286@27.116.60.99 hanging up, cause: NORMAL_CLEARING
2018-09-01 13:59:22.664604 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 480
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:60 sofia/internal/9722807286@27.116.60.99 Standard HANGUP, cause: NORMAL_CLEARING
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/9722807286@27.116.60.99) State HANGUP going to sleep
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/9722807286@27.116.60.99) State Change CS_HANGUP -> CS_REPORTING
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/9722807286@27.116.60.99) Running State Change CS_REPORTING (Cur 1 Tot 8532)
2018-09-01 13:59:22.664604 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/9722807286@27.116.60.99) State REPORTING
2018-09-01 13:59:22.744600 [DEBUG] switch_core_state_machine.c:174 sofia/internal/9722807286@27.116.60.99 Standard REPORTING, cause: NORMAL_CLEARING
2018-09-01 13:59:22.744600 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/9722807286@27.116.60.99) State REPORTING going to sleep
2018-09-01 13:59:22.744600 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/9722807286@27.116.60.99) State Change CS_REPORTING -> CS_DESTROY
2018-09-01 13:59:22.744600 [DEBUG] switch_core_session.c:1665 Session 8532 (sofia/internal/9722807286@27.116.60.99) Locked, Waiting on external entities
2018-09-01 13:59:22.744600 [NOTICE] switch_core_session.c:1683 Session 8532 (sofia/internal/9722807286@27.116.60.99) Ended
2018-09-01 13:59:22.744600 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/9722807286@27.116.60.99 [CS_DESTROY]
2018-09-01 13:59:22.744600 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/9722807286@27.116.60.99) Running State Change CS_DESTROY (Cur 0 Tot 8532)
2018-09-01 13:59:22.744600 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/9722807286@27.116.60.99) State DESTROY
2018-09-01 13:59:22.744600 [DEBUG] mod_sofia.c:343 sofia/internal/9722807286@27.116.60.99 SOFIA DESTROY
2018-09-01 13:59:22.744600 [DEBUG] switch_core_state_machine.c:181 sofia/internal/9722807286@27.116.60.99 Standard DESTROY
2018-09-01 13:59:22.744600 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/9722807286@27.116.60.99) State DESTROY going to sleep
Last edited: