Incoming Call 404 Temporary Unavailable

Hi Guys, I am working on this issue for many days but can't figure it out. So I have to seek any help here.

The current situation is I can dial out with my softphone, however if I try to call the pbx number by using my mobile phone or any other phones, the call was refused to redirect to my softphone. Here's the log while I was calling from my mobile phone:

Code:
recv 1196 bytes from udp/[182.154.16.150]:5060 at 17:06:07.386047:
   ------------------------------------------------------------------------
   INVITE sip:gw+47debd5a-d8fb-40b4-8a24-ad6efd7bda8d@202.33.120.200:5080;gw=47debd5a-d8fb-40b4-8a24-ad6efd7bda8d;transport=udp SIP/2.0
   From: <sip:020488291@as.wxcnz.net>;tag=96149ab6-13c4-5c5fa32f-609d93d4-2e35177e
   To: "Peter Wadams" <sip:9495021@as.wxcnz.net;gw=47debd5a-d8fb-40b4-8a24-ad6efd7bda8d;rinstance=5c5fa1784092e068>
   Call-ID: BW170607379100219-126746536@10.251.1.13
   CSeq: 1 INVITE
   Via: SIP/2.0/UDP 182.154.16.150:5060;branch=z9hG4bK-350639-5c5fa32f-609d93d4-33794df
   Supported: 100rel
   Recv-Info: x-broadworks-client-session-info
   X-BroadWorks-Correlation-Info: 408847:1
   Accept: application/btbc-session-info,application/dtmf-relay,application/media_control+xml,application/sdp,multipart/mixed
   Max-Forwards: 59
   Allow: ACK,BYE,CANCEL,INFO,INVITE,OPTIONS,PRACK,REFER,NOTIFY,UPDATE
   Contact: <sip:020488291@as.wxcnz.net:5060;maddr=182.154.16.150;transport=udp>
   Content-Type: application/sdp
   Content-Length: 263

   v=0
   o=BroadWorks 13559769 1 IN IP4 182.154.16.150
   s=-
   c=IN IP4 182.154.16.150
   t=0 0
   m=audio 36856 RTP/AVP 8 0 101
   a=rtpmap:8 PCMA/8000
   a=rtpmap:0 PCMU/8000
   a=rtpmap:101 telephone-event/8000
   a=fmtp:101 0-15
   a=ptime:20
   a=sqn:0
   a=cdsc:1 image udptl t38
   ------------------------------------------------------------------------
2019-02-10 17:06:07.384453 [NOTICE] switch_channel.c:1104 New Channel sofia/external/020488291@as.wxcnz.net [ff587373-644e-4ee5-a866-c4e36993637c]
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:584 (sofia/external/020488291@as.wxcnz.net) Running State Change CS_NEW (Cur 1 Tot 62)
2019-02-10 17:06:07.384453 [DEBUG] sofia.c:10080 sofia/external/020488291@as.wxcnz.net receiving invite from 182.154.16.150:5060 version: 1.8.2 -3-a98a958ac3 64bit
2019-02-10 17:06:07.384453 [DEBUG] sofia.c:10932 sofia/external/020488291@as.wxcnz.net setting variable [sip_cid_type]=[pid]
2019-02-10 17:06:07.384453 [DEBUG] sofia.c:7291 Channel sofia/external/020488291@as.wxcnz.net entering state [received][100]
2019-02-10 17:06:07.384453 [DEBUG] sofia.c:7301 Remote SDP:
v=0
o=BroadWorks 13559769 1 IN IP4 182.154.16.150
s=-
c=IN IP4 182.154.16.150
t=0 0
m=audio 36856 RTP/AVP 8 0 101
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=ptime:20
a=sqn:0
a=cdsc:1 image udptl t38

2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5507 Bah HUMBUG! Sticking with PCMA@8000h@20i
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1]
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5507 Bah HUMBUG! Sticking with PCMU@8000h@20i
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5533 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5478 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5394 Set telephone-event payload to 101@8000
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:3781 Set Codec sofia/external/020488291@as.wxcnz.net PCMU/8000 20 ms 160 samples 64000 bits 1 channels
2019-02-10 17:06:07.384453 [DEBUG] switch_core_codec.c:111 sofia/external/020488291@as.wxcnz.net Original read codec set to PCMU:0
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5737 Set telephone-event payload to 101@8000
2019-02-10 17:06:07.384453 [DEBUG] switch_core_media.c:5795 sofia/external/020488291@as.wxcnz.net Set 2833 dtmf send payload to 101 recv payload to 101
2019-02-10 17:06:07.384453 [DEBUG] sofia.c:7716 (sofia/external/020488291@as.wxcnz.net) State Change CS_NEW -> CS_INIT
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:603 (sofia/external/020488291@as.wxcnz.net) State NEW
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:584 (sofia/external/020488291@as.wxcnz.net) Running State Change CS_INIT (Cur 1 Tot 62)
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:627 (sofia/external/020488291@as.wxcnz.net) State INIT
2019-02-10 17:06:07.384453 [DEBUG] mod_sofia.c:93 sofia/external/020488291@as.wxcnz.net SOFIA INIT
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:40 sofia/external/020488291@as.wxcnz.net Standard INIT
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:48 (sofia/external/020488291@as.wxcnz.net) State Change CS_INIT -> CS_ROUTING
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:627 (sofia/external/020488291@as.wxcnz.net) State INIT going to sleep
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:584 (sofia/external/020488291@as.wxcnz.net) Running State Change CS_ROUTING (Cur 1 Tot 62)
2019-02-10 17:06:07.384453 [DEBUG] switch_channel.c:2249 (sofia/external/020488291@as.wxcnz.net) Callstate Change DOWN -> RINGING
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:643 (sofia/external/020488291@as.wxcnz.net) State ROUTING
send 414 bytes to udp/[182.154.16.150]:5060 at 17:06:07.387289:
   ------------------------------------------------------------------------
   SIP/2.0 100 Trying
   Via: SIP/2.0/UDP 182.154.16.150:5060;branch=z9hG4bK-350639-5c5fa32f-609d93d4-33794df
   From: <sip:020488291@as.wxcnz.net>;tag=96149ab6-13c4-5c5fa32f-609d93d4-2e35177e
   To: "Peter Wadams" <sip:9495021@as.wxcnz.net;gw=47debd5a-d8fb-40b4-8a24-ad6efd7bda8d;rinstance=5c5fa1784092e068>
   Call-ID: BW170607379100219-126746536@10.251.1.13
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH
   Content-Length: 0

   ------------------------------------------------------------------------
2019-02-10 17:06:07.384453 [DEBUG] mod_sofia.c:154 sofia/external/020488291@as.wxcnz.net SOFIA ROUTING
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:236 sofia/external/020488291@as.wxcnz.net Standard ROUTING
2019-02-10 17:06:07.384453 [INFO] mod_dialplan_xml.c:637 Processing 020488291 <020488291>->pF0WTk4hUd9XmtSCwh in context public
Dialplan: sofia/external/020488291@as.wxcnz.net parsing [public->caller-details] continue=true
Dialplan: sofia/external/020488291@as.wxcnz.net Regex (PASS) [caller-details] () =~ // break=never
Dialplan: sofia/external/020488291@as.wxcnz.net Action export(call_direction=inbound) INLINE
EXECUTE sofia/external/020488291@as.wxcnz.net export(call_direction=inbound)
2019-02-10 17:06:07.384453 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/external/020488291@as.wxcnz.net Action set(caller_destination=${destination_number}) INLINE
EXECUTE sofia/external/020488291@as.wxcnz.net set(caller_destination=pF0WTk4hUd9XmtSCwh)
2019-02-10 17:06:07.384453 [DEBUG] mod_dptools.c:1598 SET sofia/external/020488291@as.wxcnz.net [caller_destination]=[pF0WTk4hUd9XmtSCwh]
Dialplan: sofia/external/020488291@as.wxcnz.net Action set(caller_id_name=${caller_id_name}) INLINE
EXECUTE sofia/external/020488291@as.wxcnz.net set(caller_id_name=020488291)
2019-02-10 17:06:07.384453 [DEBUG] mod_dptools.c:1598 SET sofia/external/020488291@as.wxcnz.net [caller_id_name]=[020488291]
Dialplan: sofia/external/020488291@as.wxcnz.net Action set(caller_id_number=${caller_id_number}) INLINE
EXECUTE sofia/external/020488291@as.wxcnz.net set(caller_id_number=020488291)
2019-02-10 17:06:07.384453 [DEBUG] mod_dptools.c:1598 SET sofia/external/020488291@as.wxcnz.net [caller_id_number]=[020488291]
Dialplan: sofia/external/020488291@as.wxcnz.net parsing [public->09495021] continue=false
Dialplan: sofia/external/020488291@as.wxcnz.net Regex (FAIL) [09495021] destination_number(pF0WTk4hUd9XmtSCwh) =~ /^(09495021)$/ break=on-false
Dialplan: sofia/external/020488291@as.wxcnz.net parsing [public->099742474] continue=false
Dialplan: sofia/external/020488291@as.wxcnz.net Regex (FAIL) [099742474] destination_number(pF0WTk4hUd9XmtSCwh) =~ /^(099742474)$/ break=on-false
Dialplan: sofia/external/020488291@as.wxcnz.net parsing [public->0800] continue=false
Dialplan: sofia/external/020488291@as.wxcnz.net Regex (FAIL) [0800] destination_number(pF0WTk4hUd9XmtSCwh) =~ /^(0800000173)$/ break=on-false
Dialplan: sofia/external/020488291@as.wxcnz.net parsing [public->099742474] continue=false
Dialplan: sofia/external/020488291@as.wxcnz.net Regex (FAIL) [099742474] destination_number(pF0WTk4hUd9XmtSCwh) =~ /^(099742474)$/ break=on-false
Dialplan: sofia/external/020488291@as.wxcnz.net parsing [public->not-found] continue=false
Dialplan: sofia/external/020488291@as.wxcnz.net Regex (PASS) [not-found] () =~ // break=on-false
Dialplan: sofia/external/020488291@as.wxcnz.net Action export(call_direction=inbound) INLINE
EXECUTE sofia/external/020488291@as.wxcnz.net export(call_direction=inbound)
2019-02-10 17:06:07.384453 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [call_direction]=[inbound]
Dialplan: sofia/external/020488291@as.wxcnz.net Action set(call_direction=inbound) INLINE
EXECUTE sofia/external/020488291@as.wxcnz.net set(call_direction=inbound)
2019-02-10 17:06:07.384453 [DEBUG] mod_dptools.c:1598 SET sofia/external/020488291@as.wxcnz.net [call_direction]=[inbound]
Dialplan: sofia/external/020488291@as.wxcnz.net Action log([inbound routes] 404 not found ${sip_network_ip}) INLINE
EXECUTE sofia/external/020488291@as.wxcnz.net log([inbound routes] 404 not found 182.154.16.150)
2019-02-10 17:06:07.384453 [DEBUG] mod_dptools.c:1792 routes] 404 not found 182.154.16.150
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:286 (sofia/external/020488291@as.wxcnz.net) State Change CS_ROUTING -> CS_EXECUTE
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:643 (sofia/external/020488291@as.wxcnz.net) State ROUTING going to sleep
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:584 (sofia/external/020488291@as.wxcnz.net) Running State Change CS_EXECUTE (Cur 1 Tot 62)
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:650 (sofia/external/020488291@as.wxcnz.net) State EXECUTE
2019-02-10 17:06:07.384453 [DEBUG] mod_sofia.c:209 sofia/external/020488291@as.wxcnz.net SOFIA EXECUTE
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:328 sofia/external/020488291@as.wxcnz.net Standard EXECUTE
2019-02-10 17:06:07.384453 [NOTICE] switch_core_state_machine.c:385 sofia/external/020488291@as.wxcnz.net has executed the last dialplan instruction, hanging up.
2019-02-10 17:06:07.384453 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/020488291@as.wxcnz.net [CS_EXECUTE] [NORMAL_CLEARING]
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:650 (sofia/external/020488291@as.wxcnz.net) State EXECUTE going to sleep
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:584 (sofia/external/020488291@as.wxcnz.net) Running State Change CS_HANGUP (Cur 1 Tot 62)
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:847 (sofia/external/020488291@as.wxcnz.net) Callstate Change RINGING -> HANGUP
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:849 (sofia/external/020488291@as.wxcnz.net) State HANGUP
2019-02-10 17:06:07.384453 [DEBUG] mod_sofia.c:449 Channel sofia/external/020488291@as.wxcnz.net hanging up, cause: NORMAL_CLEARING
2019-02-10 17:06:07.384453 [DEBUG] mod_sofia.c:588 Responding to INVITE with: 480
send 821 bytes to udp/[182.154.16.150]:5060 at 17:06:07.391436:
   ------------------------------------------------------------------------
   SIP/2.0 480 Temporarily Unavailable
   Via: SIP/2.0/UDP 182.154.16.150:5060;branch=z9hG4bK-350639-5c5fa32f-609d93d4-33794df
   Max-Forwards: 59
   From: <sip:020488291@as.wxcnz.net>;tag=96149ab6-13c4-5c5fa32f-609d93d4-2e35177e
   To: "Peter Wadams" <sip:9495021@as.wxcnz.net;gw=47debd5a-d8fb-40b4-8a24-ad6efd7bda8d;rinstance=5c5fa1784092e068>;tag=HU8Z2cv5Fy2Zg
   Call-ID: BW170607379100219-126746536@10.251.1.13
   CSeq: 1 INVITE
   User-Agent: FreeSWITCH
   Accept: application/sdp
   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
   Supported: timer, path, replaces
   Allow-Events: talk, hold, conference, refer
   Reason: Q.850;cause=16;text="NORMAL_CLEARING"
   Content-Length: 0
   Remote-Party-ID: "pF0WTk4hUd9XmtSCwh" <sip:pF0WTk4hUd9XmtSCwh@as.wxcnz.net>;party=calling;privacy=off;screen=no

   ------------------------------------------------------------------------
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:60 sofia/external/020488291@as.wxcnz.net Standard HANGUP, cause: NORMAL_CLEARING
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:849 (sofia/external/020488291@as.wxcnz.net) State HANGUP going to sleep
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:619 (sofia/external/020488291@as.wxcnz.net) State Change CS_HANGUP -> CS_REPORTING
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:584 (sofia/external/020488291@as.wxcnz.net) Running State Change CS_REPORTING (Cur 1 Tot 62)
2019-02-10 17:06:07.384453 [DEBUG] switch_core_state_machine.c:935 (sofia/external/020488291@as.wxcnz.net) State REPORTING
recv 614 bytes from udp/[182.154.16.150]:5060 at 17:06:07.395403:
   ------------------------------------------------------------------------
   ACK sip:gw+47debd5a-d8fb-40b4-8a24-ad6efd7bda8d@202.33.120.200:5080;gw=47debd5a-d8fb-40b4-8a24-ad6efd7bda8d;transport=udp SIP/2.0
   From: <sip:020488291@as.wxcnz.net>;tag=96149ab6-13c4-5c5fa32f-609d93d4-2e35177e
   To: "Peter Wadams" <sip:9495021@as.wxcnz.net;gw=47debd5a-d8fb-40b4-8a24-ad6efd7bda8d;rinstance=5c5fa1784092e068>;tag=HU8Z2cv5Fy2Zg
   Call-ID: BW170607379100219-126746536@10.251.1.13
   CSeq: 1 ACK
   Via: SIP/2.0/UDP 182.154.16.150:5060;branch=z9hG4bK-350639-5c5fa32f-609d93d4-33794df
   Max-Forwards: 69
   Contact: <sip:020488291@as.wxcnz.net:5060;maddr=182.154.16.150;transport=udp>
   Content-Length: 0

   ------------------------------------------------------------------------
2019-02-10 17:06:07.484462 [DEBUG] switch_core_state_machine.c:174 sofia/external/020488291@as.wxcnz.net Standard REPORTING, cause: NORMAL_CLEARING
2019-02-10 17:06:07.484462 [DEBUG] switch_core_state_machine.c:935 (sofia/external/020488291@as.wxcnz.net) State REPORTING going to sleep
2019-02-10 17:06:07.484462 [DEBUG] switch_core_state_machine.c:610 (sofia/external/020488291@as.wxcnz.net) State Change CS_REPORTING -> CS_DESTROY
2019-02-10 17:06:07.484462 [DEBUG] switch_core_session.c:1714 Session 62 (sofia/external/020488291@as.wxcnz.net) Locked, Waiting on external entities
2019-02-10 17:06:07.504410 [NOTICE] switch_core_session.c:1732 Session 62 (sofia/external/020488291@as.wxcnz.net) Ended
2019-02-10 17:06:07.504410 [NOTICE] switch_core_session.c:1736 Close Channel sofia/external/020488291@as.wxcnz.net [CS_DESTROY]
2019-02-10 17:06:07.504410 [DEBUG] switch_core_state_machine.c:738 (sofia/external/020488291@as.wxcnz.net) Running State Change CS_DESTROY (Cur 0 Tot 62)
2019-02-10 17:06:07.504410 [DEBUG] switch_core_state_machine.c:748 (sofia/external/020488291@as.wxcnz.net) State DESTROY
2019-02-10 17:06:07.504410 [DEBUG] mod_sofia.c:354 sofia/external/020488291@as.wxcnz.net SOFIA DESTROY
2019-02-10 17:06:07.504410 [DEBUG] switch_core_state_machine.c:181 sofia/external/020488291@as.wxcnz.net Standard DESTROY
2019-02-10 17:06:07.504410 [DEBUG] switch_core_state_machine.c:748 (sofia/external/020488291@as.wxcnz.net) State DESTROY going to sleep
recv 474 bytes from udp/[69.164.221.134]:5060 at 17:06:10.866919:
   ------------------------------------------------------------------------
   OPTIONS sip:gw+e504ee97-cc27-45bd-920c-b3d83c6caf1b@202.33.120.200:9995;transport=udp;gw=e504ee97-cc27-45bd-920c-b3d83c6caf1b SIP/2.0
   Via: SIP/2.0/UDP 69.164.221.134:5060;branch=z9hG4bKb649cf46
   From: sip:keepalive@69.164.221.134;tag=28660814
   To: sip:gw+e504ee97-cc27-45bd-920c-b3d83c6caf1b@202.33.120.200:9995;transport=udp;gw=e504ee97-cc27-45bd-920c-b3d83c6caf1b
   Call-ID: a4ef40f2-b649cf46-5afd02@69.164.221.134
   CSeq: 1 OPTIONS
   Max-Forwards: 70
   Content-Length: 0
There are some 404 errors in the log, I don't know if that cause the issue.

I have redirected the 5060 and 5080 ports to the pbx server on my gateway, do I have to open other ports for communication?
 
Last edited:

markjcrane

Member
Staff member
nabor the problem is your provider is sending this pF0WTk4hUd9XmtSCwh as the destination number. That isn't the number that is being called in your case. So if you look at call detail records get the details and find what variable has the phone number that you called. Then your inbound route needs to use that variable instead of for the condition instead of destinaton_number.
 
nabor the problem is your provider is sending this pF0WTk4hUd9XmtSCwh as the destination number. That isn't the number that is being called in your case. So if you look at call detail records get the details and find what variable has the phone number that you called. Then your inbound route needs to use that variable instead of for the condition instead of destinaton_number.
I finally found the solution. The destination_number in the inbound rules must be the same as the username in the gateway setting. The strange string you prompted me was just the username in the gateway setting! So after I substituted the telephone number with the username in the destination_number parameter, I can successfully get inbound calls.

Thank you man, you saved my day!
 
But here brings a new problem. In the call detailed records, the destination number is changed to the username as well. So it becomes human-unreadable. WX20190212-113809@2x.png

What's more, what happens if one account has multiple numbers? How to deal with it?