Outgoing call: dialing takes a "long" time

Buschi · December 30, 2018, 7:35am

Hello again,

I habe just eine “small” problem with outgoing calls.

If I make a call from my desk phone through asterisk (and my VoIP provider) to my mobile a tooks about 10 seconds until the mobile is ringing.

If I make the call from a VoIP Phone, which is directly registered with the provider, it tooks only 2 or 3 seconds until the mobile is ringing.

If I log the SIP messages the connection “hangs” after the provider answered “100 Trying”.

I added gsm to allowed, but this was not the solution.

Do you have any idea what I could try?

Thanks in advance

Buschi

Here is the log file: WAIT marks the position which takes the time…


<--- SIP read from UDP:10.20.30.112:5060 --->
INVITE sip:01711234567@10.20.30.240:5060 SIP/2.0
Via: SIP/2.0/UDP 10.20.30.112:5060;branch=z9hG4bK131767208
From: "10" <sip:10@10.20.30.240:5060>;tag=1127645363
To: <sip:01711234567@10.20.30.240:5060>
Call-ID: 0_2768960618@10.20.30.112
CSeq: 1 INVITE
Contact: <sip:10@10.20.30.112:5060>
Content-Type: application/sdp
Allow: INVITE, INFO, PRACK, ACK, BYE, CANCEL, OPTIONS, NOTIFY, REGISTER, SUBSCRIBE, REFER, PUBLISH, UPDATE, MESSAGE
Max-Forwards: 70
User-Agent: Yealink SIP-T46G 28.80.0.60
Allow-Events: talk,hold,conference,refer,check-sync
Supported: replaces
Content-Length: 306

v=0
o=- 20081 20081 IN IP4 10.20.30.112
s=SDP data
c=IN IP4 10.20.30.112
t=0 0
m=audio 11944 RTP/AVP 9 0 8 18 101
a=rtpmap:9 G722/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=ptime:20
a=sendrecv
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
<------------->
--- (14 headers 15 lines) ---
Sending to 10.20.30.112:5060 (no NAT)
Sending to 10.20.30.112:5060 (no NAT)
Using INVITE request as basis request - 0_2768960618@10.20.30.112
Found peer '10' for '10' from 10.20.30.112:5060
  == Using SIP RTP CoS mark 5
Found RTP audio format 9
Found RTP audio format 0
Found RTP audio format 8
Found RTP audio format 18
Found RTP audio format 101
Found audio description format G722 for ID 9
Found audio description format PCMU for ID 0
Found audio description format PCMA for ID 8
Found audio description format G729 for ID 18
Found audio description format telephone-event for ID 101
Capabilities: us - (ulaw|alaw|gsm|h263), peer - audio=(ulaw|alaw|g722|g729)/video=(nothing)/text=(nothing), combined - (ulaw|alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
       > 0x7f0af0017550 -- Strict RTP learning after remote address set to: 10.20.30.112:11944
Peer audio RTP is at port 10.20.30.112:11944
Looking for 01711234567 in default (domain 10.20.30.240)
sip_route_dump: route/path hop: <sip:10@10.20.30.112:5060>

<--- Transmitting (no NAT) to 10.20.30.112:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.20.30.112:5060;branch=z9hG4bK131767208;received=10.20.30.112
From: "10" <sip:10@10.20.30.240:5060>;tag=1127645363
To: <sip:01711234567@10.20.30.240:5060>
Call-ID: 0_2768960618@10.20.30.112
CSeq: 1 INVITE
Server: Asterisk PBX 16.0.1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:01711234567@10.20.30.240:5060>
Content-Length: 0


<------------>
    -- Executing [01711234567@default:1] Set("SIP/10-00000002", "CALLERID(name)=098765432100") in new stack
    -- Executing [01711234567@default:2] Set("SIP/10-00000002", "CALLERID(num)=098765432100") in new stack
    -- Executing [01711234567@default:3] SIPAddHeader("SIP/10-00000002", "P-Preferred-Identity: <sip:+4998765432100@dg.voip.dg-w.de>") in new stack
    -- Executing [01711234567@default:4] Dial("SIP/10-00000002", "SIP/01711234567@098765432100,90,T") in new stack
  == Using SIP RTP CoS mark 5
Audio is at 30666
Adding codec alaw to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 185.22.44.186:5060:
INVITE sip:01711234567@dg.voip.dg-w.de SIP/2.0
Via: SIP/2.0/UDP 10.20.30.240:5060;branch=z9hG4bK49bc31de
Max-Forwards: 70
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>
Contact: <sip:098765432100@10.20.30.240:5060>
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 102 INVITE
User-Agent: Asterisk PBX 16.0.1
Date: Sun, 30 Dec 2018 07:00:51 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
P-Preferred-Identity: <sip:+4998765432100@dg.voip.dg-w.de>
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1359755519 1359755519 IN IP4 10.20.30.240
s=Asterisk PBX 16.0.1
c=IN IP4 10.20.30.240
t=0 0
m=audio 30666 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:150
a=sendrecv

---
    -- Called SIP/01711234567@098765432100

<--- SIP read from UDP:185.22.44.186:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.20.30.240:5060;received=100.68.60.55;branch=z9hG4bK49bc31de;rport=58322
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 102 INVITE

<------------->
--- (6 headers 0 lines) ---

<--- SIP read from UDP:185.22.44.186:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 10.20.30.240:5060;received=100.68.60.55;branch=z9hG4bK49bc31de;rport=58322
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>;tag=sc2dg1-d8b19e83f0806a0b
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 102 INVITE
Server: AareSwitch/6.3.11762
Contact: <sip:01711234567@10.64.1.1:5060>
WWW-Authenticate: Digest realm="10.64.1.1",nonce="5c286d235dee097b963d8ead72ca6e2242119ceb"
Content-Length: 0

<------------->
--- (10 headers 0 lines) ---
Transmitting (no NAT) to 185.22.44.186:5060:
ACK sip:01711234567@dg.voip.dg-w.de SIP/2.0
Via: SIP/2.0/UDP 10.20.30.240:5060;branch=z9hG4bK49bc31de
Max-Forwards: 70
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>;tag=sc2dg1-d8b19e83f0806a0b
Contact: <sip:098765432100@10.20.30.240:5060>
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 102 ACK
User-Agent: Asterisk PBX 16.0.1
Content-Length: 0


---
Audio is at 30666
Adding codec alaw to SDP
Adding non-codec 0x1 (telephone-event) to SDP
Reliably Transmitting (no NAT) to 185.22.44.186:5060:
INVITE sip:01711234567@dg.voip.dg-w.de SIP/2.0
Via: SIP/2.0/UDP 10.20.30.240:5060;branch=z9hG4bK1228d3a7
Max-Forwards: 70
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>
Contact: <sip:098765432100@10.20.30.240:5060>
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 INVITE
User-Agent: Asterisk PBX 16.0.1
Authorization: Digest username="xxxxxxxxxx", realm="10.64.1.1", algorithm=MD5, uri="sip:01711234567@dg.voip.dg-w.de", nonce="5c286d235dee097b963d8ead72ca6e2242119ceb", response="c8609862400af386ee7ddcd38c51ee92"
Date: Sun, 30 Dec 2018 07:00:51 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
P-Preferred-Identity: <sip:+4998765432100@dg.voip.dg-w.de>
Content-Type: application/sdp
Content-Length: 239

v=0
o=root 1359755519 1359755520 IN IP4 10.20.30.240
s=Asterisk PBX 16.0.1
c=IN IP4 10.20.30.240
t=0 0
m=audio 30666 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:150
a=sendrecv

---

<--- SIP read from UDP:185.22.44.186:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 10.20.30.240:5060;received=100.68.60.55;branch=z9hG4bK1228d3a7;rport=58322
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 INVITE

<------------->
--- (6 headers 0 lines) ---

WAIT
WAIT
WAIT
WAIT
WAIT
WAIT
WAIT
WAIT
WAIT

<--- SIP read from UDP:185.22.44.186:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.20.30.240:5060;received=100.68.60.55;branch=z9hG4bK1228d3a7;rport=58322
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>;tag=sc2dg1-733569fe656b2148
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 INVITE
Contact: <sip:01711234567@185.22.44.186:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 295

v=0
o=hiQ9200 3453920181130080051 1044774979 IN IP4 185.22.44.186
s=Phone Call via hiQ9200 SIPCA
c=IN IP4 185.22.44.186
t=0 0
m=audio 26960 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sqn: 0
a=cdsc: 1 image udptl t38
a=sendrecv
a=ptime:20
<------------->
--- (9 headers 13 lines) ---
sip_route_dump: route/path hop: <sip:01711234567@185.22.44.186:5060;transport=udp>
Found RTP audio format 8
Found RTP audio format 101
Found audio description format PCMA for ID 8
Found audio description format telephone-event for ID 101
Capabilities: us - (alaw), peer - audio=(alaw)/video=(nothing)/text=(nothing), combined - (alaw)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
       > 0x7f0b60002860 -- Strict RTP learning after remote address set to: 185.22.44.186:26960
Peer audio RTP is at port 185.22.44.186:26960
    -- SIP/098765432100-00000003 is making progress passing it to SIP/10-00000002
Audio is at 14932
Adding codec ulaw to SDP
Adding codec alaw to SDP
Adding non-codec 0x1 (telephone-event) to SDP

<--- Transmitting (no NAT) to 10.20.30.112:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.20.30.112:5060;branch=z9hG4bK131767208;received=10.20.30.112
From: "10" <sip:10@10.20.30.240:5060>;tag=1127645363
To: <sip:01711234567@10.20.30.240:5060>;tag=as23f9cc6d
Call-ID: 0_2768960618@10.20.30.112
CSeq: 1 INVITE
Server: Asterisk PBX 16.0.1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:01711234567@10.20.30.240:5060>
Content-Type: application/sdp
Content-Length: 261

v=0
o=root 944484394 944484394 IN IP4 10.20.30.240
s=Asterisk PBX 16.0.1
c=IN IP4 10.20.30.240
t=0 0
m=audio 14932 RTP/AVP 0 8 101
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:150
a=sendrecv

<------------>
       > 0x7f0af0017550 -- Strict RTP switching to RTP target address 10.20.30.112:11944 as source

<--- SIP read from UDP:185.22.44.186:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 10.20.30.240:5060;received=100.68.60.55;branch=z9hG4bK1228d3a7;rport=58322
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>;tag=sc2dg1-733569fe656b2148
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 INVITE
Contact: <sip:01711234567@185.22.44.186:5060;transport=udp>
Content-Type: application/sdp
Content-Length: 295

v=0
o=hiQ9200 3453920181130080051 1044774979 IN IP4 185.22.44.186
s=Phone Call via hiQ9200 SIPCA
c=IN IP4 185.22.44.186
t=0 0
m=audio 26960 RTP/AVP 8 101
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sqn: 0
a=cdsc: 1 image udptl t38
a=sendrecv
a=ptime:20
<------------->
--- (9 headers 13 lines) ---
sip_route_dump: route/path hop: <sip:01711234567@185.22.44.186:5060;transport=udp>
    -- SIP/098765432100-00000003 is making progress passing it to SIP/10-00000002
       > 0x7f0b60002860 -- Strict RTP switching to RTP target address 185.22.44.186:26960 as source

<--- SIP read from UDP:185.22.44.186:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 10.20.30.240:5060;received=100.68.60.55;branch=z9hG4bK1228d3a7;rport=58322
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>;tag=sc2dg1-733569fe656b2148
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 INVITE
Contact: <sip:01711234567@185.22.44.186:5060;transport=udp>
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---
sip_route_dump: route/path hop: <sip:01711234567@185.22.44.186:5060;transport=udp>
    -- SIP/098765432100-00000003 is ringing
       > 0x7f0af0017550 -- Strict RTP learning complete - Locking on source address 10.20.30.112:11944

<--- SIP read from UDP:10.20.30.112:5060 --->
CANCEL sip:01711234567@10.20.30.240:5060 SIP/2.0
Via: SIP/2.0/UDP 10.20.30.112:5060;branch=z9hG4bK131767208
From: "10" <sip:10@10.20.30.240:5060>;tag=1127645363
To: <sip:01711234567@10.20.30.240:5060>
Call-ID: 0_2768960618@10.20.30.112
CSeq: 1 CANCEL
Max-Forwards: 70
User-Agent: Yealink SIP-T46G 28.80.0.60
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
Sending to 10.20.30.112:5060 (no NAT)

<--- Reliably Transmitting (no NAT) to 10.20.30.112:5060 --->
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 10.20.30.112:5060;branch=z9hG4bK131767208;received=10.20.30.112
From: "10" <sip:10@10.20.30.240:5060>;tag=1127645363
To: <sip:01711234567@10.20.30.240:5060>;tag=as23f9cc6d
Call-ID: 0_2768960618@10.20.30.112
CSeq: 1 INVITE
Server: Asterisk PBX 16.0.1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


<------------>

<--- Transmitting (no NAT) to 10.20.30.112:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.20.30.112:5060;branch=z9hG4bK131767208;received=10.20.30.112
From: "10" <sip:10@10.20.30.240:5060>;tag=1127645363
To: <sip:01711234567@10.20.30.240:5060>;tag=as23f9cc6d
Call-ID: 0_2768960618@10.20.30.112
CSeq: 1 CANCEL
Server: Asterisk PBX 16.0.1
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de' in 32000 ms (Method: INVITE)
Reliably Transmitting (no NAT) to 185.22.44.186:5060:
CANCEL sip:01711234567@dg.voip.dg-w.de SIP/2.0
Via: SIP/2.0/UDP 10.20.30.240:5060;branch=z9hG4bK1228d3a7
Max-Forwards: 70
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 CANCEL
User-Agent: Asterisk PBX 16.0.1
Content-Length: 0


---
Scheduling destruction of SIP dialog '4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de' in 32000 ms (Method: INVITE)
  == Spawn extension (default, 01711234567, 4) exited non-zero on 'SIP/10-00000002'

<--- SIP read from UDP:10.20.30.112:5060 --->
ACK sip:01711234567@10.20.30.240:5060 SIP/2.0
Via: SIP/2.0/UDP 10.20.30.112:5060;branch=z9hG4bK131767208
From: "10" <sip:10@10.20.30.240:5060>;tag=1127645363
To: <sip:01711234567@10.20.30.240:5060>;tag=as23f9cc6d
Call-ID: 0_2768960618@10.20.30.112
CSeq: 1 ACK
Content-Length: 0

<------------->
--- (7 headers 0 lines) ---
Really destroying SIP dialog '0_2768960618@10.20.30.112' Method: ACK

<--- SIP read from UDP:185.22.44.186:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 10.20.30.240:5060;received=100.68.60.55;branch=z9hG4bK1228d3a7;rport=58322
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>;tag=sc2dg1-733569fe656b2148
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 CANCEL

<------------->
--- (6 headers 0 lines) ---

<--- SIP read from UDP:185.22.44.186:5060 --->
SIP/2.0 487 Request Terminated
Via: SIP/2.0/UDP 10.20.30.240:5060;received=100.68.60.55;branch=z9hG4bK1228d3a7;rport=58322
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>;tag=sc2dg1-733569fe656b2148
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 INVITE
Contact: <sip:01711234567@10.64.1.1:5060>
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---
Transmitting (no NAT) to 185.22.44.186:5060:
ACK sip:01711234567@185.22.44.186:5060;transport=udp SIP/2.0
Via: SIP/2.0/UDP 10.20.30.240:5060;branch=z9hG4bK1228d3a7
Max-Forwards: 70
From: "098765432100" <sip:098765432100@dg.voip.dg-w.de>;tag=as36079d1b
To: <sip:01711234567@dg.voip.dg-w.de>;tag=sc2dg1-733569fe656b2148
Contact: <sip:098765432100@10.20.30.240:5060>
Call-ID: 4bbfb5d06f1209d055e3418e0962d2d1@dg.voip.dg-w.de
CSeq: 103 ACK
User-Agent: Asterisk PBX 16.0.1
Content-Length: 0

david551 · December 30, 2018, 10:16am

That’s usually the result of a broken DNS configuration causing, most likely a reverse lookup, to time out, rather than return a result or “not found”.

Buschi · December 30, 2018, 1:35pm

Hallo David,

thank you again for your reply.

My DNS configurations is pointing primary to my pfsense and then to the openDNS servers.

If I make dig dg.voip.dg-w.de, it seems to be ok.

Could you please tell me what I should do?

Thanks in advance

Guido

david551 · December 30, 2018, 2:05pm

Make sure you can reverse resolve the addresses actually being used. Add them to /etc/hosts, if necessary.

Topic		Replies	Views
(PJSIP) Outgoing calls have 10-20 second delay before connecting Asterisk SIP	5	1796	March 28, 2019
Unexpected delay: problem with outgoing calls Asterisk Support	1	257	September 21, 2006
Sip timeout cellphones Asterisk Support	1	274	August 3, 2009
Delay on outgoing call Asterisk Support	4	396	October 29, 2015
SIP Trunk, I think Asterisk Support	0	185	December 9, 2007

Outgoing call: dialing takes a "long" time

Related topics