Moz877W#debug dialer Dial on demand events debugging is on Moz877W#debug ppp neg PPP protocol negotiation debugging is on Moz877W#debug ppp auth PPP authentication debugging is on Moz877W#debug atm events ATM events debugging is on Moz877W# 000035: *Jan 10 23:24:49.687 PCTime: DSL(ATM0): 26: Modem state = 0x8 000036: *Jan 10 23:24:52.187 PCTime: DSL(ATM0): 27: Modem state = 0x8 000037: *Jan 10 23:24:54.687 PCTime: DSL(ATM0): 28: Modem state = 0x8 000038: *Jan 10 23:24:57.187 PCTime: DSL(ATM0): 29: Modem state = 0x8 000039: *Jan 10 23:24:59.687 PCTime: DSL(ATM0): 30: Modem state = 0x9 000040: *Jan 10 23:25:02.187 PCTime: DSL(ATM0): Could not establish connection event=1 000041: *Jan 10 23:25:02.187 PCTime: DSL: SM: [DMTDSL_DO_OPEN -> DMTDSL_INIT] 000042: *Jan 10 23:25:02.259 PCTime: DSL: SM: [DMTDSL_INIT -> DMTDSL_DLOAD_1] 000043: *Jan 10 23:25:02.259 PCTime: DSL: Downloading init_AMR-R-2.5.042_no_bist.bin 000044: *Jan 10 23:25:02.263 PCTime: DSL:(ATM0) Downloaded 2 blocks... Finished! 000045: *Jan 10 23:25:02.263 PCTime: DSL(ATM0): Sent command 0x14 000046: *Jan 10 23:25:04.263 PCTime: DSL: Received response: 0x80 000047: *Jan 10 23:25:04.263 PCTime: DSL: SM: [DMTDSL_DLOAD_1 -> DMTDSL_DLOAD_2] 000048: *Jan 10 23:25:04.263 PCTime: DSL: Downloading AMR-R-2.5.042.bin 000049: *Jan 10 23:25:04.295 PCTime: DSL(ATM0): Downloaded 100 blocks 000050: *Jan 10 23:25:04.323 PCTime: DSL(ATM0): Downloaded 200 blocks 000051: *Jan 10 23:25:04.359 PCTime: DSL(ATM0): Downloaded 300 blocks 000052: *Jan 10 23:25:04.391 PCTime: DSL(ATM0): Downloaded 400 blocks 000053: *Jan 10 23:25:04.423 PCTime: DSL(ATM0): Downloaded 500 blocks 000054: *Jan 10 23:25:04.455 PCTime: DSL(ATM0): Downloaded 600 blocks 000055: *Jan 10 23:25:04.487 PCTime: DSL(ATM0): Downloaded 700 blocks 000056: *Jan 10 23:25:04.519 PCTime: DSL(ATM0): Downloaded 800 blocks 000057: *Jan 10 23:25:04.555 PCTime: DSL(ATM0): Downloaded 900 blocks 000058: *Jan 10 23:25:04.587 PCTime: DSL(ATM0): Downloaded 1000 blocks 000059: *Jan 10 23:25:04.619 PCTime: DSL(ATM0): Downloaded 1100 blocks 000060: *Jan 10 23:25:04.651 PCTime: DSL(ATM0): Downloaded 1200 blocks 000061: *Jan 10 23:25:04.683 PCTime: DSL(ATM0): Downloaded 1300 blocks 000062: *Jan 10 23:25:04.719 PCTime: DSL(ATM0): Downloaded 1400 blocks 000063: *Jan 10 23:25:04.755 PCTime: DSL(ATM0): Downloaded 1500 blocks 000064: *Jan 10 23:25:04.787 PCTime: DSL(ATM0): Downloaded 1600 blocks 000065: *Jan 10 23:25:04.819 PCTime: DSL(ATM0): Downloaded 1700 blocks 000066: *Jan 10 23:25:04.851 PCTime: DSL(ATM0): Downloaded 1800 blocks 000067: *Jan 10 23:25:04.883 PCTime: DSL(ATM0): Downloaded 1900 blocks 000068: *Jan 10 23:25:04.915 PCTime: DSL(ATM0): Downloaded 2000 blocks 000069: *Jan 10 23:25:04.951 PCTime: DSL(ATM0): Downloaded 2100 blocks 000070: *Jan 10 23:25:04.979 PCTime: DSL(ATM0): Downloaded 2200 blocks 000071: *Jan 10 23:25:05.011 PCTime: DSL(ATM0): Downloaded 2300 blocks 000072: *Jan 10 23:25:05.043 PCTime: DSL(ATM0): Downloaded 2400 blocks 000073: *Jan 10 23:25:05.075 PCTime: DSL(ATM0): Downloaded 2500 blocks 000074: *Jan 10 23:25:05.111 PCTime: DSL(ATM0): Downloaded 2600 blocks 000075: *Jan 10 23:25:05.143 PCTime: DSL(ATM0): Downloaded 2700 blocks 000076: *Jan 10 23:25:05.175 PCTime: DSL(ATM0): Downloaded 2800 blocks 000077: *Jan 10 23:25:05.207 PCTime: DSL(ATM0): Downloaded 2900 blocks 000078: *Jan 10 23:25:05.239 PCTime: DSL(ATM0): Downloaded 3000 blocks 000079: *Jan 10 23:25:05.271 PCTime: DSL(ATM0): Downloaded 3100 blocks 000080: *Jan 10 23:25:05.303 PCTime: DSL(ATM0): Downloaded 3200 blocks 000081: *Jan 10 23:25:05.339 PCTime: DSL(ATM0): Downloaded 3300 blocks 000082: *Jan 10 23:25:05.371 PCTime: DSL(ATM0): Downloaded 3400 blocks 000083: *Jan 10 23:25:05.403 PCTime: DSL(ATM0): Downloaded 3500 blocks 000084: *Jan 10 23:25:05.435 PCTime: DSL(ATM0): Downloaded 3600 blocks 000085: *Jan 10 23:25:05.467 PCTime: DSL(ATM0): Downloaded 3700 blocks 000086: *Jan 10 23:25:05.499 PCTime: DSL(ATM0): Downloaded 3800 blocks 000087: *Jan 10 23:25:05.507 PCTime: DSL:(ATM0) Downloaded 3824 blocks... Finished! 000088: *Jan 10 23:25:05.507 PCTime: DSL(ATM0): Sent command 0x14 000089: *Jan 10 23:25:07.507 PCTime: set tx_gain_offset to 0 000090: *Jan 10 23:25:07.507 PCTime: set rx_gain_offset to 0 000091: *Jan 10 23:25:07.507 PCTime: set target_noise_margin_offset to 0 000092: *Jan 10 23:25:07.507 PCTime: set max_bits_tone_limit to 15 000093: *Jan 10 23:25:07.507 PCTime: changed current state to do open!! 000094: *Jan 10 23:25:07.507 PCTime: DSL: SM: [DMTDSL_DLOAD_2 -> DMTDSL_DO_OPEN] 000095: *Jan 10 23:25:07.507 PCTime: DSL: Send ADSL_OPEN command. 000096: *Jan 10 23:25:07.507 PCTime: DSL(ATM0): Using subfunction 0x0 000097: *Jan 10 23:25:07.507 PCTime: LOCAL:Max noise margin for power cutoff 31 000098: *Jan 10 23:25:07.507 PCTime: DSL(ATM0): Sent extended command 0x3 000099: *Jan 10 23:25:10.007 PCTime: DSL(ATM0): 1: Modem state = 0x9 000100: *Jan 10 23:25:12.507 PCTime: DSL(ATM0): 2: Modem state = 0x10 000101: *Jan 10 23:25:15.007 PCTime: DSL(ATM0): 3: Modem state = 0x10 000102: *Jan 10 23:25:17.507 PCTime: DSL(ATM0): 4: Modem state = 0x10 000103: *Jan 10 23:25:20.007 PCTime: DSL(ATM0): 5: Modem state = 0x10 000104: *Jan 10 23:25:21.039 PCTime: DSL: Received response: 0x24 000105: *Jan 10 23:25:21.039 PCTime: DSL: Showtime! 000106: *Jan 10 23:25:21.039 PCTime: DSL(ATM0): Sent command 0x31 000107: *Jan 10 23:25:21.051 PCTime: DSL: Received response: 0x12 000108: *Jan 10 23:25:21.051 PCTime: DSL(ATM0): operation mode 0x0002 000109: *Jan 10 23:25:21.051 PCTime: DSL(ATM0): Sent command 0x33 000110: *Jan 10 23:25:21.055 PCTime: DSL: Received response: 0x16 000111: *Jan 10 23:25:21.055 PCTime: DSL(ATM0): Far End ITU Country Code 0xB5 000112: *Jan 10 23:25:21.055 PCTime: DSL: Far End ITU Vendor ID TSTC 000113: *Jan 10 23:25:21.055 PCTime: DSL: Far End ITU Vendor ID Specific 0x0000 000114: *Jan 10 23:25:21.055 PCTime: DSL: Far End ITU Vendor STD Number 0x0002 000115: *Jan 10 23:25:21.055 PCTime: DSL(ATM0): Sent command 0x32 000116: *Jan 10 23:25:21.063 PCTime: DSL: Received response: 0x14 000117: *Jan 10 23:25:21.063 PCTime: DSL(ATM0): Near End ITU Country Code 0x0F 000118: *Jan 10 23:25:21.063 PCTime: DSL: Near End ITU Vendor ID STMI 000119: *Jan 10 23:25:21.063 PCTime: DSL: Near End ITU Vendor ID Specific 0x0000 000120: *Jan 10 23:25:21.063 PCTime: DSL: Near End ITU Vendor STD Number 0x0003 000121: *Jan 10 23:25:21.063 PCTime: Matching SAR to Line speed: Attempt number 1 cps 1 slots 15 APL Level 0 slots 15 APL Level 1 slots 15 000122: *Jan 10 23:25:21.063 PCTime: ATM0: atmsar_get_plim_info 000123: *Jan 10 23:25:21.063 PCTime: ATM0:atmsar_update_plimtype 000124: *Jan 10 23:25:21.063 PCTime: ATM0 atmsar_update_us_bandwidth(): upstream bw =448 Kbps 000125: *Jan 10 23:25:21.063 PCTime: DSL: SM: [DMTDSL_DO_OPEN -> DMTDSL_SHOWTIME] 000126: *Jan 10 23:25:28.147 PCTime: ATM0: atmsar_vc_dlcx 000127: *Jan 10 23:25:28.147 PCTime: (ATM0)1a_enable: delay activation of vcd=1, vc=0x82EC1768 000128: *Jan 10 23:25:28.147 PCTime: atmsar enable ATM0 000129: *Jan 10 23:25:28.147 PCTime: ATM0: atmsar_bringup_interface: Interface and atm_db flags are UP 000130: *Jan 10 23:25:30.147 PCTime: %LINK-3-UPDOWN: Interface ATM0, changed state to up 000131: *Jan 10 23:25:30.147 PCTime: atmsar_atm_lineaction(ATM0): state=4 000132: *Jan 10 23:25:31.147 PCTime: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up 000133: *Jan 10 23:25:35.895 PCTime: ATM0: atmsar_1a_setup_vc, vcinfo = 0x82EC1768 000134: *Jan 10 23:25:35.895 PCTime: ATM0 atmsar_vc_setup: vcd 1 000135: *Jan 10 23:25:35.895 PCTime: atmsar_setup_cos(ATM0): vc:1 wred_name:- max_q:0 000136: *Jan 10 23:25:35.895 PCTime: ATM0: VC setup successful (vcd = 1) 000137: *Jan 10 23:25:35.895 PCTime: ATM0: atmsar_atm_get_stats,vcinfo = 0x0 000138: *Jan 10 23:25:36.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000139: *Jan 10 23:25:36.819 PCTime: Vi2 PPP: Phase is DOWN, Setup 000140: *Jan 10 23:25:36.823 PCTime: %DIALER-6-BIND: Interface Vi2 bound to profile Di0 000141: *Jan 10 23:25:36.827 PCTime: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up 000142: *Jan 10 23:25:36.827 PCTime: Vi2 DDR: Dialer statechange to up 000143: *Jan 10 23:25:36.835 PCTime: Vi2 PPP: Using dialer call direction 000144: *Jan 10 23:25:36.835 PCTime: Vi2 PPP: Treating connection as a callout 000145: *Jan 10 23:25:36.835 PCTime: Vi2 PPP: Session handle[87000003] Session id[1] 000146: *Jan 10 23:25:36.835 PCTime: Vi2 PPP: Phase is ESTABLISHING, Active Open 000147: *Jan 10 23:25:36.835 PCTime: Vi2 PPP: Authorization required 000148: *Jan 10 23:25:36.835 PCTime: Vi2 PPP: No remote authentication for call-out 000149: *Jan 10 23:25:36.835 PCTime: Vi2 LCP: O CONFREQ [Closed] id 1 len 10 000150: *Jan 10 23:25:36.835 PCTime: Vi2 LCP: MagicNumber 0x1A74995B (0x05061A74995B) 000151: *Jan 10 23:25:36.835 PCTime: atmsar_vc_tx_start(82814914). 000152: *Jan 10 23:25:36.835 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x824B686C 000153: *Jan 10 23:25:36.835 PCTime: atmsar_transmit_pak_wrapper: deq(824B686C). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000154: *Jan 10 23:25:37.123 PCTime: Vi2 LCP: I CONFREQ [REQsent] id 1 len 15 000155: *Jan 10 23:25:37.123 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000156: *Jan 10 23:25:37.123 PCTime: Vi2 LCP: MagicNumber 0x42AF7AB4 (0x050642AF7AB4) 000157: *Jan 10 23:25:37.127 PCTime: Vi2 LCP: O CONFACK [REQsent] id 1 len 15 000158: *Jan 10 23:25:37.127 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000159: *Jan 10 23:25:37.127 PCTime: Vi2 LCP: MagicNumber 0x42AF7AB4 (0x050642AF7AB4) 000160: *Jan 10 23:25:37.127 PCTime: atmsar_vc_tx_start(82814914). 000161: *Jan 10 23:25:37.127 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B22984 000162: *Jan 10 23:25:37.127 PCTime: atmsar_transmit_pak_wrapper: deq(82B22984). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000163: *Jan 10 23:25:37.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000164: *Jan 10 23:25:38.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000165: *Jan 10 23:25:38.831 PCTime: Vi2 LCP: TIMEout: State ACKsent 000166: *Jan 10 23:25:38.831 PCTime: Vi2 LCP: O CONFREQ [ACKsent] id 2 len 10 000167: *Jan 10 23:25:38.831 PCTime: Vi2 LCP: MagicNumber 0x1A74995B (0x05061A74995B) 000168: *Jan 10 23:25:38.831 PCTime: atmsar_vc_tx_start(82814914). 000169: *Jan 10 23:25:38.831 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B2140C 000170: *Jan 10 23:25:38.831 PCTime: atmsar_transmit_pak_wrapper: deq(82B2140C). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000171: *Jan 10 23:25:38.867 PCTime: Vi2 LCP: I CONFACK [ACKsent] id 2 len 10 000172: *Jan 10 23:25:38.867 PCTime: Vi2 LCP: MagicNumber 0x1A74995B (0x05061A74995B) 000173: *Jan 10 23:25:38.867 PCTime: Vi2 LCP: State is Open 000174: *Jan 10 23:25:38.867 PCTime: Vi2 PPP: No authorization without authentication 000175: *Jan 10 23:25:38.867 PCTime: Vi2 PPP: Phase is AUTHENTICATING, by the peer 000176: *Jan 10 23:25:38.867 PCTime: Vi2 CHAP: I CHALLENGE id 1 len 35 from "ESR6.Kingston4" 000177: *Jan 10 23:25:38.867 PCTime: Vi2 CHAP: Using hostname from interface CHAP 000178: *Jan 10 23:25:38.867 PCTime: Vi2 CHAP: Using password from interface CHAP 000179: *Jan 10 23:25:38.867 PCTime: Vi2 CHAP: O RESPONSE id 1 len 43 from "mozwalsh@gotadsl.co.uk" 000180: *Jan 10 23:25:38.871 PCTime: atmsar_vc_tx_start(82814914). 000181: *Jan 10 23:25:38.871 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x824B52F4 000182: *Jan 10 23:25:38.871 PCTime: atmsar_transmit_pak_wrapper: deq(824B52F4). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000183: *Jan 10 23:25:39.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000184: *Jan 10 23:25:40.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000185: *Jan 10 23:25:41.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000186: *Jan 10 23:25:42.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000187: *Jan 10 23:25:43.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000188: *Jan 10 23:25:44.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000189: *Jan 10 23:25:45.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000190: *Jan 10 23:25:46.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000191: *Jan 10 23:25:47.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000192: *Jan 10 23:25:48.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000193: *Jan 10 23:25:48.879 PCTime: Vi2 AUTH: Timeout 1 000194: *Jan 10 23:25:48.879 PCTime: Vi2 CHAP: Using hostname from interface CHAP 000195: *Jan 10 23:25:48.879 PCTime: Vi2 CHAP: Using password from interface CHAP 000196: *Jan 10 23:25:48.879 PCTime: Vi2 CHAP: O RESPONSE id 1 len 43 from "mozwalsh@gotadsl.co.uk" 000197: *Jan 10 23:25:48.879 PCTime: atmsar_vc_tx_start(82814914). 000198: *Jan 10 23:25:48.879 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B20950 000199: *Jan 10 23:25:48.879 PCTime: atmsar_transmit_pak_wrapper: deq(82B20950). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000200: *Jan 10 23:25:49.299 PCTime: Vi2 LCP: I CONFREQ [Open] id 1 len 15 000201: *Jan 10 23:25:49.299 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000202: *Jan 10 23:25:49.299 PCTime: Vi2 LCP: MagicNumber 0x42AFAAA4 (0x050642AFAAA4) 000203: *Jan 10 23:25:49.299 PCTime: Vi2 PPP: Phase is TERMINATING 000204: *Jan 10 23:25:49.299 PCTime: Vi2 PPP: Authorization required 000205: *Jan 10 23:25:49.299 PCTime: Vi2 PPP: No remote authentication for call-out 000206: *Jan 10 23:25:49.299 PCTime: Vi2 PPP: Phase is ESTABLISHING 000207: *Jan 10 23:25:49.299 PCTime: Vi2 LCP: O CONFREQ [Open] id 3 len 10 000208: *Jan 10 23:25:49.299 PCTime: Vi2 LCP: MagicNumber 0x1A74CA13 (0x05061A74CA13) 000209: *Jan 10 23:25:49.303 PCTime: atmsar_vc_tx_start(82814914). 000210: *Jan 10 23:25:49.303 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82646FF8 000211: *Jan 10 23:25:49.303 PCTime: atmsar_transmit_pak_wrapper: deq(82646FF8). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000212: *Jan 10 23:25:49.303 PCTime: Vi2 LCP: O CONFACK [Open] id 1 len 15 000213: *Jan 10 23:25:49.303 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000214: *Jan 10 23:25:49.303 PCTime: Vi2 LCP: MagicNumber 0x42AFAAA4 (0x050642AFAAA4) 000215: *Jan 10 23:25:49.303 PCTime: atmsar_vc_tx_start(82814914). 000216: *Jan 10 23:25:49.303 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B21EC8 000217: *Jan 10 23:25:49.303 PCTime: atmsar_transmit_pak_wrapper: deq(82B21EC8). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000218: *Jan 10 23:25:49.339 PCTime: Vi2 LCP: I CONFACK [ACKsent] id 3 len 10 000219: *Jan 10 23:25:49.339 PCTime: Vi2 LCP: MagicNumber 0x1A74CA13 (0x05061A74CA13) 000220: *Jan 10 23:25:49.339 PCTime: Vi2 LCP: State is Open 000221: *Jan 10 23:25:49.339 PCTime: Vi2 PPP: No authorization without authentication 000222: *Jan 10 23:25:49.339 PCTime: Vi2 PPP: Phase is AUTHENTICATING, by the peer 000223: *Jan 10 23:25:49.339 PCTime: Vi2 CHAP: I CHALLENGE id 1 len 35 from "ESR6.Kingston4" 000224: *Jan 10 23:25:49.343 PCTime: Vi2 CHAP: Using hostname from interface CHAP 000225: *Jan 10 23:25:49.343 PCTime: Vi2 CHAP: Using password from interface CHAP 000226: *Jan 10 23:25:49.343 PCTime: Vi2 CHAP: O RESPONSE id 1 len 43 from "mozwalsh@gotadsl.co.uk" 000227: *Jan 10 23:25:49.343 PCTime: atmsar_vc_tx_start(82814914). 000228: *Jan 10 23:25:49.343 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x824B5A1C 000229: *Jan 10 23:25:49.343 PCTime: atmsar_transmit_pak_wrapper: deq(824B5A1C). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000230: *Jan 10 23:25:49.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000231: *Jan 10 23:25:50.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000232: *Jan 10 23:25:51.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000233: *Jan 10 23:25:52.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000234: *Jan 10 23:25:53.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000235: *Jan 10 23:25:54.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000236: *Jan 10 23:25:55.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000237: *Jan 10 23:25:56.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000238: *Jan 10 23:25:57.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000239: *Jan 10 23:25:58.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000240: *Jan 10 23:25:59.343 PCTime: Vi2 AUTH: Timeout 1 000241: *Jan 10 23:25:59.343 PCTime: Vi2 CHAP: Using hostname from interface CHAP 000242: *Jan 10 23:25:59.343 PCTime: Vi2 CHAP: Using password from interface CHAP 000243: *Jan 10 23:25:59.343 PCTime: Vi2 CHAP: O RESPONSE id 1 len 43 from "mozwalsh@gotadsl.co.uk" 000244: *Jan 10 23:25:59.343 PCTime: atmsar_vc_tx_start(82814914). 000245: *Jan 10 23:25:59.343 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B217A0 000246: *Jan 10 23:25:59.343 PCTime: atmsar_transmit_pak_wrapper: deq(82B217A0). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000247: *Jan 10 23:25:59.379 PCTime: Vi2 LCP: I CONFREQ [Open] id 1 len 15 000248: *Jan 10 23:25:59.379 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000249: *Jan 10 23:25:59.379 PCTime: Vi2 LCP: MagicNumber 0x42AFD261 (0x050642AFD261) 000250: *Jan 10 23:25:59.383 PCTime: Vi2 PPP: Phase is TERMINATING 000251: *Jan 10 23:25:59.383 PCTime: Vi2 PPP: Authorization required 000252: *Jan 10 23:25:59.383 PCTime: Vi2 PPP: No remote authentication for call-out 000253: *Jan 10 23:25:59.383 PCTime: Vi2 PPP: Phase is ESTABLISHING 000254: *Jan 10 23:25:59.383 PCTime: Vi2 LCP: O CONFREQ [Open] id 4 len 10 000255: *Jan 10 23:25:59.383 PCTime: Vi2 LCP: MagicNumber 0x1A74F17F (0x05061A74F17F) 000256: *Jan 10 23:25:59.383 PCTime: atmsar_vc_tx_start(82814914). 000257: *Jan 10 23:25:59.383 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x8289B47C 000258: *Jan 10 23:25:59.383 PCTime: atmsar_transmit_pak_wrapper: deq(8289B47C). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000259: *Jan 10 23:25:59.383 PCTime: Vi2 LCP: O CONFACK [Open] id 1 len 15 000260: *Jan 10 23:25:59.383 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000261: *Jan 10 23:25:59.383 PCTime: Vi2 LCP: MagicNumber 0x42AFD261 (0x050642AFD261) 000262: *Jan 10 23:25:59.383 PCTime: atmsar_vc_tx_start(82814914). 000263: *Jan 10 23:25:59.383 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B8ACFC 000264: *Jan 10 23:25:59.383 PCTime: atmsar_transmit_pak_wrapper: deq(82B8ACFC). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000265: *Jan 10 23:25:59.419 PCTime: Vi2 LCP: I CONFACK [ACKsent] id 4 len 10 000266: *Jan 10 23:25:59.419 PCTime: Vi2 LCP: MagicNumber 0x1A74F17F (0x05061A74F17F) 000267: *Jan 10 23:25:59.419 PCTime: Vi2 LCP: State is Open 000268: *Jan 10 23:25:59.419 PCTime: Vi2 PPP: No authorization without authentication 000269: *Jan 10 23:25:59.419 PCTime: Vi2 PPP: Phase is AUTHENTICATING, by the peer 000270: *Jan 10 23:25:59.419 PCTime: Vi2 CHAP: I CHALLENGE id 1 len 35 from "ESR6.Kingston4" 000271: *Jan 10 23:25:59.423 PCTime: Vi2 CHAP: Using hostname from interface CHAP 000272: *Jan 10 23:25:59.423 PCTime: Vi2 CHAP: Using password from interface CHAP 000273: *Jan 10 23:25:59.423 PCTime: Vi2 CHAP: O RESPONSE id 1 len 43 from "mozwalsh@gotadsl.co.uk" 000274: *Jan 10 23:25:59.423 PCTime: atmsar_vc_tx_start(82814914). 000275: *Jan 10 23:25:59.423 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B1E588 000276: *Jan 10 23:25:59.423 PCTime: atmsar_transmit_pak_wrapper: deq(82B1E588). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000277: *Jan 10 23:25:59.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000278: *Jan 10 23:25:59.667 PCTime: Vi2 LCP: I CONFREQ [Open] id 250 len 19 000279: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: MRU 32725 (0x01047FD5) 000280: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000281: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: MagicNumber 0x7D60BFCD (0x05067D60BFCD) 000282: *Jan 10 23:25:59.671 PCTime: Vi2 PPP: Phase is TERMINATING 000283: *Jan 10 23:25:59.671 PCTime: Vi2 PPP: Authorization required 000284: *Jan 10 23:25:59.671 PCTime: Vi2 PPP: No remote authentication for call-out 000285: *Jan 10 23:25:59.671 PCTime: Vi2 PPP: Phase is ESTABLISHING 000286: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: O CONFREQ [Open] id 5 len 10 000287: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: MagicNumber 0x1A74F2A0 (0x05061A74F2A0) 000288: *Jan 10 23:25:59.671 PCTime: atmsar_vc_tx_start(82814914). 000289: *Jan 10 23:25:59.671 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B2225C 000290: *Jan 10 23:25:59.671 PCTime: atmsar_transmit_pak_wrapper: deq(82B2225C). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000291: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: O CONFACK [Open] id 250 len 19 000292: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: MRU 32725 (0x01047FD5) 000293: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000294: *Jan 10 23:25:59.671 PCTime: Vi2 LCP: MagicNumber 0x7D60BFCD (0x05067D60BFCD) 000295: *Jan 10 23:25:59.671 PCTime: atmsar_vc_tx_start(82814914). 000296: *Jan 10 23:25:59.671 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B1F044 000297: *Jan 10 23:25:59.671 PCTime: atmsar_transmit_pak_wrapper: deq(82B1F044). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000298: *Jan 10 23:25:59.711 PCTime: Vi2 LCP: I CONFACK [ACKsent] id 5 len 10 000299: *Jan 10 23:25:59.711 PCTime: Vi2 LCP: MagicNumber 0x1A74F2A0 (0x05061A74F2A0) 000300: *Jan 10 23:25:59.711 PCTime: Vi2 LCP: State is Open 000301: *Jan 10 23:25:59.711 PCTime: Vi2 PPP: No authorization without authentication 000302: *Jan 10 23:25:59.711 PCTime: Vi2 PPP: Phase is AUTHENTICATING, by the peer 000303: *Jan 10 23:25:59.715 PCTime: Vi2 CHAP: I CHALLENGE id 48 len 42 from "ar20.gs1" 000304: *Jan 10 23:25:59.715 PCTime: Vi2 CHAP: Using hostname from interface CHAP 000305: *Jan 10 23:25:59.715 PCTime: Vi2 CHAP: Using password from interface CHAP 000306: *Jan 10 23:25:59.715 PCTime: Vi2 CHAP: O RESPONSE id 48 len 43 from "mozwalsh@gotadsl.co.uk" 000307: *Jan 10 23:25:59.715 PCTime: atmsar_vc_tx_start(82814914). 000308: *Jan 10 23:25:59.719 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x824B6C00 000309: *Jan 10 23:25:59.719 PCTime: atmsar_transmit_pak_wrapper: deq(824B6C00). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000310: *Jan 10 23:25:59.899 PCTime: Vi2 CHAP: I SUCCESS id 48 len 4 000311: *Jan 10 23:25:59.899 PCTime: Vi2 PPP: Phase is FORWARDING, Attempting Forward 000312: *Jan 10 23:25:59.899 PCTime: Vi2 PPP: Phase is ESTABLISHING, Finish LCP 000313: *Jan 10 23:25:59.903 PCTime: Vi2 PPP: Phase is UP 000314: *Jan 10 23:25:59.903 PCTime: Vi2 IPCP: O CONFREQ [Closed] id 1 len 10 000315: *Jan 10 23:25:59.903 PCTime: Vi2 IPCP: Address 0.0.0.0 (0x030600000000) 000316: *Jan 10 23:25:59.903 PCTime: atmsar_vc_tx_start(82814914). 000317: *Jan 10 23:25:59.903 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B1FB00 000318: *Jan 10 23:25:59.903 PCTime: atmsar_transmit_pak_wrapper: deq(82B1FB00). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000319: *Jan 10 23:25:59.903 PCTime: Vi2 PPP: Process pending ncp packets 000320: *Jan 10 23:25:59.951 PCTime: Vi2 IPCP: I CONFREQ [REQsent] id 0 len 10 000321: *Jan 10 23:25:59.951 PCTime: Vi2 IPCP: Address 195.112.5.29 (0x0306C370051D) 000322: *Jan 10 23:25:59.951 PCTime: Vi2 IPCP: O CONFACK [REQsent] id 0 len 10 000323: *Jan 10 23:25:59.951 PCTime: Vi2 IPCP: Address 195.112.5.29 (0x0306C370051D) 000324: *Jan 10 23:25:59.951 PCTime: atmsar_vc_tx_start(82814914). 000325: *Jan 10 23:25:59.951 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B205BC 000326: *Jan 10 23:25:59.951 PCTime: atmsar_transmit_pak_wrapper: deq(82B205BC). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000327: *Jan 10 23:25:59.955 PCTime: Vi2 IPCP: I CONFNAK [ACKsent] id 1 len 10 000328: *Jan 10 23:25:59.955 PCTime: Vi2 IPCP: Address 82.133.127.197 (0x030652857FC5) 000329: *Jan 10 23:25:59.955 PCTime: Vi2 IPCP: O CONFREQ [ACKsent] id 2 len 10 000330: *Jan 10 23:25:59.955 PCTime: Vi2 IPCP: Address 82.133.127.197 (0x030652857FC5) 000331: *Jan 10 23:25:59.955 PCTime: atmsar_vc_tx_start(82814914). 000332: *Jan 10 23:25:59.955 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x8289B47C 000333: *Jan 10 23:25:59.955 PCTime: atmsar_transmit_pak_wrapper: deq(8289B47C). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000334: *Jan 10 23:26:00.007 PCTime: Vi2 IPCP: I CONFACK [ACKsent] id 2 len 10 000335: *Jan 10 23:26:00.007 PCTime: Vi2 IPCP: Address 82.133.127.197 (0x030652857FC5) 000336: *Jan 10 23:26:00.007 PCTime: Vi2 IPCP: State is Open 000337: *Jan 10 23:26:00.007 PCTime: Di0 IPCP: Install negotiated IP interface address 82.133.127.197 000338: *Jan 10 23:26:00.007 PCTime: Di0 IPCP: Install route to 195.112.5.29 000339: *Jan 10 23:26:00.007 PCTime: Vi2 DDR: dialer protocol up 000340: *Jan 10 23:26:00.011 PCTime: Vi2 IPCP: Add link info for cef entry 195.112.5.29 000341: *Jan 10 23:26:00.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000342: *Jan 10 23:26:00.903 PCTime: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up 000343: *Jan 10 23:26:00.911 PCTime: atmsar_vc_tx_start(82814914). 000344: *Jan 10 23:26:00.911 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x824B76BC 000345: *Jan 10 23:26:00.911 PCTime: atmsar_transmit_pak_wrapper: deq(824B76BC). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000346: *Jan 10 23:26:01.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000347: *Jan 10 23:26:02.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000348: *Jan 10 23:26:03.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000349: *Jan 10 23:26:04.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000350: *Jan 10 23:26:05.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000351: *Jan 10 23:26:06.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000352: *Jan 10 23:26:07.515 PCTime: atmsar_vc_tx_start(82814914). 000353: *Jan 10 23:26:07.515 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B20228 000354: *Jan 10 23:26:07.515 PCTime: atmsar_transmit_pak_wrapper: deq(82B20228). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000355: *Jan 10 23:26:07.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000356: *Jan 10 23:26:08.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000357: *Jan 10 23:26:09.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000358: *Jan 10 23:26:10.575 PCTime: atmsar_vc_tx_start(82814914). 000359: *Jan 10 23:26:10.575 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x822F98F8 000360: *Jan 10 23:26:10.575 PCTime: atmsar_transmit_pak_wrapper: deq(822F98F8). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000361: *Jan 10 23:26:10.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000362: *Jan 10 23:26:11.151 PCTime: atmsar_vc_tx_start(82814914). 000363: *Jan 10 23:26:11.151 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x824B6C00 000364: *Jan 10 23:26:11.151 PCTime: atmsar_transmit_pak_wrapper: deq(824B6C00). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000365: *Jan 10 23:26:11.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000366: *Jan 10 23:26:12.131 PCTime: atmsar_vc_tx_start(82814914). 000367: *Jan 10 23:26:12.131 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B1E1F4 000368: *Jan 10 23:26:12.131 PCTime: atmsar_transmit_pak_wrapper: deq(82B1E1F4). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000369: *Jan 10 23:26:12.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000370: *Jan 10 23:26:13.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000371: *Jan 10 23:26:14.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000372: *Jan 10 23:26:15.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000373: *Jan 10 23:26:15.635 PCTime: ATM0: atmsar_atm_get_stats,vcinfo = 0x0 000374: *Jan 10 23:26:16.067 PCTime: DSL: Defect: LCDi: retraining 000375: *Jan 10 23:26:16.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000376: *Jan 10 23:26:17.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000377: *Jan 10 23:26:18.567 PCTime: atmsar_atm_lineaction(ATM0): state=0 000378: *Jan 10 23:26:18.567 PCTime: ATM0: atmsar_1a_teardown_vc,vcinfo = 0x82EC1768 000379: *Jan 10 23:26:18.567 PCTime: atmsar_1a_teardown_vc(ATM0): vc:1 vpi:0 vci:38 000380: *Jan 10 23:26:18.567 PCTime: DSL: SM: [DMTDSL_SHOWTIME -> DMTDSL_RE_OPEN] 000381: *Jan 10 23:26:18.567 PCTime: DSL: Send ADSL_CLOSE command. 000382: *Jan 10 23:26:18.567 PCTime: DSL(ATM0): Sent command 0x4 000383: *Jan 10 23:26:19.095 PCTime: DSL: Received response: 0x25 000384: *Jan 10 23:26:19.095 PCTime: DSL: Connection closed 000385: *Jan 10 23:26:19.095 PCTime: DSL: SM: [DMTDSL_RE_OPEN -> DMTDSL_DO_OPEN] 000386: *Jan 10 23:26:19.095 PCTime: DSL: Send ADSL_OPEN command. 000387: *Jan 10 23:26:19.095 PCTime: DSL(ATM0): Using subfunction 0x0 000388: *Jan 10 23:26:19.095 PCTime: LOCAL:Max noise margin for power cutoff 31 000389: *Jan 10 23:26:19.095 PCTime: DSL(ATM0): Sent extended command 0x3 000390: *Jan 10 23:26:19.563 PCTime: Service policy input policy output applied on 0/38 000391: *Jan 10 23:26:19.567 PCTime: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down 000392: *Jan 10 23:26:19.567 PCTime: Vi2 IPCP: Remove link info for cef entry 195.112.5.29 000393: *Jan 10 23:26:19.567 PCTime: Vi2 PPP: Sending Acct Event[Down] id[4] 000394: *Jan 10 23:26:19.567 PCTime: Vi2 IPCP: State is Closed 000395: *Jan 10 23:26:19.567 PCTime: Vi2 PPP: Phase is ESTABLISHING, renegotiate LCP 000396: *Jan 10 23:26:19.567 PCTime: Vi2 PPP: Authorization required 000397: *Jan 10 23:26:19.567 PCTime: Vi2 PPP: No remote authentication for call-out 000398: *Jan 10 23:26:19.567 PCTime: Vi2 LCP: O CONFREQ [Closed] id 6 len 10 000399: *Jan 10 23:26:19.567 PCTime: Vi2 LCP: MagicNumber 0x1A754067 (0x05061A754067) 000400: *Jan 10 23:26:19.567 PCTime: Vi2 PPP: Authorization required 000401: *Jan 10 23:26:19.567 PCTime: Vi2 PPP: No remote authentication for call-out 000402: *Jan 10 23:26:19.567 PCTime: Vi2 LCP: O CONFREQ [Closed] id 7 len 10 000403: *Jan 10 23:26:19.567 PCTime: Vi2 LCP: MagicNumber 0x1A754068 (0x05061A754068) 000404: *Jan 10 23:26:19.571 PCTime: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di0 000405: *Jan 10 23:26:19.575 PCTime: Di0 IPCP: Remove route to 195.112.5.29 000406: *Jan 10 23:26:19.575 PCTime: Di0 IPCP: Remove default route thru 195.112.5.29 000407: *Jan 10 23:26:19.579 PCTime: Vi2 PPP: Sending Acct Event[Down] id[4] 000408: *Jan 10 23:26:19.579 PCTime: Vi2 LCP: State is Closed 000409: *Jan 10 23:26:19.579 PCTime: Vi2 PPP: Phase is DOWN 000410: *Jan 10 23:26:20.567 PCTime: %LINK-3-UPDOWN: Interface ATM0, changed state to down 000411: *Jan 10 23:26:20.567 PCTime: atmsar_atm_lineaction(ATM0): state=0 000412: *Jan 10 23:26:20.567 PCTime: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to down 000413: *Jan 10 23:26:21.567 PCTime: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to down 000414: *Jan 10 23:26:21.595 PCTime: DSL(ATM0): 1: Modem state = 0x8 000415: *Jan 10 23:26:24.095 PCTime: DSL(ATM0): 2: Modem state = 0x8 000416: *Jan 10 23:26:26.595 PCTime: DSL(ATM0): 3: Modem state = 0x9 000417: *Jan 10 23:26:28.147 PCTime: ATM0: atmsar_vc_dlcx 000418: *Jan 10 23:26:29.095 PCTime: DSL(ATM0): 4: Modem state = 0x9 000419: *Jan 10 23:26:31.595 PCTime: DSL(ATM0): 5: Modem state = 0x10 000420: *Jan 10 23:26:34.095 PCTime: DSL(ATM0): 6: Modem state = 0x10 000421: *Jan 10 23:26:34.571 PCTime: Vi2 DDR: re-enable timeout 000422: *Jan 10 23:26:36.595 PCTime: DSL(ATM0): 7: Modem state = 0x10 000423: *Jan 10 23:26:39.095 PCTime: DSL(ATM0): 8: Modem state = 0x10 000424: *Jan 10 23:26:39.227 PCTime: DSL: Received response: 0x24 000425: *Jan 10 23:26:39.227 PCTime: DSL: Showtime! 000426: *Jan 10 23:26:39.227 PCTime: DSL(ATM0): Sent command 0x31 000427: *Jan 10 23:26:39.231 PCTime: DSL: Received response: 0x12 000428: *Jan 10 23:26:39.231 PCTime: DSL(ATM0): operation mode 0x0002 000429: *Jan 10 23:26:39.231 PCTime: DSL(ATM0): Sent command 0x33 000430: *Jan 10 23:26:39.239 PCTime: DSL: Received response: 0x16 000431: *Jan 10 23:26:39.239 PCTime: DSL(ATM0): Far End ITU Country Code 0xB5 000432: *Jan 10 23:26:39.239 PCTime: DSL: Far End ITU Vendor ID TSTC 000433: *Jan 10 23:26:39.239 PCTime: DSL: Far End ITU Vendor ID Specific 0x0000 000434: *Jan 10 23:26:39.239 PCTime: DSL: Far End ITU Vendor STD Number 0x0002 000435: *Jan 10 23:26:39.239 PCTime: DSL(ATM0): Sent command 0x32 000436: *Jan 10 23:26:39.243 PCTime: DSL: Received response: 0x14 000437: *Jan 10 23:26:39.243 PCTime: DSL(ATM0): Near End ITU Country Code 0x0F 000438: *Jan 10 23:26:39.243 PCTime: DSL: Near End ITU Vendor ID STMI 000439: *Jan 10 23:26:39.243 PCTime: DSL: Near End ITU Vendor ID Specific 0x0000 000440: *Jan 10 23:26:39.243 PCTime: DSL: Near End ITU Vendor STD Number 0x0003 000441: *Jan 10 23:26:39.243 PCTime: ATM0 atmsar_update_us_bandwidth(): upstream bw =448 Kbps 000442: *Jan 10 23:26:39.243 PCTime: DSL: SM: [DMTDSL_DO_OPEN -> DMTDSL_SHOWTIME] 000443: *Jan 10 23:26:48.147 PCTime: ATM0: atmsar_vc_dlcx 000444: *Jan 10 23:26:48.147 PCTime: (ATM0)1a_enable: delay activation of vcd=1, vc=0x82EC1768 000445: *Jan 10 23:26:48.147 PCTime: atmsar enable ATM0 000446: *Jan 10 23:26:48.147 PCTime: ATM0: atmsar_bringup_interface: Interface and atm_db flags are UP 000447: *Jan 10 23:26:50.147 PCTime: %LINK-3-UPDOWN: Interface ATM0, changed state to up 000448: *Jan 10 23:26:50.147 PCTime: atmsar_atm_lineaction(ATM0): state=4 000449: *Jan 10 23:26:51.147 PCTime: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up ATM0 000450: *Jan 10 23:26:55.467 PCTime: ATM0: atmsar_1a_setup_vc, vcinfo = 0x82EC1768 000451: *Jan 10 23:26:55.467 PCTime: ATM0 atmsar_vc_setup: vcd 1 000452: *Jan 10 23:26:55.467 PCTime: atmsar_setup_cos(ATM0): vc:1 wred_name:- max_q:0 000453: *Jan 10 23:26:55.467 PCTime: ATM0: VC setup successful (vcd = 1) 000454: *Jan 10 23:26:55.467 PCTime: ATM0: atmsar_atm_get_stats,vcinfo = 0x0 000455: *Jan 10 23:26:55.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000456: *Jan 10 23:26:56.467 PCTime: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up 000457: *Jan 10 23:26:56.467 PCTime: Vi2 DDR: Dialer statechange to up 000458: *Jan 10 23:26:56.467 PCTime: %DIALER-6-BIND: Interface Vi2 bound to profile Di0 000459: *Jan 10 23:26:56.467 PCTime: Vi2 PPP: Using dialer call direction 000460: *Jan 10 23:26:56.467 PCTime: Vi2 PPP: Treating connection as a callout 000461: *Jan 10 23:26:56.467 PCTime: Vi2 PPP: Session handle[2E000004] Session id[7] 000462: *Jan 10 23:26:56.467 PCTime: Vi2 PPP: Phase is ESTABLISHING, Active Open 000463: *Jan 10 23:26:56.467 PCTime: Vi2 PPP: Authorization required 000464: *Jan 10 23:26:56.467 PCTime: Vi2 PPP: No remote authentication for call-out 000465: *Jan 10 23:26:56.467 PCTime: Vi2 LCP: O CONFREQ [Closed] id 8 len 10 000466: *Jan 10 23:26:56.467 PCTime: Vi2 LCP: MagicNumber 0x1A75D0B2 (0x05061A75D0B2) 000467: *Jan 10 23:26:56.467 PCTime: atmsar_vc_tx_start(82814914). 000468: *Jan 10 23:26:56.467 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x8289BF38 000469: *Jan 10 23:26:56.467 PCTime: atmsar_transmit_pak_wrapper: deq(8289BF38). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000470: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: I CONFREQ [REQsent] id 251 len 19 000471: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: MRU 32725 (0x01047FD5) 000472: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000473: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: MagicNumber 0x7416C6ED (0x05067416C6ED) 000474: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: O CONFACK [REQsent] id 251 len 19 000475: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: MRU 32725 (0x01047FD5) 000476: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: AuthProto CHAP (0x0305C22305) 000477: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: MagicNumber 0x7416C6ED (0x05067416C6ED) 000478: *Jan 10 23:26:56.515 PCTime: atmsar_vc_tx_start(82814914). 000479: *Jan 10 23:26:56.515 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82646FF8 000480: *Jan 10 23:26:56.515 PCTime: atmsar_transmit_pak_wrapper: deq(82646FF8). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000481: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: I CONFACK [ACKsent] id 8 len 10 000482: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: MagicNumber 0x1A75D0B2 (0x05061A75D0B2) 000483: *Jan 10 23:26:56.515 PCTime: Vi2 LCP: State is Open 000484: *Jan 10 23:26:56.519 PCTime: Vi2 PPP: No authorization without authentication 000485: *Jan 10 23:26:56.519 PCTime: Vi2 PPP: Phase is AUTHENTICATING, by the peer 000486: *Jan 10 23:26:56.519 PCTime: Vi2 LCP: I TERMREQ [Open] id 252 len 4 000487: *Jan 10 23:26:56.519 PCTime: Vi2 LCP: O TERMACK [Open] id 252 len 4 000488: *Jan 10 23:26:56.519 PCTime: atmsar_vc_tx_start(82814914). 000489: *Jan 10 23:26:56.519 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B8B090 000490: *Jan 10 23:26:56.519 PCTime: atmsar_transmit_pak_wrapper: deq(82B8B090). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000491: *Jan 10 23:26:56.519 PCTime: Vi2 PPP: Sending Acct Event[Down] id[5] 000492: *Jan 10 23:26:56.519 PCTime: Vi2 PPP: Phase is TERMINATING 000493: *Jan 10 23:26:56.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000494: *Jan 10 23:26:57.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000495: *Jan 10 23:26:58.511 PCTime: Vi2 LCP: TIMEout: State TERMsent 000496: *Jan 10 23:26:58.511 PCTime: Vi2 LCP: State is Closed 000497: *Jan 10 23:26:58.511 PCTime: Vi2 PPP: Phase is DOWN 000498: *Jan 10 23:26:58.511 PCTime: Vi2 PPP: Phase is ESTABLISHING, Passive Open 000499: *Jan 10 23:26:58.511 PCTime: Vi2 LCP: State is Listen 000500: *Jan 10 23:26:58.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000501: *Jan 10 23:26:59.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000502: *Jan 10 23:27:00.527 PCTime: Vi2 LCP: TIMEout: State Listen 000503: *Jan 10 23:27:00.527 PCTime: Vi2 PPP: Authorization required 000504: *Jan 10 23:27:00.527 PCTime: Vi2 PPP: No remote authentication for call-out 000505: *Jan 10 23:27:00.527 PCTime: Vi2 LCP: O CONFREQ [Listen] id 9 len 10 000506: *Jan 10 23:27:00.527 PCTime: Vi2 LCP: MagicNumber 0x1A75E094 (0x05061A75E094) 000507: *Jan 10 23:27:00.527 PCTime: atmsar_vc_tx_start(82814914). 000508: *Jan 10 23:27:00.527 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B21078 000509: *Jan 10 23:27:00.527 PCTime: atmsar_transmit_pak_wrapper: deq(82B21078). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000510: *Jan 10 23:27:00.563 PCTime: ATM0: AAL5 rx errors (status = 0C010000) 000511: *Jan 10 23:27:00.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000512: *Jan 10 23:27:01.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000513: *Jan 10 23:27:02.543 PCTime: Vi2 LCP: TIMEout: State REQsent 000514: *Jan 10 23:27:02.543 PCTime: Vi2 LCP: O CONFREQ [REQsent] id 10 len 10 000515: *Jan 10 23:27:02.543 PCTime: Vi2 LCP: MagicNumber 0x1A75E094 (0x05061A75E094) 000516: *Jan 10 23:27:02.543 PCTime: atmsar_vc_tx_start(82814914). 000517: *Jan 10 23:27:02.543 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x822F98F8 000518: *Jan 10 23:27:02.543 PCTime: atmsar_transmit_pak_wrapper: deq(822F98F8). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000519: *Jan 10 23:27:02.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000520: *Jan 10 23:27:03.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000521: *Jan 10 23:27:04.243 PCTime: DSL: Defect: LCDi: retraining 000522: *Jan 10 23:27:04.559 PCTime: Vi2 LCP: TIMEout: State REQsent 000523: *Jan 10 23:27:04.559 PCTime: Vi2 LCP: O CONFREQ [REQsent] id 11 len 10 000524: *Jan 10 23:27:04.559 PCTime: Vi2 LCP: MagicNumber 0x1A75E094 (0x05061A75E094) 000525: *Jan 10 23:27:04.559 PCTime: atmsar_vc_tx_start(82814914). 000526: *Jan 10 23:27:04.559 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82647AB4 000527: *Jan 10 23:27:04.559 PCTime: atmsar_transmit_pak_wrapper: deq(82647AB4). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000528: *Jan 10 23:27:04.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000529: *Jan 10 23:27:05.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000530: *Jan 10 23:27:06.575 PCTime: Vi2 LCP: TIMEout: State REQsent 000531: *Jan 10 23:27:06.575 PCTime: Vi2 LCP: O CONFREQ [REQsent] id 12 len 10 000532: *Jan 10 23:27:06.575 PCTime: Vi2 LCP: MagicNumber 0x1A75E094 (0x05061A75E094) 000533: *Jan 10 23:27:06.575 PCTime: atmsar_vc_tx_start(82814914). 000534: *Jan 10 23:27:06.575 PCTime: ATM0:atmsar_dequeue_pak, dequeued a pak = 0x82B1FE94 000535: *Jan 10 23:27:06.575 PCTime: atmsar_transmit_pak_wrapper: deq(82B1FE94). vcd: 1.atmsar_transmit_pak_wrapper : encap = Data 000536: *Jan 10 23:27:06.619 PCTime: ATM0: vcd = 1, safe_start called from periodic 000537: *Jan 10 23:27:06.743 PCTime: atmsar_atm_lineaction(ATM0): state=0 000538: *Jan 10 23:27:06.743 PCTime: ATM0: atmsar_1a_teardown_vc,vcinfo = 0x82EC1768 000539: *Jan 10 23:27:06.743 PCTime: atmsar_1a_teardown_vc(ATM0): vc:1 vpi:0 vci:38 000540: *Jan 10 23:27:06.743 PCTime: DSL: SM: [DMTDSL_SHOWTIME -> DMTDSL_RE_OPEN] 000541: *Jan 10 23:27:06.743 PCTime: DSL: Send ADSL_CLOSE command. 000542: *Jan 10 23:27:06.743 PCTime: DSL(ATM0): Sent command 0x4 000543: *Jan 10 23:27:07.287 PCTime: DSL: Received response: 0x25 000544: *Jan 10 23:27:07.287 PCTime: DSL: Connection closed 000545: *Jan 10 23:27:07.287 PCTime: DSL: SM: [DMTDSL_RE_OPEN -> DMTDSL_DO_OPEN] 000546: *Jan 10 23:27:07.291 PCTime: DSL: Send ADSL_OPEN command. 000547: *Jan 10 23:27:07.291 PCTime: DSL(ATM0): Using subfunction 0x0 000548: *Jan 10 23:27:07.291 PCTime: LOCAL:Max noise margin for power cutoff 31 000549: *Jan 10 23:27:07.291 PCTime: DSL(ATM0): Sent extended command 0x3 000550: *Jan 10 23:27:07.711 PCTime: Service policy input policy output applied on 0/38 000551: *Jan 10 23:27:07.715 PCTime: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down 000552: *Jan 10 23:27:07.715 PCTime: Vi2 PPP: Authorization required 000553: *Jan 10 23:27:07.715 PCTime: Vi2 PPP: No remote authentication for call-out 000554: *Jan 10 23:27:07.715 PCTime: Vi2 LCP: O CONFREQ [Closed] id 13 len 10 000555: *Jan 10 23:27:07.715 PCTime: Vi2 LCP: MagicNumber 0x1A75FCAC (0x05061A75FCAC) 000556: *Jan 10 23:27:07.715 PCTime: %DIALER-6-UNBIND: Interface Vi2 unbound from profile Di0 000557: *Jan 10 23:27:07.715 PCTime: Vi2 PPP: Sending Acct Event[Down] id[6] 000558: *Jan 10 23:27:07.715 PCTime: Vi2 LCP: State is Closed 000559: *Jan 10 23:27:07.715 PCTime: Vi2 PPP: Phase is DOWN 000560: *Jan 10 23:27:08.147 PCTime: ATM0: atmsar_vc_dlcx 000561: *Jan 10 23:27:08.743 PCTime: %LINK-3-UPDOWN: Interface ATM0, changed state to down 000562: *Jan 10 23:27:08.743 PCTime: atmsar_atm_lineaction(ATM0): state=0 000563: *Jan 10 23:27:09.743 PCTime: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to down 000564: *Jan 10 23:27:09.791 PCTime: DSL(ATM0): 1: Modem state = 0x9 000565: *Jan 10 23:27:12.291 PCTime: DSL(ATM0): 2: Modem state = 0x10 000566: *Jan 10 23:27:14.791 PCTime: DSL(ATM0): 3: Modem state = 0x10 (Line is up) Moz877W#show dsl int atm0 ATM0 Alcatel 20190 chipset information ATU-R (DS) ATU-C (US) Modem Status: Showtime (DMTDSL_SHOWTIME) DSL Mode: ITU G.992.1 (G.DMT) Annex A ITU STD NUM: 0x03 0x2 Vendor ID: 'STMI' 'TSTC' Vendor Specific: 0x0000 0x0000 Vendor Country: 0x0F 0xB5 Capacity Used: 100% 58% Noise Margin: 15.0 dB 20.0 dB Output Power: 20.0 dBm 12.5 dBm Attenuation: 41.0 dB 20.5 dB Defect Status: None None Last Fail Code: None Watchdog Counter: 0x85 Watchdog Resets: 0 Selftest Result: 0x00 Subfunction: 0x00 Interrupts: 26803 (0 spurious) PHY Access Err: 0 Activations: 3 LED Status: ON LED On Time: 100 LED Off Time: 100 Init FW: embedded Operation FW: embedded FW Version: 2.542 Interleave Fast Interleave Fast Speed (kbps): 6240 0 448 0 Cells: 0 0 381 0 Reed-Solomon EC: 0 0 0 0 CRC Errors: 0 0 0 0 Header Errors: 0 0 0 0 LOM Monitoring : Disabled DMT Bits Per Bin 000: 0 0 0 0 0 0 0 0 0 2 4 5 6 7 7 8 010: 8 8 8 9 9 9 8 8 8 8 7 7 6 5 4 0 020: 0 0 0 0 0 B B C C C C C C C A C 030: C C C C C C C C C C C B C C C C 040: 0 C B B B B B 2 B B B B B B B B 050: B B B B B B B A A A A A A A A A 060: A A A A A A A A A A A A A A A A 070: A A A A A 9 A A 9 A A 9 9 9 9 9 080: 9 9 9 9 9 9 9 9 8 9 9 9 9 9 9 9 090: 9 9 8 8 8 8 8 8 8 8 8 8 8 8 8 7 0A0: 7 5 8 8 8 7 8 8 8 8 8 8 7 7 7 7 0B0: 7 7 7 7 7 7 7 7 7 7 7 7 7 7 7 7 0C0: 7 7 7 7 7 7 7 7 7 7 7 7 5 5 6 6 0D0: 7 6 6 5 6 6 6 5 6 4 6 6 6 5 6 6 0E0: 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 5 0F0: 5 5 5 5 4 5 5 5 5 5 5 5 2 2 4 5 DSL: Training log buffer capability is not enabled Moz877W# (Line is down) Moz877W#show 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.1 (G.DMT) Annex A ITU STD NUM: 0x03 0x2 Vendor ID: 'STMI' 'TSTC' Vendor Specific: 0x0000 0x0000 Vendor Country: 0x0F 0xB5 Capacity Used: 100% 58% Noise Margin: 13.0 dB 20.0 dB Output Power: 20.0 dBm 12.5 dBm Attenuation: 41.0 dB 20.5 dB Defect Status: LCDi LOS LOF LCDi Last Fail Code: None Watchdog Counter: 0x3E Watchdog Resets: 0 Selftest Result: 0x00 Subfunction: 0x00 Interrupts: 26823 (0 spurious) PHY Access Err: 0 Activations: 6 LED Status: OFF LED On Time: 100 LED Off Time: 100 Init FW: embedded Operation FW: embedded FW Version: 2.542 Interleave Fast Interleave Fast Speed (kbps): 6240 0 448 0 Cells: 63 0 60844 0 Reed-Solomon EC: 3 0 192 193 CRC Errors: 400 0 204 192 Header Errors: 1 0 208 185 LOM Monitoring : Disabled DMT Bits Per Bin 000: 0 0 0 0 0 0 0 0 0 2 4 5 6 7 7 8 010: 8 8 8 9 9 9 8 8 8 8 7 7 6 5 4 0 020: 0 0 0 0 0 C C C C C C C C C A C 030: C C C C C C C C C C C C C C C C 040: 0 C B B B B B B B B 2 B B B B B 050: B B B B B B B A A A A A A A A A 060: A A A A A A A A A A A A A A A A 070: A A A A A 9 A A 9 A 9 9 9 9 9 9 080: A 9 9 9 9 9 9 9 9 9 9 9 9 9 9 9 090: 8 9 8 8 8 8 8 8 8 8 8 8 8 8 7 7 0A0: 7 5 8 8 8 7 8 8 8 8 8 7 8 8 7 7 0B0: 7 6 7 2 7 7 7 7 7 7 7 7 7 7 7 7 0C0: 7 7 7 7 7 7 7 7 6 7 7 7 5 4 6 6 0D0: 6 7 6 4 6 6 6 6 6 4 6 6 6 6 6 6 0E0: 6 6 5 6 5 5 5 6 6 5 5 5 5 5 5 5 0F0: 5 5 5 5 5 5 4 5 5 5 5 4 2 2 4 5 DSL: Training log buffer capability is not enabled