Cisco 877 ATM errors on ADSL2+

paulhughes5 · ‎06-27-2011

Hello

I am trying to connect up a 877 running IOS 12-4-24T5 and DSL firmware 3.0.33 to an ADSL2+ line.

Initially there was a provisioning error and an ADSL1 line was set up which worked fine and synced up at 8Mb for around a week. Now the line has been migrated to 2+ I only manage to keep sync for about 3 seconds.

Doing a debug atm I can see Defect: LCDf: retraining but I'm struggling to find much documentation to describe this error.

Does anyone have any suggestions as to what may be the cause or better still a solution?

Thanks

Paul

MaseBarnes · ‎06-27-2011

Please try 4.0.17:

http://www.cisco.com/cisco/software/release.html?mdfid=279624018&catid=268437899&softwareid=282821763&release=4.0.17&relind=AVAILABLE&rellifecycle=&reltype=latest

paulhughes5 · ‎06-27-2011

The notes mention that version is for annex M only, I'm using annex A. Will this still work using this flavor of ADSL2+?

MaseBarnes · ‎06-27-2011

Oh, then try 3.0.43 ...

paulhughes5 · ‎06-27-2011

I have tried 3.0.43 and there is no difference.

MaseBarnes · ‎06-27-2011

Could you post a "sh dsl int atm 0" and "deb atm er", "deb atm ev",

"deb pppoe er" and "deb pppoe ev" please?

paulhughes5 · ‎06-27-2011

I'll grab those later on as I don't have access to it currently.

Its running PPPoA if that makes any difference to the results your after. From the debug atm that I ran last time I had access the Defect: LCDf: retraining was the message seen when the connection dropped.

paulhughes5 · ‎06-27-2011

Hopfully the below answers you questions around debug info.

I have tested the line with a normal ADSL home router and it is working so there seems to be some conflict between the Cisco and the ADSL2+ set up.

Any Ideas?

c
*** Network Gateway ***

DSL-Gateway#debug atm ev
DSL-Gateway#debug atm events
ATM events debugging is on
DSL-Gateway#de
DSL-Gateway#deb
DSL-Gateway#debug atm err
DSL-Gateway#debug atm errors
ATM errors debugging is on
DSL-Gateway#deb
DSL-Gateway#debug ppp?
ppp pppatm pppoe

DSL-Gateway#debug pppa
DSL-Gateway#debug pppatm ?
elog PPPoA elog trace
errors PPPoA errors
events PPPoA events
states PPPoA states
trace PPPoA trace

DSL-Gateway#debug pppatm er
DSL-Gateway#debug pppatm errors
PPP over ATM errors debugging is on
DSL-Gateway#debug pppatm errors
DSL-Gateway#debug pppatm events
PPP over ATM events debugging is on
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#sh ip int brie
Interface                  IP-Address      OK? Method Status                Protocol
ATM0                       unassigned      YES NVRAM down                  down
Dialer0                    unassigned      YES NVRAM up                    up
Dialer1                    unassigned      YES NVRAM up                    up
FastEthernet0              unassigned      YES unset up                    down
FastEthernet1              unassigned      YES unset up                    down
FastEthernet2              unassigned      YES unset up                    down
FastEthernet3              unassigned      YES unset up                    up
NVI0                       unassigned      YES unset administratively down down
Virtual-Access1            unassigned      YES unset up                    up
Virtual-Access2            unassigned      YES unset down                  down
Vlan1                      10.0.21.1       YES NVRAM up                    up
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#term mon
DSL-Gateway#
Jun 27 17:00:29.602: DSL: SM: [DMTDSL_DO_OPEN -> DMTDSL_SHOWTIME]
Jun 27 17:00:29.602: DSL(ATM0): Sent extended command 0xC
Jun 27 17:00:29.606: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:00:29.606: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:00:29.606: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49cle
Jun 27 17:00:32.107: DSL(ATM0): Sent extended command 0xC
Jun 27 17:00:32.243: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:00:32.243: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:00:32.243: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:00:34.743: DSL(ATM0): Sent extended command 0xC
Jun 27 17:00:34.743: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:00:34.743: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:00:34.743: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:00:36.704: ATM0: atmsar_vc_dlcx
Jun 27 17:00:36.704: (ATM0)1a_enable: delay activation of vcd=1, vc=0x846F1CFC
Jun 27 17:00:36.704: atmsar enable ATM0

Jun 27 17:00:36.704: ATM0: atmsar_bringup_interface: Interface and atm_db flags are UP
Jun 27 17:00:37.244: DSL(ATM0): Sent extended command 0xC
Jun 27 17:00:38.704: %LINK-3-UPDOWN: Interface ATM0, changed state to up
Jun 27 17:00:38.704: atmsar_atm_lineaction(ATM0): state=4
Jun 27 17:00:38.704: ATM: Repapulate, ATM0
Jun 27 17:00:38.704: ATM: PVC activated, ATM0 VCD 1 (0/38)
Jun 27 17:00:39.704: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up
Jun 27 17:00:39.744: DSL(ATM0): alcdsl_sm_wait_for_event failed
Jun 27 17:00:39.744: DSL(ATM0): Get FAR End parameter failed
Jun 27 17:00:42.245: DSL(ATM0): Sent extended command 0xC
Jun 27 17:00:42.709: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:00:42.709: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:00:42.709: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:00:44.666: Reserved bw for 0/38 Available bw = 732
Jun 27 17:00:44.666: ATM0: atmsar_1a_setup_vc, vcinfo = 0x846F1CFC
Jun 27 17:00:44.666: ATM0 atmsar_vc_setup: vcd 1
Jun 27 17:00:44.666: Fill up paramaters for PVC 0/38[1] - Request for CoS 0 PCR 0 SCR 0 MCR 0 Available 732
Jun 27 17:00:44.666: Scheduler parameters for 0/38. Type UBR. PCR 732
Jun 27 17:00:44.666: Total scheduled bandwidth after configuringPVC 0/38 will be 0
Jun 27 17:00:44.666: atmsar_setup_cos(ATM0): vc:1 wred_name:- max_q:0
Jun 27 17:00:44.666: ATM0: VC setup successful (vcd = 1)
Jun 27 17:00:44.666: PPPATM: ATM0 0/38 [0], Event = VC Updated
Jun 27 17:00:44.666: ATM: PVC activated, ATM0 VCD 1 (0/38)
Jun 27 17:00:44.666: PPPATM: ATM0 0/38 [0], Event = Up Pending
Jun 27 17:00:45.210: DSL(ATM0): Defect: LCDf: retraining
Jun 27 17:00:45.582: PPPATM: ATM0 0/38 [0], Event = Up Dequeued
Jun 27 17:00:45.582: PPPATM: ATM0 0/38 [0], Event = Processing Up
Jun 27 17:00:45.582: PPPATM: ATM0 0/38 [0], Event = Vaccess Up
Jun 27 17:00:45.586: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up
Jun 27 17:00:45.586: %DIALER-6-BIND: Interface Vi2 bound to profile Di1
Jun 27 17:00:47.874: atmsar_atm_lineaction(ATM0): state=0
Jun 27 17:00:47.874: atmsar_1a_teardown_vc(ATM0): vc:1 vpi:0 vci:38
Jun 27 17:00:47.874: ATM(): IP multicast cache invalidated for ATM0
Jun 27 17:00:47.874: ATM: PVC removed, ATM0 VCD 1 (0/38)
Jun 27 17:00:47.874: PPPATM: ATM0 0/38 [0], Event = Down Pending
Jun 27 17:00:47.874: DSL: SM: [DMTDSL_SHOWTIME -> DMTDSL_RE_OPEN]
Jun 27 17:00:47.874: DSL(ATM0): Send ADSL_CLOSE command.
Jun 27 17:00:47.874: DSL(ATM0): Sent command 0x4
Jun 27 17:00:48.858: PPPATM: ATM0 0/38 [0], Event = Down Processed
Jun 27 17:00:48.858: PPPATM: ATM0 0/38 [0], Event = Disconnecting
Jun 27 17:00:48.858: Service policy input policy output applied on 0/38
Jun 27 17:00:48.858: DBS is not configured on ATM0 vc 0/38

Jun 27 17:00:48.858: PPPATM: ATM0 0/38 [0], Event = Vaccess Down
Jun 27 17:00:48.862: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down
Jun 27 17:00:48.862: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di1
Jun 27 17:00:49.875: %LINK-3-UPDOWN: Interface ATM0, changed state to down
Jun 27 17:00:49.875: atmsar_atm_lineaction(ATM0): state=0
Jun 27 17:00:50.375: DSL(ATM0): No response to ADSL_CLOSE
Jun 27 17:00:50.375: DSL: SM: [DMTDSL_RE_OPEN -> DMTDSL_INIT]
Jun 27 17:00:50.447: DSL: SM: [DMTDSL_INIT -> DMTDSL_DLOAD_1]
Jun 27 17:00:50.447: DSL(ATM0): Downloading init_AMR-3.0.043.bin
Jun 27 17:00:50.451: DSL:(ATM0) Downloaded 2 blocks... Finished!
Jun 27 17:00:50.451: DSL(ATM0): Sent command 0x14
Jun 27 17:00:50.875: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to down
Jun 27 17:00:52.451: DSL(ATM0): Received response: 0x80
Jun 27 17:00:52.451: DSL: SM: [DMTDSL_DLOAD_1 -> DMTDSL_DLOAD_2]
Jun 27 17:00:52.451: DSL(ATM0): Downloading AMR-3.0.043.bin
Jun 27 17:00:52.483: DSL(ATM0): Downloaded 100 blocks
Jun 27 17:00:52.515: DSL(ATM0): Downloaded 200 blocks
Jun 27 17:00:52.547: DSL(ATM0): Downloaded 300 blocks
Jun 27 17:00:52.579: DSL(ATM0): Downloaded 400 blocks
Jun 27 17:00:52.611: DSL(ATM0): Downloaded 500 blocks
Jun 27 17:00:52.647: DSL(ATM0): Downloaded 600 blocks
Jun 27 17:00:52.679: DSL(ATM0): Downloaded 700 blocks
Jun 27 17:00:52.711: DSL(ATM0): Downloaded 800 blocks
Jun 27 17:00:52.743: DSL(ATM0): Downloaded 900 blocks
Jun 27 17:00:52.775: DSL(ATM0): Downloaded 1000 blocks
Jun 27 17:00:52.807: DSL(ATM0): Downloaded 1100 blocks
Jun 27 17:00:52.843: DSL(ATM0): Downloaded 1200 blocks
Jun 27 17:00:52.875: DSL(ATM0): Downloaded 1300 blocks
Jun 27 17:00:52.907: DSL(ATM0): Downloaded 1400 blocks
Jun 27 17:00:52.939: DSL(ATM0): Downloaded 1500 blocks
Jun 27 17:00:52.971: DSL(ATM0): Downloaded 1600 blocks
Jun 27 17:00:53.003: DSL(ATM0): Downloaded 1700 blocks
Jun 27 17:00:53.039: DSL(ATM0): Downloaded 1800 blocks
Jun 27 17:00:53.071: DSL(ATM0): Downloaded 1900 blocks
Jun 27 17:00:53.103: DSL(ATM0): Downloaded 2000 blocks
Jun 27 17:00:53.135: DSL(ATM0): Downloaded 2100 blocks
Jun 27 17:00:53.167: DSL(ATM0): Downloaded 2200 blocks
Jun 27 17:00:53.199: DSL(ATM0): Downloaded 2300 blocks
Jun 27 17:00:53.235: DSL(ATM0): Downloaded 2400 blocks
Jun 27 17:00:53.267: DSL(ATM0): Downloaded 2500 blocks
Jun 27 17:00:53.299: DSL(ATM0): Downloaded 2600 blocks
Jun 27 17:00:53.331: DSL(ATM0): Downloaded 2700 blocks
Jun 27 17:00:53.364: DSL(ATM0): Downloaded 2800 blocks
Jun 27 17:00:53.396: DSL(ATM0): Downloaded 2900 blocks
Jun 27 17:00:53.432: DSL(ATM0): Downloaded 3000 blocks
Jun 27 17:00:53.464: DSL(ATM0): Downloaded 3100 blocks
Jun 27 17:00:53.496: DSL(ATM0): Downloaded 3200 blocks
Jun 27 17:00:53.528: DSL(ATM0): Downloaded 3300 blocks
Jun 27 17:00:53.560: DSL(ATM0): Downloaded 3400 blocks
Jun 27 17:00:53.592: DSL(ATM0): Downloaded 3500 blocks
Jun 27 17:00:53.624: DSL(ATM0): Downloaded 3600 blocks
Jun 27 17:00:53.660: DSL(ATM0): Downloaded 3700 blocks
Jun 27 17:00:53.692: DSL(ATM0): Downloaded 3800 blocks
Jun 27 17:00:53.740: DSL(ATM0): Downloaded 3900 blocks
Jun 27 17:00:53.772: DSL(ATM0): Downloaded 4000 blocks
Jun 27 17:00:53.800: DSL:(ATM0) Downloaded 4093 blocks... Finished!
Jun 27 17:00:53.800: DSL(ATM0): Sent command 0x14
Jun 27 17:00:55.800: set tx_gain_offset to 0
Jun 27 17:00:55.800: set rx_gain_offset to 0
Jun 27 17:00:55.800: set target_noise_margin_offset to 0
Jun 27 17:00:55.800: set max_bits_tone_limit to 15
Jun 27 17:00:55.800: changed current state to do open!!
Jun 27 17:00:55.800: DSL: SM: [DMTDSL_DLOAD_2 -> DMTDSL_DO_OPEN]
Jun 27 17:00:55.800: DSL(ATM0): Send ADSL_OPEN command.
Jun 27 17:00:55.800: DSL(ATM0): Using preferred open mode
Jun 27 17:00:55.800: DSL(ATM0): Using ITU sync first for 5 secs, then ANSI/ITU sync alternatively for 2 secs
Jun 27 17:00:55.800: DSL(ATM0): Using subfunction 0x0
Jun 27 17:00:55.800: LOCAL:Max noise margin for power cutoff 31
Jun 27 17:00:55.800: DSL(ATM0): GPCI[0] 0x5
Jun 27 17:00:55.800: DSL(ATM0): GPCI[1] 0x9
Jun 27 17:00:55.800: DSL(ATM0): GPCI[2] 0x1
Jun 27 17:00:55.800: DSL(ATM0): GPCI[3] 0x0
Jun 27 17:00:55.800: DSL(ATM0): Sent extended command 0x3
Jun 27 17:00:56.708: ATM0: atmsar_vc_dlcx
Jun 27 17:00:58.301: DSL(ATM0): 1: Modem state = 0x9
Jun 27 17:01:00.801: DSL(ATM0): 2: Modem state = 0x9
Jun 27 17:01:03.302: DSL(ATM0): 3: Modem state = 0x10
Jun 27 17:01:05.802: DSL(ATM0): 4: Modem state = 0x10
Jun 27 17:01:08.303: DSL(ATM0): 5: Modem state = 0x10
Jun 27 17:01:10.803: DSL(ATM0): 6: Modem state = 0x10
Jun 27 17:01:13.304: DSL(ATM0): 7: Modem state = 0x10
Jun 27 17:01:15.805: DSL(ATM0): 8: Modem state = 0x10
Jun 27 17:01:18.305: DSL(ATM0): 9: Modem state = 0x10
Jun 27 17:01:18.365: DSL(ATM0): Received response: 0x24
Jun 27 17:01:18.365: DSL(ATM0): Showtime!
Jun 27 17:01:18.365: DSL(ATM0): Sent command 0x31
Jun 27 17:01:18.377: DSL(ATM0): Received response: 0x12
Jun 27 17:01:18.377: DSL(ATM0): operation mode 0x40000
Jun 27 17:01:18.377: DSL(ATM0): Sent extended command 0xC
Jun 27 17:01:18.529: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:01:18.529: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:18.529: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:18.529: DSL(ATM0): Sent extended command 0xC
Jun 27 17:01:18.533: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:01:18.533: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:18.533: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:18.533: DSL(ATM0): Sent command 0x33
Jun 27 17:01:18.537: DSL(ATM0): Received response: 0x16
Jun 27 17:01:18.537: DSL(ATM0): Far End Chip Country Code 0xB5
Jun 27 17:01:18.537: DSL: Far End Chip Vendor ID TSTC
Jun 27 17:01:18.537: DSL: Far End Chip Vendor ID Specific 0x0510
Jun 27 17:01:18.537: DSL: Far End ITU Vendor STD Number 0x0003
Jun 27 17:01:18.537: DSL(ATM0): Sent command 0x32
Jun 27 17:01:18.545: DSL(ATM0): Received response: 0x14
Jun 27 17:01:18.545: DSL(ATM0): Near End Chip Country Code 0x0F
Jun 27 17:01:18.545: DSL: Near End Chip Vendor ID STMI
Jun 27 17:01:18.545: DSL: Near End Chip Vendor ID Specific 0x0000
Jun 27 17:01:18.545: DSL: Near End ITU Vendor STD Number 0x0003
Jun 27 17:01:18.545: DSL(ATM0): Sent extended command 0x5
Jun 27 17:01:18.553: DSL(ATM0): Near End Modem Country Code 0xB5
Jun 27 17:01:18.553: DSL: Near End Modem Vendor ID CSCO
Jun 27 17:01:18.553: DSL: Near End Modem Vendor ID Specific 0x0000
Jun 27 17:01:18.553: DSL: Near End Modem Version 12.4(24)T5
Jun 27 17:01:18.553: DSL: Near End Modem Serial Number FCZ112550D 877-K9 12.4
Jun 27 17:01:18.553: DSL(ATM0): get Near End extended ITU ID succeeded
Jun 27 17:01:18.553: DSL(ATM0): Sent extended command 0x5
Jun 27 17:01:18.733: DSL(ATM0): Far End Modem Country Code 0xB5
Jun 27 17:01:18.733: DSL: Far End Modem Vendor ID TSTC
Jun 27 17:01:18.733: DSL: Far End Modem Vendor ID Specific 0x5100
Jun 27 17:01:18.733: DSL: Far End Modem Version
Jun 27 17:01:18.733: DSL: Far End Modem Serial Number 00000000000000000000000000000000
Jun 27 17:01:18.733: DSL(ATM0): get Far End extended ITU ID succeeded
Jun 27 17:01:18.733: ATM0 atmsar_update_us_bandwidth(): upstream bw =732 Kbps
Jun 27 17:01:18.733: DSL: SM: [DMTDSL_DO_OPEN -> DMTDSL_SHOWTIME]
Jun 27 17:01:18.733: DSL(ATM0): Sent extended command 0xC
Jun 27 17:01:19.349: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:01:19.349: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:19.349: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:21.850: DSL(ATM0): Sent extended command 0xC
Jun 27 17:01:21.850: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:01:21.850: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:21.850: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:24.350: DSL(ATM0): Sent extended command 0xC
Jun 27 17:01:26.715: ATM0: atmsar_vc_dlcx
Jun 27 17:01:26.715: (ATM0)1a_enable: delay activation of vcd=1, vc=0x846F1CFC
Jun 27 17:01:26.715: atmsar enable ATM0

Jun 27 17:01:26.715: ATM0: atmsar_bringup_interface: Interface and atm_db flags are UP
Jun 27 17:01:26.851: DSL(ATM0): alcdsl_sm_wait_for_event failed
Jun 27 17:01:26.851: DSL(ATM0): Get FAR End parameter failed
Jun 27 17:01:28.715: %LINK-3-UPDOWN: Interface ATM0, changed state to up
Jun 27 17:01:28.715: atmsar_atm_lineaction(ATM0): state=4
Jun 27 17:01:28.715: ATM: Repapulate, ATM0
Jun 27 17:01:28.715: ATM: PVC activated, ATM0 VCD 1 (0/38)
Jun 27 17:01:29.352: DSL(ATM0): Sent extended command 0xC
Jun 27 17:01:29.352: DSL(ATM0): ext response 0xF received, data size 49
Jun 27 17:01:29.352: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:29.352: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49
Jun 27 17:01:29.716: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up
Jun 27 17:01:31.852: DSL(ATM0): Defect: LOM
Jun 27 17:01:31.852: DSL(ATM0): Defect: LCDf: retraining
Jun 27 17:01:34.461: Reserved bw for 0/38 Available bw = 732
Jun 27 17:01:34.461: ATM0: atmsar_1a_setup_vc, vcinfo = 0x846F1CFC
Jun 27 17:01:34.461: ATM0 atmsar_vc_setup: vcd 1
Jun 27 17:01:34.461: Fill up paramaters for PVC 0/38[1] - Request for CoS 0 PCR 0 SCR 0 MCR 0 Available 732
Jun 27 17:01:34.461: Scheduler parameters for 0/38. Type UBR. PCR 732
Jun 27 17:01:34.461: Total scheduled bandwidth after configuringPVC 0/38 will be 0
Jun 27 17:01:34.461: atmsar_setup_cos(ATM0): vc:1 wred_name:- max_q:0
Jun 27 17:01:34.461: ATM0: VC setup successful (vcd = 1)
Jun 27 17:01:34.461: PPPATM: ATM0 0/38 [0], Event = VC Updated
Jun 27 17:01:34.461: ATM: PVC activated, ATM0 VCD 1 (0/38)
Jun 27 17:01:34.461: PPPATM: ATM0 0/38 [0], Event = Up Pending
Jun 27 17:01:35.065: atmsar_atm_lineaction(ATM0): state=0
Jun 27 17:01:35.065: atmsar_1a_teardown_vc(ATM0): vc:1 vpi:0 vci:38
Jun 27 17:01:35.065: ATM(): IP multicast cache invalidated for ATM0
Jun 27 17:01:35.065: ATM: PVC removed, ATM0 VCD 1 (0/38)
Jun 27 17:01:35.065: PPPATM: ATM0 0/38 [0], Event = Down before Up is processed
Jun 27 17:01:35.065: DSL: SM: [DMTDSL_SHOWTIME -> DMTDSL_RE_OPEN]
Jun 27 17:01:35.065: DSL(ATM0): Send ADSL_CLOSE command.
Jun 27 17:01:35.065: DSL(ATM0): Sent command 0x4
Jun 27 17:01:36.717: ATM0: atmsar_vc_dlcx
Jun 27 17:01:37.065: %LINK-3-UPDOWN: Interface ATM0, changed state to down
Jun 27 17:01:37.065: atmsar_atm_lineaction(ATM0): state=0
Jun 27 17:01:37.565: DSL(ATM0): No response to ADSL_CLOSE
Jun 27 17:01:37.565: DSL: SM: [DMTDSL_RE_OPEN -> DMTDSL_INIT]
Jun 27 17:01:37.637: DSL: SM: [DMTDSL_INIT -> DMTDSL_DLOAD_1]
Jun 27 17:01:37.637: DSL(ATM0): Downloading init_AMR-3.0.043.bin
Jun 27 17:01:37.645: DSL:(ATM0) Downloaded 2 blocks... Finished!
Jun 27 17:01:37.645: DSL(ATM0): Sent command 0x14
Jun 27 17:01:38.066: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to down
Jun 27 17:01:39.646: DSL(ATM0): Received response: 0x80
Jun 27 17:01:39.646: DSL: SM: [DMTDSL_DLOAD_1 -> DMTDSL_DLOAD_2]
Jun 27 17:01:39.646: DSL(ATM0): Downloading AMR-3.0.043.bin
Jun 27 17:01:39.678: DSL(ATM0): Downloaded 100 blocks
Jun 27 17:01:39.710: DSL(ATM0): Downloaded 200 blocks
Jun 27 17:01:39.742: DSL(ATM0): Downloaded 300 blocks
Jun 27 17:01:39.774: DSL(ATM0): Downloaded 400 blocks
Jun 27 17:01:39.806: DSL(ATM0): Downloaded 500 blocks
Jun 27 17:01:39.842: DSL(ATM0): Downloaded 600 blocks
Jun 27 17:01:39.874: DSL(ATM0): Downloaded 700 blocks
Jun 27 17:01:39.906: DSL(ATM0): Downloaded 800 blocks
Jun 27 17:01:39.938: DSL(ATM0): Downloaded 900 blocks
Jun 27 17:01:39.970: DSL(ATM0): Downloaded 1000 blocks
Jun 27 17:01:40.002: DSL(ATM0): Downloaded 1100 blocks
Jun 27 17:01:40.038: DSL(ATM0): Downloaded 1200 blocks
Jun 27 17:01:40.070: DSL(ATM0): Downloaded 1300 blocks
Jun 27 17:01:40.102: DSL(ATM0): Downloaded 1400 blocks
Jun 27 17:01:40.134: DSL(ATM0): Downloaded 1500 blocks
Jun 27 17:01:40.166: DSL(ATM0): Downloaded 1600 blocks
Jun 27 17:01:40.198: DSL(ATM0): Downloaded 1700 blocks
Jun 27 17:01:40.234: DSL(ATM0): Downloaded 1800 blocks
Jun 27 17:01:40.266: DSL(ATM0): Downloaded 1900 blocks
Jun 27 17:01:40.298: DSL(ATM0): Downloaded 2000 blocks
Jun 27 17:01:40.330: DSL(ATM0): Downloaded 2100 blocks
Jun 27 17:01:40.362: DSL(ATM0): Downloaded 2200 blocks
Jun 27 17:01:40.394: DSL(ATM0): Downloaded 2300 blocks
Jun 27 17:01:40.430: DSL(ATM0): Downloaded 2400 blocks
Jun 27 17:01:40.462: DSL(ATM0): Downloaded 2500 blocks
Jun 27 17:01:40.494: DSL(ATM0): Downloaded 2600 blocks
Jun 27 17:01:40.526: DSL(ATM0): Downloaded 2700 blocks
Jun 27 17:01:40.558: DSL(ATM0): Downloaded 2800 blocks
Jun 27 17:01:40.590: DSL(ATM0): Downloaded 2900 blocks
Jun 27 17:01:40.622: DSL(ATM0): Downloaded 3000 blocks
Jun 27 17:01:40.658: DSL(ATM0): Downloaded 3100 blocks
Jun 27 17:01:40.690: DSL(ATM0): Downloaded 3200 blocks
Jun 27 17:01:40.722: DSL(ATM0): Downloaded 3300 blocks
Jun 27 17:01:40.754: DSL(ATM0): Downloaded 3400 blocks
Jun 27 17:01:40.798: DSL(ATM0): Downloaded 3500 blocks
Jun 27 17:01:40.834: DSL(ATM0): Downloaded 3600 blocks
Jun 27 17:01:40.866: DSL(ATM0): Downloaded 3700 blocks
Jun 27 17:01:40.898: DSL(ATM0): Downloaded 3800 blocks
Jun 27 17:01:40.930: DSL(ATM0): Downloaded 3900 blocks
Jun 27 17:01:40.962: DSL(ATM0): Downloaded 4000 blocks
Jun 27 17:01:40.994: DSL:(ATM0) Downloaded 4093 blocks... Finished!
Jun 27 17:01:40.994: DSL(ATM0): Sent command 0x14
Jun 27 17:01:42.995: set tx_gain_offset to 0
Jun 27 17:01:42.995: set rx_gain_offset to 0
Jun 27 17:01:42.995: set target_noise_margin_offset to 0
Jun 27 17:01:42.995: set max_bits_tone_limit to 15
Jun 27 17:01:42.995: changed current state to do open!!
Jun 27 17:01:42.995: DSL: SM: [DMTDSL_DLOAD_2 -> DMTDSL_DO_OPEN]
Jun 27 17:01:42.995: DSL(ATM0): Send ADSL_OPEN command.
Jun 27 17:01:42.995: DSL(ATM0): Using preferred open mode
Jun 27 17:01:42.995: DSL(ATM0): Using ITU sync first for 5 secs, then ANSI/ITU sync alternatively for 2 secs
Jun 27 17:01:42.995: DSL(ATM0): Using subfunction 0x0
Jun 27 17:01:42.995: LOCAL:Max noise margin for power cutoff 31u al
Jun 27 17:01:42.995: DSL(ATM0): GPCI[0] 0x5
Jun 27 17:01:42.995: DSL(ATM0): GPCI[1] 0x9
Jun 27 17:01:42.995: DSL(ATM0): GPCI[2] 0x1
Jun 27 17:01:42.995: DSL(ATM0): GPCI[3] 0x0
Jun 27 17:01:42.995: DSL(ATM0): Sent extended command 0x3l
All possible debugging has been turned off
DSL-Gateway#sh dsl int atm0
ATM0
Alcatel 20190 chipset information
Line not activated: displaying cached data from last activation
   ATU-R (DS)   ATU-C (US)
Modem Status: Showtime (DMTDSL_DO_OPEN)
DSL Mode: ITU G.992.5 (ADSL2+) Annex A
ITU STD NUM:   0x03     0x3
Chip Vendor ID: 'STMI'     'TSTC'
Chip Vendor Specific: 0x0000    0x0510
Chip Vendor Country:   0x0F    0xB5
Modem Vendor ID: 'CSCO'     'TSTC'
Modem Vendor Specific: 0x0000    0x5100
Modem Vendor Country: 0xB5    0xB5
Serial Number Near:    FCZ112550D 877-K9   12.4
Serial Number Far: Chip ID:   C196 (0) capability-enabled
DFE BOM: DFE3.0 Annex A (1)
Capacity Used: 97%     62%
Noise Margin: -2.5 dB     8.0 dB
Output Power: 20.0 dBm    12.5 dBm
Attenuation: 38.0 dB    19.0 dB
FEC ES Errors:   3     5830
ES Errors:   7     14057
SES Errors:   7     13968
LOSES Errors:   1     6332122
UES Errors:   0     6334633
Defect Status:            LCD       LOM     LOS LOF LCD
Last Fail Code: None
Watchdog Counter: 0x27
Watchdog Resets: 0
Selftest Result: 0x00
Subfunction: 0x00
Interrupts: 20528 (0 spurious)
PHY Access Err: 0
Activations: 4
LED Status: ON
LED On Time: 100
LED Off Time: 100
Init FW: init_AMR-3.0.043.bin
Operation FW: AMR-3.0.043.bin
FW Source: external
FW Version: 3.0.43

    DS Channel1   DS Channel0 US Channel1   US Channel0
Speed (kbps):           0         8399          0          732
Cells:            0            0          0        28248
Reed-Solomon EC:          0          150          0      2094236
CRC Errors:           0          665          0       596527
Header Errors:           0            1          0        44506
Total BER:    0E-0   0E-0
Leakage Average BER:   0E-0   2E-0
Interleave Delay:   Available only during SHOWTIME
   ATU-R (DS) ATU-C (US)
Bitswap:        enabled    enabled

LOM Monitoring : Disabled

DMT Bits Per Bin information for ADSL2+ is available only during SHOWTIME.

DSL: Training log buffer capability is not enabled
DSL-Gateway#
Jun 27 17:02:08.724: %LINK-3-UPDOWN: Interface ATM0, changed state to up
Jun 27 17:02:09.725: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up
Jun 27 17:02:15.150: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up
Jun 27 17:02:15.150: %DIALER-6-BIND: Interface Vi2 bound to profile Di1
Jun 27 17:02:23.212: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down
Jun 27 17:02:23.212: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di1
Jun 27 17:02:24.208: %LINK-3-UPDOWN: Interface ATM0, changed state to down
Jun 27 17:02:25.208: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to downconf t
Enter configuration commands, one per line. End with CNTL/Z.
DSL-Gateway(config)#int atm0
DSL-Gateway(config-if)#shu
DSL-Gateway(config-if)#shutdown
DSL-Gateway(config-if)#^Z
DSL-Gateway#do sh r
Jun 27 17:02:32.314: %LINK-5-CHANGED: Interface ATM0, changed state to administratively down

DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#sh run int atm0
Building configuration...

Current configuration : 142 bytes
!
interface ATM0
no ip address
shutdown
no atm ilmi-keepalive
pvc 0/38
encapsulation aal5mux ppp dialer
dialer pool-member 1
!
end

DSL-Gateway#sh run int di1
Building configuration...

Current configuration : 415 bytes
!
interface Dialer1
mtu 1492
ip address negotiated
no ip redirects
no ip unreachables
no ip proxy-arp
ip nat outside
ip virtual-reassembly
encapsulation ppp
dialer pool 1
ppp authentication chap pap callin
ppp chap hostname xxxxx@xxxx.net
ppp chap password 7 xxxxxx
ppp pap sent-username xxxx@xxxx.net password 7 xxxxxxx
service-policy output Upload
end

DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
Alcatel 20190 chipset information
Line not activated: displaying cached data from last activation
   ATU-R (DS)   ATU-C (US)
Modem Status: Showtime (DMTDSL_DO_OPEN)
DSL Mode: ITU G.992.5 (ADSL2+) Annex A
ITU STD NUM:   0x03     0x3
Chip Vendor ID: 'STMI'     'TSTC'
Chip Vendor Specific: 0x0000    0x0510
Chip Vendor Country:   0x0F    0xB5
Modem Vendor ID: 'CSCO'     'TSTC'
Modem Vendor Specific: 0x0000    0x5100
Modem Vendor Country: 0xB5    0xB5
Serial Number Near:    FCZ112550D 877-K9   12.4
Serial Number Far: Chip ID:   C196 (0) capability-enabled
DFE BOM: DFE3.0 Annex A (1)
Capacity Used: 97%     62%
Noise Margin: -1.0 dB     8.0 dB
Output Power: 20.0 dBm    12.5 dBm
Attenuation: 38.0 dB    19.0 dB
FEC ES Errors:   5     5831
ES Errors:   8     14064
SES Errors:   8     13975
LOSES Errors:   1     6332151
UES Errors:   0     6334662
Defect Status:            LCD       LOM     LOS LOF LCD
Last Fail Code: None
Watchdog Counter: 0x27
Watchdog Resets: 0
Selftest Result: 0x00
Subfunction: 0x00
Interrupts: 28736 (0 spurious)
PHY Access Err: 0
Activations: 5
LED Status: OFF
LED On Time: 100
LED Off Time: 100
Init FW: init_AMR-3.0.043.bin
Operation FW: AMR-3.0.043.bin
FW Source: external
FW Version: 3.0.43

    DS Channel1   DS Channel0 US Channel1   US Channel0
Speed (kbps):           0         8353          0          732
Cells:            0            0          0        28223
Reed-Solomon EC:          0          154          0      2094237
CRC Errors:           0          665          0       596829
Header Errors:           0            1          0        44514
Total BER:    0E-0   0E-0
Leakage Average BER:   0E-0   2E-0
Interleave Delay:   Available only during SHOWTIME
   ATU-R (DS) ATU-C (US)
Bitswap:        enabled    enabled

LOM Monitoring : Disabled

DMT Bits Per Bin information for ADSL2+ is available only during SHOWTIME.

DSL: Training log buffer capability is not enabled
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#
DSL-Gateway#sh ip int bri
Interface                  IP-Address      OK? Method Status                Protocol
ATM0                       unassigned      YES NVRAM down                  down
Dialer0                    unassigned      YES NVRAM up                    up
Dialer1                    unassigned      YES NVRAM up                    up
FastEthernet0              unassigned      YES unset up                    down
FastEthernet1              unassigned      YES unset up                    down
FastEthernet2              unassigned      YES unset up                    down
FastEthernet3              unassigned      YES unset up                    up
NVI0                       unassigned      YES unset administratively down down
Virtual-Access1            unassigned      YES unset up                    up
Virtual-Access2            unassigned      YES unset down                  down
Vlan1                      10.0.21.1       YES NVRAM up                    up
DSL-Gateway#
Jun 27 17:04:18.754: %LINK-3-UPDOWN: Interface ATM0, changed state to up
Jun 27 17:04:19.754: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up
Jun 27 17:04:24.559: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up
Jun 27 17:04:24.559: %DIALER-6-BIND: Interface Vi2 bound to profile Di1
Jun 27 17:04:31.157: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down
Jun 27 17:04:31.157: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di1
Jun 27 17:04:32.161: %LINK-3-UPDOWN: Interface ATM0, changed state to down
Jun 27 17:04:33.161: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to downu all
All possible debugging has been turned off

MaseBarnes · ‎06-27-2011

Dialer1 gets connected for 7 seconds, sees to be an error in LCP / PPP.

Can you post a debug ppp neg / auth / err / whatsoever please?

paulhughes5 · ‎06-27-2011

Someone else in our office has said there is an issue between the chipset on the Cisco DSL and the MSANs being use by the ISP (BT). I can post the ppp debugs when I get connected up again however the ATM interface seems to go up and down even if the dialer is shutdown.

paolo bevilacqua · ‎06-28-2011

Try contacting Cisco TAC, ask for escalation to the specific product support team.

They may have an unpublished firmware for the issue.

Also check with telco which settings they have in place for your circuit, that is not Annex M, and if they have alternative settings.

paulhughes5 · ‎06-30-2011

Unfortunately I don't have a support account to be able to contact TAC. I've tried all the firmware that I can find any none seem to have made any difference.

I imagine there must be some new firmware out for the 877, I cant see that I'm the only person with an issue. Are there any alternative ways to get hold of newer firmware?

paolo bevilacqua · ‎06-30-2011

A support contract for such a small router is very economic, and is the best way to have problems resolved (and insure your router against faults).

MaseBarnes · ‎06-30-2011

Ack!

If you buy a SmartNet only for TAC and SW updates it's very "cheap".

Lately I bought a SN with 5for3 year promo only 80 EUR for a 892 router.

sewillar · ‎07-27-2011

Hi Paul,

As several users have pointed out a service contract can be economic. You can use our Cisco Partner Locator to find some in your area.

http://tools.cisco.com/WWChannels/LOCATR/openBasicSearch.do

You can usually run a quick Google Search to find online prices. For example:

http://www.google.com/#hl=en&xhr=t&q=Cisco877+ASDL+contract&cp=22&pf=p&sclient=psy&source=hp&aq=f&aqi=&aql=&oq=Cisco877+ASDL+contract&pbx=1&bav=on.2,or.r_gc.r_pw.&fp=984b534b048f1d79&biw=1280&bih=827

Doing a search through the google search revealed a 1 year technical support contact ranged from $44 on the low end to $87 on the high end. These are also generally renewable each year.