[asterisk-users] Asterisk PRI hangup

Wed Oct 5 10:16:04 CDT 2011

> Sorry for the resend, but i don't have got any response, so i try to
> re-open the same problem.
> 
> Hello all,
> 
> Form 2-3 weeks i have some problems with incoming ISDN calls, it
> interrupts after 1-2 minutes of call. I have tried to debug this with
> pri set debug on span 1, i have noticied much of this messages:
> 
> -- Timeout occured, restarting PRI
> q921.c:468 t200_expire: q921_state now is
> Q921_LINK_CONNECTION_RELEASED
> q921.c:858 q921_reset: q921_state now is Q921_LINK_CONNECTION_RELEASED
> Sending TEI management message 1, TEI=127
> Received MDL message
> TEI assiged to 71
> q921.c:858 q921_reset: q921_state now is Q921_LINK_CONNECTION_RELEASED
> Sending Set Asynchronous Balanced Mode Extended
> q921.c:211 q921_send_sabme: q921_state now is Q921_AWAITING_ESTABLISH
> -- Got UA from network peer Link up.
> q921.c:858 q921_reset: q921_state now is Q921_LINK_CONNECTION_RELEASED
> q921.c:805 q921_dchannel_up: q921_state now is
> Q921_LINK_CONNECTION_ESTABLISHED
> -- Timeout occured, restarting PRI
> q921.c:468 t200_expire: q921_state now is
> Q921_LINK_CONNECTION_RELEASED
> q921.c:858 q921_reset: q921_state now is Q921_LINK_CONNECTION_RELEASED
> Sending TEI management message 1, TEI=127
> Received MDL message
> TEI assiged to 72
> q921.c:858 q921_reset: q921_state now is Q921_LINK_CONNECTION_RELEASED
> Sending Set Asynchronous Balanced Mode Extended
> q921.c:211 q921_send_sabme: q921_state now is Q921_AWAITING_ESTABLISH
> -- Got UA from network peer Link up.
> q921.c:858 q921_reset: q921_state now is Q921_LINK_CONNECTION_RELEASED
> q921.c:805 q921_dchannel_up: q921_state now is
> Q921_LINK_CONNECTION_ESTABLISHED
> 
> And there is a debug session of an hanged-up incoming call:
> 
> 
> 
> > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard
> (0) 0: 0 Location: Private network serving the local user (1)
> >                               Ext: 1 Progress Description: Inband
> information or appropriate pattern now available. (8) ]
> == Extension Changed 215[ext-local] new state Ringing for Notify User
> 202
> -- SIP/203-00000017 is ringing
> -- SIP/206-00000019 is ringing
> -- SIP/210-0000001a is ringing
> -- SIP/205-00000018 is ringing
> -- SIP/201-00000015 is ringing
> -- SIP/215-0000001b is ringing
> -- SIP/202-00000016 is ringing
> -- SIP/201-00000015 answered DAHDI/1-1
> == Extension Changed 201[ext-local] new state InUse for Notify User
> 202
> == Extension Changed 201[ext-local] new state InUse for Notify User
> 215
> == Extension Changed 215[ext-local] new state Idle for Notify User 202
> == Extension Changed 210[ext-local] new state Idle for Notify User 202
> == Extension Changed 210[ext-local] new state Idle for Notify User 215
> == Extension Changed 206[ext-local] new state Idle for Notify User 202
> == Extension Changed 206[ext-local] new state Idle for Notify User 215
> == Extension Changed 205[ext-local] new state Idle for Notify User 202
> == Extension Changed 205[ext-local] new state Idle for Notify User 215
> == Extension Changed 203[ext-local] new state Idle for Notify User 202
> == Extension Changed 203[ext-local] new state Idle for Notify User 215
> -- Executing [s at macro-auto-blkvm:1] Set("SIP/201-00000015",
> "__MACRO_RESULT=") in new stack
> == Extension Changed 202[ext-local] new state Idle for Notify User 215
> -- Executing [s at macro-auto-blkvm:2] NoOp("SIP/201-00000015",
> "Deleting: BLKVM/600/DAHDI/1-1 TRUE") in new stack
> -- Stopped music on hold on DAHDI/1-1
> q931.c:2951 q931_connect: call 93 on channel 1 enters state 8 (Connect
> Request)
> > Protocol Discriminator: Q.931 (8) len=11
> > Call Ref: len= 1 (reference 93/0x5D) (Terminator)
> > Message type: CONNECT (7)
> > [18 01 89]
> > Channel ID (len= 3) [ Ext: 1 IntID: Implicit Other Spare: 0
> Exclusive Dchan: 0
> >                        ChanSel: B1 channel
> ]
> > [1e 02 81 82]
> > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard
> (0) 0: 0 Location: Private network serving the local user (1)
> >                               Ext: 1 Progress Description: Called
> equipment is non-ISDN. (2) ]
> < Protocol Discriminator: Q.931 (8) len=4
> < Call Ref: len= 1 (reference 93/0x5D) (Originator)
> < Message type: CONNECT ACKNOWLEDGE (15)
> q931.c:3711 q931_receive: call 93 on channel 1 enters state 10
> (Active)
> -- Got SABME from network peer.
> Sending Unnumbered Acknowledgement
> q921.c:858 q921_reset: q921_state now is Q921_LINK_CONNECTION_RELEASED
> q921.c:805 q921_dchannel_up: q921_state now is
> Q921_LINK_CONNECTION_ESTABLISHED
> < Protocol Discriminator: Q.931 (8) len=4
> < Call Ref: len= 1 (reference 93/0x5D) (Originator)
> < Message type: STATUS ENQUIRY (117)
> YYY Here we get reset YYY
> > Protocol Discriminator: Q.931 (8) len=7
> > Call Ref: len= 1 (reference 93/0x5D) (Terminator)
> > Message type: STATUS (125)
> > [14 01 00]
> > Call State (len= 3) [ Ext: 0 Coding: CCITT (ITU) standard (0) Call
> state: Null (0)
> -- Got reject requesting packet 0... Retransmitting.
> < Protocol Discriminator: Q.931 (8) len=4
> < Call Ref: len= 1 (reference 93/0x5D) (Originator)
> < Message type: STATUS ENQUIRY (117)
> YYY Here we get reset YYY
> > Protocol Discriminator: Q.931 (8) len=7
> > Call Ref: len= 1 (reference 93/0x5D) (Terminator)
> > Message type: STATUS (125)
> > [14 01 00]
> > Call State (len= 3) [ Ext: 0 Coding: CCITT (ITU) standard (0) Call
> state: Null (0)
> < Protocol Discriminator: Q.931 (8) len=8
> < Call Ref: len= 1 (reference 93/0x5D) (Originator)
> < Message type: DISCONNECT (69)
> < [08 02 82 a9]
> < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0
> Location: Public network serving the local user (2)
> < Ext: 1 Cause: Temporary failure (41), class =
> Network Congestion (resource unavailable) (2) ]
> -- Processing IE 8 (cs0, Cause)
> 
> At this point the call interrupts. And the log continues:
> 
> q931.c:3826 q931_receive: call 93 on channel 1 enters state 12
> (Disconnect Indication)
> -- Channel 0/1, span 1 got hangup request, cause 41
> -- Executing [h at macro-dial:1] Macro("DAHDI/1-1", "hangupcall") in
> new stack
> -- Executing [s at macro-hangupcall:1] GotoIf("DAHDI/1-1", "1?skiprg")
> in new stack
> -- Goto (macro-hangupcall,s,4)
> -- Executing [s at macro-hangupcall:4] GotoIf("DAHDI/1-1",
> "0?skipblkvm") in new stack
> -- Executing [s at macro-hangupcall:5] NoOp("DAHDI/1-1", "Cleaning Up
> Block VM Flag: BLKVM/600/DAHDI/1-1") in new stack
> -- Executing [s at macro-hangupcall:6] NoOp("DAHDI/1-1", "Deleting:
> BLKVM/600/DAHDI/1-1 ") in new stack
> -- Executing [s at macro-hangupcall:7] GotoIf("DAHDI/1-1", "1?theend")
> in new stack
> -- Goto (macro-hangupcall,s,9)
> -- Executing [s at macro-hangupcall:9] Hangup("DAHDI/1-1", "") in new
> stack
> == Spawn extension (macro-hangupcall, s, 9) exited non-zero on
> 'DAHDI/1-1' in macro 'hangupcall'
> == Extension Changed 201[ext-local] new state Idle for Notify User 202
> == Extension Changed 201[ext-local] new state Idle for Notify User 215
> == Spawn extension (macro-dial, s, 7) exited non-zero on 'DAHDI/1-1'
> in macro 'dial'
> == Spawn extension (ext-group, 600, 17) exited non-zero on 'DAHDI/1-1'
> NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Disconnect Indication,
> peerstate Disconnect Request
> q931.c:2967 q931_release: call 93 on channel 1 enters state 19
> (Release
> Request)
> > Protocol Discriminator: Q.931 (8) len=8
> > Call Ref: len= 1 (reference 93/0x5D) (Terminator)
> > Message type: RELEASE (77)
> > [08 02 81 a9]
> > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0
> Location: Private network serving the local user (1)
> >                  Ext: 1 Cause: Temporary failure (41), class =
> Network Congestion (resource unavailable) (2) ]
> -- Hungup 'DAHDI/1-1'
> Timed out looking for release complete
> > Protocol Discriminator: Q.931 (8) len=8
> > Call Ref: len= 1 (reference 93/0x5D) (Terminator)
> > Message type: RELEASE (77)
> > [08 02 81 a9]
> > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0
> Location: Private network serving the local user (1)
> >                  Ext: 1 Cause: Temporary failure (41), class =
> Network Congestion (resource unavailable) (2) ]
> 
> What can be the cause of that problem?
> 
> My config is: OpenSuSE with this packages:
> 
> asterisk162-devel-1.6.2.17-83.1.i586
> asterisk162-dahdi-1.6.2.17-83.1.i586
> asterisk162-debuginfo-1.6.2.17-83.1.i586
> asterisk162-addons-1.6.2.3-38.2.i586
> asterisk162-1.6.2.17-83.1.i586
> dahdi-tools-devel-2.4.1-34.1.i586
> asterisk162-dahdi-1.6.2.17-83.1.i586
> dahdi-linux-kmp-default-2.4.1_2.6.31.14_0.6-14.1.i586
> dahdi-linux-2.4.1-14.1.i586
> dahdi-tools-2.4.1-34.1.i586
> free-pbx 2.7.0.10
> My dahdi-channels.conf is the following:
> 
> group=0,11
> context=from-pstn
> switchtype = euroisdn
> signalling = bri_cpe_ptmp
> channel => 1-2
> context = default
> group = 63
> 
> my chan_dahdi.conf is the following:
> 
> [trunkgroups]
> 
> [channels]
> context=incoming
> internationalprefix = 00
> nationalprefix = 0
> unknownprefix =
> usecallerid=yes
> mwisendtype=rpas,lrev
> callwaiting=yes
> usecallingpres=yes
> callwaitingcallerid=yes
> threewaycalling=yes
> transfer=yes
> canpark=yes
> cancallforward=yes
> callreturn=yes
> echocancel=yes
> echocancelwhenbridged=yes
> group=1
> callgroup=1
> pickupgroup=1
> 
> If more configuration details are needed, just ask.

The ISDN peer is restarting the link for some reason.  The restart
also seems to be taking down all active calls when it should not
be doing that.  The ISDN debug output looks to be libpri 1.4.10.2.
Try upgrading libpri to 1.4.12.  The Q.921 implementation in libpri
was rewritten to better follow the spec and should be keeping active
calls up.

Richard