[cisco-nas] Dial-IN problems with an AS5200

Aaron Leonard Aaron at cisco.com
Thu Aug 21 09:28:47 EDT 2003


Your debugs show that the call connected at ISDN layer 3,
but that the sync PPP packets sent by each side failed
successfully to be received by the other side.

Presumably if you were to do a "show interface WHATEVER:B-CHANNEL"
before and after the call, you would see packets transmitted
and input errors incrementing.

This is very likely simply caused by transmission problems
in your circuit network.

A less likely cause would be a problem in the AS5200, where
some particular timeslot in the E1 controller is misbehaving.
See if the failing calls are or are not associated with the
E1 timeslot.  If so, then this would be the 5200's fault,
not the PSTN's.

Aaron

---

> Hi!

> I have an strange behavior on an AS5200. Sometimes you can dial-in
> without any Problems and sometimes it hangs up.
> I've tried different IOS Versions but nothing helps.
> (12.0(7)T3, 12.1(20), 12.1(10)AA)

> The failure that occurs is always the same. It doesn't matter
> which IOS Version I try.
> Does anyone has seen a failure like this?

> Thankful for any support,
>   Ahmad Cheikh-Moussa

> Here is an debug output from the AS5200 and a Cisco 1003:
> At this Moment the AS5200 runs 12.0(7)T3

> Cisco AS5200
> Aug 21 11:10:17.456 MEST: ISDN Se0:15: RX <-  SETUP pd = 8  callref = 0x38C3
> Aug 21 11:10:17.460 MEST:         Bearer Capability i = 0x8890
> Aug 21 11:10:17.464 MEST:         Channel ID i = 0xA9838A
> Aug 21 11:10:17.468 MEST:         Calling Party Number i = 0x2181,
> '431XXXXX'
> Aug 21 11:10:17.472 MEST:         Called Party Number i = 0xA1, '431XXXXX'
> Aug 21 11:10:17.484 MEST: ISDN Se0:15: Incoming call id = 0x1D0, dsl 0
> Aug 21 11:10:17.492 MEST: ISDN Se0:15: received CALL_INCOMING  call_id 0x1D0
> Aug 21 11:10:17.496 MEST: ISDN Se0:15: CALL_INCOMING: call type is DATA,
> bchan = 9
> Aug 21 11:10:17.500 MEST: ISDN Se0:15: Event:  Received a DATA call from
> 431XXXXXX on B10 at 64 Kb/s
> Aug 21 11:10:17.504 MEST: ISDN Se0:15: RM returned call_type 0 resource
> type 0
> Aug 21 11:10:17.516 MEST: ISDN Se0:15: TX ->  CALL_PROC pd = 8  callref
> = 0xB8C3
> Aug 21 11:10:17.520 MEST:         Channel ID i = 0xA9838A
> Aug 21 11:10:17.528 MEST: ISDN Se0:15: isdn_send_connect(): msg 74, call
> id 0x1D0, ces 1 bchan 9, call type DATA
> Aug 21 11:10:17.596 MEST: %LINK-3-UPDOWN: Interface Serial0:9, changed
> state to up
> Aug 21 11:10:17.632 MEST: Se0:9 PPP: Treating connection as a callin
> Aug 21 11:10:17.636 MEST: Se0:9 PPP: Phase is ESTABLISHING, Passive Open
> Aug 21 11:10:17.640 MEST: Se0:9 CHAP: Using alternate hostname XX-ki
> Aug 21 11:10:17.640 MEST: Se0:9 LCP: State is Listen
> Aug 21 11:10:17.656 MEST: ISDN Se0:15: TX ->  CONNECT pd = 8  callref =
> 0xB8C3
> Aug 21 11:10:17.660 MEST:         Channel ID i = 0xA9838A
> Aug 21 11:10:17.696 MEST: ISDN Se0:15: RX <-  CONNECT_ACK pd = 8
> callref = 0x38C3
> Aug 21 11:10:17.712 MEST: ISDN Se0:15: received CALL_PROGRESSing call_id
> 0x1D0
> Aug 21 11:10:17.716 MEST: ISDN Se0:15: CALL_PROGRESS: CALL_CONNECTED
> call id 0x1D0, bchan -1, dsl 0
> Aug 21 11:10:19.644 MEST: Se0:9 LCP: TIMEout: State Listen
> Aug 21 11:10:19.648 MEST: Se0:9 CHAP: Using alternate hostname XX-ki
> Aug 21 11:10:19.656 MEST: Se0:9 LCP: O CONFREQ [Listen] id 164 len 31
> Aug 21 11:10:19.660 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:19.664 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:19.668 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:19.672 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:21.652 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:21.656 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 165 len 31
> Aug 21 11:10:21.660 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:21.664 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:21.668 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:21.672 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:23.628 MEST: %ISDN-6-CONNECT: Interface Serial0:9 is now
> connected to 431XXXXXX
> Aug 21 11:10:23.652 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:23.656 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 166 len 31
> Aug 21 11:10:23.660 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:23.664 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:23.668 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:23.672 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:25.652 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:25.656 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 167 len 31
> Aug 21 11:10:25.660 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:25.664 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:25.668 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:25.672 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:27.652 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:27.656 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 168 len 31
> Aug 21 11:10:27.660 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:27.664 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:27.668 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:27.672 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:29.708 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:29.712 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 169 len 31
> Aug 21 11:10:29.716 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:29.720 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:29.724 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:29.728 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:31.772 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:31.776 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 170 len 31
> Aug 21 11:10:31.780 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:31.784 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:31.788 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:31.792 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:33.840 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:33.844 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 171 len 31
> Aug 21 11:10:33.848 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:33.852 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:33.856 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:33.860 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:35.900 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:35.908 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 172 len 31
> Aug 21 11:10:35.912 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:35.916 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:35.920 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:35.924 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:37.964 MEST: Se0:9 LCP: TIMEout: State REQsent
> Aug 21 11:10:37.972 MEST: Se0:9 LCP: O CONFREQ [REQsent] id 173 len 31
> Aug 21 11:10:37.972 MEST: Se0:9 LCP:    AuthProto CHAP (0x0305C22305)
> Aug 21 11:10:37.976 MEST: Se0:9 LCP:    MagicNumber 0x64DBEE75
> (0x050664DBEE75)
> Aug 21 11:10:37.980 MEST: Se0:9 LCP:    MRRU 1524 (0x110405F4)
> Aug 21 11:10:37.988 MEST: Se0:9 LCP:    EndpointDisc 1 Local
> (0x130C016E65747573652D6B69)
> Aug 21 11:10:38.596 MEST: ISDN Se0:15: RX <-  DISCONNECT pd = 8  callref
> = 0x38C3
> Aug 21 11:10:38.600 MEST:         Cause i = 0x8090 - Normal call clearing
> Aug 21 11:10:38.616 MEST: ISDN Se0:15: received CALL_DISC  call_id 0x1D0
> Aug 21 11:10:38.624 MEST: %ISDN-6-DISCONNECT: Interface Serial0:9
> disconnected from 431XX , call lasted 21 seconds
> Aug 21 11:10:38.728 MEST: %LINK-3-UPDOWN: Interface Serial0:9, changed
> state to down
> Aug 21 11:10:38.756 MEST: Se0:9 LCP: State is Closed
> Aug 21 11:10:38.760 MEST: Se0:9 PPP: Phase is DOWN
> Cisco 1003

> chapuser#
> chapuser#deb
> chapuser#debug isd
> chapuser#debug isdn q93
> chapuser#debug isdn q931
> ISDN Q931 packets debugging is on
> chapuser#deb
> chapuser#debug ppp au
> chapuser#debug ppp authentication
> PPP authentication debugging is on
> chapuser#deb
> chapuser#debug ppp neg
> chapuser#debug ppp negotiation
> PPP protocol negotiation debugging is on
> chapuser#
> chapuser#
> chapuser#
> chapuser#

> Type escape sequence to abort.

> 00:38:38: %ISDN-6-LAYER2UP: Layer 2 for Interface BR0, TEI 80 changed to up
> 00:38:38: ISDN BR0: TX ->  SETUP pd = 8  callref = 0x04
> 00:38:38:         Bearer Capability i = 0x8890
> 00:38:38:         Channel ID i = 0x83
> 00:38:38:         Called Party Number i = 0x80, '00431XXXXXX',
> Plan:Unknown, Type:Unknown
> 00:38:38: ISDN BR0: RX <-  SETUP_ACK pd = 8  callref = 0x84
> 00:38:38:         Channel ID i = 0x89.
> 00:38:40: ISDN BR0: RX <-  CALL_PROC pd = 8  callref = 0x84
> 00:38:40: ISDN BR0: RX <-  CONNECT pd = 8  callref = 0x84
> 00:38:40:         Date/Time i = 0x0308140B1E
> 00:38:40:         Connected Number i = 0x2183343331323630383030
> 00:38:40: ISDN BR0: TX ->  CONNECT_ACK pd = 8  callref = 0x04
> 00:38:40: %LINK-3-UPDOWN: Interface BRI0:1, changed state to up
> 00:38:40: %DIALER-6-BIND: Interface BR0:1 bound to profile Di1
> 00:38:40: BR0:1 PPP: Treating connection as a callout
> 00:38:40: BR0:1 PPP: Phase is ESTABLISHING, Active Open
> 00:38:40: BR0:1 PPP: No remote authentication for call-out
> 00:38:40: BR0:1 LCP: O CONFREQ [Closed] id 21 len 10
> 00:38:40: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0)
> 00:38:41: ISDN BR0: RX <-  FACILITY pd = 8  callref = 0x84
> 00:38:41:         Facility i =
> 0x91A1130202027B020122300AA1053003020100820100
> 00:38:41:       - ETSI Supplementary Service, Invoke, AOC-D Charging
> Units: 0
> 00:38:41: BRI0:1: AOC-D Recorded Units = 0.
> 00:38:42: BR0:1 LCP: TIMEout: State REQsent
> 00:38:42: BR0:1 LCP: O CONFREQ [REQsent] id 22 len 10
> 00:38:42: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0).
> 00:38:44: BR0:1 LCP: TIMEout: State REQsent
> 00:38:44: BR0:1 LCP: O CONFREQ [REQsent] id 23 len 10
> 00:38:44: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0).
> 00:38:46: %ISDN-6-CONNECT: Interface BRI0:1 is now connected to 00431XXXXXX
> 00:38:46: BR0:1 LCP: TIMEout: State REQsent
> 00:38:46: BR0:1 LCP: O CONFREQ [REQsent] id 24 len 10
> 00:38:46: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0).
> Success rate is 0 percent (0/5)
> chapuser#
> 00:38:48: BR0:1 LCP: TIMEout: State REQsent
> 00:38:48: BR0:1 LCP: O CONFREQ [REQsent] id 25 len 10
> 00:38:48: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0)
> chapuser#
> 00:38:50: BR0:1 LCP: TIMEout: State REQsent
> 00:38:50: BR0:1 LCP: O CONFREQ [REQsent] id 26 len 10
> 00:38:50: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0)
> 00:38:52: BR0:1 LCP: TIMEout: State REQsent
> 00:38:52: BR0:1 LCP: O CONFREQ [REQsent] id 27 len 10
> 00:38:52: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0)
> 00:38:54: BR0:1 LCP: TIMEout: State REQsent
> 00:38:54: BR0:1 LCP: O CONFREQ [REQsent] id 28 len 10
> 00:38:54: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0)
> 00:38:56: BR0:1 LCP: TIMEout: State REQsent
> 00:38:56: BR0:1 LCP: O CONFREQ [REQsent] id 29 len 10
> 00:38:56: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0)
> 00:38:58: BR0:1 LCP: TIMEout: State REQsent
> 00:38:58: BR0:1 LCP: O CONFREQ [REQsent] id 30 len 10
> 00:38:58: BR0:1 LCP:    MagicNumber 0xE041C8A0 (0x0506E041C8A0)
> 00:39:00: BR0:1 LCP: TIMEout: State REQsent
> 00:39:00: BR0:1 PPP: Treating connection as a callout
> 00:39:00: %DIALER-6-UNBIND: Interface BR0:1 unbound from profile Di1
> 00:39:00: BR0:1 LCP: State is Listen
> 00:39:00: %ISDN-6-DISCONNECT: Interface BRI0:1  disconnected from
> 00431XXXXX , call lasted 20 seconds
> 00:39:00: ISDN BR0: TX ->  DISCONNECT pd = 8  callref = 0x04
> 00:39:00:         Cause i = 0x8090 - Normal call clearing
> 00:39:01: ISDN BR0: RX <-  RELEASE pd = 8  callref = 0x84
> 00:39:01:         Cause i = 0x809F - Normal, unspecified
> 00:39:01: ISDN BR0: TX ->  RELEASE_COMP pd = 8  callref = 0x04
> 00:39:01: %LINK-3-UPDOWN: Interface BRI0:1, changed state to down
> 00:39:01: BR0:1 LCP: State is Closed
> 00:39:01: BR0:1 PPP: Phase is DOWN
> chapuser#
> 00:39:11: %ISDN-6-LAYER2DOWN: Layer 2 for Interface BR0, TEI 80 changed
> to down
> chapuser#

> --
> Ahmad Cheikh-Moussa
> NetUSE AG
> Dr.-Hell-Stra?e, 24107 Kiel, Federal Republic of Germany
> Telefon: +49 431 386435 00 --  Telefax: +49 431 386435 99
> Service: Service at NetUSE.DE --  http://NetUSE.DE/

> _______________________________________________
> cisco-nas mailing list
> cisco-nas at puck.nether.net
> https://puck.nether.net/mailman/listinfo/cisco-nas


More information about the cisco-nas mailing list