Hello,
We have an intermittent issue with our Asterisk servers I am hoping someone can help with. Seemingly, without a consistent pattern, a percentage of our calls connect LEGA and LEGB properly but are terminated about 40 seconds after LEGB connects (due to a timeout caused by the details below).
To summarize as briefly as possible:
- The carrier connects call to Asterisk (All messaging looks good)
- Asterisk connects the call to our ISDN channel’s application to successfully complete LEGA. (All messaging looks good)
- ISDN channel attempts a LEGB call to Asterisk (All messaging looks good)
- Asterisk attempts the call to the carrier to complete LEGB. (All messaging looks good)
- At this point the call is connected including audio and both parties can interact
- On a successful call all messaging looks good (see below), HOWEVER, when the problem exists, when the problem exists, even though the carrier sends the final CONNECT to Asterisk, and Asterisk logs that it has received it, Asterisk does not forward the CONNECT to the ISDN channel which causes the ISDN channel to tear down both legs of the call at 40 second timeout.
We have verified all the messaging using both pcap captures as well as native Asterisk debug logs.
We are running Asterisk 13.21. This seems to be happening to a small number of calls compared to the total calls that complete appropriately, but it is difficult to know exactly what percentage of calls is accurate.
It does not look like an ISDN hardware issue as we have seen the issue across multiple different cards (and the fact that we can see in logs Asterisk never sends the CONNECT to ISDN). It does not seem to be a hardware issue with the servers running Asterisk as 1) We have multiple servers exhibiting the same issue and 2) many successful calls following the same call flow. It does not seem to be a carrier issue as 1) The problem occurs across multiple carriers and 2) the problem can be clearly seen is inside Asterisk (carrier passes the CONNECT message to Asterisk, Asterisk acknowledges it but does not forward it to ISDN channel)
The only clue we have been able to see as a potential pattern is the longer the dialed number the more likely the problem occurs (but not always). For example we can dial a number in Turkey (long number format) and the problem occurs. Dial the same number and the problem may or may not happen. DIal it again and the call works perfectly.
The problem is shown in the following code captured from a successful call (the problem occurs for the same number on the same server). Note the lines (lines 6 and 11) reading:
Message Type: CONNECT (7)
When both appear the call connects properly. When the forward to ISDN channel (second CONNECT - line 11) is missing shows Asterisk is not forwarding the message to the ISDN interface and the call ultimately times out and tears down even though it is actually conected.
|----------------------- LEG A ------------| |--------------- LEG B --------------------|
(1) (2) (3) (4)
<Incoming call via carrier> SIP -> SIP <Asterisk> ISDN -> ISDN <Application server> ISDN -> ISDN <Asterisk> SIP -> SIP <Outgoing call via carrier>
When it works we get an ISDN CONNECT from (4) -> (3):
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 q931.c:6006 q931_connect: Call 7087 enters state 10 (Active). Hold state: Idle
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > DL-DATA request
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > Protocol Discriminator: Q.931 (8) len=14
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > TEI=0 Call Ref: len= 2 (reference 7087/0x1BAF) (Sent to originator)
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > Message Type: CONNECT (7)
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 TEI=0 Transmitting N(S)=81, window is open V(A)=81 K=7
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > Protocol Discriminator: Q.931 (8) len=14
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > TEI=0 Call Ref: len= 2 (reference 7087/0x1BAF) (Sent to originator)
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > Message Type: CONNECT (7)
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > [18 03 a9 83 97]
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > ChanSel: As indicated in following octets
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > Ext: 1 Coding: 0 Number Specified Channel Type: 3
[Apr 25 11:58:41] VERBOSE[36466] chan_dahdi.c: PRI Span: 12 > Ext: 1 Channel: 23 Type: NET]
When it does not work:
Asterisk is not sending ISDN CONNECT to ISDN Interface at (3) from SIP interface at (4) and at 40 seconds our Application Server sends a DISCONNECT to Asterisk at (3) then back to (2) to tear both sides of the call down.
I apologize if the formatting does not come across perfectly.
Thank you for any help or thoughts.
Lee Hartigan