Resolving issue

sergio · September 29, 2020, 3:58am

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

david551 · September 29, 2020, 9:51am

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.

sergio · September 29, 2020, 12:19pm

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

david551 · September 29, 2020, 12:45pm

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.

sergio · September 29, 2020, 1:07pm

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

sergio · September 29, 2020, 2:04pm

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

sergio · October 1, 2020, 1:02am

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

But it’s still unclear,

How should I find this? Is a log so poor and needs to be reported, or am I missing something?
Why I need to set bind? I use this transport only for outgoing connections.

system · October 31, 2020, 1:02am

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

Topic		Replies	Views
Outbound Issue for PJSIP Asterisk SIP	6	727	November 11, 2023
Extension and dialplan issues	14	1650	March 29, 2016
Intermittent request timeout issue when we dial an extension Asterisk Support	11	199	December 30, 2023
[Call-Forwarding] What's the problem? Asterisk SIP	2	620	February 19, 2019
Asterisk & PJSIP issue with TLS Asterisk Support	8	1257	October 30, 2017

Resolving issue

Related topics