Buy or Renew
Buy or Renew
cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 
cancel
Start a conversation
747
Views
0
Helpful
2
Replies

ADSL issue on Cisco 877

Kim Alm
Level 1
Level 1

‎08-10-2015 12:36 AM - edited ‎03-08-2019 01:17 AM

Hi,

I had my Cisco 877 unplugged for six weeks during my vacation and now it refuses to bring up my ATM interface. It comes briefly up on boot goes momentarily into status up/up just to go into up/down in a matter of seconds. This is a configuration that has worked flawlessly for years.

Cisco877#sho ip int bri
Interface                  IP-Address      OK? Method Status                Protocol
ATM0                       unassigned      YES NVRAM  up                    up
BVI1                       unassigned      YES DHCP   up                    up
...


Cisco877#sho ip int bri
Interface                  IP-Address      OK? Method Status                Protocol
ATM0                       unassigned      YES NVRAM  down                  down
BVI1                       unassigned      YES DHCP   up                    up
...

The ADSL line is confirmed to work with the modem provided by my ISP. I have another 877 with an older firmware that where replaced by my current 877, this older 877 behaves in exact the same way.

I'm fresh out of ideas what might causes this and would appreciate some ideas.

Let's start from the basics, the version:

Cisco877#sho ver
Cisco IOS Software, C870 Software (C870-ADVIPSERVICESK9-M), Version 12.4(24)T8, RELEASE SOFTWARE (fc1)
Technical Support: http://www.cisco.com/techsupport
Copyright (c) 1986-2012 by Cisco Systems, Inc.
Compiled Sun 09-Sep-12 09:09 by prod_rel_team

I will not post the full config, as it's ridiculously long, but for short, ATM0 is my ADSL interface and it's bound to BVI1 which is supposed to get an IP via DHCP from the ISP.

 

ADSL modem runs firmware version AMR-4.0.015.bin which has been stable with my ISP.

 

Cisco877#sho run

...

!
interface ATM0
 description Saunalahti ADSL
 mac-address 0000.0cb5.b926
 no ip address
 no ip redirects
 no ip unreachables
 no ip proxy-arp
 no atm ilmi-keepalive
 pvc 0/100
  protocol ip 255.255.255.255 broadcast
  broadcast
  oam-pvc manage
  encapsulation aal5snap
  protocol ip inarp
 !
 dsl lom 200
 dsl noise-margin 3
 dsl bitswap both
 bridge-group 1
!

....
!
interface BVI1
 description Saunalahti ADSL, reitittimen ulkoverkon portti
 mac-address 0000.0cb5.b926
 ip dhcp client client-id ascii 0100.000c.b5b9.26
 ip dhcp client lease 2 0 0
 ip address dhcp
 ip access-group FW-BVI1-IN in
 ip access-group FW-BVI1-OUT out
 no ip unreachables
 no ip proxy-arp
 ip nat outside
 ip inspect BVI1 out
 ip virtual-reassembly
 ip tcp adjust-mss 1432
!

 

The following ATM and BVI lines are logged on boot, then nothing:

000041: *Jun 25 00:08:41.356 EET_DST: %LINK-3-UPDOWN: Interface BVI1, changed state to down
000042: *Jun 25 00:08:42.357 EET_DST: %LINEPROTO-5-UPDOWN: Line protocol on Interface BVI1, changed state to down
...
000047: *Jun 25 00:09:10.151 EET_DST: %LINK-3-UPDOWN: Interface BVI1, changed state to up
000048: *Jun 25 00:09:11.151 EET_DST: %LINEPROTO-5-UPDOWN: Line protocol on Interface BVI1, changed state to up
...
000051: *Jun 25 00:10:12.833 EET_DST: %LINK-3-UPDOWN: Interface ATM0, changed state to up
000052: *Jun 25 00:10:13.833 EET_DST: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up

 

"debug atm events" starts to log the following messages, and these goes on forever.

Cisco877#sho log | beg 000052
000052: *Jun 25 00:10:13.833 EET_DST: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up
000053: *Jun 25 00:19:22.806 EET_DST: DSL(ATM0): Sent extended command 0xC
000054: *Jun 25 00:19:23.319 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000055: *Jun 25 00:19:23.319 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000056: *Jun 25 00:19:23.319 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000057: *Jun 25 00:19:25.819 EET_DST: DSL(ATM0): Sent extended command 0xC
000058: *Jun 25 00:19:25.819 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000059: *Jun 25 00:19:25.819 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000060: *Jun 25 00:19:25.819 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000061: *Jun 25 00:19:28.320 EET_DST: DSL(ATM0): Sent extended command 0xC
000062: *Jun 25 00:19:28.364 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000063: *Jun 25 00:19:28.364 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000064: *Jun 25 00:19:28.364 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000065: *Jun 25 00:19:30.864 EET_DST: DSL(ATM0): Sent extended command 0xC
000066: *Jun 25 00:19:31.136 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000067: *Jun 25 00:19:31.136 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000068: *Jun 25 00:19:31.136 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000069: *Jun 25 00:19:33.637 EET_DST: DSL(ATM0): Sent extended command 0xC
000070: *Jun 25 00:19:33.681 EET_DST: DSL(ATM0): ext response 0xF received, data size 49


Show interface doesn't give me much of clues.


Cisco877#sho int atm 0
ATM0 is up, line protocol is down
  Hardware is MPC ATMSAR (with Alcatel ADSL Module)
  Description: Saunalahti ADSL
  MTU 4470 bytes, sub MTU 4470, BW 874 Kbit/sec, DLY 420 usec,
     reliability 255/255, txload 1/255, rxload 1/255
  Encapsulation ATM, loopback not set
  Encapsulation(s): AAL5  AAL2, PVC mode
  10 maximum active VCs, 1024 VCs per VP, 1 current VCCs
  VC Auto Creation Disabled.
  VC idle disconnect time: 300 seconds
  Last input never, output 00:00:03, output hang never
  Last clearing of "show interface" counters never
  Input queue: 0/75/0/0 (size/max/drops/flushes); Total output drops: 0
  Queueing strategy: Per VC Queueing
  5 minute input rate 0 bits/sec, 0 packets/sec
  5 minute output rate 0 bits/sec, 0 packets/sec
     0 packets input, 0 bytes, 0 no buffer
     Received 0 broadcasts, 0 runts, 0 giants, 0 throttles
     0 input errors, 0 CRC, 0 frame, 0 overrun, 0 ignored, 0 abort
     31 packets output, 1597 bytes, 0 underruns
     0 output errors, 0 collisions, 0 interface resets
     0 unknown protocol drops
     0 output buffer failures, 0 output buffers swapped out
Cisco877#

 

Cisco877#sho int bvi1
BVI1 is up, line protocol is up
  Hardware is BVI, address is 0000.0cb5.b926 (bia 0015.630f.1c4c)
  Description: Saunalahti ADSL, reitittimen ulkoverkon portti
  Internet address will be negotiated using DHCP
  MTU 4470 bytes, BW 4608 Kbit/sec, DLY 5000 usec,
     reliability 255/255, txload 1/255, rxload 1/255
  Encapsulation ARPA, loopback not set
  ARP type: ARPA, ARP Timeout 04:00:00
  Last input never, output never, output hang never
  Last clearing of "show interface" counters never
  Input queue: 0/75/0/0 (size/max/drops/flushes); Total output drops: 0
  Queueing strategy: fifo
  Output queue: 0/0 (size/max)
  5 minute input rate 0 bits/sec, 0 packets/sec
  5 minute output rate 0 bits/sec, 0 packets/sec
     0 packets input, 0 bytes, 0 no buffer
     Received 0 broadcasts, 0 runts, 0 giants, 0 throttles
     0 input errors, 0 CRC, 0 frame, 0 overrun, 0 ignored, 0 abort
     24 packets output, 14832 bytes, 0 underruns
     0 output errors, 0 collisions, 0 interface resets
     0 unknown protocol drops
     0 output buffer failures, 0 output buffers swapped out
Cisco877#

 


Cisco877#sho dsl interface atm 0
ATM0
Alcatel 20190 chipset information
                ATU-R (DS)                      ATU-C (US)
Modem Status:    Showtime (DMTDSL_SHOWTIME)
DSL Mode:        ITU G.992.5 (ADSL2+) Annex A
ITU STD NUM:     0x03                            0x2
Chip Vendor ID:  'STMI'                          'IFTN'
Chip Vendor Specific:  0x0000                    0x71C5
Chip Vendor Country:   0x0F                      0xB5
Modem Vendor ID: 'CSCO'                          '    '
Modem Vendor Specific: 0x0000                    0x0000
Modem Vendor Country:  0xB5                      0x00
Serial Number Near:    FHK0944227 877-K9   12.4
Serial Number Far:  Chip ID:     C196 (0)
DFE BOM:         DFE3.0 Annex A (1)
Capacity Used:   99%                             99%
Noise Margin:    13.0 dB                          9.0 dB
Output Power:    19.0 dBm                        10.5 dBm
Attenuation:     41.0 dB                         22.0 dB
FEC ES Errors:    2                               6
ES Errors:        2                               0
SES Errors:       1                               0
LOSES Errors:     1                               6
UES Errors:       0                              281
Defect Status:   None                            None
Last Fail Code:  None
Watchdog Counter: 0x87
Watchdog Resets: 0
Selftest Result: 0x00
Subfunction:     0x00
Interrupts:      8362 (0 spurious)
PHY Access Err:  0
Activations:     1
LED Status:      ON
LED On Time:     100
LED Off Time:    100
Init FW:         init_AMR-4.0.015.bin
Operation FW:    AMR-4.0.015.bin
FW Source:       external
FW Version:      4.0.15

                 DS Channel1      DS Channel0   US Channel1       US Channel0
Speed (kbps):             0             7191             0               874
Cells:                    0               39             0            641321
Reed-Solomon EC:          0                3             0                23
CRC Errors:               0                1             0                 0
Header Errors:            0                1             0                 0
Total BER:                0E-0           1082E-9
Leakage Average BER:      0E-0           1046E-9
Interleave Delay:         0               35             0                 0
                        ATU-R (DS)      ATU-C (US)
Bitswap:               enabled            enabled
Bitswap success:          0                   0
Bitswap failure:          0                   0

LOM Monitoring : Enabled
LOM watch configured for 200 times
LOM appeared continuously for 0 times


DMT Bits Per Bin
000: 0 0 0 0 0 0 3 5 7 9 A B B C C C
...

 

Any help at all would be very much appreciated!

 

 

Labels:
0 Helpful
2 Replies 2

Kim Alm
Level 1
Level 1

‎08-10-2015 12:56 PM

Ran debug atm events and errors.

This is what happens when I enter a no shut on atm 0.

000114: *Jun 25 03:49:35.547 EET_DST: ATM0: atmsar_1a_reset
000115: *Jun 25 03:49:35.547 EET_DST: ATM0: atmsar_get_plim_info
000116: *Jun 25 03:49:35.547 EET_DST: ATM0:atmsar_update_plimtype
000117: *Jun 25 03:49:35.547 EET_DST: ATM0 atmsar_1a_reset: PLIM type is 18, Rate is 874Mbps
000118: *Jun 25 03:49:35.547 EET_DST: ATM0 atmsar_1a_shutdown: state=4
000119: *Jun 25 03:49:35.547 EET_DST: ATM0: atmsar_shutdown, newstate = 0
000120: *Jun 25 03:49:35.551 EET_DST: DSL: SET: [DMTDSL_STOP -> DMTDSL_INIT]
000121: *Jun 25 03:49:35.551 EET_DST: Resetting ATM0
000122: *Jun 25 03:49:35.551 EET_DST:  atmsar_1a_config(ATM0)
000123: *Jun 25 03:49:35.551 EET_DST:  atmsar_1a_enable(ATM0)
000124: *Jun 25 03:49:35.551 EET_DST: ATM0: atmsar_init
000125: *Jun 25 03:49:35.551 EET_DST: ATM0 atmsar_update_us_bandwidth(): upstream bw =874 Kbps
000126: *Jun 25 03:49:36.043 EET_DST: (ATM0)1a_enable: delay activation of vcd=1, vc=0x8556D9CC
000127: *Jun 25 03:49:36.043 EET_DST: ATM0 atmsar_bringup_interface: line is not up, not bringingup the interface

000128: *Jun 25 03:49:36.047 EET_DST: DSL: SM: [DMTDSL_STOP -> DMTDSL_INIT]
000129: *Jun 25 03:49:36.123 EET_DST: DSL: SM: [DMTDSL_INIT -> DMTDSL_DLOAD_1]
000130: *Jun 25 03:49:36.123 EET_DST: DSL(ATM0): Downloading init_AMR-4.0.015.bin
000131: *Jun 25 03:49:36.127 EET_DST: DSL:(ATM0) Downloaded 2 blocks... Finished!
000132: *Jun 25 03:49:36.127 EET_DST: DSL(ATM0): Sent command 0x14
000133: *Jun 25 03:49:37.547 EET_DST: %LINK-3-UPDOWN: Interface ATM0, changed state to down
000134: *Jun 25 03:49:37.547 EET_DST:  atmsar_atm_lineaction(ATM0): state=0
000135: *Jun 25 03:49:38.127 EET_DST: DSL(ATM0): Received response: 0x80
000136: *Jun 25 03:49:38.127 EET_DST: DSL: SM: [DMTDSL_DLOAD_1 -> DMTDSL_DLOAD_2]
000137: *Jun 25 03:49:38.127 EET_DST: DSL(ATM0): Downloading AMR-4.0.015.bin
000138: *Jun 25 03:49:38.163 EET_DST: DSL(ATM0): Downloaded 100 blocks
000139: *Jun 25 03:49:38.195 EET_DST: DSL(ATM0): Downloaded 200 blocks
000140: *Jun 25 03:49:38.227 EET_DST: DSL(ATM0): Downloaded 300 blocks
000141: *Jun 25 03:49:38.259 EET_DST: DSL(ATM0): Downloaded 400 blocks
000142: *Jun 25 03:49:38.291 EET_DST: DSL(ATM0): Downloaded 500 blocks
000143: *Jun 25 03:49:38.323 EET_DST: DSL(ATM0): Downloaded 600 blocks
000144: *Jun 25 03:49:38.367 EET_DST: DSL(ATM0): Downloaded 700 blocks
000145: *Jun 25 03:49:38.399 EET_DST: DSL(ATM0): Downloaded 800 blocks
000146: *Jun 25 03:49:38.431 EET_DST: DSL(ATM0): Downloaded 900 blocks
000147: *Jun 25 03:49:38.463 EET_DST: DSL(ATM0): Downloaded 1000 blocks
000148: *Jun 25 03:49:38.495 EET_DST: DSL(ATM0): Downloaded 1100 blocks
000149: *Jun 25 03:49:38.527 EET_DST: DSL(ATM0): Downloaded 1200 blocks
000150: *Jun 25 03:49:38.563 EET_DST: DSL(ATM0): Downloaded 1300 blocks
000151: *Jun 25 03:49:38.595 EET_DST: DSL(ATM0): Downloaded 1400 blocks
000152: *Jun 25 03:49:38.627 EET_DST: DSL(ATM0): Downloaded 1500 blocks
000153: *Jun 25 03:49:38.667 EET_DST: DSL(ATM0): Downloaded 1600 blocks
000154: *Jun 25 03:49:38.699 EET_DST: DSL(ATM0): Downloaded 1700 blocks
000155: *Jun 25 03:49:38.727 EET_DST: DSL(ATM0): Downloaded 1800 blocks
000156: *Jun 25 03:49:38.763 EET_DST: DSL(ATM0): Downloaded 1900 blocks
000157: *Jun 25 03:49:38.795 EET_DST: DSL(ATM0): Downloaded 2000 blocks
000158: *Jun 25 03:49:38.827 EET_DST: DSL(ATM0): Downloaded 2100 blocks
000159: *Jun 25 03:49:38.863 EET_DST: DSL(ATM0): Downloaded 2200 blocks
000160: *Jun 25 03:49:38.895 EET_DST: DSL(ATM0): Downloaded 2300 blocks
000161: *Jun 25 03:49:38.927 EET_DST: DSL(ATM0): Downloaded 2400 blocks
000162: *Jun 25 03:49:38.967 EET_DST: DSL(ATM0): Downloaded 2500 blocks
000163: *Jun 25 03:49:39.003 EET_DST: DSL(ATM0): Downloaded 2600 blocks
000164: *Jun 25 03:49:39.035 EET_DST: DSL(ATM0): Downloaded 2700 blocks
000165: *Jun 25 03:49:39.067 EET_DST: DSL(ATM0): Downloaded 2800 blocks
000166: *Jun 25 03:49:39.099 EET_DST: DSL(ATM0): Downloaded 2900 blocks
000167: *Jun 25 03:49:39.135 EET_DST: DSL(ATM0): Downloaded 3000 blocks
000168: *Jun 25 03:49:39.167 EET_DST: DSL(ATM0): Downloaded 3100 blocks
000169: *Jun 25 03:49:39.203 EET_DST: DSL(ATM0): Downloaded 3200 blocks
000170: *Jun 25 03:49:39.235 EET_DST: DSL(ATM0): Downloaded 3300 blocks
000171: *Jun 25 03:49:39.272 EET_DST: DSL(ATM0): Downloaded 3400 blocks
000172: *Jun 25 03:49:39.304 EET_DST: DSL(ATM0): Downloaded 3500 blocks
000173: *Jun 25 03:49:39.340 EET_DST: DSL(ATM0): Downloaded 3600 blocks
000174: *Jun 25 03:49:39.372 EET_DST: DSL(ATM0): Downloaded 3700 blocks
000175: *Jun 25 03:49:39.404 EET_DST: DSL(ATM0): Downloaded 3800 blocks
000176: *Jun 25 03:49:39.436 EET_DST: DSL(ATM0): Downloaded 3900 blocks
000177: *Jun 25 03:49:39.468 EET_DST: DSL(ATM0): Downloaded 4000 blocks
000178: *Jun 25 03:49:39.504 EET_DST: DSL(ATM0): Downloaded 4100 blocks
000179: *Jun 25 03:49:39.508 EET_DST: DSL:(ATM0) Downloaded 4116 blocks... Finished!
000180: *Jun 25 03:49:39.508 EET_DST: DSL(ATM0): Sent command 0x14
000181: *Jun 25 03:49:41.508 EET_DST: set tx_gain_offset to 0
000182: *Jun 25 03:49:41.508 EET_DST: set rx_gain_offset to 0
000183: *Jun 25 03:49:41.508 EET_DST: set target_noise_margin_offset to 6
000184: *Jun 25 03:49:41.508 EET_DST: set max_bits_tone_limit to 15
000185: *Jun 25 03:49:41.508 EET_DST: changed current state to do open!!
000186: *Jun 25 03:49:41.508 EET_DST: DSL: SM: [DMTDSL_DLOAD_2 -> DMTDSL_DO_OPEN]
000187: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): Send ADSL_OPEN command.
000188: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): Using preferred open mode
000189: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): Using ITU sync first for 5 secs, then ANSI/ITU sync alternatively for 2 secs
000190: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): Using subfunction 0x0
000191: *Jun 25 03:49:41.508 EET_DST: LOCAL:Max noise margin for power cutoff 31
000192: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): GPCI[0] 0x5
000193: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): GPCI[1] 0x9
000194: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): GPCI[2] 0x1
000195: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): GPCI[3] 0x0
000196: *Jun 25 03:49:41.508 EET_DST: DSL(ATM0): Sent extended command 0x3
000197: *Jun 25 03:49:44.009 EET_DST: DSL(ATM0): 1: Modem state = 0x9
000198: *Jun 25 03:49:46.509 EET_DST: DSL(ATM0): 2: Modem state = 0x9
000199: *Jun 25 03:49:49.010 EET_DST: DSL(ATM0): 3: Modem state = 0x9
000200: *Jun 25 03:49:51.510 EET_DST: DSL(ATM0): 4: Modem state = 0x9
000201: *Jun 25 03:49:54.011 EET_DST: DSL(ATM0): 5: Modem state = 0x10
000202: *Jun 25 03:49:56.511 EET_DST: DSL(ATM0): 6: Modem state = 0x10
000203: *Jun 25 03:49:59.012 EET_DST: DSL(ATM0): 7: Modem state = 0x10
000204: *Jun 25 03:50:01.512 EET_DST: DSL(ATM0): 8: Modem state = 0x10
000205: *Jun 25 03:50:04.013 EET_DST: DSL(ATM0): 9: Modem state = 0x10
000206: *Jun 25 03:50:05.929 EET_DST: DSL(ATM0): Received response: 0x22
000207: *Jun 25 03:50:05.929 EET_DST: DSL(ATM0): Open failed: Protocol error received -- retrying
000208: *Jun 25 03:50:05.929 EET_DST: DSL(ATM0): sleep 5 seconds
000209: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): Send ADSL_OPEN command.
000210: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): Using preferred open mode
000211: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): Using ITU sync first for 5 secs, then ANSI/ITU sync alternatively for 2 secs
000212: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): Using subfunction 0x0
000213: *Jun 25 03:50:10.931 EET_DST: LOCAL:Max noise margin for power cutoff 31
000214: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): GPCI[0] 0x5
000215: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): GPCI[1] 0x9
000216: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): GPCI[2] 0x1
000217: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): GPCI[3] 0x0
000218: *Jun 25 03:50:10.931 EET_DST: DSL(ATM0): Sent extended command 0x3
000219: *Jun 25 03:50:13.431 EET_DST: DSL(ATM0): 1: Modem state = 0x9
000220: *Jun 25 03:50:15.932 EET_DST: DSL(ATM0): 2: Modem state = 0x9
000221: *Jun 25 03:50:18.432 EET_DST: DSL(ATM0): 3: Modem state = 0x9
000222: *Jun 25 03:50:20.933 EET_DST: DSL(ATM0): 4: Modem state = 0x9
000223: *Jun 25 03:50:23.433 EET_DST: DSL(ATM0): 5: Modem state = 0x10
000224: *Jun 25 03:50:25.934 EET_DST: DSL(ATM0): 6: Modem state = 0x10
000225: *Jun 25 03:50:28.434 EET_DST: DSL(ATM0): 7: Modem state = 0x10
000226: *Jun 25 03:50:30.935 EET_DST: DSL(ATM0): 8: Modem state = 0x10
000227: *Jun 25 03:50:33.435 EET_DST: DSL(ATM0): 9: Modem state = 0x10
000228: *Jun 25 03:50:35.936 EET_DST: DSL(ATM0): 10: Modem state = 0x10
000229: *Jun 25 03:50:36.084 EET_DST: DSL(ATM0): Received response: 0x24
000230: *Jun 25 03:50:36.084 EET_DST: DSL(ATM0): Showtime!
000231: *Jun 25 03:50:36.084 EET_DST: DSL(ATM0): Sent command 0x31
000232: *Jun 25 03:50:36.096 EET_DST: DSL(ATM0): Received response: 0x12
000233: *Jun 25 03:50:36.096 EET_DST: DSL(ATM0): operation mode 0x40000
000234: *Jun 25 03:50:36.096 EET_DST: DSL(ATM0): Sent extended command 0xC
000235: *Jun 25 03:50:36.144 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000236: *Jun 25 03:50:36.144 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000237: *Jun 25 03:50:36.144 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000238: *Jun 25 03:50:36.144 EET_DST: DSL(ATM0): Sent extended command 0xC
000239: *Jun 25 03:50:36.152 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000240: *Jun 25 03:50:36.152 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000241: *Jun 25 03:50:36.152 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000242: *Jun 25 03:50:36.152 EET_DST: DSL(ATM0): Sent command 0x33
000243: *Jun 25 03:50:36.156 EET_DST: DSL(ATM0): Received response: 0x16
000244: *Jun 25 03:50:36.156 EET_DST: DSL(ATM0): Far End Chip Country Code 0xB5
000245: *Jun 25 03:50:36.156 EET_DST: DSL: Far End Chip Vendor ID IFTN
000246: *Jun 25 03:50:36.156 EET_DST: DSL: Far End Chip Vendor ID Specific 0x71C5
000247: *Jun 25 03:50:36.156 EET_DST: DSL: Far End ITU Vendor STD Number 0x0002
000248: *Jun 25 03:50:36.156 EET_DST: DSL(ATM0): Sent command 0x32
000249: *Jun 25 03:50:36.160 EET_DST: DSL(ATM0): Received response: 0x14
000250: *Jun 25 03:50:36.160 EET_DST: DSL(ATM0): Near End Chip Country Code 0x0F
000251: *Jun 25 03:50:36.160 EET_DST: DSL: Near End Chip Vendor ID STMI
000252: *Jun 25 03:50:36.160 EET_DST: DSL: Near End Chip Vendor ID Specific 0x0000
000253: *Jun 25 03:50:36.160 EET_DST: DSL: Near End ITU Vendor STD Number 0x0003
000254: *Jun 25 03:50:36.164 EET_DST: DSL(ATM0): Sent extended command 0x5
000255: *Jun 25 03:50:36.168 EET_DST: DSL(ATM0): Near End Modem Country Code 0xB5
000256: *Jun 25 03:50:36.168 EET_DST: DSL: Near End Modem Vendor ID CSCO
000257: *Jun 25 03:50:36.168 EET_DST: DSL: Near End Modem Vendor ID Specific 0x0000
000258: *Jun 25 03:50:36.168 EET_DST: DSL: Near End Modem Version 12.4(24)T8
000259: *Jun 25 03:50:36.168 EET_DST: DSL: Near End Modem Serial Number FHK0944227 877-K9   12.4
000260: *Jun 25 03:50:36.168 EET_DST: DSL(ATM0): get Near End extended ITU ID succeeded
000261: *Jun 25 03:50:36.172 EET_DST: DSL(ATM0): Sent extended command 0x5
000262: *Jun 25 03:50:36.224 EET_DST: DSL(ATM0): Far End Modem Country Code 0x00
000263: *Jun 25 03:50:36.224 EET_DST: DSL: Far End Modem Vendor ID
000264: *Jun 25 03:50:36.224 EET_DST: DSL: Far End Modem Vendor ID Specific 0x0000
000265: *Jun 25 03:50:36.224 EET_DST: DSL: Far End Modem Version
000266: *Jun 25 03:50:36.224 EET_DST: DSL: Far End Modem Serial Number
000267: *Jun 25 03:50:36.224 EET_DST: DSL(ATM0): get Far End extended ITU ID succeeded
000268: *Jun 25 03:50:36.224 EET_DST: Matching SAR to Line speed: Attempt number 1
cps 1 slots 30
APL Level 0 slots 30
APL Level 1 slots 30
APL Level 2 slots 30

000269: *Jun 25 03:50:36.224 EET_DST: ATM0: atmsar_get_plim_info
000270: *Jun 25 03:50:36.224 EET_DST: ATM0:atmsar_update_plimtype
000271: *Jun 25 03:50:36.224 EET_DST: ATM0 atmsar_update_us_bandwidth(): upstream bw =902 Kbps
000272: *Jun 25 03:50:36.224 EET_DST: DSL: SM: [DMTDSL_DO_OPEN -> DMTDSL_SHOWTIME]
000273: *Jun 25 03:50:36.224 EET_DST: DSL(ATM0): Sent extended command 0xC
000274: *Jun 25 03:50:36.232 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000275: *Jun 25 03:50:36.232 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000276: *Jun 25 03:50:36.232 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000277: *Jun 25 03:50:38.733 EET_DST: DSL(ATM0): Sent extended command 0xC
000278: *Jun 25 03:50:38.821 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000279: *Jun 25 03:50:38.821 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000280: *Jun 25 03:50:38.821 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000281: *Jun 25 03:50:41.321 EET_DST: DSL(ATM0): Sent extended command 0xC
000282: *Jun 25 03:50:41.321 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000283: *Jun 25 03:50:41.321 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000284: *Jun 25 03:50:41.321 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000285: *Jun 25 03:50:43.822 EET_DST: DSL(ATM0): Sent extended command 0xC
000286: *Jun 25 03:50:44.422 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000287: *Jun 25 03:50:44.422 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000288: *Jun 25 03:50:44.422 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000289: *Jun 25 03:50:44.590 EET_DST: ATM0: atmsar_vc_dlcx
000290: *Jun 25 03:50:44.590 EET_DST: (ATM0)1a_enable: delay activation of vcd=1, vc=0x8556D9CC
000291: *Jun 25 03:50:44.590 EET_DST: atmsar enable ATM0

000292: *Jun 25 03:50:44.590 EET_DST: ATM0: atmsar_bringup_interface: Interface and atm_db flags are UP
000293: *Jun 25 03:50:46.590 EET_DST: %LINK-3-UPDOWN: Interface ATM0, changed state to up
000294: *Jun 25 03:50:46.590 EET_DST:  atmsar_atm_lineaction(ATM0): state=4
000295: *Jun 25 03:50:46.922 EET_DST: DSL(ATM0): Sent extended command 0xC
000296: *Jun 25 03:50:46.922 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000297: *Jun 25 03:50:46.922 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000298: *Jun 25 03:50:46.922 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000299: *Jun 25 03:50:47.591 EET_DST: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up
000300: *Jun 25 03:50:47.743 EET_DST:  Reserved bw for 0/100 Available bw = 902
000301: *Jun 25 03:50:47.743 EET_DST: ATM0: atmsar_1a_setup_vc, vcinfo = 0x8556D9CC
000302: *Jun 25 03:50:47.743 EET_DST: ATM0 atmsar_vc_setup: vcd 1
000303: *Jun 25 03:50:47.743 EET_DST:  Fill up paramaters for PVC 0/100[1] - Request for CoS 0 PCR 0 SCR 0 MCR 0 Available 902
000304: *Jun 25 03:50:47.743 EET_DST:  Scheduler parameters for 0/100. Type UBR. PCR 902
000305: *Jun 25 03:50:47.743 EET_DST:  Total scheduled bandwidth after configuringPVC 0/100 will be 0
000306: *Jun 25 03:50:47.743 EET_DST: atmsar_setup_cos(ATM0): vc:1 wred_name:- max_q:0
000307: *Jun 25 03:50:47.743 EET_DST: ATM0: VC setup successful (vcd = 1)
000308: *Jun 25 03:50:47.743 EET_DST: ATM: PVC activated, ATM0 VCD 1 (0/100)
000309: *Jun 25 03:50:47.743 EET_DST: ATM: ADJ added, ATM0, ip 255.255.255.255 conn id 0
000310: *Jun 25 03:50:47.747 EET_DST: ATM: Repapulate, ATM0
000311: *Jun 25 03:50:47.747 EET_DST: ATM: PVC activated, ATM0 VCD 1 (0/100)
000312: *Jun 25 03:50:47.747 EET_DST: ATM(ATM0): Encapsulation error1, link=7, host=FFFFFFFF
000313: *Jun 25 03:50:47.747 EET_DST: ATM: ADJ added, ATM0, ip 255.255.255.255 conn id 0
000314: *Jun 25 03:50:49.423 EET_DST: DSL(ATM0): Sent extended command 0xC
000315: *Jun 25 03:50:49.463 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000316: *Jun 25 03:50:49.463 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000317: *Jun 25 03:50:49.463 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000318: *Jun 25 03:50:51.964 EET_DST: DSL(ATM0): Sent extended command 0xC
000319: *Jun 25 03:50:51.964 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000320: *Jun 25 03:50:51.964 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000321: *Jun 25 03:50:51.964 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000322: *Jun 25 03:50:52.744 EET_DST: ATM_OAM(ATM0): Bad Correlation tag.  Received 0x19, Expected 0x1D from VPI:0 VCI:100
000323: *Jun 25 03:50:54.464 EET_DST: DSL(ATM0): Sent extended command 0xC
000324: *Jun 25 03:50:54.504 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000325: *Jun 25 03:50:54.504 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000326: *Jun 25 03:50:54.504 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000327: *Jun 25 03:50:54.724 EET_DST: ATM(): IP multicast cache invalidated for ATM0
000328: *Jun 25 03:50:54.724 EET_DST: ATM: PVC removed, ATM0 VCD 1 (0/100)
000329: *Jun 25 03:50:54.724 EET_DST: ATM: ADJ removed, ATM0, ip 255.255.255.255 conn id 0
000330: *Jun 25 03:50:54.724 EET_DST: ATM(ATM0): VCD#1 VC 0/100 failed to echo OAM. 6 tries
000331: *Jun 25 03:50:54.740 EET_DST: ATM_OAM(ATM0): Bad Correlation tag.  Received 0x1A, Expected 0x1E from VPI:0 VCI:100
000332: *Jun 25 03:50:57.005 EET_DST: DSL(ATM0): Sent extended command 0xC
000333: *Jun 25 03:50:57.209 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000334: *Jun 25 03:50:57.209 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000335: *Jun 25 03:50:57.213 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000336: *Jun 25 03:50:57.605 EET_DST: ATM_OAM(ATM0): Bad Correlation tag.  Received 0x1B, Expected 0x1E from VPI:0 VCI:100
000337: *Jun 25 03:50:59.713 EET_DST: DSL(ATM0): Sent extended command 0xC
000338: *Jun 25 03:50:59.757 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000339: *Jun 25 03:50:59.757 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000340: *Jun 25 03:50:59.757 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000341: *Jun 25 03:51:02.258 EET_DST: DSL(ATM0): Sent extended command 0xC
000342: *Jun 25 03:51:02.258 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000343: *Jun 25 03:51:02.258 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000344: *Jun 25 03:51:02.258 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000345: *Jun 25 03:51:04.758 EET_DST: DSL(ATM0): Sent extended command 0xC
000346: *Jun 25 03:51:05.347 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000347: *Jun 25 03:51:05.347 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000348: *Jun 25 03:51:05.347 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000349: *Jun 25 03:51:05.631 EET_DST: ATM(ATM0): VCD#1 VC 0/100 failed to echo OAM. 7 tries
000350: *Jun 25 03:51:05.647 EET_DST: ATM_OAM(ATM0): Bad Correlation tag.  Received 0x1C, Expected 0x1F from VPI:0 VCI:100
000351: *Jun 25 03:51:07.847 EET_DST: DSL(ATM0): Sent extended command 0xC
000352: *Jun 25 03:51:08.251 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000353: *Jun 25 03:51:08.251 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000354: *Jun 25 03:51:08.251 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000355: *Jun 25 03:51:10.752 EET_DST: DSL(ATM0): Sent extended command 0xC
000356: *Jun 25 03:51:10.792 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000357: *Jun 25 03:51:10.792 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000358: *Jun 25 03:51:10.792 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000359: *Jun 25 03:51:12.648 EET_DST: ATM_OAM(ATM0): Bad Correlation tag.  Received 0x1D, Expected 0x1F from VPI:0 VCI:100
000360: *Jun 25 03:51:13.292 EET_DST: DSL(ATM0): Sent extended command 0xC
000361: *Jun 25 03:51:13.292 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000362: *Jun 25 03:51:13.292 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000363: *Jun 25 03:51:13.292 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000364: *Jun 25 03:51:15.793 EET_DST: DSL(ATM0): Sent extended command 0xC
000365: *Jun 25 03:51:15.833 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000366: *Jun 25 03:51:15.833 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000367: *Jun 25 03:51:15.833 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000368: *Jun 25 03:51:16.561 EET_DST: ATM(ATM0): VCD#1 VC 0/100 failed to echo OAM. 8 tries
000369: *Jun 25 03:51:16.577 EET_DST: ATM_OAM(ATM0): Bad Correlation tag.  Received 0x1E, Expected 0x20 from VPI:0 VCI:100
000370: *Jun 25 03:51:18.333 EET_DST: DSL(ATM0): Sent extended command 0xC
000371: *Jun 25 03:51:18.694 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000372: *Jun 25 03:51:18.694 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000373: *Jun 25 03:51:18.694 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000374: *Jun 25 03:51:21.194 EET_DST: DSL(ATM0): Sent extended command 0xC
000375: *Jun 25 03:51:21.234 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000376: *Jun 25 03:51:21.234 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000377: *Jun 25 03:51:21.234 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000378: *Jun 25 03:51:23.735 EET_DST: DSL(ATM0): Sent extended command 0xC
000379: *Jun 25 03:51:23.735 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000380: *Jun 25 03:51:23.735 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000381: *Jun 25 03:51:23.735 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000382: *Jun 25 03:51:26.235 EET_DST: DSL(ATM0): Sent extended command 0xC
000383: *Jun 25 03:51:26.275 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000384: *Jun 25 03:51:26.275 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000385: *Jun 25 03:51:26.275 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000386: *Jun 25 03:51:27.495 EET_DST: ATM(ATM0): VCD#1 VC 0/100 failed to echo OAM. 9 tries
000387: *Jun 25 03:51:27.676 EET_DST: ATM_OAM(ATM0): Bad Correlation tag.  Received 0x1F, Expected 0x21 from VPI:0 VCI:100
000388: *Jun 25 03:51:28.776 EET_DST: DSL(ATM0): Sent extended command 0xC
000389: *Jun 25 03:51:28.776 EET_DST: DSL(ATM0): ext response 0xF received, data size 49
000390: *Jun 25 03:51:28.776 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000391: *Jun 25 03:51:28.776 EET_DST: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
000392: *Jun 25 03:51:30.116 EET_DST: ATM0 atmsar_1a_shutdown: state=6
000393: *Jun 25 03:51:30.116 EET_DST: ATM0: atmsar_shutdown, newstate = 6
000394: *Jun 25 03:51:30.116 EET_DST: DSL: SET: [DMTDSL_SHOWTIME -> DMTDSL_STOP]
000395: *Jun 25 03:51:30.116 EET_DST: Resetting ATM0
000396: *Jun 25 03:51:30.116 EET_DST:  atmsar_1a_teardown_vc(ATM0): vc:1 vpi:0 vci:100
000397: *Jun 25 03:51:30.116 EET_DST: ATM(): IP multicast cache invalidated for ATM0
000398: *Jun 25 03:51:30.116 EET_DST: ATM: PVC removed, ATM0 VCD 1 (0/100)
000399: *Jun 25 03:51:30.116 EET_DST: ATM: ADJ removed, ATM0, ip 255.255.255.255 conn id 0
000400: *Jun 25 03:51:31.276 EET_DST:  atmsar_atm_lineaction(ATM0): state=6
000401: *Jun 25 03:51:31.276 EET_DST: DSL: SM: [DMTDSL_SHOWTIME -> DMTDSL_STOP]
000402: *Jun 25 03:51:31.776 EET_DST: DSL(ATM0): Sent command 0x4


And this is after shutdown of interface atm 0.
000403: *Jun 25 03:51:32.116 EET_DST: %LINK-5-CHANGED: Interface ATM0, changed state to administratively down
000404: *Jun 25 03:51:32.116 EET_DST:  atmsar_atm_lineaction(ATM0): state=6
000405: *Jun 25 03:51:32.301 EET_DST: DSL(ATM0): Received response: 0x25
000406: *Jun 25 03:51:32.301 EET_DST: DSL(ATM0): Connection closed
000407: *Jun 25 03:51:33.117 EET_DST: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to down
Cisco877#

0 Helpful

Kim Alm
Level 1
Level 1
In response to Kim Alm

‎08-12-2015 12:11 AM

This is now resolved!

I had "oam-pvc manage" active on my atm interface, now it looks like my ISP is no longer allowing atm pings, therefore the failed echos kept the line down.

000330: *Jun 25 03:50:54.724 EET_DST: ATM(ATM0): VCD#1 VC 0/100 failed to echo OAM. 6 tries

I have reason to use "oam-pvc manage" on this line, but have to do without it fore the time being.

ISP also measured my line and admitted that the line is crap so that will be the next fight to get that fixed, but now I'm at least online again!

0 Helpful
Customers Also Viewed These Support Documents
Review Cisco Networking for a $25 gift card