Resolving issue

I have two records in dialplan:

exten => testA,1,Dial(PJSIP/outgoing/sip:thetestcall@sip.linphone.org)
exten => testB,1,Dial(PJSIP/outgoing/sip:thetestcall@iptel.org)

Calling testA works fine, trying to call testB gives:

    -- Executing [testB@context:1] Dial("PJSIP/client-00000002", "PJSIP/outgoing/sip:thetestcall@iptel.org") in new stack
    -- Called PJSIP/outgoing/sip:thetestcall@iptel.org
  == Everyone is busy/congested at this time (1:0/1/0)
    -- Auto fallthrough, channel 'PJSIP/client-00000002' status is 'CONGESTION'
<--- Transmitting SIP response (342 bytes) to TLS:<CLIENT_IP>:42435 --->
SIP/2.0 503 Service Unavailable
v: SIP/2.0/TLS <CLIENT_IP>:42435;rport=42435;received=<CLIENT_IP>;branch=z9hG4bK.sdLpOW0sj
i: cPXhYEPQLW
f: <sip:client@domain.tld>;tag=6YBHFYM0j
t: <sip:testB@domain.tld>;tag=3c93e8ac-908d-4049-bf19-84eec4b967e1
CSeq: 21 INVITE
Server: Asterisk PBX 16.2.1~dfsg-1+deb10u2
Reason: Q.850;cause=34
l:  0

The main thing that I can’t understand is that I see completely no output from

% tcpdump -ni any host 91.121.209.194 or host 54.37.202.229 or host 212.79.111.155

for testB call, while testA call produces it. If I ping or telnet iptel.org 5060, I see corresponding packages on tcpdump. It looks like asterisk doesn’t even try to connect to iptel.org.

Asterisk 16.2 debian stable

Normally, if you turn up the logging, there is a point at which you will see a message saying why the call failed. The Everyone is busy message is rather late in the process.

the logging

is pjsip set logger on enough?

The Everyone is busy message is rather late in the process

The log before is the same in both cases with the exception of digits:

<--- Received SIP request (1439 bytes) from TLS:<CLIENT_IP>:42593 --->
INVITE sip:testB@domain.tld SIP/2.0
Via: SIP/2.0/TLS <CLIENT_IP>:42593;branch=<BRANCH>;rport
From: <sip:client@domain.tld>;tag=<TAG>
To: sip:testB@domain.tld
CSeq: 20 INVITE
Call-ID: <ID>
Max-Forwards: 70
Route: <sip:proxy.domain.tld;transport=tls;lr>
Supported: replaces, outbound, gruu
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
Content-Type: application/sdp
Content-Length: 765
Contact: <sip:client@<CLIENT_IP>:42593;transport=tls>;expires=59;+sip.instance="<urn:uuid:<UUID>>"
User-Agent: LinphoneAndroid/4.3.1 (client) LinphoneSDK/4.4.2 (tags/4.4.2^0)

v=0
o=client 396 2555 IN IP4 <CLIENT_IP>
s=Talk
c=IN IP4 <CLIENT_IP>
t=0 0
a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics
m=audio 7078 RTP/SAVP 96 0 8 9 18 101 97
a=rtpmap:96 opus/48000/2
a=fmtp:96 useinbandfec=1
a=fmtp:18 annexb=yes
a=rtpmap:101 telephone-event/48000
a=rtpmap:97 telephone-event/8000
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:<>
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:<>
a=crypto:3 AES_256_CM_HMAC_SHA1_80 inline:<>
a=crypto:4 AES_256_CM_HMAC_SHA1_32 inline:<>
a=rtcp-fb:* trr-int 1000
a=rtcp-fb:* ccm tmmbr

<--- Transmitting SIP response (438 bytes) to TLS:<CLIENT_IP>:42593 --->
SIP/2.0 401 Unauthorized
v: SIP/2.0/TLS <CLIENT_IP>:42593;rport=42593;received=<CLIENT_IP>;branch=<BRANCH>
i: <i>
f: <sip:client@domain.tld>;tag=<TAG>
t: <sip:testB@domain.tld>;tag=<TAG>
CSeq: 20 INVITE
WWW-Authenticate: Digest realm="asterisk",nonce="<NONCE>",opaque="<OPAQUE>",algorithm=md5,qop="auth"
Server: Asterisk PBX 16.2.1~dfsg-1+deb10u2
l:  0


<--- Received SIP request (456 bytes) from TLS:<CLIENT_IP>:42593 --->
ACK sip:testB@domain.tld SIP/2.0
Via: SIP/2.0/TLS <CLIENT_IP>:42593;branch=<BRANCH>;rport
Call-ID: <ID>
From: <sip:client@domain.tld>;tag=<TAG>
To: <sip:testB@domain.tld>;tag=<TAG>
Contact: <sip:client@<CLIENT_IP>:42593;transport=tls>;expires=59;+sip.instance="<urn:uuid:<UUID>>"
Route: <sip:proxy.domain.tld;transport=tls;lr>
Max-Forwards: 70
CSeq: 20 ACK
Content-Length: 0


<--- Received SIP request (1719 bytes) from TLS:<CLIENT_IP>:42593 --->
INVITE sip:testB@domain.tld SIP/2.0
Via: SIP/2.0/TLS <CLIENT_IP>:42593;branch=<BRANCH>;rport
From: <sip:client@domain.tld>;tag=<TAG>
To: sip:testB@domain.tld
CSeq: 21 INVITE
Call-ID: <ID>
Max-Forwards: 70
Route: <sip:proxy.domain.tld;transport=tls;lr>
Supported: replaces, outbound, gruu
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO, UPDATE
Content-Type: application/sdp
Content-Length: 765
Contact: <sip:client@<CLIENT_IP>:42593;transport=tls>;expires=59;+sip.instance="<urn:uuid:<UUID>>"
User-Agent: LinphoneAndroid/4.3.1 (client) LinphoneSDK/4.4.2 (tags/4.4.2^0)
Authorization:  Digest realm="asterisk", nonce="<NONCE>", algorithm=md5, opaque="<OPAQUE>", username="client",  uri="sip:testB@domain.tld", response="<RESPONSE>", cnonce="<CNONCE>", nc=00000001, qop=auth

v=0
o=client 396 2555 IN IP4 <CLIENT_IP>
s=Talk
c=IN IP4 <CLIENT_IP>
t=0 0
a=rtcp-xr:rcvr-rtt=all:10000 stat-summary=loss,dup,jitt,TTL voip-metrics
m=audio 7078 RTP/SAVP 96 0 8 9 18 101 97
a=rtpmap:96 opus/48000/2
a=fmtp:96 useinbandfec=1
a=fmtp:18 annexb=yes
a=rtpmap:101 telephone-event/48000
a=rtpmap:97 telephone-event/8000
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:<>
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:<>
a=crypto:3 AES_256_CM_HMAC_SHA1_80 inline:<>
a=crypto:4 AES_256_CM_HMAC_SHA1_32 inline:<>
a=rtcp-fb:* trr-int 1000
a=rtcp-fb:* ccm tmmbr

  == Setting global variable 'SIPDOMAIN' to 'domain.tld'
<--- Transmitting SIP response (264 bytes) to TLS:<CLIENT_IP>:42593 --->
SIP/2.0 100 Trying
v: SIP/2.0/TLS <CLIENT_IP>:42593;rport=42593;received=<CLIENT_IP>;branch=<BRANCH>
i: <i>
f: <sip:client@domain.tld>;tag=<TAG>
t: <sip:testB@domain.tld>
CSeq: 21 INVITE
Server: Asterisk PBX 16.2.1~dfsg-1+deb10u2
l:  0


    -- Executing [testB@context:1] Dial("PJSIP/client-0000000d", "PJSIP/outgoing/sip:thetestcall@iptel.org") in new stack

diff with test[AB] reduced to test:

% diff /tmp/test*
18c18
< o=client 802 2454 IN IP4 <CLIENT_IP>
---
> o=client 396 2555 IN IP4 <CLIENT_IP>
79c79
< o=client 802 2454 IN IP4 <CLIENT_IP>
---
> o=client 396 2555 IN IP4 <CLIENT_IP>
109c109
<     -- Executing [test@context:1] Dial("PJSIP/client-0000000f", "PJSIP/outgoing/sip:thetestcall@sip.linphone.org") in new stack
---
>     -- Executing [test@context:1] Dial("PJSIP/client-0000000d", "PJSIP/outgoing/sip:thetestcall@iptel.org") in new stack

No. You are looking for a warning, debugging or verbose message.

The differences you are showing are, loosely, serial numbers. They are session numbers and SDP version numbers.

I added debug for console:

console => notice,warning,error,debug

in logger.conf and looks like the issue is in domain resolution:

linphone:

res_pjsip/pjsip_resolver.c:477 sip_resolve: Performing SIP DNS resolution of target 'sip.linphone.org'
res_pjsip/pjsip_resolver.c:504 sip_resolve: Transport type for target 'sip.linphone.org' is 'Unspecified'
res_pjsip/pjsip_resolver.c:547 sip_resolve: [0x7f4e740593f8] Created resolution tracking for target 'sip.linphone.org'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740593f8] Added target 'sip.linphone.org' with record type '35', transport 'Unspecified', and port '0'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740593f8] Added target '_sips._tcp.sip.linphone.org' with record type '33', transport 'TLS', and port '5061'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740593f8] Added target '_sip._tcp.sip.linphone.org' with record type '33', transport 'TCP', and port '5060'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740593f8] Added target '_sip._udp.sip.linphone.org' with record type '33', transport 'UDP', and port '5060'
res_pjsip/pjsip_resolver.c:616 sip_resolve: [0x7f4e740593f8] Starting initial resolution using parallel queries for target 'sip.linphone.org'
res_pjsip_session.c:3538 session_inv_on_state_changed: Source of transaction state change is TX_MSG 
dns.c:557 ast_search_dns_ex: DNS search failed for sip.linphone.org 
dns_system_resolver.c:155 dns_system_resolver_process_query: DNS search failed for query: 'sip.linphone.org'
res_pjsip/pjsip_resolver.c:277 sip_resolve_callback: [0x7f4e740593f8] All parallel queries completed
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740593f8] SRV record received on target '_sips._tcp.sip.linphone.org'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740593f8] Added target 'sip6.linphone.org' with record type '1', transport 'TLS', and port '5223'
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740593f8] SRV record received on target '_sips._tcp.sip.linphone.org'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740593f8] Added target 'sip1.linphone.org' with record type '1', transport 'TLS', and port '5223'
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740593f8] SRV record received on target '_sips._tcp.sip.linphone.org'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740593f8] Added target 'sip6.linphone.org' with record type '1', transport 'TLS', and port '443'
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740593f8] SRV record received on target '_sip._tcp.sip.linphone.org'
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740593f8] SRV record received on target '_sip._tcp.sip.linphone.org'
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740593f8] SRV record received on target '_sip._udp.sip.linphone.org'
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740593f8] SRV record received on target '_sip._udp.sip.linphone.org'
res_pjsip/pjsip_resolver.c:413 sip_resolve_callback: [0x7f4e740593f8] New queries added, performing parallel resolution again
res_pjsip/pjsip_resolver.c:277 sip_resolve_callback: [0x7f4e740593f8] All parallel queries completed
res_pjsip/pjsip_resolver.c:326 sip_resolve_callback: [0x7f4e740593f8] A record received on target 'sip6.linphone.org'
res_pjsip/pjsip_resolver.c:326 sip_resolve_callback: [0x7f4e740593f8] A record received on target 'sip1.linphone.org'
res_pjsip/pjsip_resolver.c:326 sip_resolve_callback: [0x7f4e740593f8] A record received on target 'sip6.linphone.org'
res_pjsip/pjsip_resolver.c:419 sip_resolve_callback: [0x7f4e740593f8] Resolution completed - 3 viable targets
res_pjsip/pjsip_resolver.c:201 sip_resolve_invoke_user_callback: [0x7f4e740593f8] Address '0' is 54.37.202.229:5223 with transport 'TLS'
res_pjsip/pjsip_resolver.c:201 sip_resolve_invoke_user_callback: [0x7f4e740593f8] Address '1' is 91.121.209.194:5223 with transport 'TLS'
res_pjsip/pjsip_resolver.c:201 sip_resolve_invoke_user_callback: [0x7f4e740593f8] Address '2' is 54.37.202.229:443 with transport 'TLS'
res_pjsip/pjsip_resolver.c:207 sip_resolve_invoke_user_callback: [0x7f4e740593f8] Invoking user callback with '3' addresses

iptel:

res_pjsip/pjsip_resolver.c:477 sip_resolve: Performing SIP DNS resolution of target 'iptel.org'
res_pjsip/pjsip_resolver.c:504 sip_resolve: Transport type for target 'iptel.org' is 'Unspecified'
res_pjsip/pjsip_resolver.c:547 sip_resolve: [0x7f4e740564e8] Created resolution tracking for target 'iptel.org'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740564e8] Added target 'iptel.org' with record type '35', transport 'Unspecified', and port '0'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740564e8] Added target '_sips._tcp.iptel.org' with record type '33', transport 'TLS', and port '5061'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740564e8] Added target '_sip._tcp.iptel.org' with record type '33', transport 'TCP', and port '5060'
res_pjsip/pjsip_resolver.c:177 sip_resolve_add: [0x7f4e740564e8] Added target '_sip._udp.iptel.org' with record type '33', transport 'UDP', and port '5060'
res_pjsip/pjsip_resolver.c:616 sip_resolve: [0x7f4e740564e8] Starting initial resolution using parallel queries for target 'iptel.org'
res_pjsip_session.c:3538 session_inv_on_state_changed: Source of transaction state change is TX_MSG 
dns.c:557 ast_search_dns_ex: DNS search failed for iptel.org
dns_system_resolver.c:155 dns_system_resolver_process_query: DNS search failed for query: 'iptel.org'
dns.c:557 ast_search_dns_ex: DNS search failed for _sips._tcp.iptel.org
dns_system_resolver.c:155 dns_system_resolver_process_query: DNS search failed for query: '_sips._tcp.iptel.org'
res_pjsip/pjsip_resolver.c:277 sip_resolve_callback: [0x7f4e740564e8] All parallel queries completed
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740564e8] SRV record received on target '_sip._tcp.iptel.org'
res_pjsip/pjsip_resolver.c:349 sip_resolve_callback: [0x7f4e740564e8] SRV record received on target '_sip._udp.iptel.org'
res_pjsip/pjsip_resolver.c:419 sip_resolve_callback: [0x7f4e740564e8] Resolution completed - 0 viable targets
res_pjsip/pjsip_resolver.c:207 sip_resolve_invoke_user_callback: [0x7f4e740564e8] Invoking user callback with '0' addresses

but manually it works fine:

% host iptel.org                          
iptel.org has address 212.79.111.155
iptel.org mail is handled by 50 mx3.zoho.com.
iptel.org mail is handled by 10 mx.zoho.com.
iptel.org mail is handled by 20 mx2.zoho.com.

% host -t SRV _sip._tcp.iptel.org
_sip._tcp.iptel.org has SRV record 0 100 5060 sip.iptel.org.

% host -t SRV _sip._udp.iptel.org                          
_sip._udp.iptel.org has SRV record 0 25 5060 sip.iptel.org.

% host sip.iptel.org.                            
sip.iptel.org has address 212.79.111.155

I have another asterisk 16.3 run on OpenWrt 19.07.3 that uses the same local resolver and configured similarly, and it works fine with iptel.org

It was due to a lack of tcp or udp sections with transport declaration in pjsip.conf.

But it’s still unclear,

  1. How should I find this? Is a log so poor and needs to be reported, or am I missing something?

  2. Why I need to set bind? I use this transport only for outgoing connections.