internal extension not working SIP 404

D

dgxa

Member
May 19, 2021
43
2
8
35
Lima, Peru
Hello I have this error in a new fusionpbx instalacion ACL allow withh 0.0.0.0 and call beteewn extension not work

I recieved the messaje

Dialplan: sofia/internal/300@midomain.com Action log(WARNING [inbound routes] 404 not found ${sip_network_ip} destination_number ${destination_number} sip_to_user ${sip_to_user} sip_req_user ${sip_req_user})
Dialplan: sofia/internal/300@midomain.com Action respond(404 Not Found)
Click to expand...
This is my all trace

2025-06-01 23:12:07.950343 99.57% [NOTICE] switch_channel.c:1142 New Channel sofia/internal/300@midomain.com [a1ee7747-c36b-426e-b57d-f1aed0a80454]
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/300@midomain.com) Running State Change CS_NEW (Cur 1 Tot 6)
2025-06-01 23:12:07.950343 99.57% [INFO] sofia.c:10460 sofia/internal/300@midomain.com receiving invite from 150.224.234.2:49874 version: 1.10.12 -release-10222002881-a88d069d6fgit a88d069 2024-08-02 21:02:27Z 64bit call-id: 8a6fbb7a681a4004a1ec1a6393fbea8d
2025-06-01 23:12:07.950343 99.57% [DEBUG] sofia.c:10554 verifying acl "providers" for ip/port 150.224.234.2:0.
2025-06-01 23:12:07.950343 99.57% [DEBUG] sofia.c:10583 IP 150.224.234.2 Approved by acl "providers[]". Access Granted.
2025-06-01 23:12:07.950343 99.57% [DEBUG] sofia.c:11675 Setting NAT mode based on nat.auto
2025-06-01 23:12:07.950343 99.57% [DEBUG] sofia.c:7493 Channel sofia/internal/300@midomain.com entering state [received][100]
2025-06-01 23:12:07.950343 99.57% [DEBUG] sofia.c:7503 Remote SDP:
v=0
o=- 3957783127 3957783127 IN IP4 192.168.0.104
s=pjmedia
b=AS:84
t=0 0
a=X-nat:0
m=audio 4002 RTP/AVP 8 0 101
c=IN IP4 192.168.0.104
b=TIAS:64000
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=rtcp:4003 IN IP4 192.168.0.104
a=ssrc:342770450 cname:16f24ddc32a07cfa

2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5588 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5526 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5438 Set telephone-event payload to 101@8000
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:3731 Set Codec sofia/internal/300@midomain.com PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_codec.c:111 sofia/internal/300@midomain.com Original read codec set to PCMA:8
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5798 Set telephone-event payload to 101@8000
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_media.c:5856 sofia/internal/300@midomain.com Set 2833 dtmf send payload to 101 recv payload to 101
2025-06-01 23:12:07.950343 99.57% [DEBUG] sofia.c:7927 (sofia/internal/300@midomain.com) State Change CS_NEW -> CS_INIT
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:600 (sofia/internal/300@midomain.com) State NEW
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/300@midomain.com) Running State Change CS_INIT (Cur 1 Tot 6)
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/300@midomain.com) State INIT
2025-06-01 23:12:07.950343 99.57% [DEBUG] mod_sofia.c:97 sofia/internal/300@midomain.com SOFIA INIT
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:40 sofia/internal/300@midomain.com Standard INIT
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:48 (sofia/internal/300@midomain.com) State Change CS_INIT -> CS_ROUTING
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:624 (sofia/internal/300@midomain.com) State INIT going to sleep
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/300@midomain.com) Running State Change CS_ROUTING (Cur 1 Tot 6)
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_channel.c:2399 (sofia/internal/300@midomain.com) Callstate Change DOWN -> RINGING
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/300@midomain.com) State ROUTING
2025-06-01 23:12:07.950343 99.57% [DEBUG] mod_sofia.c:158 sofia/internal/300@midomain.com SOFIA ROUTING
2025-06-01 23:12:07.950343 99.57% [DEBUG] switch_core_state_machine.c:230 sofia/internal/300@midomain.com Standard ROUTING
2025-06-01 23:12:07.950343 99.57% [INFO] mod_dialplan_xml.c:639 Processing 300 <300>->200 in context public
2025-06-01 23:12:07.975230 99.57% [NOTICE] switch_cpp.cpp:1466 [xml_handler] multiple key:dialplan:public
Dialplan: sofia/internal/300@midomain.com parsing [public->caller-details] continue=true
Dialplan: sofia/internal/300@midomain.com Regex (PASS) [caller-details] () =~ // break=never
Dialplan: sofia/internal/300@midomain.com Action export(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/internal/300@midomain.com export(call_direction=inbound)
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/300@midomain.com Action set(caller_destination=${sip_to_user}) INLINE
EXECUTE [depth=0] sofia/internal/300@midomain.com set(caller_destination=200)
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_dptools.c:1671 SET sofia/internal/300@midomain.com [caller_destination]=[200]
Dialplan: sofia/internal/300@midomain.com Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE [depth=0] sofia/internal/300@midomain.com set(caller_id_name=300)
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_dptools.c:1671 SET sofia/internal/300@midomain.com [caller_id_name]=[300]
Dialplan: sofia/internal/300@midomain.com Action set(caller_id_number=${caller_id_number})
Dialplan: sofia/internal/300@midomain.com parsing [public->not-found] continue=false
Dialplan: sofia/internal/300@midomain.com Regex (PASS) [not-found] () =~ // break=on-false
Dialplan: sofia/internal/300@midomain.com Action export(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/internal/300@midomain.com export(call_direction=inbound)
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_channel.c:1334 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/internal/300@midomain.com Action set(call_direction=inbound) INLINE
EXECUTE [depth=0] sofia/internal/300@midomain.com set(call_direction=inbound)
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_dptools.c:1671 SET sofia/internal/300@midomain.com [call_direction]=[inbound]
Dialplan: sofia/internal/300@midomain.com Action log(WARNING [inbound routes] 404 not found ${sip_network_ip} destination_number ${destination_number} sip_to_user ${sip_to_user} sip_req_user ${sip_req_user})
Dialplan: sofia/internal/300@midomain.com Action respond(404 Not Found)
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:281 (sofia/internal/300@midomain.com) State Change CS_ROUTING -> CS_EXECUTE
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:640 (sofia/internal/300@midomain.com) State ROUTING going to sleep
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/300@midomain.com) Running State Change CS_EXECUTE (Cur 1 Tot 6)
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/300@midomain.com) State EXECUTE
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_sofia.c:213 sofia/internal/300@midomain.com SOFIA EXECUTE
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:323 sofia/internal/300@midomain.com Standard EXECUTE
EXECUTE [depth=0] sofia/internal/300@midomain.com set(caller_id_number=300)
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_dptools.c:1671 SET sofia/internal/300@midomain.com [caller_id_number]=[300]
EXECUTE [depth=0] sofia/internal/300@midomain.com log(WARNING [inbound routes] 404 not found 150.224.234.2 destination_number 200 sip_to_user 200 sip_req_user 200)
2025-06-01 23:12:07.975230 99.57% [WARNING] mod_dptools.c:1865 [inbound routes] 404 not found 150.224.234.2 destination_number 200 sip_to_user 200 sip_req_user 200
EXECUTE [depth=0] sofia/internal/300@midomain.com respond(404 Not Found)
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_sofia.c:2358 Responding with 404 [Not Found]
2025-06-01 23:12:07.975230 99.57% [NOTICE] mod_sofia.c:2426 Hangup sofia/internal/300@midomain.com [CS_EXECUTE] [UNALLOCATED_NUMBER]
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_session.c:2979 sofia/internal/300@midomain.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:647 (sofia/internal/300@midomain.com) State EXECUTE going to sleep
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/300@midomain.com) Running State Change CS_HANGUP (Cur 1 Tot 6)
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:844 (sofia/internal/300@midomain.com) Callstate Change RINGING -> HANGUP
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/300@midomain.com) State HANGUP
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_sofia.c:469 Channel sofia/internal/300@midomain.com hanging up, cause: UNALLOCATED_NUMBER
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_sofia.c:614 Responding to INVITE with: 404
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:59 sofia/internal/300@midomain.com Standard HANGUP, cause: UNALLOCATED_NUMBER
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:846 (sofia/internal/300@midomain.com) State HANGUP going to sleep
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:616 (sofia/internal/300@midomain.com) State Change CS_HANGUP -> CS_REPORTING
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:581 (sofia/internal/300@midomain.com) Running State Change CS_REPORTING (Cur 1 Tot 6)
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/300@midomain.com) State REPORTING
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:168 sofia/internal/300@midomain.com Standard REPORTING, cause: UNALLOCATED_NUMBER
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:932 (sofia/internal/300@midomain.com) State REPORTING going to sleep
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:607 (sofia/internal/300@midomain.com) State Change CS_REPORTING -> CS_DESTROY
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_session.c:1744 Session 6 (sofia/internal/300@midomain.com) Locked, Waiting on external entities
2025-06-01 23:12:07.975230 99.57% [NOTICE] switch_core_session.c:1762 Session 6 (sofia/internal/300@midomain.com) Ended
2025-06-01 23:12:07.975230 99.57% [NOTICE] switch_core_session.c:1766 Close Channel sofia/internal/300@midomain.com [CS_DESTROY]
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:735 (sofia/internal/300@midomain.com) Running State Change CS_DESTROY (Cur 0 Tot 6)
2025-06-01 23:12:07.975230 99.57% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/300@midomain.com) State DESTROY
2025-06-01 23:12:07.975230 99.57% [DEBUG] mod_sofia.c:380 sofia/internal/300@midomain.com SOFIA DESTROY
2025-06-01 23:12:08.090721 99.57% [DEBUG] switch_core_state_machine.c:175 sofia/internal/300@midomain.com Standard DESTROY
2025-06-01 23:12:08.090721 99.57% [DEBUG] switch_core_state_machine.c:745 (sofia/internal/300@midomain.com) State DESTROY going to sleep
Click to expand...

If I calling from the extension 300 to 200 and the two extension stay in context midomain.com why the dialplan working in context public mod_dialplan_xml.c:639 Processing 300 <300>->200 in context public

Someone help me to clarify this. This is a new fusionpbx installtion: version 5.3 debian 12
 
pbxgeek said:
Are you by chance registered using an external profile instead of an internal one??
Click to expand...
No only internal, I make a test with other network an work fine. Maybe is a NAT problem.

This is the scenery

IP PC: a.a.a.a

IP VNC in PC: b.b.b.b

IP public VPN: c.c.c.c

Fusion PBX public ip on the internet: d.d.d.d
 
It says that the dialplan is processed in the public context instead of the domain context. Which is why I thought you might be registering to external profile. If it's not the case you need to check that both extensions' context setting is set to your domain and doesn't say public.
Code: 
  <variable name="user_context" value="yourdomain.com"/>

Your call from 300 to 200 is being routed in public context because either the extension’s user_context or your override this somewhere in your dialplan.
 
You must log in or register to reply here.
Top Bottom