Inbound call - empty logs

Asterisk Asterisk SIP
1

Asterisk v16.13.0

Currently I have outgoing call working from an asterisk server using a softphone to my mobile phone using a provided DID number.

What I want is to get incoming call to work. What I am expecting is a simple ‘hello-world’ response but I am getting a line busy signal.

Using zoiper5, SIP credentials I entered

Domain: {{public_ip_of_asterisk_server}}:5060
Username: 428
Password: password

    Data centre
 +---------------------+
 +    Asterisk         +
 +  +-------------+    +      +-------------+
 +  + 172.16.5.58 +    + ---- +   Internet  +
 +  +-------------+    +      +-------------+
 + --------------------+         |
                                 |
        Office                   |
 + ------------------- +         |
 +  soft phone/laptop  +         |
 + +----------------+  +  -------+
 + + 192.168.115.71 +  +
 + +----------------+  +
 + --------------------+

My pjsip.conf and extensions.conf settings as follows:

pjsip.conf

;=========== General settings ===========
[global]
type=global
user_agent=Asterisk PBX SBC

[transport-udp]
type=transport
protocol=udp
bind=0.0.0.0:{{port}}

;=========== Extension 428 ===========
[428]
type=endpoint
context=from-internal
disallow=all
allow=alaw,ulaw
auth=auth428
aors=428

[auth428]
type=auth
auth_type=userpass
username=428
password=password

[428]
type=aor
max_contacts=2


;=========== Extension 1000 ===========
[1000]
type=endpoint
context=from-internal
disallow=all
allow=alaw,ulaw
auth=auth1000
aors=1000

[auth1000]
type=auth
auth_type=userpass
username=1000
password=password

[1000]
type=aor
max_contacts=2


;======================== Registration ============================


; register={{voip_user}}:{{voip_password}}@{{voip_url}}/{{voip_user}}
[my_provider]
type=registration
transport=transport-udp
outbound_auth=my_provider-auth
server_uri=sip:{{voip_url}}:{{port}}
client_uri=sip:{{voip_user}}@{{voip_url}}:{{port}}
retry_interval=60
contact_user={{voip_user}}

[my_provider-auth]
type=auth
auth_type=userpass
password={{voip_password}}
username={{voip_user}}

[my_provider_aor]
type=aor
contact=sip:{{voip_url}}:{{port}}
qualify_frequency=200
;max_contacts=1

[my_provider_endpoint]
type=endpoint
transport=transport-udp
context=from-external
disallow=all
allow=alaw,ulaw
outbound_auth=my_provider-auth
aors=my_provider_aor
from_user={{voip_user}}

[my_provider_identify]
type=identify
endpoint=my_provider_endpoint
match={{voip_url}}

extensions.conf

[from-external]
exten => _X.,1,Answer()
same => n,Wait(1)
same => n,Playback(hello-world)
same => n,Hangup()

exten => {{did_number}},1,Answer()
same => n,Wait(1)
same => n,Playback(hello-world)

rtp.conf

[general]
rtpstart=19900
rtpend=20000

logger.conf

[general]

rotatestrategy = rotate

[logfiles]

console = verbose,notice,warning,error

And below are my endpoints and registration:

pjsip show endpoints

 Endpoint:  <Endpoint/CID.....................................>  <State.....>  <Channels.>
    I/OAuth:  <AuthId/UserName...........................................................>
        Aor:  <Aor............................................>  <MaxContact>
      Contact:  <Aor/ContactUri..........................> <Hash....> <Status> <RTT(ms)..>
  Transport:  <TransportId........>  <Type>  <cos>  <tos>  <BindAddress..................>
   Identify:  <Identify/Endpoint.........................................................>
        Match:  <criteria.........................>
    Channel:  <ChannelId......................................>  <State.....>  <Time.....>
        Exten: <DialedExten...........>  CLCID: <ConnectedLineCID.......>
==========================================================================================

 Endpoint:  428                                                  Not in use    0 of inf
     InAuth:  auth428/428
        Aor:  428                                                2
      Contact:  428/sip:428@101.2.168.7:48539;transport=UD c652491c81 NonQual         nan

 Endpoint:  my_provider_endpoint                                 Not in use    0 of inf
    OutAuth:  my_provider-auth/{{voip_user}}
        Aor:  my_provider_aor                                    1
      Contact:  my_provider_aor/sip:{{voip_url}}           6cf2b49040 Avail         2.877
  Transport:  transport-udp             udp      0      0  0.0.0.0:{{port}}
   Identify:  my_provider_identify/my_provider_endpoint
        Match: {{asterisk_public_ip}}/32


Objects found: 2

pjsip show registrations

 <Registration/ServerURI..............................>  <Auth..........>  <Status.......>
==========================================================================================

 my_provider/sip:{{voip_url}}  my_provider-auth  Registered

Objects found: 1

Below is the logs when I perform outgoing call

[Mar 14 23:11:40] NOTICE[5676]: res_pjsip/pjsip_distributor.c:676 log_failed_request: Request 'OPTIONS' from '"Unknown" <sip:Unknown@172.16.5.56>' failed for '172.16.5.56:{{port}}' (callid: 072f2bd052f18f214f64023826ee2d7f@172.16.5.56:{{port}}) - No matching endpoint found
[Mar 14 23:12:39] NOTICE[5676]: res_pjsip/pjsip_distributor.c:676 log_failed_request: Request 'OPTIONS' from '"Unknown" <sip:Unknown@172.16.5.56>' failed for '172.16.5.56:{{port}}' (callid: 451438a06308e76852a41a6041362516@172.16.5.56:{{port}}) - No matching endpoint found
  == Setting global variable 'SIPDOMAIN' to '{{my_phone_number}}'
    -- Executing [{{my_phone_number}}@from-internal:1] Dial("PJSIP/428-0000001a", "PJSIP/{{my_phone_number}}@my_provider_endpoint") in new stack
    -- Called PJSIP/{{my_phone_number}}@my_provider_endpoint
       > 0x7fb578788300 -- Strict RTP learning after remote address set to: {{asterisk_public_ip}}:13150
    -- PJSIP/my_provider_endpoint-0000001b is making progress passing it to PJSIP/428-0000001a
    -- PJSIP/my_provider_endpoint-0000001b is making progress passing it to PJSIP/428-0000001a
       > 0x7fb578782ee0 -- Strict RTP learning after remote address set to: 101.2.168.7:65056
       > 0x7fb578788300 -- Strict RTP switching to RTP target address {{asterisk_public_ip}}:13150 as source
       > 0x7fb578782ee0 -- Strict RTP switching to RTP target address 101.2.168.7:65056 as source
       > 0x7fb578788300 -- Strict RTP learning complete - Locking on source address {{asterisk_public_ip}}:13150
       > 0x7fb578782ee0 -- Strict RTP learning complete - Locking on source address 101.2.168.7:65056
    -- PJSIP/my_provider_endpoint-0000001b answered PJSIP/428-0000001a
    -- Channel PJSIP/my_provider_endpoint-0000001b joined 'simple_bridge' basic-bridge <e9d5360e-4b7c-461c-967c-054e5be761e5>
    -- Channel PJSIP/428-0000001a joined 'simple_bridge' basic-bridge <e9d5360e-4b7c-461c-967c-054e5be761e5>
       > Bridge e9d5360e-4b7c-461c-967c-054e5be761e5: switching from simple_bridge technology to native_rtp
       > Remotely bridged 'PJSIP/428-0000001a' and 'PJSIP/my_provider_endpoint-0000001b' - media will flow directly between them
    -- Channel PJSIP/428-0000001a left 'native_rtp' basic-bridge <e9d5360e-4b7c-461c-967c-054e5be761e5>
  == Spawn extension (from-internal, {{my_phone_number}}, 1) exited non-zero on 'PJSIP/428-0000001a'
    -- Channel PJSIP/my_provider_endpoint-0000001b left 'native_rtp' basic-bridge <e9d5360e-4b7c-461c-967c-054e5be761e5>

And below are logs for the ‘line busy’ inbound call

sbc01*CLI> core set verbose 500
Console verbose was 5 and is now 500.
sbc01*CLI> core set debug 500
Core debug was 5 and is now 500.
sbc01*CLI> pjsip set logger on
PJSIP Logging enabled
<--- Received SIP request (525 bytes) from UDP:172.16.5.56:5060 --->
OPTIONS sip:172.16.5.58 SIP/2.0
Via: SIP/2.0/UDP 172.16.5.56:5060;branch=z9hG4bK4c36f0d6;rport
Max-Forwards: 70
From: "Unknown" <sip:Unknown@172.16.5.56>;tag=as71585172
To: <sip:172.16.5.58>
Contact: <sip:Unknown@172.16.5.56:5060>
Call-ID: 53b7d01e02f5ccc36c5589b05fca9c04@172.16.5.56:5060
CSeq: 102 OPTIONS
User-Agent: wave2-172.16.5.56
Date: Sun, 14 Mar 2021 23:35:40 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


[Mar 14 23:35:40] NOTICE[5817]: res_pjsip/pjsip_distributor.c:676 log_failed_request: Request 'OPTIONS' from '"Unknown" <sip:Unknown@172.16.5.56>' failed for '172.16.5.56:5060' (callid: 53b7d01e02f5ccc36c5589b05fca9c04@172.16.5.56:5060) - No matching endpoint found
<--- Transmitting SIP response (490 bytes) to UDP:172.16.5.56:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 172.16.5.56:5060;rport=5060;received=172.16.5.56;branch=z9hG4bK4c36f0d6
Call-ID: 53b7d01e02f5ccc36c5589b05fca9c04@172.16.5.56:5060
From: "Unknown" <sip:Unknown@172.16.5.56>;tag=as71585172
To: <sip:172.16.5.58>;tag=z9hG4bK4c36f0d6
CSeq: 102 OPTIONS
WWW-Authenticate: Digest realm="asterisk",nonce="1615764940/25c7f4b12d8ca369949728c2da2e0652",opaque="02dcdce90d337cf8",algorithm=md5,qop="auth"
Server: Asterisk PBX SBC
Content-Length:  0


<--- Received SIP request (886 bytes) from UDP:101.2.168.7:48539 --->
REGISTER sip:{{public_ip_of_asterisk_server}}:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 101.2.168.7:48539;branch=z9hG4bK-524287-1---d17a60f65b5f2c42;rport
Max-Forwards: 70
Contact: <sip:428@101.2.168.7:48539;rinstance=742449034d020c88;transport=UDP>
To: <sip:428@{{public_ip_of_asterisk_server}}:5060;transport=UDP>
From: <sip:428@{{public_ip_of_asterisk_server}}:5060;transport=UDP>;tag=9aa0f358
Call-ID: F18XYKwn0dfMnoNiSFz7BA..
CSeq: 185 REGISTER
Expires: 60
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
User-Agent: Z 5.4.6 rv2.10.10.2-mod
Authorization: Digest username="428",realm="asterisk",nonce="1615764898/e637179d73ed0d2caa7dab355f835694",uri="sip:{{public_ip_of_asterisk_server}}:5060;transport=UDP",response="a8dbc6694024e2d847e1a18ca6d23a3b",cnonce="915adca29d1cc32d6792a5f392fd084f",nc=00000002,qop=auth,algorithm=md5,opaque="7f13a1ae21a7215c"
Allow-Events: presence, kpml, talk
Content-Length: 0


<--- Transmitting SIP response (509 bytes) to UDP:101.2.168.7:48539 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 101.2.168.7:48539;rport=48539;received=101.2.168.7;branch=z9hG4bK-524287-1---d17a60f65b5f2c42
Call-ID: F18XYKwn0dfMnoNiSFz7BA..
From: <sip:428@{{public_ip_of_asterisk_server}}>;tag=9aa0f358
To: <sip:428@{{public_ip_of_asterisk_server}}>;tag=z9hG4bK-524287-1---d17a60f65b5f2c42
CSeq: 185 REGISTER
WWW-Authenticate: Digest realm="asterisk",nonce="1615764951/8ffab4cf6be27b4d8849fb6b0fe4e4ac",opaque="3a6a699625689a58",stale=true,algorithm=md5,qop="auth"
Server: Asterisk PBX SBC
Content-Length:  0


<--- Received SIP request (886 bytes) from UDP:101.2.168.7:48539 --->
REGISTER sip:{{public_ip_of_asterisk_server}}:5060;transport=UDP SIP/2.0
Via: SIP/2.0/UDP 101.2.168.7:48539;branch=z9hG4bK-524287-1---25fba858b278e6ea;rport
Max-Forwards: 70
Contact: <sip:428@101.2.168.7:48539;rinstance=742449034d020c88;transport=UDP>
To: <sip:428@{{public_ip_of_asterisk_server}}:5060;transport=UDP>
From: <sip:428@{{public_ip_of_asterisk_server}}:5060;transport=UDP>;tag=9aa0f358
Call-ID: F18XYKwn0dfMnoNiSFz7BA..
CSeq: 186 REGISTER
Expires: 60
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
User-Agent: Z 5.4.6 rv2.10.10.2-mod
Authorization: Digest username="428",realm="asterisk",nonce="1615764951/8ffab4cf6be27b4d8849fb6b0fe4e4ac",uri="sip:{{public_ip_of_asterisk_server}}:5060;transport=UDP",response="afaede5cd4eee0fad9d089fe8e16b268",cnonce="448e4adcecadc45d5e7bb726d9bcf892",nc=00000001,qop=auth,algorithm=md5,opaque="3a6a699625689a58"
Allow-Events: presence, kpml, talk
Content-Length: 0


<--- Transmitting SIP response (482 bytes) to UDP:101.2.168.7:48539 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 101.2.168.7:48539;rport=48539;received=101.2.168.7;branch=z9hG4bK-524287-1---25fba858b278e6ea
Call-ID: F18XYKwn0dfMnoNiSFz7BA..
From: <sip:428@{{public_ip_of_asterisk_server}}>;tag=9aa0f358
To: <sip:428@{{public_ip_of_asterisk_server}}>;tag=z9hG4bK-524287-1---25fba858b278e6ea
CSeq: 186 REGISTER
Date: Sun, 14 Mar 2021 23:35:51 GMT
Contact: <sip:428@101.2.168.7:48539;transport=UDP;rinstance=742449034d020c88>;expires=59
Expires: 60
Server: Asterisk PBX SBC
Content-Length:  0


<--- Received SIP request (410 bytes) from UDP:193.107.216.17:5092 --->
OPTIONS sip:100@{{public_ip_of_asterisk_server}} SIP/2.0
Via: SIP/2.0/UDP 95.214.54.116:5092;branch=z9hG4bK-700195426;rport
Content-Length: 0
From: "sipvicious"<sip:100@1.1.1.1>;tag=36373037343865643133633401363438383936343436
Accept: application/sdp
User-Agent: friendly-scanner
To: "sipvicious"<sip:100@1.1.1.1>
Contact: sip:100@95.214.54.116:5092
CSeq: 1 OPTIONS
Call-ID: 458359052056842172676895
Max-Forwards: 70


[Mar 14 23:36:10] NOTICE[5817]: res_pjsip/pjsip_distributor.c:676 log_failed_request: Request 'OPTIONS' from '"sipvicious" <sip:100@1.1.1.1>' failed for '193.107.216.17:5092' (callid: 458359052056842172676895) - No matching endpoint found
<--- Transmitting SIP response (514 bytes) to UDP:193.107.216.17:5092 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 95.214.54.116:5092;rport=5092;received=193.107.216.17;branch=z9hG4bK-700195426
Call-ID: 458359052056842172676895
From: "sipvicious" <sip:100@1.1.1.1>;tag=36373037343865643133633401363438383936343436
To: "sipvicious" <sip:100@1.1.1.1>;tag=z9hG4bK-700195426
CSeq: 1 OPTIONS
WWW-Authenticate: Digest realm="asterisk",nonce="1615764970/098684a3ff017b66f477db65e84e3c54",opaque="01890b3f673c6acc",algorithm=md5,qop="auth"
Server: Asterisk PBX SBC
Content-Length:  0

Firewalls are off

# systemctl status iptables
● iptables.service - IPv4 firewall with iptables
   Loaded: loaded (/usr/lib/systemd/system/iptables.service; disabled; vendor preset: disabled)
   Active: inactive (dead)

# ufw status
Status: inactive

With redacted ports:

# netstat -plunt
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 127.0.0.1:25            0.0.0.0:*               LISTEN      1737/master
udp        0      0 0.0.0.0:58654           0.0.0.0:*                           26889/asterisk
udp        0      0 0.0.0.0:5060            0.0.0.0:*                           26889/asterisk
udp6       0      0 :::44118                :::*                                26889/asterisk

The server 172.16.5.58 is accessible from the internet:

172.16.5.58

dig +short myip.opendns.com @resolver1.opendns.com

laptop

ssh user@the_public_ip_address

As you can see, there doesn’t seem to be anything in the logs when I am making a call from my mobile phone to the DID number.

Only one thing left is the public internet may not be able to punch through NAT to reach 172.16.5.58 but I am not sure about what to put inside external_media_address and external_signaling_address. Are they the router IP address of the data centre?

So I made the following changes:

pjsip.conf

[transport-udp]
type=transport
protocol=udp
bind=0.0.0.0:5060
local_net=172.16.5.0/32
local_net=192.168.115.0/32
external_media_address=172.16.5.1
external_signaling_address=172.16.5.1

[428]
type=endpoint
context=from-internal
disallow=all
allow=alaw,ulaw
auth=auth428
aors=428
direct_media=no

The log is still empty.

2

There has been a successful registration on AOR 428, so the firewalling and NAT are good enough to allow a call to be started from the device that registered, but the device has made no attempt to start a call. The NAT settings are not relevant until Asterisk starts replying to the INVITE that hasn’t been sent, so I can’t see if that is going wrong.

However, I do find the local net specifications strange. Normally one provides networks, not point addresses (/32), and normally /32 addresses don’t end in 0.

3

I have tried with different combinations of local_net.

pjsip.conf

[transport-udp]
type=transport
protocol=udp
bind=0.0.0.0:5060
local_net=172.16.5.0/24
local_net=192.168.115.0/24
;external_media_address=172.16.5.1
;external_signaling_address=172.16.5.1

as well as

local_net=172.16.0.0/16
local_net=192.168.0.0/16

Also, I cannot make outbound calls when I enable both external_media_address and external_signaling_address

[Mar 15 02:33:51] NOTICE[5835]: chan_mgcp.c:4709 reload_config: Unable to load config mgcp.conf, MGCP disabled
  == Setting global variable 'SIPDOMAIN' to '{{public_ip_of_asterisk_server}}'
    -- Executing [{{my_phone_number}}@from-internal:1] Dial("PJSIP/428-0000000c", "PJSIP/{{my_phone_number}}@my_provider_endpoint") in new stack
    -- Called PJSIP/{{my_phone_number}}@my_provider_endpoint
  == Everyone is busy/congested at this time (1:0/0/1)
    -- Auto fallthrough, channel 'PJSIP/428-0000000c' status is 'CHANUNAVAIL'
  == Setting global variable 'SIPDOMAIN' to '{{public_ip_of_asterisk_server}}'
    -- Executing [{{my_phone_number}}@from-internal:1] Dial("PJSIP/428-0000000e", "PJSIP/{{my_phone_number}}@my_provider_endpoint") in new stack
    -- Called PJSIP/{{my_phone_number}}@my_provider_endpoint
  == Everyone is busy/congested at this time (1:0/0/1)
    -- Auto fallthrough, channel 'PJSIP/428-0000000e' status is 'CHANUNAVAIL'

What else could be the reason why calls are not reaching asterisk?

4

The device on AOR 428 is successfully making inbound calls to Asterisk. Did you mean inbound calls from your provider in the original posting?

There is no configuration for your provider in the snippets of pjsip.conf that you have provided so far.

5

This is not the registration required?

6

Oops. I didn’t scroll far enough.

7

Assuming that url doesn’t mean URL, in voip_url, but is actually the provider’s IP address, surely that should be {{voip_url}}/32

However, with that error, the incoming request should still get logged.

Also, why do you specifically say public IP, when you haven’t configured for the use of NAT?

Also, unless {{voip_user}} is the same as {{did_number}}, in which case why distinguish, incoming calls are going to either go to _X., or get rejected. The latter would apply if {{voip_user}} starts with anything other than a digit. Again the call should get logged, even if rejected.

8

Yup, my bad, it is the ip address of voip provider

Match : {{voip_ip}}/32

The server 172.16.5.58 can be accessed from the internet, I can ssh into it using its public ip. I am not even sure why I brought that up.

No, they are not. voip_user are numbers in 2xxxxxxx+ format while did_number looks like a local Australian number.

I just realized that an anonymous call is disabled by default! So I enable it but:

extensions.conf

[anonymous]
exten => _X.,1,Answer()
same => n,Wait(1)
same => n,Playback(hello-world)
same => n,Hangup()

pjsip.conf

[anonymous]
type=endpoint
context=anonymous
disallow=all
allow=speex,g726,g722,ilbc,gsm,alaw

and did a core reload

> module show like anonymous
Module                         Description                              Use Count  Status      Support Level
res_pjsip_endpoint_identifier_anonymous.so PJSIP Anonymous endpoint identifier      0          Running              core
1 modules loaded

When I call did number (the one that looks like local Aussie number), I expect to get a hello-world reply but instead I still get the same busy line tone.

Any ideas?

9

Never mind. I reverted back to chan_sip driver and it turns out I have a wrong context set in sip_general_additional.conf file.

;context=from-sip-external
context=from-trunk-sip-Hosted01
10

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.