[asterisk-bugs] [JIRA] (PRI-96) Q931 not sending RELEASE after getting DISCONNECT

Wed Jan 16 18:36:47 CST 2013

    [ https://issues.asterisk.org/jira/browse/PRI-96?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=201662#comment-201662 ] 

Kris Shaw commented on PRI-96:
------------------------------

alaa,

I inserted a usleep(5000); into the q921_transmit function, before the packet is sent. 

For me, even with K=1 the PBX processor didn't seem able to keep up with messages being delivered from the PRI interface. The 5ms second was enough to cure all the strange PRI issues I was having (the actual L2/L3 PRI traces were OK, but unexpected errors and retransmit requests were being generated by the PBX).

> Q931 not sending RELEASE after getting DISCONNECT
> -------------------------------------------------
>
>                 Key: PRI-96
>                 URL: https://issues.asterisk.org/jira/browse/PRI-96
>             Project: LibPRI
>          Issue Type: Bug
>          Components: General
>            Reporter: Russell Brown
>         Attachments: cause102
>
>
> Several times per day, I'm getting Disconnection Cause Codes 102's (recovery on timer expiry) which BT tell me are the result of Asterisk not sending
> a RELEASE in response to a DISCONNECT.
> I'm seeing a handfuls of these in 'bursts' on a system making/taking around 1500 calls per day and while the net result is that we loose a channel for 30 seconds while it times out, these instances are visible to the boss and I'm getting grief over them :-(
> I've turned on pri debug and attached an example of one of these calls and
> it does seem that BT are correct - there's no response sent to the DISCONNECT
> message and the exchange sends a RELEASE with a cause code of 102 some 30 seconds after the original DISCONNECT was sent.
> Curiously the logger always seems to output the same strangeness for the Cause data in these instances like so:-
> {noformat}
> [May 18 14:27:45] VERBOSE[4471] logger.c: < Protocol Discriminator: Q.931 (8)  len=16
> [May 18 14:27:45] VERBOSE[4471] logger.c: < Call Ref: len= 2 (reference 215/0xD7) (Originator)
> [May 18 14:27:45] VERBOSE[4471] logger.c: < Message type: RELEASE (77)
> [May 18 14:27:45] VERBOSE[4471] logger.c: < [08 02 80 90]
> [May 18 14:27:45] VERBOSE[4471] logger.c: < Cause (len= 4) [ Ext: 1  Coding: CCITT (ITU) standard (0)  Spare: 0  Location: User (0)
> [May 18 14:27:45] VERBOSE[4471] logger.c: <                  Ext: 1  Cause: Normal Clearing (16), class = Normal Event (1) ]
> [May 18 14:27:45] VERBOSE[4471] logger.c: < [08 05 82 e6 33 30 35]
> [May 18 14:27:45] VERBOSE[4471] logger.c: < Cause (len= 7) [ Ext: 1  Coding: CCITT (ITU) standard (0)  Spare: 0  Location: Public network serving the local user (2)
> [May 18 14:27:45] VERBOSE[4471] logger.c: <                  Ext: 1  Cause: Recover on timer expiry (102), class = Protocol Error (e.g. unknown message) (6) ]
> [May 18 14:27:45] VERBOSE[4471] logger.c: <              Cause data:[May 18 14:27:45] VERBOSE[4471] logger.c:  33[May 18 14:27:45] VERBOSE[4471] logger.c:  30[May 18 14:27:45] VERBOSE[4471] logger.c:  35[May 18 14:27:45] VERBOSE[4471] logger.c:  (Timer T[May 18 14:27:45] VERBOSE[4471] logger.c: 3[May 18 14:27:45] VERBOSE[4471] logger.c: 0[May 18 14:27:45] VERBOSE[4471] logger.c: 5[May 18 14:27:45] VERBOSE[4471] logger.c: )
> [May 18 14:27:45] VERBOSE[4471] logger.c: -- Processing IE 8 (cs0, Cause)
> [May 18 14:27:45] VERBOSE[4471] logger.c: -- Processing IE 8 (cs0, Cause)
> [May 18 14:27:45] VERBOSE[4471] logger.c: q931.c:3801 q931_receive: call 215 on channel 5 enters state 0 (Null)
> [May 18 14:27:45] VERBOSE[4471] logger.c:     -- Channel 0/5, span 1 got hangup, cause 102
> {noformat}
> If it's any help, here's the timing of the instances this week (grep 'cause 102' /var/log/asterisk/full.X) so you can see the clumping:
> Monday:
> {noformat}
> [May 17 09:41:38] VERBOSE[4472] logger.c:     -- Channel 0/7, span 2 got hangup, cause 102
> [May 17 15:44:21] VERBOSE[4471] logger.c:     -- Channel 0/5, span 1 got hangup, cause 102
> [May 17 15:44:26] VERBOSE[4471] logger.c:     -- Channel 0/1, span 1 got hangup, cause 102
> [May 17 15:44:37] VERBOSE[4472] logger.c:     -- Channel 0/4, span 2 got hangup, cause 102
> [May 17 15:46:11] VERBOSE[4472] logger.c:     -- Channel 0/9, span 2 got hangup, cause 102
> [May 17 15:46:19] VERBOSE[4472] logger.c:     -- Channel 0/3, span 2 got hangup, cause 102
> {noformat}
> Tuesday:
> {noformat}
> [May 18 14:26:17] VERBOSE[4472] logger.c:     -- Channel 0/7, span 2 got hangup, cause 102
> [May 18 14:26:24] VERBOSE[4472] logger.c:     -- Channel 0/8, span 2 got hangup, cause 102
> [May 18 14:27:14] VERBOSE[4471] logger.c:     -- Channel 0/6, span 1 got hangup, cause 102
> [May 18 14:27:45] VERBOSE[4471] logger.c:     -- Channel 0/5, span 1 got hangup, cause 102
> {noformat}
> Today (so far):
> {noformat}
> [May 19 11:03:27] VERBOSE[4472] logger.c:     -- Channel 0/6, span 2 got hangup, cause 102
> [May 19 11:04:15] VERBOSE[4471] logger.c:     -- Channel 0/2, span 1 got hangup, cause 102
> [May 19 11:04:23] VERBOSE[4472] logger.c:     -- Channel 0/5, span 2 got hangup, cause 102
> [May 19 11:04:32] VERBOSE[4471] logger.c:     -- Channel 0/3, span 1 got hangup, cause 102
> {noformat}
> ****** ADDITIONAL INFORMATION ******
> Asterisk 1.4.31
> LibPri 1.4.10.2
> Digium, Inc. Wildcard TE205P (rev 02)
> 2 PRI isdns (one with 30 channels one with 8)

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira