Re: Cisco: Disconnect Reason (0xDF00) - Host Disconnect

kentngo · ‎02-19-2003

Any suggestion on what to look for ?

Problem: 5% of the clients are experiencing Microsoft Error 629 (The port was disconnected by the remote machine) when dialing into the Cisco 3640.

Platform:

3600 Software (C3640-D-M), Version 12.2(7c)

MICA-6DM Firmware: CP ver 2730

48 Serial network interface(s)

48 terminal line(s)

2 Channelized T1/PRI port(s)

sh modem:

Avg Hold Inc calls Out calls Busied Failed No Succ

Mdm Time Succ Fail Succ Fail Out Dial Answer Pct.

* 1/0 01:38:09 156 15 0 0 0 0 0 91%

1/1 01:06:55 189 8 0 0 0 0 0 96%

* 1/2 01:18:07 151 19 0 0 0 0 0 89%

* 1/3 01:15:56 171 14 0 0 0 0 0 92%

* 1/4 01:02:27 191 15 0 0 0 0 0 93%

* 1/5 01:05:24 174 20 0 0 0 0 0 90%

* 1/6 01:18:03 171 12 0 0 0 0 0 93%

1/7 02:14:31 133 7 0 0 0 0 0 95%

1/8 01:08:43 183 13 0 0 0 0 0 93%

* 1/9 01:25:35 160 14 0 0 0 0 0 92%

1/10 01:25:25 167 18 0 0 0 0 0 90%

* 1/11 01:33:36 160 15 0 0 0 0 0 91%

* 1/12 01:13:37 180 18 0 0 0 0 0 91%

1/13 00:11:12 371 39 0 0 0 0 1 90%

* 1/14 01:22:57 171 12 0 0 0 0 0 93%

* 1/15 01:15:26 162 21 0 0 0 0 0 89%

1/16 00:17:45 365 31 0 0 0 0 0 92%

1/17 01:21:23 172 10 0 0 0 0 0 95%

1/18 01:28:50 161 14 0 0 0 0 0 92%

* 1/19 01:24:54 164 12 0 0 0 0 0 93%

* 1/20 01:12:43 178 10 0 0 0 0 0 95%

* 1/21 01:52:00 143 9 0 0 0 0 0 94%

* 1/22 01:37:33 159 10 0 0 0 0 0 94%

* 1/23 01:45:07 146 6 0 0 0 0 0 96%

2/0 01:18:31 170 21 0 0 0 0 0 89%

2/1 01:11:56 172 14 0 0 0 0 0 92%

2/2 01:34:58 158 8 0 0 0 0 0 95%

* 2/3 01:57:51 140 12 0 0 0 0 0 92%

2/4 00:29:27 308 25 0 0 0 0 0 92%

* 2/5 01:39:47 159 8 0 0 0 0 0 95%

2/6 00:10:40 382 26 0 0 0 0 0 94%

2/7 00:12:54 359 33 0 0 0 0 0 92%

* 2/8 02:18:07 129 14 0 0 0 0 0 90%

* 2/9 01:26:36 162 10 0 0 0 0 0 94%

2/10 01:30:31 155 15 0 0 0 0 0 91%

* 2/11 01:00:08 195 18 0 0 0 0 0 92%

* 2/12 02:15:16 128 9 0 0 0 0 0 93%

* 2/13 01:12:54 177 13 0 0 0 0 0 93%

2/14 00:51:38 235 14 0 0 0 0 1 94%

2/15 00:00:43 433 42 0 0 0 0 0 91%

2/16 01:23:38 164 7 0 0 0 0 0 96%

2/17 00:12:30 366 36 0 0 0 0 0 91%

2/18 01:42:52 145 11 0 0 0 0 0 93%

2/19 00:13:45 373 26 0 0 0 0 0 93%

* 2/20 01:03:48 189 13 0 0 0 0 0 94%

* 2/21 01:17:16 178 16 0 0 0 0 0 92%

2/22 01:42:46 150 14 0 0 0 0 0 91%

* 2/23 01:10:26 164 14 0 0 0 0 0 92%

Total: 01:02:17 9569 781 0 0 0 0 2 92%

tepatel · ‎02-19-2003

This is not easy issue to troubleshoot. We need to see lots of data before pin-pointing the issue. Here is the link which explains mica modem disconnect reasons

http://www.cisco.com/warp/public/76/mica-states-drs.html

Now we need to know how far users go during connection when they dialin and before they get disconnected.

Error 629 is the microsoft's reason for disconnection which may not represent the actual issue. So we need to know

1)do they get the modem handshake tone after dialin

2)Do they hear any abnormal modem trainup sound during handshake.

3)Do they see "Veryfying username and password" on client side.

4)Do they see error 629 after they see "Veryfying username and password" displayed.

We need to take a look on "show modem csr summary" to see the call success rate.

After that we need to track the user who gets that error with debug turned on 3640 for modem and ppp. So that we can see what router thinks about that connection. Following debug we need for a call showing 629 error.

debug isdn q931

debug ppp nego

debug modem

debug modem csm

debug async state

Once we identify the mica modem used for that connection, need to know following for that mica modem.

sh modem log slot/port

sh modem operational-status slot/port

kentngo · ‎03-11-2003

1) Modem handshake seems to be normal

2) No abnormal sound during handshake

3) Do see "Veryfying username and password" on client side.

4) Error 629 occur after they see "Veryfying username and password" displayed

Below is the output with all the above debugs turn on when the error 629 occur:

Feb 26 08:21:37.555: ISDN Se3/0:23: RX <- SETUP pd = 8 callref = 0x1633

Feb 26 08:21:37.555: Bearer Capability i = 0x8090A2

Feb 26 08:21:37.555: Channel ID i = 0xE9808301

Feb 26 08:21:37.555: Net Specific Fac i = 0x006280

Feb 26 08:21:37.555: Called Party Number i = 0x81, '5678', Plan:ISDN, Type:Unknown

Feb 26 08:21:37.563: CSM: MODEM_REPORT from 3/0:0, call_id=0x3489, event=0x1, cause=0x0, dchan_idb=0x617B2F10

Feb 26 08:21:37.563: CSM: Next free modem = 2/19; statbits = 10020

Feb 26 08:21:37.563: Modem 2/19 CSM: modem is allocated, modems free=33

Feb 26 08:21:37.563: Modem 2/19 CSM: Incoming call from Unknown to 5678, id 0x3489

Feb 26 08:21:37.563: Modem 2/19 CSM: (CSM_PROC_IDLE)<--ISDN_CALL

Feb 26 08:21:37.611: ISDN Se3/0:23: TX -> CALL_PROC pd = 8 callref = 0x9633

Feb 26 08:21:37.615: Channel ID i = 0xA98381

Feb 26 08:21:37.615: ISDN Se3/0:23: TX -> ALERTING pd = 8 callref = 0x9633

Feb 26 08:21:37.615: ISDN Se3/0:23: TX -> CONNECT pd = 8 callref = 0x9633

Feb 26 08:21:37.699: ISDN Se3/0:23: RX <- CONNECT_ACK pd = 8 callref = 0x1633

Feb 26 08:21:37.703: ISDN Se3/0:23: CALL_PROGRESS: CALL_CONNECTED call id 0x3489, bchan 0, dsl 0

Feb 26 08:21:37.703: CSM: MODEM_REPORT from 3/0:0, call_id=0x3489, event=0x4, cause=0x0, dchan_idb=0x617B2F10

Feb 26 08:21:37.703: Modem 2/19 CSM: MODEM_REPORT rcvd DEV_CONNECTED for call_id 0x3489

Feb 26 08:21:37.707: Modem 2/19 CSM: (CSM_PROC_MODEM_RESERVED)<--ISDN_CONNECTED

Feb 26 08:21:37.707: Modem 2/19 Mica: configured for Answer mode, with Null signaling, 0x0 tone detection.

Feb 26 08:21:37.807: Modem 2/19 Mica: in modem state CALL_SETUP

Feb 26 08:21:38.887: Modem 2/19 Mica: in modem state CONNECT

Feb 26 08:21:43.375: Modem 2/19 Mica: in modem state LINK

Feb 26 00:21:43: %ISDN-6-CONNECT: Interface Serial3/0:0 is now connected to unknown

Feb 26 08:21:54.878: Modem 2/19 Mica: in modem state TRAINUP

Feb 26 08:21:58.566: TTY55: timer type 2 expired (continued in 651)

Feb 26 08:22:03.202: Modem 2/19 Mica: in modem state EC_NEGOTIATING

Feb 26 08:22:03.750: Modem 2/19 CSM: (CSM_PROC_WAIT_FOR_CARRIER)<--MODEM_CONNECTED

Feb 26 08:22:03.750: Modem 2/19 Mica: in modem state STEADY

Feb 26 08:22:03.762: Modem 2/19 Mica: CONNECT at 50666/26400 (Tx/Rx), V90, LAPM, V42bis

Feb 26 08:22:04.566: TTY84: DSR came up

Feb 26 08:22:04.566: tty84: Modem: IDLE->(unknown)

Feb 26 08:22:04.570: TTY84: EXEC creation

Feb 26 08:22:04.770: TTY84: set timer type 10, 0 seconds

Feb 26 08:22:05.570: TTY84: timer type 10 expired

Feb 26 08:22:05.570: TTY84: fg timeout type 10

Feb 26 08:22:07.870: TTY84: set timer type 10, 0 seconds

Feb 26 08:22:08.570: TTY84: timer type 10 expired

Feb 26 08:22:08.570: TTY84: fg timeout type 10

Feb 26 08:22:10.870: TTY84: set timer type 10, 0 seconds

Feb 26 08:22:11.570: TTY84: timer type 10 expired

Feb 26 08:22:11.570: TTY84: fg timeout type 10

Feb 26 08:22:12.570: TTY42: timer type 2 expired (continued in 839)

Feb 26 08:22:15.670: TTY84: Line reset by "Exec"

Feb 26 08:22:15.670: TTY84: Modem: (unknown)->HANGUP

Feb 26 08:22:15.670: TTY84: no timer type 0 to destroy

Feb 26 08:22:15.670: TTY84: no timer type 1 to destroy

Feb 26 08:22:15.670: TTY84: no timer type 3 to destroy

Feb 26 08:22:15.670: TTY84: no timer type 4 to destroy

Feb 26 08:22:15.670: TTY84: no timer type 2 to destroy

Feb 26 08:22:16.570: TTY84: dropping DTR, hanging up

Feb 26 08:22:16.570: Modem 2/19 CSM: (CSM_PROC_CONNECTED)<--ASYNC_DTR_DOWN

Feb 26 08:22:16.570: tty84: Modem: HANGUP->IDLE

Feb 26 08:22:16.586: Modem 2/19 Mica: in modem state TERMINATING

Feb 26 08:22:16.610: Modem 2/19 CSM: (CSM_PROC_DISCONNECTED)<--MODEM_DISCONNECTED

Feb 26 08:22:16.610: Modem 2/19 Mica: in modem state IDLE

Feb 26 08:22:16.610: Modem 2/19 CSM: (CSM_PROC_DISCONNECTED)<--QUEUED_DISCONNECT

Feb 26 08:22:16.654: Modem 2/19 CSM: CSM_MODEM_DEALLOCATE: modem is deallocated

Feb 26 00:22:16: %ISDN-6-DISCONNECT: Interface Serial3/0:0 disconnected from unknown , call lasted 38 seconds

Feb 26 08:22:16.658: ISDN Se3/0:23: TX -> DISCONNECT pd = 8 callref = 0x9633

Feb 26 08:22:16.658: Cause i = 0x8090 - Normal call clearing

Feb 26 08:22:16.662: Modem 2/19 Mica: DISCONNECT after 00:00:38, due to reason (0xDF00) Host Disconnect.

Feb 26 08:22:16.850: ISDN Se3/0:23: RX <- RELEASE pd = 8 callref = 0x1633

Feb 26 08:22:16.854: CSM: MODEM_REPORT from 3/0:0, call_id=0x3489, event=0x0, cause=0x0, dchan_idb=0x617B2F10

Feb 26 08:22:16.854: CSM: MODEM_REPORT rcvd DEV_IDLE for call_id 0x3489, modem not found due to wrong b channel number or b channel is deallocated

Feb 26 08:22:16.858: ISDN Se3/0:23: TX -> RELEASE_COMP pd = 8 callref = 0x9633

Feb 26 08:22:19.582: TTY84: restoring DTR

Feb 26 08:22:19.582: Modem 2/19 CSM: received ASYNC_DTR_UP for line 84

Feb 26 08:22:22.582: TTY50: timer type 2 expired (continued in 859)

Feb 26 08:22:29.582: TTY35: timer type 2 expired (continued in 699)

Feb 26 08:22:30.582: TTY37: timer type 2 expired (continued in 838)

tepatel · ‎03-11-2003

As per the debug

Feb 26 08:22:03.762: Modem 2/19 Mica: CONNECT at 50666/26400 (Tx/Rx), V90, LAPM, V42bis

Two modems did get connected at very good speed on 50.6K so modem layer is fine but the line is disconnected by EXEC process as per

Feb 26 08:22:15.670: TTY84: Line reset by "Exec"

Which means that customer may be authenticating in a terminal window after dialing and take too long to enter the username and password etc..OR router didin't receive any PPP data in time after two modems connected so that i can get out of exec mode and start ppp.

So all-n-all it looks like user side issue. Modem layer is fine so AS is working ok.

liviu.gheorghe · ‎03-11-2003

Do you have any chat scripts configured on the lines? I saw some very strange effects of chat script configured on modems.

Can you post the config of the async interface and lines?

Regards, LG
*** Please Rate All Helpful Responses ***

kentngo · ‎03-13-2003

We don't have any chat scripts configured. I increased the fast-idle time to see if it help. Other than that it is a pretty simple setup.

interface Serial3/0:23

ip unnumbered Loopback0

encapsulation ppp

dialer idle-timeout 36000

dialer fast-idle 40

isdn switch-type primary-dms100

isdn incoming-voice modem

peer default ip address pool dialin_pool

no fair-queue

no cdp enable

ppp authentication pap callin

ppp multilink

!

interface Group-Async1

ip unnumbered Loopback0

encapsulation ppp

ip tcp header-compression passive

no ip mroute-cache

dialer in-band

dialer idle-timeout 36000

dialer fast-idle 40

dialer-group 1

async mode interactive

ipx ppp-client Loopback0

peer default ip address pool dialin_pool

no fair-queue

ppp authentication pap callin

group-range 33 56

!

line 33 56

session-timeout 15 output

modem Dialin

autoselect during-login

autoselect ppp

cheath · ‎11-21-2003

Hi,

I am experiencing the same behavior on the 3640 platform. In a rural area with bad CAS lines. I bumped the max connect protocol to v.90. Still getting Error 629. I am going to try removing "Autoselect during-login" and "async mode interactive" to bypass the login prompt for the caller....

Chandler

fpenland · ‎04-16-2004

I also am having a similar problem with my 3640, I am on the newest Mica firmware. Users can connect and seem to stay connected until they try to download anything. When they try to download somthing it dissconects them.