[asterisk-users] BT ISDN-30 Pri getting 'stuck' on outgoing calls.
Russell Brown
russell at lls.lls.com
Fri May 22 12:51:17 CDT 2009
I've having problems with a BT 2 span ISDN-30/Digium TE205P asterisk
setup with outgoing calls not completing and requiring an Asterisk reset
to 'unstick' span 1.
Sorry this is a bit long but I'm completely out of my depth :-(
This system has been in use for some while and I recently upgraded it to
asterisk 1.4.24, zaptel 1.4.11 and libpri 1.4.9. I didn't change
/etc/zaptel.conf or zapata.conf.
The upgrade fixed the problems with calls getting stuck in voicemail and
a few other issues but the inability to make outgoing calls that started
a couple of days after the upgrade is a bit of a bigger problem!
Initially it looked like a BT fault and indeed BT agreed that there was
a problem with a 'card in the exchange'. However they say that they've
changed that and the problem's still happening :-(
It's not consistently failing. On Tuesday it was fine. On Wednesday it
failed 7 times, Thursday 4 and today 11. This could be down to usage
though (more calls being made). Each time span 1 won't complete
outgoing calls we have to restart asterisk and then it comes right back
for a while. Span 2 (which only has 8 channels enabled) seems to
continue working.
BT have now installed an ISDN monitor and their engineer is saying that
there are problems with Asterisk generating "malformed" packets and "out
of sequence" packets.
Here's what the BT engineer said including examples from his ISDN
monitor of the failures (some asterisk pri debug logs follow that).
Can anyone suggest a course of action here? While I can happily
construct dialplans and stuff, this level of ISDN is completely beyond
my experience.
Here's the BT chappies report:
>I've had a good look at the trace containing yesterday afternoon's failures.
>There seem to be 2 issues that I think are closely related.
>
>Malformed Packets
>
>Intermittently packets sent by the PBX are malformed. My analyser shows them
>as CRC-Errors, but, in fact, when you study the data in hex you see that,
>quite simply, some information is missing. Like my analyser, the exchange
>doesn't understand these malformed packets and ignores them which means that
>the next packet sent by the PBX has an incorrect "sequence number" and is
>rejected by the exchange. The exchange then asks for the packet with the
>correct sequence number to be resent.
>
>This is happening intermittently throughout the trace; when it happens at
>quieter periods the correct sequence is quickly recovered and call
>processing carries on. When it happens at busier periods, or when there are
>two or more incorrect packets close together, things quickly start to get
>out of control with the sequence between exchange and PBX (that has to be
>followed) getting further and further apart. Eventually we start to see the
>layer 3 "call reset" messages that we were looking at yesterday morning, but
>even these can't recover the situation because the sequence is so far out.
>The only cure (as we know) is a complete PBX or exchange reset which
>re-establishes the packet sequence and allows calls to be passed once again.
>
><<Malformed Packet>>
>*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-
>
>12:18:30/850.8 1- RS D1 BOP FRAME flg=3D999 =
> [0043]
> D2 Q921 (S:00 T:000 C/R:1) I P:0 NR:103 NS:058 =
>[0039]
> D3 Q931 Pro:08 Ref:(O,00 ca) SETUP =20
> IE:(0/a1) len:0 >> Sending complete
> IE:(0/04) len:3 >> Bearer capability
> Oct 3 : -00----- Coding =3D ITU-T
> ---00000 Capability =3D Speech
> Oct 4 : -00----- Transfer mode =3D Circuit
> ---10000 Transfer rate =3D 64 kbits/s
> Oct 5 : -0100011 L1 protocol =3D G711 A-law
> IE:(0/18) len:3 >> Channel identification
> Oct 3 : -0------ Int id =3D implicit
> --1----- Interface =3D Primary
> ----0--- Preferred/Exclusive =3D =
>Preferred
> ------01 Channel select =3D Indication =
>follows
> Oct 32: -00----- Coding =3D ITU-T
> ---0---- Number/Map =3D Number
> ----0011 Type =3D B-channel
> Oct 33: ---00010 Channel number =3D 2
> IE:(0/6c) len:12 >> Calling party number
> Oct 3 : -010---- Type of number =3D National
> ----0001 Numbering plan=3D ISDN/tel. =
>(E164/E163)
> Oct 3a: -00----- Presentation =3D Allowed
> ------11 Screening =3D Network =
>provided
> Oct 4 : ******** Number =3D 1633413000
> IE:(0/70) len:7 >> Called party number
> Oct 3 : -000---- Type of number =3D Unknown
> ----0001 Numbering plan=3D ISDN/tel. =
>(E164/E163)
> Oct 4 : ******** Number =3D 846080
>12:18:30/855.6 1- TS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:1) RR P/F:0 NR:059
>12:18:30/857.6 1- TS D1 BOP FRAME flg=3D008 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:1) RR P/F:0 NR:059
>12:18:30/858.7 1- TS D1 BOP CRC ERROR flg=3D001 =
> [0008]
> 00 18 03 a9 83 82 0a 33
>12:18:30/860.7 1- TS D1 BOP FRAME flg=3D001 =
> [0013]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:059 NS:104 =
>[0009]
> D3 Q931 Pro:08 Ref:(D,00 ca) ALERTING =20
> IE:(0/1e) len:2 >> Progress indicator
> Oct 3 : -00----- Coding =3D ITU-T
> ----0001 Loc =3D Private net to local =
>usr
> Oct 4 : -0001000 8 =3D In-band info now =
>available
>12:18:30/866.2 1- RS D1 BOP FRAME flg=3D117 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) REJ P/F:0 NR:103
>12:18:30/871.8 1- TS D1 BOP FRAME flg=3D073 =
> [0014]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:059 NS:103 =
>[0010]
> D3 Q931 Pro:08 Ref:(D,00 ca) CALL PROCEEDING =20
> IE:(0/18) len:3 >> Channel identification
> Oct 3 : -0------ Int id =3D implicit
> --1----- Interface =3D Primary
> ----1--- Preferred/Exclusive =3D =
>Exclusive
> ------01 Channel select =3D Indication =
>follows
> Oct 32: -00----- Coding =3D ITU-T
> ---0---- Number/Map =3D Number
> ----0011 Type =3D B-channel
> Oct 33: ---00010 Channel number =3D 2
>12:18:30/873.8 1- TS D1 BOP FRAME flg=3D001 =
> [0013]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:059 NS:104 =
>[0009]
> D3 Q931 Pro:08 Ref:(D,00 ca) ALERTING =20
> IE:(0/1e) len:2 >> Progress indicator
> Oct 3 : -00----- Coding =3D ITU-T
> ----0001 Loc =3D Private net to local =
>usr
> Oct 4 : -0001000 8 =3D In-band info now =
>available
>12:18:30/876.1 1- RS D1 BOP FRAME flg=3D073 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:0 NR:104
>12:18:30/886.0 1- RS D1 BOP FRAME flg=3D073 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:0 NR:105
>
>*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-
>
>Out Of Sequence Packets.
>
>There are occasions when the PBX simply sends "layer 3" messages that are
>out-of-sequence. They are not malformed this time, simply out-of-sequence.
>Once again the rejection / recovery process begins, but, if this happens at
>a busy time the consequence will be the same.
>
><<Message out of sequence>>
>*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-
>
>12:17:54/317.9 1- RS D1 BOP FRAME flg=3D999 =
> [0033]
> D2 Q921 (S:00 T:000 C/R:1) I P:0 NR:092 NS:048 =
>[0029]
> D3 Q931 Pro:08 Ref:(O,00 c7) SETUP =20
> IE:(0/a1) len:0 >> Sending complete
> IE:(0/04) len:3 >> Bearer capability
> Oct 3 : -00----- Coding =3D ITU-T
> ---00000 Capability =3D Speech
> Oct 4 : -00----- Transfer mode =3D Circuit
> ---10000 Transfer rate =3D 64 kbits/s
> Oct 5 : -0100011 L1 protocol =3D G711 A-law
> IE:(0/18) len:3 >> Channel identification
> Oct 3 : -0------ Int id =3D implicit
> --1----- Interface =3D Primary
> ----0--- Preferred/Exclusive =3D =
>Preferred
> ------01 Channel select =3D Indication =
>follows
> Oct 32: -00----- Coding =3D ITU-T
> ---0---- Number/Map =3D Number
> ----0011 Type =3D B-channel
> Oct 33: ---00100 Channel number =3D 4
> IE:(0/6c) len:2 >> Calling party number
> Oct 3 : -000---- Type of number =3D Unknown
> ----0000 Numbering plan=3D Unknown
> Oct 3a: -01----- Presentation =3D Restricted
> ------11 Screening =3D Network =
>provided
> Oct 4 : ******** Number =3D=20
> IE:(0/70) len:7 >> Called party number
> Oct 3 : -000---- Type of number =3D Unknown
> ----0001 Numbering plan=3D ISDN/tel. =
>(E164/E163)
> Oct 4 : ******** Number =3D 846060
>12:17:54/321.9 1- TS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:1) RR P/F:0 NR:049
>12:17:54/323.9 1- TS D1 BOP FRAME flg=3D010 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:1) RR P/F:0 NR:049
>12:17:54/326.0 1- TS D1 BOP FRAME flg=3D002 =
> [0013]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:049 NS:093 =
>[0009]
> D3 Q931 Pro:08 Ref:(D,00 c7) ALERTING =20
> IE:(0/1e) len:2 >> Progress indicator
> Oct 3 : -00----- Coding =3D ITU-T
> ----0001 Loc =3D Private net to local =
>usr
> Oct 4 : -0001000 8 =3D In-band info now =
>available
>12:17:54/334.5 1- RS D1 BOP FRAME flg=3D127 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) REJ P/F:0 NR:092
>12:17:54/340.1 1- TS D1 BOP FRAME flg=3D097 =
> [0014]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:049 NS:092 =
>[0010]
> D3 Q931 Pro:08 Ref:(D,00 c7) CALL PROCEEDING =20
> IE:(0/18) len:3 >> Channel identification
> Oct 3 : -0------ Int id =3D implicit
> --1----- Interface =3D Primary
> ----1--- Preferred/Exclusive =3D =
>Exclusive
> ------01 Channel select =3D Indication =
>follows
> Oct 32: -00----- Coding =3D ITU-T
> ---0---- Number/Map =3D Number
> ----0011 Type =3D B-channel
> Oct 33: ---00100 Channel number =3D 4
>12:17:54/342.1 1- TS D1 BOP FRAME flg=3D001 =
> [0013]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:049 NS:093 =
>[0009]
> D3 Q931 Pro:08 Ref:(D,00 c7) ALERTING =20
> IE:(0/1e) len:2 >> Progress indicator
> Oct 3 : -00----- Coding =3D ITU-T
> ----0001 Loc =3D Private net to local =
>usr
> Oct 4 : -0001000 8 =3D In-band info now =
>available
>12:17:54/344.4 1- RS D1 BOP FRAME flg=3D073 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:0 NR:093
>12:17:54/354.4 1- RS D1 BOP FRAME flg=3D074 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:0 NR:094
>12:17:56/741.6 1- RS D1 BOP FRAME flg=3D999 =
> [0013]
> D2 Q921 (S:00 T:000 C/R:1) I P:0 NR:094 NS:049 =
>[0009]
> D3 Q931 Pro:08 Ref:(O,00 c0) DISCONNECT =20
> IE:(0/08) len:2 >> Cause
> Oct 3 : -00----- Coding =3D ITU-T
> ----0000 Loc =3D User
> Oct 4 : -0010000 016 =3D Normal clearing
>
>*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-
>
>It might be a clue that, on nearly all occasions, the packet that is
>malformed or out-of-sequence is the "Call Proceeding" packet.
>
>For good measure here is a typical good sequence.
>
><<A good Call>>
>*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-
>
>12:12:31/490.6 1- RS D1 BOP FRAME flg=3D999 =
> [0047]
> D2 Q921 (S:00 T:000 C/R:1) I P:0 NR:026 NS:122 =
>[0043]
> D3 Q931 Pro:08 Ref:(O,00 b7) SETUP =20
> IE:(0/a1) len:0 >> Sending complete
> IE:(0/04) len:3 >> Bearer capability
> Oct 3 : -00----- Coding =3D ITU-T
> ---10000 Capability =3D 3.1 kHz =
>audio
> Oct 4 : -00----- Transfer mode =3D Circuit
> ---10000 Transfer rate =3D 64 kbits/s
> Oct 5 : -0100011 L1 protocol =3D G711 A-law
> IE:(0/18) len:3 >> Channel identification
> Oct 3 : -0------ Int id =3D implicit
> --1----- Interface =3D Primary
> ----0--- Preferred/Exclusive =3D =
>Preferred
> ------01 Channel select =3D Indication =
>follows
> Oct 32: -00----- Coding =3D ITU-T
> ---0---- Number/Map =3D Number
> ----0011 Type =3D B-channel
> Oct 33: ---00100 Channel number =3D 4
> IE:(0/1e) len:2 >> Progress indicator
> Oct 3 : -00----- Coding =3D ITU-T
> ----0000 Loc =3D User
> Oct 4 : -0000011 3 =3D Origination address =
>non-ISDN
> IE:(0/6c) len:12 >> Calling party number
> Oct 3 : -010---- Type of number =3D National
> ----0001 Numbering plan=3D ISDN/tel. =
>(E164/E163)
> Oct 3a: -00----- Presentation =3D Allowed
> ------11 Screening =3D Network =
>provided
> Oct 4 : ******** Number =3D 1291673603
> IE:(0/70) len:7 >> Called party number
> Oct 3 : -000---- Type of number =3D Unknown
> ----0001 Numbering plan=3D ISDN/tel. =
>(E164/E163)
> Oct 4 : ******** Number =3D 846070
>12:12:31/494.7 1- TS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:1) RR P/F:0 NR:123
>12:12:31/496.8 1- TS D1 BOP FRAME flg=3D001 =
> [0014]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:123 NS:026 =
>[0010]
> D3 Q931 Pro:08 Ref:(D,00 b7) CALL PROCEEDING =20
> IE:(0/18) len:3 >> Channel identification
> Oct 3 : -0------ Int id =3D implicit
> --1----- Interface =3D Primary
> ----1--- Preferred/Exclusive =3D =
>Exclusive
> ------01 Channel select =3D Indication =
>follows
> Oct 32: -00----- Coding =3D ITU-T
> ---0---- Number/Map =3D Number
> ----0011 Type =3D B-channel
> Oct 33: ---00100 Channel number =3D 4
>12:12:31/498.8 1- TS D1 BOP FRAME flg=3D001 =
> [0013]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:123 NS:027 =
>[0009]
> D3 Q931 Pro:08 Ref:(D,00 b7) ALERTING =20
> IE:(0/1e) len:2 >> Progress indicator
> Oct 3 : -00----- Coding =3D ITU-T
> ----0001 Loc =3D Private net to local =
>usr
> Oct 4 : -0001000 8 =3D In-band info now =
>available
>12:12:31/505.5 1- RS D1 BOP FRAME flg=3D113 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:0 NR:027
>12:12:31/506.3 1- RS D1 BOP FRAME flg=3D001 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:0 NR:028
>12:12:41/511.6 1- TS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:1 NR:123
>12:12:41/520.2 1- RS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:1 NR:028
>12:12:42/980.3 1- TS D1 BOP FRAME flg=3D999 =
> [0018]
> D2 Q921 (S:00 T:000 C/R:0) I P:0 NR:123 NS:028 =
>[0014]
> D3 Q931 Pro:08 Ref:(D,00 b7) CONNECT =20
> IE:(0/18) len:3 >> Channel identification
> Oct 3 : -0------ Int id =3D implicit
> --1----- Interface =3D Primary
> ----1--- Preferred/Exclusive =3D =
>Exclusive
> ------01 Channel select =3D Indication =
>follows
> Oct 32: -00----- Coding =3D ITU-T
> ---0---- Number/Map =3D Number
> ----0011 Type =3D B-channel
> Oct 33: ---00100 Channel number =3D 4
> IE:(0/1e) len:2 >> Progress indicator
> Oct 3 : -00----- Coding =3D ITU-T
> ----0001 Loc =3D Private net to local =
>usr
> Oct 4 : -0000010 2 =3D Destination address =
>non-ISDN
>12:12:42/984.1 1- RS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:0 NR:029
>12:12:42/994.8 1- RS D1 BOP FRAME flg=3D075 =
> [0009]
> D2 Q921 (S:00 T:000 C/R:1) I P:0 NR:029 NS:123 =
>[0005]
> D3 Q931 Pro:08 Ref:(O,00 b7) CONNECT ACKNOWLEDGE=20
>12:12:42/999.7 1- TS D1 BOP FRAME flg=3D148 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:1) RR P/F:0 NR:124
>12:12:53/005.6 1- TS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:1 NR:124
>12:12:53/008.8 1- RS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:1 NR:029
>12:13:03/022.5 1- TS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:1 NR:124
>12:13:03/023.6 1- RS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:1) RR P/F:1 NR:029
>12:13:03/028.5 1- TS D1 BOP FRAME flg=3D042 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:1) RR P/F:1 NR:124
>12:13:03/033.7 1- RS D1 BOP FRAME flg=3D075 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:1 NR:029
>12:13:13/041.5 1- TS D1 BOP FRAME flg=3D999 =
> [0004]
> D2 Q921 (S:00 T:000 C/R:0) RR P/F:1 NR:124
>
>*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-*-
>
>
>Summary
>
>I cannot see any issues or anomalies with the BT ISDN30 service.
>There appear to problems with the creation and sequencing of "layer 3"
>messages; most often (but not exclusively) the message affected is "Call
>Proceeding".
>
>British Telecommunications plc. Registered office: 81 Newgate Street London
>EC1A 7AJ
>Registered in England no: 1800000
and here's a pri debug log for a failing state (it's tricky to get clean
examples because of the call volume going on but I think this is right).
Failing call:
> Protocol Discriminator: Q.931 (8) len=39
> Call Ref: len= 2 (reference 844/0x34C) (Originator)
> Message type: SETUP (5)
> [04 03 80 90 a3]
> Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: Speech (0)
> Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16)
> User information layer 1: A-Law (35)
> [18 03 a9 83 9a]
> Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0
> ChanSel: As indicated in following octets
> Ext: 1 Coding: 0 Number Specified Channel Type: 3
> Ext: 1 Channel: 26 ]
> [6c 08 00 80 38 34 36 30 38 30]
> Calling Number (len=10) [ Ext: 0 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0)
> Presentation: Presentation permitted, user number not screened (0) '846080' ]
> [70 0c 80 30 31 37 38 30 34 37 31 38 30 32]
> Called Number (len=14) [ Ext: 1 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0) '01780471802' ]
q931.c:3128 q931_setup: call 33612 on channel 26 enters state 1 (Call Initiated)
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
Timed out looking for release complete
Delaying transmission of 74, window is 7/7 long
Stopping T_203 timer
Starting T_200 timer
-- Restarting T200 timer
> Protocol Discriminator: Q.931 (8) len=9
> Call Ref: len= 2 (reference 255/0xFF) (Terminator)
> Message type: RELEASE (77)
> [08 02 81 e6]
> Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1)
> Ext: 1 Cause: Recover on timer expiry (102), class = Protocol Error (e.g. unknown message) (6) ]
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
Final time-out looking for release complete
NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null
NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
-- T200 counter expired, What to do...
-- Retransmitting 43 bytes
> [ 00 01 d4 5f 08 02 80 99 4d 08 02 81 e6 ]
> Informational frame:
> SAPI: 00 C/R: 0 EA: 0
> TEI: 000 EA: 1
> N(S): 106 0: 0
> N(R): 047 P: 1
> 9 bytes of data
-- Rescheduling retransmission (1)
< [ 00 01 01 af ]
< Supervisory frame:
< SAPI: 00 C/R: 0 EA: 0
< TEI: 000 EA: 1
< Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
< N(R): 087 P/F: 1
< 0 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
-- Got RR response to our frame
-- Restarting T203 timer
< [ 02 01 5e ae 08 02 00 01 05 a1 04 03 90 90 a3 18 03 a1 83 86 1e 02 85 81 6c 0c 21 83 31 36 35 36 37 38 35 33 37 35 70 07 81 38 34 36 30 38 30 ]
< Informational frame:
< SAPI: 00 C/R: 1 EA: 0
< TEI: 000 EA: 1
< N(S): 047 0: 0
< N(R): 087 P: 0
< 43 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Stopping T203 counter since we got an ACK
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
< Protocol Discriminator: Q.931 (8) len=43
< Call Ref: len= 2 (reference 1/0x1) (Originator)
< Message type: SETUP (5)
< [a1]
< Sending Complete (len= 1)
< [04 03 90 90 a3]
< Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: 3.1kHz audio (16)
< Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16)
< User information layer 1: A-Law (35)
< [18 03 a1 83 86]
< Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Preferred Dchan: 0
< ChanSel: As indicated in following octets
< Ext: 1 Coding: 0 Number Specified Channel Type: 3
< Ext: 1 Channel: 6 ]
< [1e 02 85 81]
< Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the remote user (5)
< Ext: 1 Progress Description: Call is not end-to-end ISDN; further call progress information may be available inband. (1) ]
< [6c 0c 21 83 31 36 35 36 37 38 35 33 37 35]
< Calling Number (len=14) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1)
< Presentation: Presentation allowed of network provided number (3) '1656785375' ]
< [70 07 81 38 34 36 30 38 30]
< Called Number (len= 9) [ Ext: 1 TON: Unknown Number Type (0) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) '846080' ]
-- Making new call for cr 1
-- Processing Q.931 Call Setup
-- Processing IE 161 (cs0, Sending Complete)
-- Processing IE 4 (cs0, Bearer Capability)
-- Processing IE 24 (cs0, Channel Identification)
-- Processing IE 30 (cs0, Progress Indicator)
-- Processing IE 108 (cs0, Calling Party Number)
-- Processing IE 112 (cs0, Called Party Number)
q931.c:3545 q931_receive: call 1 on channel 6 enters state 6 (Call Present)
Sending Receiver Ready (48)
> [ 02 01 01 60 ]
> Supervisory frame:
> SAPI: 00 C/R: 1 EA: 0
> TEI: 000 EA: 1
> Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
> N(R): 048 P/F: 0
> 0 bytes of data
-- Restarting T203 timer
q931.c:2810 q931_call_proceeding: call 1 on channel 6 enters state 9 (Incoming Call Proceeding)
Delaying transmission of 75, window is 7/7 long
Stopping T_203 timer
Starting T_200 timer
-- Restarting T200 timer
> Protocol Discriminator: Q.931 (8) len=10
> Call Ref: len= 2 (reference 1/0x1) (Terminator)
> Message type: CALL PROCEEDING (2)
> [18 03 a9 83 86]
> Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0
> ChanSel: As indicated in following octets
> Ext: 1 Coding: 0 Number Specified Channel Type: 3
> Ext: 1 Channel: 6 ]
q931.c:2838 q931_alerting: call 1 on channel 6 enters state 7 (Call Received)
Delaying transmission of 76, window is 7/7 long
Starting T_200 timer
-- Restarting T200 timer
> Protocol Discriminator: Q.931 (8) len=9
> Call Ref: len= 2 (reference 1/0x1) (Terminator)
> Message type: ALERTING (1)
> [1e 02 81 88]
> 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) ]
< [ 02 01 60 ae 08 02 00 02 05 a1 04 03 90 90 a3 18 03 a1 83 87 1e 02 84 83 6c 0c 21 83 31 32 33 39 36 35 34 35 32 36 70 07 81 38 34 36 30 37 37 ]
< Informational frame:
< SAPI: 00 C/R: 1 EA: 0
< TEI: 000 EA: 1
< N(S): 048 0: 0
< N(R): 087 P: 0
< 43 bytes of data
Handling message for SAPI/TEI=0/0
-- ACKing all packets from 86 to (but not including) 87
-- Waiting for acknowledge, restarting T200 counter
-- Restarting T200 timer
< Protocol Discriminator: Q.931 (8) len=43
< Call Ref: len= 2 (reference 2/0x2) (Originator)
< Message type: SETUP (5)
< [a1]
< Sending Complete (len= 1)
< [04 03 90 90 a3]
< Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: 3.1kHz audio (16)
< Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16)
< User information layer 1: A-Law (35)
< [18 03 a1 83 87]
< Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Preferred Dchan: 0
< ChanSel: As indicated in following octets
< Ext: 1 Coding: 0 Number Specified Channel Type: 3
< Ext: 1 Channel: 7 ]
< [1e 02 84 83]
< Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the remote user (4)
< Ext: 1 Progress Description: Calling equipment is non-ISDN. (3) ]
< [6c 0c 21 83 31 32 33 39 36 35 34 35 32 36]
< Calling Number (len=14) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1)
< Presentation: Presentation allowed of network provided number (3) '1239654526' ]
< [70 07 81 38 34 36 30 37 37]
< Called Number (len= 9) [ Ext: 1 TON: Unknown Number Type (0) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) '846077' ]
-- Making new call for cr 2
-- Processing Q.931 Call Setup
-- Processing IE 161 (cs0, Sending Complete)
-- Processing IE 4 (cs0, Bearer Capability)
-- Processing IE 24 (cs0, Channel Identification)
-- Processing IE 30 (cs0, Progress Indicator)
-- Processing IE 108 (cs0, Calling Party Number)
-- Processing IE 112 (cs0, Called Party Number)
q931.c:3545 q931_receive: call 2 on channel 7 enters state 6 (Call Present)
Sending Receiver Ready (49)
> [ 02 01 01 62 ]
> Supervisory frame:
> SAPI: 00 C/R: 1 EA: 0
> TEI: 000 EA: 1
> Zero: 0 S: 0 01: 1 [ RR (receive ready) ]
> N(R): 049 P/F: 0
> 0 bytes of data
-- Restarting T203 timer
q931.c:2810 q931_call_proceeding: call 2 on channel 7 enters state 9 (Incoming Call Proceeding)
Delaying transmission of 77, window is 7/7 long
Stopping T_203 timer
Starting T_200 timer
-- Restarting T200 timer
> Protocol Discriminator: Q.931 (8) len=10
> Call Ref: len= 2 (reference 2/0x2) (Terminator)
> Message type: CALL PROCEEDING (2)
> [18 03 a9 83 87]
> Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0
> ChanSel: As indicated in following octets
> Ext: 1 Coding: 0 Number Specified Channel Type: 3
> Ext: 1 Channel: 7 ]
q931.c:2838 q931_alerting: call 2 on channel 7 enters state 7 (Call Received)
Delaying transmission of 78, window is 7/7 long
Starting T_200 timer
-- Restarting T200 timer
> Protocol Discriminator: Q.931 (8) len=9
> Call Ref: len= 2 (reference 2/0x2) (Terminator)
> Message type: ALERTING (1)
> [1e 02 81 88]
> 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) ]
NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Call Initiated, peerstate Overlap sending
q931.c:3009 q931_disconnect: call 33612 on channel 26 enters state 11 (Disconnect Request)
Delaying transmission of 79, window is 7/7 long
Starting T_200 timer
-- Restarting T200 timer
> Protocol Discriminator: Q.931 (8) len=9
> Call Ref: len= 2 (reference 844/0x34C) (Originator)
> Message type: DISCONNECT (69)
> [08 02 81 90]
> Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1)
> Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ]
If you've got this far then Thanks! and well done!
Any help much appreciated.
--
Regards,
Russell
--------------------------------------------------------------------
| Russell Brown | MAIL: russell at lls.com PHONE: 01780 471800 |
| Lady Lodge Systems | WWW Work: http://www.lls.com |
| Peterborough, England | WWW Play: http://www.ruffle.me.uk |
--------------------------------------------------------------------
More information about the asterisk-users
mailing list