12-21-2012 10:39 AM
We're fighting an issue with a 3660 router (fitted with a pair ot 2-port T1/E1 cards and four NM-24DM sleds) being used as a dial-up remote access platform. Over time, we see an increasing number of dial-in attempts fail to authenticate.
What happens is the units come up and everything works perfectly; users dial in, they connect, exchange traffic, everyone is happy. Every so often, perhaps every 30 minutes or so, what we'll see is a single modem (for example, the modem in slot 5/10) will begin to experience a large percentage of calls that fail to authenticate, comprising at least 50% of that port's connection attempts, and often 100%:
%CALLRECORD-3-MODEM_CALL_REC_ERROR: DS0 slot/contr/chan=1/1/4, slot/port=5/10, call_id=18E, userid=(n/a), ip=0.0.0.0,
From what we can tell, no authentication attempt actually occurs:
#show debug
General OS:
Modem control/process activation debugging is on
AAA Authentication debugging is on
AAA Accounting debugging is on
AAA Administrative debugging is on
AAA POD packet processing debugging is on
AAA Subsystem debugs debugging is on
AAA API debugs debugging is on
AAA Local debugs debugging is on
AAA Radius debugs debugging is on
Dial on demand:
Dial on demand events debugging is on
CSM Modem Management:
Modem Management Call Switching Module debugging is on
Call Trace Upload:
Call Trace Upload debugging is on
PPP:
PPP authentication debugging is on
MPPE Packet Details debugging is on
PPP protocol errors debugging is on
PPP protocol negotiation debugging is on
PPP packet display debugging is on
PPP forwarding events debugging is on
Multilink events debugging is on
PPP Callback Control Protocol debugging is on
PPP Detailed Elogs debugging is on
Asynchronous interfaces:
Async Rotary Line Queuing Activity debugging is on
Async interface framing debugging is on
Async packet I/O debugging is on
Async interface state changes debugging is on
BAP:
BAP general debugging is on
Modem Relay:
Modem relay errors debugging is on
Modem relay events debugging is on
Modem relay packetizer debugging is on
106719: *Dec 21 12:13:24.113: TTY171: restoring DTR
106720: *Dec 21 12:13:24.113: Modem 5/10 CSM: received ASYNC_DTR_UP for line 171
106733: *Dec 21 12:13:24.865: AAA/API(00000000): aaa_util_unique_id_alloc(), pc 0x601706B8, enter {
106734: *Dec 21 12:13:24.865: AAA/BIND(000016FE): Bind i/f Serial1/0:0
106735: *Dec 21 12:13:24.865: AAA/ACCT/HC(000016FE): Register Se1/0:0 64Kbit/s, poll every 10h 0m 0s
106736: *Dec 21 12:13:24.865: AAA/ACCT/HC(000016FE): Update Se1/0:0
106737: *Dec 21 12:13:24.865: AAA/ACCT/HC(000016FE): Se1/0:0 [init-sess] (rx/tx) base 0/0 pre 0/0 call 0/0
106738: *Dec 21 12:13:24.865: AAA/ACCT/HC(000016FE): Se1/0:0 [init-sess] (rx/tx) adjusted, pre 0/0 call 0/0
106739: *Dec 21 12:13:24.865: AAA/API(00000000): aaa_event_alloc(), pc 0x604D0124 {
106740: *Dec 21 12:13:24.865: AAA/API(00000000): } aaa_event_alloc()
106741: *Dec 21 12:13:24.865: AAA/API(000016FE): aaa_event_send_and_free(), pc 0x604D3F84 {
106742: *Dec 21 12:13:24.869: AAA/ACCT/EVENT/(000016FE): CALL START
106743: *Dec 21 12:13:24.869: Getting session id for NET(000016FE) : db=669A860C
106744: *Dec 21 12:13:24.869: AAA/ACCT(00000000): add node, session 9053
106745: *Dec 21 12:13:24.869: AAA/ACCT/NET(000016FE): add, count 1
106746: *Dec 21 12:13:24.869: AAA/API(000016FE): } aaa_event_send_and_free()
106747: *Dec 21 12:13:24.869: Getting session id for NONE(000016FE) : db=669A860C
106748: *Dec 21 12:13:24.869: AAA/API(000016FE): } aaa_util_unique_id_alloc()
106749: *Dec 21 12:13:24.869: AAA/API(00000000): aaa_event_alloc(), pc 0x6015BA58, enter {
106750: *Dec 21 12:13:24.869: AAA/API(00000000): } aaa_event_alloc()
106751: *Dec 21 12:13:24.869: AAA/API(000016FE): aaa_attr_event_add_string(), pc 0x6015BAA4, enter {
106752: *Dec 21 12:13:24.869: AAA/API(000016FE): } aaa_attr_event_add_string()
106753: *Dec 21 12:13:24.869: AAA/API(000016FE): aaa_attr_event_add_string(), pc 0x6015BAC8, enter {
106754: *Dec 21 12:13:24.869: AAA/API(000016FE): } aaa_attr_event_add_string()
106755: *Dec 21 12:13:24.869: AAA/API(000016FE): aaa_event_send_and_free(), pc 0x601706D4, enter {
106756: *Dec 21 12:13:24.869: AAA/ACCT/EVENT/(000016FE): ATTR REPLACE
106757: *Dec 21 12:13:24.869: AAA/API(00000000): add_attr_to_list(), pc 0x604CBEF4 {
106758: *Dec 21 12:13:24.869: AAA/API(00000000): } add_attr_to_list()
106759: *Dec 21 12:13:24.869: AAA/ACCT(000016FE): Send NEWINFO accounting notification to EM successfully
106760: *Dec 21 12:13:24.869: AAA/API(000016FE): } aaa_event_send_and_free()
106761: *Dec 21 12:13:24.869: CSM: MODEM_REPORT from 1/0:0, call_id=0x18B7, event=0x1, cause=0x0, dchan_idb=0x65B05600
106762: *Dec 21 12:13:24.869: CSM: Next free modem = 5/10; statbits = 80010020
106763: *Dec 21 12:13:24.869: Modem 5/10 CSM: modem is allocated, modems free=0
106764: *Dec 21 12:13:24.869: Modem 5/10 CSM: Incoming call from <removed> to <removed>, id 0x18B7
106765: *Dec 21 12:13:24.869: Modem 5/10 CSM: (CSM_PROC_IDLE)<--ISDN_CALL
106766: *Dec 21 12:13:24.949: CSM: MODEM_REPORT from 1/0:0, call_id=0x18B7, event=0x4, cause=0x0, dchan_idb=0x65B05600
106767: *Dec 21 12:13:24.949: Modem 5/10 CSM: MODEM_REPORT rcvd DEV_CONNECTED for call_id 0x18B7
106768: *Dec 21 12:13:24.949: Modem 5/10 CSM: (CSM_PROC_MODEM_RESERVED)<--ISDN_CONNECTED
106769: *Dec 21 12:13:24.949: Modem 5/10 Mica: configured for Answer mode, with Null signaling, 0x0 tone detection.
106770: *Dec 21 12:13:24.949: %ISDN-6-CONNECT: Interface Serial1/0:0 is now connected to <removed> N/A
106771: *Dec 21 12:13:25.025: %ISDN-6-CHAN_UNAVAILABLE: Interface Se1/0:23 Requested Channel 15 is not available
106772: *Dec 21 12:13:25.049: Modem 5/10 CSM: (CSM_PROC_WAIT_FOR_CARRIER)<--CSM_EVENT_MODEM_SETUP
106773: *Dec 21 12:13:25.049: Modem 5/10 Mica: in modem state CALL_SETUP
106788: *Dec 21 12:13:26.121: Modem 5/10 Mica: in modem state CONNECT
106791: *Dec 21 12:13:26.521: Modem 5/10 Mica: in modem state LINK
106841: *Dec 21 12:13:30.217: Modem 5/10 Mica: in modem state RANGING
106932: *Dec 21 12:13:36.249: Modem 5/10 Mica: in modem state HALF_DUPLEX_TRAIN
106946: *Dec 21 12:13:37.201: Modem 5/10 Mica: in modem state TRAINUP
106983: *Dec 21 12:13:39.653: Modem 5/10 Mica: in modem state EC_NEGOTIATING
107015: *Dec 21 12:13:41.453: Modem 5/10 CSM: (CSM_PROC_WAIT_FOR_CARRIER)<--MODEM_CONNECTED
107016: *Dec 21 12:13:41.453: Modem 5/10 Mica: in modem state STEADY
107017: *Dec 21 12:13:41.453: Modem 5/10 Mica: received ConnectInfo
107018: *Dec 21 12:13:41.453: TTY171: DSR came up
107019: *Dec 21 12:13:41.453: tty171: Modem: IDLE->(unknown)
107020: *Dec 21 12:13:41.457: AAA/LOCAL: exec
107021: *Dec 21 12:13:41.457: TTY171: EXEC creation
107022: *Dec 21 12:13:41.457: AAA/API(00000000): aaa_util_unique_id_alloc(), pc 0x6056C888, enter {
107023: *Dec 21 12:13:41.457: AAA/ACCT/HC(000016FE): Register As171 9Kbit/s, already registered; FAIL
107024: *Dec 21 12:13:41.457: AAA/ACCT/HC(000016FE): Update As171
107025: *Dec 21 12:13:41.457: AAA/ACCT/HC(000016FE): As171 [init-sess] (rx/tx) base 190993/524643 pre 190993/524643 call 190993/524643
107026: *Dec 21 12:13:41.461: AAA/ACCT/HC(000016FE): As171 [init-sess] (rx/tx) adjusted, pre 0/0 call 0/0
107027: *Dec 21 12:13:41.461: AAA/API(000016FE): aaa_attr_update(), pc 0x604CF7AC {
107028: *Dec 21 12:13:41.461: AAA/API(000016FE): } aaa_attr_update()
107029: *Dec 21 12:13:41.461: AAA/API(000016FE): } aaa_util_unique_id_alloc()
107030: *Dec 21 12:13:41.461: AAA/LOCAL: new_ascii_login: tty 658099B0 idb 6580AC30
107031: *Dec 21 12:13:41.461: AAA/API(00000000): aaa_req_alloc(), pc 0x605123F4, enter {
107032: *Dec 21 12:13:41.461: AAA/API(00000000): } aaa_req_alloc()
107033: *Dec 21 12:13:41.461: AAA/AUTHEN/LOGIN (000016FE): Pick method list 'Permanent Local'
107034: *Dec 21 12:13:41.461: AAA SRV(000016FE): process authen req
107035: *Dec 21 12:13:41.461: AAA SRV(000016FE): Authen method=LOCAL
107036: *Dec 21 12:13:41.461: AAA/LOCAL/LOGIN(000016FE): get user
107037: *Dec 21 12:13:41.461: AAA SRV(000016FE): protocol reply GET_USER for Authentication
107038: *Dec 21 12:13:41.461: AAA SRV(000016FE): Return Authentication status=GET_USER
107039: *Dec 21 12:13:41.465: TTY171: create timer type 10, 0 seconds
107040: *Dec 21 12:13:41.473: Modem 5/10 Mica: CONNECT at 33600/28800 (Tx/Rx), V34+, LAPM, V42bis
107047: *Dec 21 12:13:41.937: TTY171: pause timer type 10 (OK)
107048: *Dec 21 12:13:41.937: AAA/API(000016FE): aaa_attr_req_add(), pc 0x60512994, enter {
107049: *Dec 21 12:13:41.937: AAA/API(000016FE): } aaa_attr_req_add()
107050: *Dec 21 12:13:41.941: AAA SRV(000016FE): process authen req
107051: *Dec 21 12:13:41.941: AAA SRV(000016FE): Authen method=LOCAL
107052: *Dec 21 12:13:41.941: AAA/LOCAL/LOGIN(000016FE): get user
107053: *Dec 21 12:13:41.941: AAA SRV(000016FE): protocol reply GET_USER for Authentication
107054: *Dec 21 12:13:41.941: AAA SRV(000016FE): Return Authentication status=GET_USER
107055: *Dec 21 12:13:41.941: TTY171: resume timer type 10 (OK)
107056: *Dec 21 12:13:41.945: TTY171: pause timer type 10 (OK)
107057: *Dec 21 12:13:41.945: AAA/API(000016FE): aaa_attr_req_add(), pc 0x60512994, enter {
107058: *Dec 21 12:13:41.945: AAA/API(000016FE): } aaa_attr_req_add()
107059: *Dec 21 12:13:41.945: AAA SRV(000016FE): process authen req
107060: *Dec 21 12:13:41.945: AAA SRV(000016FE): Authen method=LOCAL
107061: *Dec 21 12:13:41.945: AAA/LOCAL/LOGIN(000016FE): get user
107062: *Dec 21 12:13:41.945: AAA SRV(000016FE): protocol reply GET_USER for Authentication
107063: *Dec 21 12:13:41.945: AAA SRV(000016FE): Return Authentication status=GET_USER
107064: *Dec 21 12:13:41.945: TTY171: resume timer type 10 (OK)
107068: *Dec 21 12:13:42.457: TTY171: timer type 10 expired
107069: *Dec 21 12:13:42.457: TTY171: fg timeout type 10
107070: *Dec 21 12:13:42.473: TTY171: pause timer type 10 (OK)
107071: *Dec 21 12:13:42.473: AAA/API(00000000): aaa_event_alloc(), pc 0x605128B4, enter {
107072: *Dec 21 12:13:42.473: AAA/API(00000000): } aaa_event_alloc()
107073: *Dec 21 12:13:42.473: AAA/API(000016FE): aaa_event_send_and_free(), pc 0x60512910, enter {
107074: *Dec 21 12:13:42.473: AAA/ACCT/EVENT/(000016FE): EXEC DOWN
107075: *Dec 21 12:13:42.473: AAA/API(000016FE): } aaa_event_send_and_free()
107092: *Dec 21 12:13:44.473: TTY171: Line reset by "Exec"
107093: *Dec 21 12:13:44.473: AAA/ACCT/HC(000016FE): Update As171
107094: *Dec 21 12:13:44.473: AAA/ACCT/HC(000016FE): As171 [pre-sess] (rx/tx) base 190993/524643 pre 190993/524643 call 190993/524643
107095: *Dec 21 12:13:44.473: AAA/ACCT/HC(000016FE): As171 [pre-sess] (rx/tx) adjusted, pre 0/0 call 0/0
107096: *Dec 21 12:13:44.473: AAA/ACCT/HC(000016FE): Update As171
107097: *Dec 21 12:13:44.473: AAA/ACCT/HC(000016FE): As171 [sess] (rx/tx) base 190993/524643 pre 190993/524643 call 190993/524643
107098: *Dec 21 12:13:44.473: AAA/ACCT/HC(000016FE): As171 [sess] (rx/tx) adjusted, pre 0/0 call 0/0
107099: *Dec 21 12:13:44.473: AAA/ACCT/HC(000016FE): Deregister As171
107100: *Dec 21 12:13:44.473: TTY171: Modem: (unknown)->HANGUP
107101: *Dec 21 12:13:44.473: TTY171: no timer type 0 to destroy
107102: *Dec 21 12:13:44.473: TTY171: no timer type 1 to destroy
107103: *Dec 21 12:13:44.473: TTY171: no timer type 3 to destroy
107104: *Dec 21 12:13:44.473: TTY171: no timer type 4 to destroy
107105: *Dec 21 12:13:44.473: TTY171: destroy timer type 10
107106: *Dec 21 12:13:44.473: TTY171: no timer type 2 to destroy
107107: *Dec 21 12:13:44.473: AAA/API(00000000): aaa_event_alloc(), pc 0x604D0124, enter {
107108: *Dec 21 12:13:44.473: AAA/API(00000000): } aaa_event_alloc()
107109: *Dec 21 12:13:44.473: AAA/API(000016FE): aaa_event_send_and_free(), pc 0x604D4700, enter {
107110: *Dec 21 12:13:44.473: AAA/ACCT/EVENT/(000016FE): CALL STOP
107111: *Dec 21 12:13:44.473: AAA/ACCT/CALL STOP(000016FE): Sending stop requests
107112: *Dec 21 12:13:44.473: AAA/ACCT(000016FE): Send all stops
107113: *Dec 21 12:13:44.473: AAA/ACCT/NET(000016FE): STOP
107114: *Dec 21 12:13:44.473: AAA/ACCT/NET(000016FE): Method list not found
107115: *Dec 21 12:13:44.473: AAA/ACCT(000016FE): del node, session 9053
107116: *Dec 21 12:13:44.473: AAA/ACCT/NET(000016FE): free_rec, count 0
107117: *Dec 21 12:13:44.473: AAA/ACCT/NET(000016FE) reccnt 0, csr TRUE, osr 0
107118: *Dec 21 12:13:44.473: AAA/ACCT/NET(000016FE): Last rec in db, intf not enqueued
107119: *Dec 21 12:13:44.473: AAA/API(000016FE): } aaa_event_send_and_free()
107120: *Dec 21 12:13:44.477: TTY171: dropping DTR, hanging up
107121: *Dec 21 12:13:44.477: Modem 5/10 CSM: (CSM_PROC_CONNECTED)<--ASYNC_DTR_DOWN
107122: *Dec 21 12:13:44.477: tty171: Modem: HANGUP->(unknown)
107123: *Dec 21 12:13:44.497: Modem 5/10 Mica: in modem state TERMINATING
107124: *Dec 21 12:13:44.497: Modem 5/10 Mica: received TerminateInfo
107125: *Dec 21 12:13:44.513: %ISDN-6-CHAN_UNAVAILABLE: Interface Se1/0:23 Requested Channel 15 is not available
107126: *Dec 21 12:13:44.521: Modem 5/10 CSM: (CSM_PROC_DISCONNECTED)<--MODEM_DISCONNECTED
107127: *Dec 21 12:13:44.521: Modem 5/10 CSM: Stopping dm tone timer
107128: *Dec 21 12:13:44.521: Modem 5/10 Mica: in modem state IDLE
107129: *Dec 21 12:13:44.521: Modem 5/10 CSM: (CSM_PROC_DISCONNECTED)<--QUEUED_DISCONNECT
107130: *Dec 21 12:13:44.525: Modem 5/10 CSM: Stopping dm tone timer
107131: *Dec 21 12:13:44.557: Modem 5/10 CSM: CSM_MODEM_DEALLOCATE: modem is deallocated
107132: *Dec 21 12:13:44.557: TTY171: dropping DTR, hanging up
107133: *Dec 21 12:13:44.557: Modem 5/10 CSM: (CSM_PROC_IDLE)<--ASYNC_DTR_DOWN
107134: *Dec 21 12:13:44.557: tty171: Modem: HANGUP->IDLE
107135: *Dec 21 12:13:44.573: Modem 5/10 Mica: DISCONNECT after 00:00:18, due to reason (0xDF00) Host Disconnect.
107136: *Dec 21 12:13:44.573: %MODEM_HIST-3-END_CALL: Mica Modem 5/10
Connect Protocol - LAPM, Compression - V42bis, Connected Standard - V34+
Tx/Rx bit rate - 33600/28800
Call Time - 00:00:18, Disconnect Reason (0xDF00) - Host Disconnect
0 retrains and/or speed shifts, 1 ec retransmissions requested
1218 chars tx, 45 chars rx, 0 chars rx bad
0 ppp packets tx, 0 ppp packets rx, 0 ppp packets rx bad
12 ec packets tx, 2 ec packets rx, 0 ec packets rx bad
0 v110 packets tx, 0 v110 packets rx
0 v110 packets rx bad, 0 v110 sync loss
107137: *Dec 21 12:13:44.573: %MODEM_HIST-3-END_CALL: Mica Modem 5/10
0 total speedshifts, Total/current MOH time - 0/0 sec, 0 MOH count
Modem not on hold, 0 call waiting retrains, 0 MOH requests
Encoder/Decoder state - Link Compression Not Negotiated/Link Compression Not Negotiated
Tx/Rx compression ratio - 0.00:1/0.00:1
0/0 Tx/Rx dictionary resets
107138: *Dec 21 12:13:44.573: %CALLRECORD-3-MODEM_CALL_REC_ERROR: DS0 slot/contr/chan=1/0/0, slot/port=5/10, call_id=18B7, userid=(n/a), ip=0.0.0.0, calling=<removed>, called=8<removed>, std=V34+, prot=LAPM, comp = V42bis init-rx/tx b-rate=28800/33600, finl-rx/tx b-rate=28800/33600, rbs=0, d-pad=None, retr=0, rx/tx chars=45/1218, bad=0, rx/tx ec=2/12, bad=0, total moh time=0 sec, current moh time=0 sec, moh count=0, moh status=0x0, call waiting retrains=0, moh req=0, encoder/decoder state=0xFF/0xFF, rx/tx comp ratio=0.00:1/0.00:1, rx/tx dict reset=0/0, time=18, finl-state=STEADY, disc(modem)=DF00 Tx (host to line) data flushing - OK/Requested by host/non-s
107139: *Dec 21 12:13:44.577: %ISDN-6-DISCONNECT: Interface Serial1/0:0 disconnected from <removed>, call lasted 19 seconds
#show modem opera 5/10
Modem (5/10) Operational Status:
Parameter #0 Disconnect Reason Info: (0xDF00)
Type (=6 ): Tx (host to line) data flushing - OK
Class (=31): Requested by host
Reason (=0 ): non-specific host disconnect
Parameter #1 Connect Protocol: LAP-M
Parameter #2 Compression: V.44-Both
Parameter #3 EC Retransmission Count: 0
Parameter #4 Self Test Error Count: 0
Parameter #5 Call Timer: 19 secs
Parameter #6 Total Retrains: 0
Parameter #7 Sq Value: 4
Parameter #8 Connected Standard: V.34+
Parameter #9 TX,RX Bit Rate: 33600, 28800
Parameter #11 TX,RX Symbol Rate: 3429, 3429
Parameter #13 TX,RX Carrier Frequency: 1959, 1959
Parameter #15 TX,RX Trellis Coding: 32, 16
Parameter #16 TX,RX Preemphasis Index: 3, 8
Parameter #17 TX,RX Constellation Shaping: On, Off
Parameter #18 TX,RX Nonlinear Encoding: On, Off
Parameter #19 TX,RX Precoding: On, Off
Parameter #20 TX,RX Xmit Level Reduction: 0, 0 dBm
Parameter #21 Signal Noise Ratio: 37 dB
Parameter #22 Receive Level: -19 dBm
Parameter #23 Frequency Offset: 0.125 Hz
Parameter #24 Phase Jitter Frequency: 0.0 Hz
Parameter #25 Phase Jitter Level: 0 degrees
Parameter #26 Far End Echo Level: -36 dBm
Parameter #27 Phase Roll: 0.0 Hz
Parameter #28 Round Trip Delay: 81 msecs
Parameter #30 Characters transmitted, received: 1208, 196
Parameter #32 General Portware Information: 0
Parameter #33 PPP/SLIP packets transmitted, received: 0, 0
Parameter #35 PPP/SLIP packets received (BAD/ABORTED): 0
Parameter #36 EC packets transmitted, received OK: 10, 2
Parameter #38 Moving Average of EC packets (Received BAD/ABORTED): 0
Parameter #39 Robbed Bit Signalling (RBS) pattern: 0
Parameter #40 Digital Pad: None, Digital Pad Compensation: None
Parameter #42 SS7/COT Status: 0
Parameter #43 V110/PIAFS frames received bad: 0
Parameter #44 V110/PIAFS frames received good: 0
Parameter #45 V110/PIAFS frames transmitted: 0
Parameter #46 V110/PIAFS sync lost: 0
Parameter #93 PIAFS RTF: 0
Parameter #120 Total Speedshifts: 0
Parameter #108 Total MOH Time: 0 secs
Parameter #109 Current MOH Time: 0 secs
Parameter #105 MOH Status: Modem is Not on Hold
Parameter #106 MOH Count: 0
Parameter #107 MOH Request Count: 0
Parameter #110 Retrains due to Call Waiting: 0
Parameter #114 DC Encoder,Decoder State: compressed/compressed
Parameter #115 DC TX,RX Compression Ratio: 1.0:1, 1.0:1
Parameter #117 DC TX,RX Dictionary Reset Count: 1, 1
Parameter #119 Diagnostic Code: 00 00 00 00 00 00 00 00
Line Shape:
..........................*
................................*
.................................*
.................................*
................................*
.................................*
.................................*
.................................*
................................*
................................*
.................................*
................................*
................................*
................................*
................................*
................................*
................................*
................................*
...............................*
...............................*
.............................*
............................*
..........................*
......................*
..............*
Once an individual modem enters this state, it behaves in this fashion indefinitely. Shutting the modem down and restarting it has no effect. Only a reload of the chassis seems to have any impact. Once the chassis is reloaded, the behavior is normal for all modems.
After a while -- the time varies -- individual modems will begin experiencing problems again. The individual modems that are affected seem random; they're different each time, but eventaully most of the modems are affected and the chassis must be reloaded.
We have multiple units in mutiple locations that seem to be having this issue.
What could cause it, how could it be prevented, and could there be a method of clearing this state short of reloading the chassis?
12-21-2012 03:38 PM
Evan Kisbey wrote:
...
107039: *Dec 21 12:13:41.465: TTY171: create timer type 10, 0 seconds
...
Could this be part of the problem?
12-21-2012 04:51 PM
Saw that;
(config-line)#timeout login response 300
results in;
134681: *Dec 21 18:31:13.311: TTY195: create timer type 10, 300 seconds
Call still fails in identical fashion. So while the "0" seconds timer indeed may be symptomatic, it is apparently not the cause...
12-21-2012 05:16 PM
Oddly, I've noticed that the autoconfigure string fails on these hung modems:
138048: *Dec 21 18:50:18.553: TTY195: restoring DTR
138049: *Dec 21 18:50:18.553: TTY195: autoconfigure probe started
138050: *Dec 21 18:50:18.553: TTY195: Modem command: --AT&F&D2s29=1--
138056: *Dec 21 18:50:24.729: TTY195: Modem configuration FAILED
138057: *Dec 21 18:50:24.729: TTY195: Done with modem configuration
Going in and trying to force an autoconfigure, I'm left with:
138593: *Dec 21 18:58:49.880: TTY195: No modem found
Shutting the modem, bad, busyout, etc, seem to have no effect... a reboot is all that seems to fix this.
...FYI, Portware 2940 on IOS 12.4(25d)...
12-28-2012 01:28 PM
An interesting observation;
When one of the modems goes bad, in order to postpone a reboot and minimize customer impact, we will issue a "modem bad" statement on the afflicted line (for example, line 110) to prevent further calls hitting that modem. Since the line is a member of a group of lines associated with an ansynch group interface prior to this point, adding this statement creates a new "line" stanza in the configuration for the changed modem.
What we're noticing is that stanzas created for the afflicted modems differ from modems that are funcitoning normally. For example, in the following, line 3/13 is not working properly. Line 3/0 is fine. We issue a "modem bad" to line 97 (3/0) and then to 110 (3/13) and observe the results:
#sho run
line 97 120
session-timeout 2 output
absolute-timeout 10
modem InOut
modem autoconfigure type mica-v34production
no editing
autoselect during-login
autoselect ppp
#conf t
(config)#line 97
(config-line)#modem bad
(config-line)#do sho run
line 97
session-timeout 2 output
absolute-timeout 10
modem InOut
modem autoconfigure type mica-v34production
modem bad
no editing
autoselect during-login
autoselect ppp
line 98 120
session-timeout 2 output
absolute-timeout 10
modem InOut
modem autoconfigure type mica-v34production
no editing
autoselect during-login
autoselect ppp
(config-line)#line 110
(config-line)#modem bad
(config-line)#do sho run
line 97
session-timeout 2 output
absolute-timeout 10
modem InOut
modem autoconfigure type mica-v34production
modem bad
no editing
autoselect during-login
autoselect ppp
line 98 109
session-timeout 2 output
absolute-timeout 10
modem InOut
modem autoconfigure type mica-v34production
no editing
autoselect during-login
autoselect ppp
line 110
exec-timeout 0 0
timeout login response 0
modem InOut
modem autoconfigure type mica-v34production
modem bad
data-character-bits 8
exec-character-bits 8
special-character-bits 8
length 0
width 0
no history
no editing
transport preferred none
escape-character soft 0
escape-character 0
no ip tcp input-coalesce-threshold
autoselect during-login
autoselect ppp
hold-character 0
lat out-group all disabled
line 111 120
session-timeout 2 output
absolute-timeout 10
modem InOut
modem autoconfigure type mica-v34production
no editing
autoselect during-login
autoselect ppp
What would cause these additional lines in the configuration? They have to be related somehow!
01-02-2013 10:31 AM
So, some progress on this. An individual modem can be restored to function by issuing the following commands, effectively pulling out the altered settings:
session-timeout 2 output
absolute-timeout 10
exec-timeout 0 0
default exec-timeout
default timeout login response
no data-character-bits
exec-character-bits 7
special-character-bits 7
default length
default width
default history size
default history
default editing
default transport preferred
default escape-character soft
default escape-character
ip tcp input-coalesce-threshold 20
default hold-character
default lat out-group
So the question now becomes, what causes these to be altered, and how do I prevent it?
Discover and save your favorite ideas. Come back to expert answers, step-by-step guides, recent topics, and more.
New here? Get started with these tips. How to use Community New member guide