router 870 - debug shows dialer 1 success chap but atm0 failed,

John Peterson · ‎01-04-2012

Happy New Years Guys,

I have a cisco 870 router which I'm trying to connect to my ISP all the interfaces are in a up, up state. But I'm unable to ping any IP address on the internet.

When I do a debug ppp I can see that the username and password are correct with the dialer 1 interface as there is no errors and I can see success.

But when I shutdown the atm0 interface and then do a no shutdown I see a message called authentication failed.

How does the atm0 interface work with the dialer, what could be the problem?

Also I spoke to the ISP and they can't see any connection being made but the debug shows success. I also get a default gateway via the ISP but it is the incorrect default gateway as I can't ping the internet and the ISP confirms that the default gateway is incorrect.

Thanks

cadet alain · ‎01-04-2012

Hi,

Could you post the debug outputs.

Regards.

Alain

Don't forget to rate helpful posts.

John Peterson · ‎01-04-2012

I'm sorry I don't currently have them on me.

I believe this is a PPPoA connection as it using ATM when I need to configure a atm0.1 point-to-point interface or could I just configure the atm0 interface as normal?

Is there any debug commands which you could help me with?

Thanks

John Peterson · ‎01-05-2012

The error message which I received is

CHAP: I FAILURE id 2 len 25 msg is "Authentication failed"

But this only happens when the ATM is shutdown and then no shutdown is issued.

cadet alain · ‎01-05-2012

Hi,

when you reenable the ATM then there is a CHAP negotiation going on with your ISP and you receive a message inbound telling there was a problem.

Could you post your running config and also post outputs from debug ppp negotiation and debug ppp authentication

Regards.

Alain

Don't forget to rate helpful posts.

John Peterson · ‎01-05-2012

This is the ATM Debugs

001992: *Mar 1 23:05:53.147: ATM0 atmsar_1a_shutdown: state=6

001993: *Mar 1 23:05:53.147: ATM0: atmsar_shutdown, newstate = 6

001994: *Mar 1 23:05:53.147: DSL: SET: [DMTDSL_SHOWTIME -> DMTDSL_STOP]

001995: *Mar 1 23:05:53.147: Resetting ATM0

001996: *Mar 1 23:05:53.147: atmsar_1a_teardown_vc(ATM0): vc:1 vpi:0 vci:38

001997: *Mar 1 23:05:53.147: ATM(): IP multicast cache invalidated for ATM0

001998: *Mar 1 23:05:53.151: ATM: PVC removed, ATM0 VCD 1 (0/38)

001999: *Mar 1 23:05:53.483: atmsar_atm_lineaction(ATM0): state=6

002000: *Mar 1 23:05:53.483: DSL: SM: [DMTDSL_SHOWTIME -> DMTDSL_STOP]

002001: *Mar 1 23:05:53.983: DSL(ATM0): Sent command 0x4

002002: *Mar 1 23:05:54.507: DSL(ATM0): Received response: 0x25

002003: *Mar 1 23:05:54.507: DSL(ATM0): Connection closed

002004: *Mar 1 23:05:55.147: %LINK-5-CHANGED: Interface ATM0, changed state to administratively down

002005: *Mar 1 23:05:55.147: atmsar_atm_lineaction(ATM0): state=6

002006: *Mar 1 23:05:56.147: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to down

scorpion035(config-if)#no shut

scorpion035(config-if)#no shutdown

scorpion035(config-if)#

002007: *Mar 1 23:06:36.464: ATM0: atmsar_1a_reset

002008: *Mar 1 23:06:36.464: ATM0: atmsar_get_plim_info

002009: *Mar 1 23:06:36.464: ATM0:atmsar_update_plimtype

002010: *Mar 1 23:06:36.464: ATM0 atmsar_1a_reset: PLIM type is 18, Rate is 856Mbps

002011: *Mar 1 23:06:36.464: ATM0 atmsar_1a_shutdown: state=4

002012: *Mar 1 23:06:36.464: ATM0: atmsar_shutdown, newstate = 0

002013: *Mar 1 23:06:36.464: DSL: SET: [DMTDSL_STOP -> DMTDSL_INIT]

002014: *Mar 1 23:06:36.464: Resetting ATM0

002015: *Mar 1 23:06:36.464: atmsar_1a_config(ATM0)

002016: *Mar 1 23:06:36.464: atmsar_1a_enable(ATM0)

002017: *Mar 1 23:06:36.468: ATM0: atmsar_init

002018: *Mar 1 23:06:36.468: ATM0 atmsar_update_us_bandwidth(): upstream bw =856 Kbps

002019: *Mar 1 23:06:36.960: (ATM0)1a_enable: delay activation of vcd=1, vc=0x830BE9EC

002020: *Mar 1 23:06:36.964: DSL: SM: [DMTDSL_STOP -> DMTDSL_INIT]

002021: *Mar 1 23:06:37.040: DSL: SM: [DMTDSL_INIT -> DMTDSL_DLOAD_1]

002022: *Mar 1 23:06:37.040: DSL(ATM0): Downloading init_AMR-3.0.014_no_bist.bin

002023: *Mar 1 23:06:37.044: DSL:(ATM0) Downloaded 2 blocks... Finished!

002024: *Mar 1 23:06:37.044: DSL(ATM0): Sent command 0x14

002025: *Mar 1 23:06:38.464: %LINK-3-UPDOWN: Interface ATM0, changed state to down

002026: *Mar 1 23:06:38.464: atmsar_atm_lineaction(ATM0): state=0

002027: *Mar 1 23:06:39.044: DSL(ATM0): Received response: 0x80

002028: *Mar 1 23:06:39.044: DSL: SM: [DMTDSL_DLOAD_1 -> DMTDSL_DLOAD_2]

002029: *Mar 1 23:06:39.044: DSL(ATM0): Downloading AMR-3.0.014.bin

002030: *Mar 1 23:06:39.076: DSL(ATM0): Downloaded 100 blocks

002031: *Mar 1 23:06:39.108: DSL(ATM0): Downloaded 200 blocks

002032: *Mar 1 23:06:39.140: DSL(ATM0): Downloaded 300 blocks

002033: *Mar 1 23:06:39.176: DSL(ATM0): Downloaded 400 blocks

002034: *Mar 1 23:06:39.208: DSL(ATM0): Downloaded 500 blocks

002035: *Mar 1 23:06:39.240: DSL(ATM0): Downloaded 600 blocks

002036: *Mar 1 23:06:39.272: DSL(ATM0): Downloaded 700 blocks

002037: *Mar 1 23:06:39.308: DSL(ATM0): Downloaded 800 blocks

002038: *Mar 1 23:06:39.340: DSL(ATM0): Downloaded 900 blocks

002039: *Mar 1 23:06:39.373: DSL(ATM0): Downloaded 1000 blocks

002040: *Mar 1 23:06:39.405: DSL(ATM0): Downloaded 1100 blocks

002041: *Mar 1 23:06:39.437: DSL(ATM0): Downloaded 1200 blocks

002042: *Mar 1 23:06:39.473: DSL(ATM0): Downloaded 1300 blocks

002043: *Mar 1 23:06:39.509: DSL(ATM0): Downloaded 1400 blocks

002044: *Mar 1 23:06:39.541: DSL(ATM0): Downloaded 1500 blocks

002045: *Mar 1 23:06:39.573: DSL(ATM0): Downloaded 1600 blocks

002046: *Mar 1 23:06:39.605: DSL(ATM0): Downloaded 1700 blocks

002047: *Mar 1 23:06:39.641: DSL(ATM0): Downloaded 1800 blocks

002048: *Mar 1 23:06:39.673: DSL(ATM0): Downloaded 1900 blocks

002049: *Mar 1 23:06:39.705: DSL(ATM0): Downloaded 2000 blocks

002050: *Mar 1 23:06:39.737: DSL(ATM0): Downloaded 2100 blocks

002051: *Mar 1 23:06:39.773: DSL(ATM0): Downloaded 2200 blocks

002052: *Mar 1 23:06:39.805: DSL(ATM0): Downloaded 2300 blocks

002053: *Mar 1 23:06:39.837: DSL(ATM0): Downloaded 2400 blocks

002054: *Mar 1 23:06:39.873: DSL(ATM0): Downloaded 2500 blocks

002055: *Mar 1 23:06:39.905: DSL(ATM0): Downloaded 2600 blocks

002056: *Mar 1 23:06:39.941: DSL(ATM0): Downloaded 2700 blocks

002057: *Mar 1 23:06:39.985: DSL(ATM0): Downloaded 2800 blocks

002058: *Mar 1 23:06:40.017: DSL(ATM0): Downloaded 2900 blocks

002059: *Mar 1 23:06:40.049: DSL(ATM0): Downloaded 3000 blocks

002060: *Mar 1 23:06:40.081: DSL(ATM0): Downloaded 3100 blocks

002061: *Mar 1 23:06:40.117: DSL(ATM0): Downloaded 3200 blocks

002062: *Mar 1 23:06:40.149: DSL(ATM0): Downloaded 3300 blocks

002063: *Mar 1 23:06:40.181: DSL(ATM0): Downloaded 3400 blocks

002064: *Mar 1 23:06:40.213: DSL(ATM0): Downloaded 3500 blocks

002065: *Mar 1 23:06:40.245: DSL(ATM0): Downloaded 3600 blocks

002066: *Mar 1 23:06:40.281: DSL(ATM0): Downloaded 3700 blocks

002067: *Mar 1 23:06:40.313: DSL(ATM0): Downloaded 3800 blocks

002068: *Mar 1 23:06:40.345: DSL(ATM0): Downloaded 3900 blocks

002069: *Mar 1 23:06:40.377: DSL(ATM0): Downloaded 4000 blocks

002070: *Mar 1 23:06:40.409: DSL(ATM0): Downloaded 4100 blocks

002071: *Mar 1 23:06:40.417: DSL:(ATM0) Downloaded 4121 blocks... Finished!

002072: *Mar 1 23:06:40.417: DSL(ATM0): Sent command 0x14

002073: *Mar 1 23:06:42.417: set tx_gain_offset to 0

002074: *Mar 1 23:06:42.417: set rx_gain_offset to 0

002075: *Mar 1 23:06:42.417: set target_noise_margin_offset to 0

002076: *Mar 1 23:06:42.417: set max_bits_tone_limit to 15

002077: *Mar 1 23:06:42.417: changed current state to do open!!

002078: *Mar 1 23:06:42.417: DSL: SM: [DMTDSL_DLOAD_2 -> DMTDSL_DO_OPEN]

002079: *Mar 1 23:06:42.417: DSL(ATM0): Send ADSL_OPEN command.

002080: *Mar 1 23:06:42.417: DSL(ATM0): Using preferred open mode

002081: *Mar 1 23:06:42.417: DSL(ATM0): Using ITU sync first for 5 secs, then ANSI/ITU sync alternatively for 2 secs

002082: *Mar 1 23:06:42.417: DSL(ATM0): Using subfunction 0x0

002083: *Mar 1 23:06:42.417: LOCAL:Max noise margin for power cutoff 31

002084: *Mar 1 23:06:42.417: DSL(ATM0): GPCI[0] 0x5

002085: *Mar 1 23:06:42.417: DSL(ATM0): GPCI[1] 0x9

002086: *Mar 1 23:06:42.417: DSL(ATM0): GPCI[2] 0x1

002087: *Mar 1 23:06:42.417: DSL(ATM0): GPCI[3] 0x0

002088: *Mar 1 23:06:42.417: DSL(ATM0): Sent extended command 0x3

002089: *Mar 1 23:06:44.917: DSL(ATM0): 1: Modem state = 0x9

002090: *Mar 1 23:06:47.418: DSL(ATM0): 2: Modem state = 0x9

002091: *Mar 1 23:06:49.918: DSL(ATM0): 3: Modem state = 0x10

002092: *Mar 1 23:06:52.418: DSL(ATM0): 4: Modem state = 0x10

002093: *Mar 1 23:06:54.918: DSL(ATM0): 5: Modem state = 0x10

002094: *Mar 1 23:06:57.419: DSL(ATM0): 6: Modem state = 0x10

002095: *Mar 1 23:06:59.919: DSL(ATM0): 7: Modem state = 0x10

002096: *Mar 1 23:07:02.127: DSL(ATM0): Received response: 0x22

002097: *Mar 1 23:07:02.127: DSL(ATM0): Open failed: Protocol error received -- retrying

002098: *Mar 1 23:07:02.127: DSL(ATM0): sleep 5 seconds

002099: *Mar 1 23:07:07.128: DSL(ATM0): Send ADSL_OPEN command.

002100: *Mar 1 23:07:07.128: DSL(ATM0): Using preferred open mode

002101: *Mar 1 23:07:07.128: DSL(ATM0): Using ITU sync first for 5 secs, then ANSI/ITU sync alternatively for 2 secs

002102: *Mar 1 23:07:07.128: DSL(ATM0): Using subfunction 0x0

002103: *Mar 1 23:07:07.128: LOCAL:Max noise margin for power cutoff 31

002104: *Mar 1 23:07:07.128: DSL(ATM0): GPCI[0] 0x5

002105: *Mar 1 23:07:07.128: DSL(ATM0): GPCI[1] 0x9

002106: *Mar 1 23:07:07.128: DSL(ATM0): GPCI[2] 0x1

002107: *Mar 1 23:07:07.128: DSL(ATM0): GPCI[3] 0x0

002108: *Mar 1 23:07:07.128: DSL(ATM0): Sent extended command 0x3

002109: *Mar 1 23:07:09.628: DSL(ATM0): 1: Modem state = 0x9

002110: *Mar 1 23:07:12.129: DSL(ATM0): 2: Modem state = 0x9

002111: *Mar 1 23:07:14.629: DSL(ATM0): 3: Modem state = 0x10

002112: *Mar 1 23:07:17.129: DSL(ATM0): 4: Modem state = 0x10

002113: *Mar 1 23:07:19.630: DSL(ATM0): 5: Modem state = 0x10

002114: *Mar 1 23:07:22.130: DSL(ATM0): 6: Modem state = 0x10

002115: *Mar 1 23:07:24.630: DSL(ATM0): 7: Modem state = 0x10

002116: *Mar 1 23:07:24.990: DSL(ATM0): Received response: 0x24

002117: *Mar 1 23:07:24.990: DSL(ATM0): Showtime!

002118: *Mar 1 23:07:24.990: DSL(ATM0): Sent command 0x31

002119: *Mar 1 23:07:24.998: DSL(ATM0): Received response: 0x12

002120: *Mar 1 23:07:24.998: DSL(ATM0): operation mode 0x10000

002121: *Mar 1 23:07:24.998: DSL(ATM0): Sent extended command 0xC

002122: *Mar 1 23:07:25.210: DSL(ATM0): ext response 0xF received, data size 49

002123: *Mar 1 23:07:25.210: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49

002124: *Mar 1 23:07:25.210: DSL(ATM0): 0x01

002125: *Mar 1 23:07:25.210: DSL(ATM0): Get FAR End parameter failed

002126: *Mar 1 23:07:25.210: DSL(ATM0): Sent extended command 0xC

002127: *Mar 1 23:07:25.214: DSL(ATM0): ext response 0xF received, data size 49

002128: *Mar 1 23:07:25.214: DSL(ATM0): ADSL_GET_MANAGEMENT_COUNTERS_EXT - data length = 49

002129: *Mar 1 23:07:25.214: DSL(ATM0): 0x00

002130: *Mar 1 23:07:25.214: DSL(ATM0): Get NEAR End parameter failed

002131: *Mar 1 23:07:25.214: DSL(ATM0): Sent command 0x33

002132: *Mar 1 23:07:25.218: DSL(ATM0): Received response: 0x16

002133: *Mar 1 23:07:25.218: DSL(ATM0): Far End Chip Country Code 0xB5

002134: *Mar 1 23:07:25.218: DSL: Far End Chip Vendor ID IFTN

002135: *Mar 1 23:07:25.218: DSL: Far End Chip Vendor ID Specific 0x71BE

002136: *Mar 1 23:07:25.218: DSL: Far End ITU Vendor STD Number 0x0002

002137: *Mar 1 23:07:25.218: DSL(ATM0): Sent command 0x32

002138: *Mar 1 23:07:25.222: DSL(ATM0): Received response: 0x14

002139: *Mar 1 23:07:25.222: DSL(ATM0): Near End Chip Country Code 0x0F

002140: *Mar 1 23:07:25.222: DSL: Near End Chip Vendor ID STMI

002141: *Mar 1 23:07:25.222: DSL: Near End Chip Vendor ID Specific 0x0000

002142: *Mar 1 23:07:25.222: DSL: Near End ITU Vendor STD Number 0x0003

002143: *Mar 1 23:07:25.222: DSL(ATM0): Sent extended command 0x5

002144: *Mar 1 23:07:25.230: DSL(ATM0): Near End Modem Country Code 0xB5

002145: *Mar 1 23:07:25.230: DSL: Near End Modem Vendor ID CSCO

002146: *Mar 1 23:07:25.230: DSL: Near End Modem Vendor ID Specific 0x0000

002147: *Mar 1 23:07:25.230: DSL: Near End Modem Version 12.4(20)T6

002148: *Mar 1 23:07:25.230: DSL: Near End Modem Serial Number FCZ1514902Z

002149: *Mar 1 23:07:25.230: DSL(ATM0): get Near End extended ITU ID succeeded

002150: *Mar 1 23:07:25.230: DSL(ATM0): Sent extended command 0x5

002151: *Mar 1 23:07:25.382: DSL(ATM0): Far End Modem Country Code 0x00

002152: *Mar 1 23:07:25.382: DSL: Far End Modem Vendor ID

002153: *Mar 1 23:07:25.382: DSL: Far End Modem Vendor ID Specific 0x0000

002154: *Mar 1 23:07:25.386: DSL: Far End Modem Version

002155: *Mar 1 23:07:25.386: DSL: Far End Modem Serial Number

002156: *Mar 1 23:07:25.386: DSL(ATM0): get Far End extended ITU ID succeeded

002157: *Mar 1 23:07:25.386: Matching SAR to Line speed: Attempt number 1

cps 1 slots 29

APL Level 0 slots 29

APL Level 1 slots 29

APL Level 2 slots 29

002158: *Mar 1 23:07:25.386: ATM0: atmsar_get_plim_info

002159: *Mar 1 23:07:25.386: ATM0:atmsar_update_plimtype

002160: *Mar 1 23:07:25.386: ATM0 atmsar_update_us_bandwidth(): upstream bw =871 Kbps

002161: *Mar 1 23:07:25.386: DSL: SM: [DMTDSL_DO_OPEN -> DMTDSL_SHOWTIME]

002162: *Mar 1 23:07:32.815: ATM0: atmsar_vc_dlcx

002163: *Mar 1 23:07:32.815: (ATM0)1a_enable: delay activation of vcd=1, vc=0x830BE9EC

002164: *Mar 1 23:07:32.815: atmsar enable ATM0

002165: *Mar 1 23:07:32.815: ATM0: atmsar_bringup_interface: Interface and atm_db flags are UP

002166: *Mar 1 23:07:33.591: ATM: Repapulate, ATM0

002167: *Mar 1 23:07:33.591: ATM: PVC activated, ATM0 VCD 1 (0/38)

002168: *Mar 1 23:07:34.816: %LINK-3-UPDOWN: Interface ATM0, changed state to up

002169: *Mar 1 23:07:34.816: atmsar_atm_lineaction(ATM0): state=4

002170: *Mar 1 23:07:35.816: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up

002171: *Mar 1 23:07:41.228: ATM0: atmsar_1a_setup_vc, vcinfo = 0x830BE9EC

002172: *Mar 1 23:07:41.228: ATM0 atmsar_vc_setup: vcd 1

002173: *Mar 1 23:07:41.228: Fill up paramaters for PVC 0/38[1] - Request for CoS 0 PCR 0 SCR 0 MCR 0 Available 871

002174: *Mar 1 23:07:41.228: Scheduler parameters for 0/38. Type UBR. PCR 871

002175: *Mar 1 23:07:41.228: Total scheduled bandwidth after configuringPVC 0/38 will be 0

002176: *Mar 1 23:07:41.228: atmsar_setup_cos(ATM0): vc:1 wred_name:- max_q:0

002177: *Mar 1 23:07:41.228: ATM0: VC setup successful (vcd = 1)

002178: *Mar 1 23:07:41.228: ATM: PVC activated, ATM0 VCD 1 (0/38)

cadet alain · ‎01-05-2012

Hi,

We need the PPP debugs.

Regards.

Alain

Don't forget to rate helpful posts.

John Peterson · ‎01-05-2012

000599: *Mar 1 01:07:12.358: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to down

000600: *Mar 1 01:07:14.355: %LINK-3-UPDOWN: Interface Dialer1, changed state to up

000601: *Mar 1 01:07:32.873: %LINK-3-UPDOWN: Interface ATM0, changed state to up

000602: *Mar 1 01:07:33.029: %LINK-3-UPDOWN: Interface Virtual-Access2, changed state to up

000603: *Mar 1 01:07:33.029: %DIALER-6-BIND: Interface Vi2 bound to profile Di1

000604: *Mar 1 01:07:33.033: Vi2 PPP: Using dialer call direction

000605: *Mar 1 01:07:33.033: Vi2 PPP: Treating connection as a callout

000606: *Mar 1 01:07:33.033: Vi2 PPP: Session handle[5A00005B] Session id[99]

000607: *Mar 1 01:07:33.033: Vi2 PPP: Phase is ESTABLISHING, Active Open

000608: *Mar 1 01:07:33.033: Vi2 PPP: No remote authentication for call-out

000609: *Mar 1 01:07:33.033: Vi2 LCP: O CONFREQ [Closed] id 112 len 10

000610: *Mar 1 01:07:33.033: Vi2 LCP: MagicNumber 0xE4F4F99E (0x0506E4F4F99E)

000611: *Mar 1 01:07:33.265: Vi2 LCP: I CONFREQ [REQsent] id 52 len 19

000612: *Mar 1 01:07:33.265: Vi2 LCP: MRU 1500 (0x010405DC)

000613: *Mar 1 01:07:33.265: Vi2 LCP: AuthProto CHAP (0x0305C22305)

000614: *Mar 1 01:07:33.265: Vi2 LCP: MagicNumber 0x7029BC4A (0x05067029BC4A)

000615: *Mar 1 01:07:33.265: Vi2 LCP: O CONFACK [REQsent] id 52 len 19

000616: *Mar 1 01:07:33.265: Vi2 LCP: MRU 1500 (0x010405DC)

000617: *Mar 1 01:07:33.265: Vi2 LCP: AuthProto CHAP (0x0305C22305)

000618: *Mar 1 01:07:33.265: Vi2 LCP: MagicNumber 0x7029BC4A (0x05067029BC4A)

000619: *Mar 1 01:07:33.265: Vi2 LCP: I CONFACK [ACKsent] id 112 len 10

000620: *Mar 1 01:07:33.269: Vi2 LCP: MagicNumber 0xE4F4F99E (0x0506E4F4F99E)

000621: *Mar 1 01:07:33.269: Vi2 LCP: State is Open

000622: *Mar 1 01:07:33.269: Vi2 PPP: Phase is AUTHENTICATING, by the peer

000623: *Mar 1 01:07:33.281: Vi2 CHAP: I CHALLENGE id 1 len 36 from "bras-red9.l-far"

000624: *Mar 1 01:07:33.281: Vi2 CHAP: Using hostname from interface CHAP

000625: *Mar 1 01:07:33.281: Vi2 CHAP: Using password from interface CHAP

000626: *Mar 1 01:07:33.281: Vi2 CHAP: O RESPONSE id 1 len 51 from "XXXX"

000627: *Mar 1 01:07:33.873: %LINEPROTO-5-UPDOWN: Line protocol on Interface ATM0, changed state to up

000628: *Mar 1 01:07:35.481: Vi2 LCP: I CONFREQ [Open] id 1 len 15

000629: *Mar 1 01:07:35.481: Vi2 LCP: AuthProto CHAP (0x0305C22305)

000630: *Mar 1 01:07:35.481: Vi2 LCP: MagicNumber 0x9B1059B7 (0x05069B1059B7)

000631: *Mar 1 01:07:35.485: Vi2 PPP: Phase is TERMINATING

000632: *Mar 1 01:07:35.485: Vi2 PPP: No remote authentication for call-out

000633: *Mar 1 01:07:35.485: Vi2 PPP: Phase is ESTABLISHING

000634: *Mar 1 01:07:35.485: Vi2 LCP: O CONFREQ [Open] id 113 len 10

000635: *Mar 1 01:07:35.485: Vi2 LCP: MagicNumber 0xE4F50334 (0x0506E4F50334)

000636: *Mar 1 01:07:35.489: Vi2 LCP: O CONFACK [Open] id 1 len 15

000637: *Mar 1 01:07:35.489: Vi2 LCP: AuthProto CHAP (0x0305C22305)

000638: *Mar 1 01:07:35.489: Vi2 LCP: MagicNumber 0x9B1059B7 (0x05069B1059B7)

000639: *Mar 1 01:07:35.501: Vi2 LCP: I CONFACK [ACKsent] id 113 len 10

000640: *Mar 1 01:07:35.501: Vi2 LCP: MagicNumber 0xE4F50334 (0x0506E4F50334)

000641: *Mar 1 01:07:35.501: Vi2 LCP: State is Open

000642: *Mar 1 01:07:35.501: Vi2 PPP: Phase is AUTHENTICATING, by the peer

000643: *Mar 1 01:07:35.513: Vi2 CHAP: I CHALLENGE id 1 len 34 from "lts01.the.dsl"

000644: *Mar 1 01:07:35.517: Vi2 CHAP: Using hostname from interface CHAP

000645: *Mar 1 01:07:35.517: Vi2 CHAP: Using password from interface CHAP

000646: *Mar 1 01:07:35.517: Vi2 CHAP: O RESPONSE id 1 len 51 from "XXXX"

000647: *Mar 1 01:07:35.569: Vi2 LCP: I CONFREQ [Open] id 1 len 15

000648: *Mar 1 01:07:35.573: Vi2 LCP: AuthProto CHAP (0x0305C22305)

000649: *Mar 1 01:07:35.573: Vi2 LCP: MagicNumber 0xE5296FA7 (0x0506E5296FA7)

000650: *Mar 1 01:07:35.573: Vi2 PPP: Phase is TERMINATING

000651: *Mar 1 01:07:35.573: Vi2 PPP: No remote authentication for call-out

000652: *Mar 1 01:07:35.573: Vi2 PPP: Phase is ESTABLISHING

000653: *Mar 1 01:07:35.577: Vi2 LCP: O CONFREQ [Open] id 114 len 10

000654: *Mar 1 01:07:35.577: Vi2 LCP: MagicNumber 0xE4F5038D (0x0506E4F5038D)

000655: *Mar 1 01:07:35.577: Vi2 LCP: O CONFACK [Open] id 1 len 15

000656: *Mar 1 01:07:35.577: Vi2 LCP: AuthProto CHAP (0x0305C22305)

000657: *Mar 1 01:07:35.577: Vi2 LCP: MagicNumber 0xE5296FA7 (0x0506E5296FA7)

000658: *Mar 1 01:07:35.589: Vi2 LCP: I CONFACK [ACKsent] id 114 len 10

000659: *Mar 1 01:07:35.589: Vi2 LCP: MagicNumber 0xE4F5038D (0x0506E4F5038D)

000660: *Mar 1 01:07:35.589: Vi2 LCP: State is Open

000661: *Mar 1 01:07:35.589: Vi2 PPP: Phase is AUTHENTICATING, by the peer

000662: *Mar 1 01:07:35.597: Vi2 CHAP: I CHALLENGE id 2 len 30 from "tch.bras1"

000663: *Mar 1 01:07:35.601: Vi2 CHAP: Using hostname from interface CHAP

000664: *Mar 1 01:07:35.601: Vi2 CHAP: Using password from interface CHAP

000665: *Mar 1 01:07:35.601: Vi2 CHAP: O RESPONSE id 2 len 51 from "XXXXX"

000666: *Mar 1 01:07:35.629: Vi2 CHAP: I SUCCESS id 2 len 4

000667: *Mar 1 01:07:35.629: Vi2 PPP: Phase is FORWARDING, Attempting Forward

000668: *Mar 1 01:07:35.629: Vi2 PPP: Queue IPCP code[1] id[1]

000669: *Mar 1 01:07:35.629: Vi2 PPP: Phase is ESTABLISHING, Finish LCP

000670: *Mar 1 01:07:35.629: Vi2 PPP: Phase is UP

000671: *Mar 1 01:07:35.633: Vi2 IPCP: O CONFREQ [Closed] id 1 len 10

000672: *Mar 1 01:07:35.633: Vi2 IPCP: Address 0.0.0.0 (0x030600000000)

000673: *Mar 1 01:07:35.633: Vi2 PPP: Process pending ncp packets

000674: *Mar 1 01:07:35.633: Vi2 IPCP: Redirect packet to Vi2

000675: *Mar 1 01:07:35.633: Vi2 IPCP: I CONFREQ [REQsent] id 1 len 10

000676: *Mar 1 01:07:35.633: Vi2 IPCP: Address 46.247.0.70 (0x03062EF70046)

000677: *Mar 1 01:07:35.633: Vi2 IPCP: O CONFACK [REQsent] id 1 len 10

000678: *Mar 1 01:07:35.633: Vi2 IPCP: Address 46.247.0.70 (0x03062EF70046)

000679: *Mar 1 01:07:35.645: Vi2 IPCP: I CONFREJ [ACKsent] id 1 len 10

000680: *Mar 1 01:07:35.645: Vi2 IPCP: Address 0.0.0.0 (0x030600000000)

000681: *Mar 1 01:07:35.645: Vi2 IPCP: O CONFREQ [ACKsent] id 2 len 4

000682: *Mar 1 01:07:35.661: Vi2 IPCP: I CONFACK [ACKsent] id 2 len 4

000683: *Mar 1 01:07:35.661: Vi2 IPCP: State is Open

000684: *Mar 1 01:07:35.661: Di1 IPCP: Install route to 46.247.0.70

000685: *Mar 1 01:07:35.665: Vi2 IPCP: Add link info for cef entry 46.247.0.70

John Peterson · ‎01-05-2012

The route 46.247.0.70 which it is getting from the ISP is incorrect, the ip address should start with 176....

Thanks

paolo bevilacqua · ‎01-05-2012

You can override that with a default route pointing to dialer1.

And "no ppp ipcp default-route".

John Peterson · ‎01-05-2012

Which interface would this go into?

paolo bevilacqua · ‎01-05-2012

ip route commands are global.

John Peterson · ‎01-05-2012

I've done this but the route is still being injected:

003418: *Mar 1 01:57:25.363: Vi2 IPCP: State is Open

003419: *Mar 1 01:57:25.363: Di1 IPCP: Install route to 46.247.0.67

003420: *Mar 1 01:57:25.367: Vi2 IPCP: Add link info for cef entry 46.247.0.67

003421: *Mar 1 01:57:26.331: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access2, changed state to up

paolo bevilacqua · ‎01-05-2012

Check the no ... command above.

John Peterson · ‎01-05-2012

I have also included the no cmd, still inject the route.

router 870 - debug shows dialer 1 success chap but atm0 failed, why?