Asterisk 16.5.1 on sip trunk stops operating correctly on inbound calls

I noticed this issue a couple of times, but haven’t had time to investigate further until today.

After some time of operation, Asterisk misbehaves, although no indication of failure is triggered, other than external peers cannot call in. The call is cancelled early in connection establishment with SIP/2.0 403 Forbidden, while the peers appear to be functional (sip show peers gives OK status on all lines). Neither sip reload nor dialplan reload fixes the problem, only restarting the Asterisk process does.

The SIP debug trace of a failed attempt is as follows:

-> INVITE from trunk provider
<- SIP/2.0 403 Forbidden

The SIP debug trace after Asterisk’s restart:

-> INVITE from trunk provider
<- SIP/2.0 100 Trying

Comparing the traces show no essential difference, but these lines are missing in the misbehaving case:

[Sep 23 10:58:36] Looking for xxxxxxxx [SIP trunk user id] in inbound [inbound trunk context] (domain xx.xx.xx.xx [external ip address])
[Sep 23 10:58:36] sip_route_dump: route/path hop: <sip:213.167.161.5;lr=on;ftag=as29aebd46;did=4ae.cc95deb1>
[Sep 23 10:58:36] sip_route_dump: route/path hop: <sip:213.167.162.8;lr=on;ftag=as29aebd46;vsf=AAAAABsFDgMABgIDBwcCcFgmBxUGA0cUS2Rl;cctrl=4ae.d31682c4>

So it looks, like Asterisk is loosing the association of inbound calls to the external sip provider, that neither sip reload nor dialplan reload can restore, only restarting Asterisk does.

Some excepts of my sip.conf:

[general]
allowguest = no
srvlookup = yes
transport = udp
nat = force_rport,comedia
directmedia = no
externhost = external-dns-name
autodomain = yes
domain = siptrunk-provider
domain = siptrunk-provider-alt-name
allowexternaldomains = no
; register main trunk
register => main-inbound:xxx
; register test trunk
register => test-inbound:yyy

; HFO inbound template
[hfo_in](!)
context = inbound
type = peer
deny = 0.0.0.0/0.0.0.0
permit = 213.167.161.0/26
permit = 213.167.162.0/26
directmedia = no
insecure = port,invite
qualify = yes
qualifyfreq = 60    ; probe far end peer every 60 seconds (default: 2 seconds)

[hfo_in1](hfo_in)
host = 213.167.161.5

[hfo_in2](hfo_in)
host = 213.167.162.5

Needless to say, that this state is rather disturbing, given, that it takes a caller, who knows other ways to contact us and is willing to notice us on this misbehavior.

Asterisk is working reliable for days, but suddenly it reaches this state.

Any hints, how to debug this any further is much appreciated.

Thanks,
Pete

This behavior looks similar to a common problem with German Telekom ALL-IP lines. Other companies may be affected in case they use Telekom lines. In case of HFO, I don’t know.

I guess your system always works fine again if you restart asterisk (and not only the SIP module). You could also check with “sip set debug on” whether at some point OPTION requests also get a 403s. In that case you could then check whether the DNS resolution (SRV records) has changed the current server.

First of all, @EkFudrek, thanks for the response.

I’m pretty sure, that HFO doesn’t use any Telekom lines.

Yes, everything is working fine after restarting asterisk, and at least a second similar setup (same Asterisk version, same trunk provider, other internet gateway: Telekom V-DSL instead of Vodafone Cable) is affected.

Negative, no separate SIP OPTION packages circling. It’s just the SIP INVITE and the RTP announcement, that is answered with SIP FORBIDDEN.

Could you elaborate on this, please?

Here’s a the complete debug log of such a failing request:

[Sep 23 10:56:58] <--- SIP read from UDP:213.167.161.5:5060 --->
[Sep 23 10:56:58] INVITE sip:siptrunk@external-ip:external-port SIP/2.0
[Sep 23 10:56:58] Record-Route: <sip:213.167.161.5;lr=on;ftag=as4204fc6d;did=385.afe19785>
[Sep 23 10:56:58] Record-Route: <sip:213.167.161.8;lr=on;ftag=as4204fc6d;vsf=AAAAABsFDgMABgIDBwcCcFgmBxUGA0cUS2Rl;cctrl=385.bfb9c523>
[Sep 23 10:56:58] Via: SIP/2.0/UDP 213.167.161.5;branch=z9hG4bK0788.c2d0cfb2.0
[Sep 23 10:56:58] Via: SIP/2.0/UDP 213.167.161.8;branch=z9hG4bK0788.5aa774f.0
[Sep 23 10:56:58] Via: SIP/2.0/UDP 213.167.161.50:5060;branch=z9hG4bK4b242cff
[Sep 23 10:56:58] Max-Forwards: 68
[Sep 23 10:56:58] From: <sip:external-caller@hfosip.de>;tag=as4204fc6d
[Sep 23 10:56:58] To: <sip:internal-callee@213.167.161.8:5060>
[Sep 23 10:56:58] Contact: <sip:+49-external-caller@213.167.161.50:5060>
[Sep 23 10:56:58] Call-ID: 20eb90896591b0081ee9c54502464eab@hfosip.de
[Sep 23 10:56:58] CSeq: 102 INVITE
[Sep 23 10:56:58] User-Agent: mgw2i.anc
[Sep 23 10:56:58] Date: Mon, 23 Sep 2019 08:56:58 GMT
[Sep 23 10:56:58] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
[Sep 23 10:56:58] Supported: replaces
[Sep 23 10:56:58] Content-Type: application/sdp
[Sep 23 10:56:58] Content-Length: 309
[Sep 23 10:56:58] P-Preferred-Identity: "+49-external-caller" <sip:+49-external-caller@hfosip.de>
[Sep 23 10:56:58]
[Sep 23 10:56:58] v=0
[Sep 23 10:56:58] o=krypton 1028461935 1028461935 IN IP4 213.167.161.50
[Sep 23 10:56:58] s=krypton
[Sep 23 10:56:58] c=IN IP4 213.167.161.50
[Sep 23 10:56:58] t=0 0
[Sep 23 10:56:58] m=audio 35684 RTP/AVP 8 0 111 9 101
[Sep 23 10:56:58] a=rtpmap:8 PCMA/8000
[Sep 23 10:56:58] a=rtpmap:0 PCMU/8000
[Sep 23 10:56:58] a=rtpmap:111 G726-32/8000
[Sep 23 10:56:58] a=rtpmap:9 G722/8000
[Sep 23 10:56:58] a=rtpmap:101 telephone-event/8000
[Sep 23 10:56:58] a=fmtp:101 0-16
[Sep 23 10:56:58] a=ptime:20
[Sep 23 10:56:58] a=sendrecv
[Sep 23 10:56:58] <------------->
[Sep 23 10:56:58] --- (19 headers 14 lines) ---
[Sep 23 10:56:58] Sending to 213.167.161.5:5060 (NAT)
[Sep 23 10:56:58] Sending to 213.167.161.5:5060 (NAT)
[Sep 23 10:56:58] Using INVITE request as basis request - 20eb90896591b0081ee9c54502464eab@hfosip.de
[Sep 23 10:56:58] Found peer 'hfo_in1' for 'external-caller' from 213.167.161.5:5060
[Sep 23 10:56:58]   == Using SIP RTP TOS bits 184
[Sep 23 10:56:58]   == Using SIP RTP CoS mark 5
[Sep 23 10:56:58] Found RTP audio format 8
[Sep 23 10:56:58] Found RTP audio format 0
[Sep 23 10:56:58] Found RTP audio format 111
[Sep 23 10:56:58] Found RTP audio format 9
[Sep 23 10:56:58] Found RTP audio format 101
[Sep 23 10:56:58] Found audio description format PCMA for ID 8
[Sep 23 10:56:58] Found audio description format PCMU for ID 0
[Sep 23 10:56:58] Found audio description format G726-32 for ID 111
[Sep 23 10:56:58] Found audio description format G722 for ID 9
[Sep 23 10:56:58] Found audio description format telephone-event for ID 101
[Sep 23 10:56:58] Capabilities: us - (alaw|ulaw), peer - audio=(ulaw|alaw|g722|g726)/video=(nothing)/text=(nothing), combined - (alaw|ulaw)
[Sep 23 10:56:58] Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
[Sep 23 10:56:58]        > 0x7f657c0827c0 -- Strict RTP learning after remote address set to: 213.167.161.50:35684
[Sep 23 10:56:58] Peer audio RTP is at port 213.167.161.50:35684
[Sep 23 10:56:58]
[Sep 23 10:56:58] <--- Reliably Transmitting (NAT) to 213.167.161.5:5060 --->
[Sep 23 10:56:58] SIP/2.0 403 Forbidden
[Sep 23 10:56:58] Via: SIP/2.0/UDP 213.167.161.5;branch=z9hG4bK0788.c2d0cfb2.0;received=213.167.161.5;rport=5060
[Sep 23 10:56:58] Via: SIP/2.0/UDP 213.167.161.8;branch=z9hG4bK0788.5aa774f.0
[Sep 23 10:56:58] Via: SIP/2.0/UDP 213.167.161.50:5060;branch=z9hG4bK4b242cff
[Sep 23 10:56:58] From: <sip:external-caller@hfosip.de>;tag=as4204fc6d
[Sep 23 10:56:58] To: <sip:internal-callee@213.167.161.8:5060>;tag=as475aba48
[Sep 23 10:56:58] Call-ID: 20eb90896591b0081ee9c54502464eab@hfosip.de
[Sep 23 10:56:58] CSeq: 102 INVITE
[Sep 23 10:56:58] Server: Asterisk PBX 16.5.1
[Sep 23 10:56:58] Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
[Sep 23 10:56:58] Supported: replaces, timer
[Sep 23 10:56:58] Content-Length: 0
[Sep 23 10:56:58]
[Sep 23 10:56:58]
[Sep 23 10:56:58] <------------>
[Sep 23 10:56:58] Scheduling destruction of SIP dialog '20eb90896591b0081ee9c54502464eab@hfosip.de' in 6400 ms (Method: INVITE)
[Sep 23 10:56:58]
[Sep 23 10:56:58] <--- SIP read from UDP:213.167.161.5:5060 --->
[Sep 23 10:56:58] ACK sip:siptrunk@external-ip:external-port SIP/2.0
[Sep 23 10:56:58] Via: SIP/2.0/UDP 213.167.161.5;branch=z9hG4bK0788.c2d0cfb2.0
[Sep 23 10:56:58] Max-Forwards: 68
[Sep 23 10:56:58] From: <sip:external-caller@hfosip.de>;tag=as4204fc6d
[Sep 23 10:56:58] To: <sip:internal-callee@213.167.161.8:5060>;tag=as475aba48
[Sep 23 10:56:58] Call-ID: 20eb90896591b0081ee9c54502464eab@hfosip.de
[Sep 23 10:56:58] CSeq: 102 ACK
[Sep 23 10:56:58] Content-Length: 0
[Sep 23 10:56:58]
[Sep 23 10:56:58] <------------->
[Sep 23 10:56:58] --- (8 headers 0 lines) ---
[Sep 23 10:56:58] Really destroying SIP dialog '20eb90896591b0081ee9c54502464eab@hfosip.de' Method: ACK

The missing 3 lines, as noted above, would appear after the line Peer audio RTP is at port 213.167.161.50:35684 in the behaving case.

Do this:
dig +short tel.t-online.de
to get the normal A record. Then try
dig +short tel.t-online.de NAPTR
to see which services are available, followed by
dig +short _sip._udp.tel.t-online.de SRV
to get to the real proxies. Then you can evaluate the A records.

Depending on which SIP stack you are using, this happens either automatically, or in a rudimentary way.

If it initially works, and then not, then there must be a reason. Proxy changes signaled by the service provider’s DNS system can be a hint. Otherwise long pcap traces are your friends.

What is the krypton owner?

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