cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
543
Views
0
Helpful
6
Replies

PPPoe PAP Authentication Problem

lvinge
Level 1
Level 1

Following is a debug of an PPPoe PAP authentication attempt between a Cisco 2610 connected to a ADSL modem. When attempting to logon using PAP the message dated "*Feb 28 22:55:09.474" where "choice:" is being send back to the router appears to be causing an authentication problem. The ISP hasn't a clue. Any ideas.

Thanks

Lars

*Feb 28 22:55:08.043: %DIALER-6-BIND: Interface Vi1 bound to profile Di1

*Feb 28 22:55:08.047: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state t

o up

*Feb 28 22:55:08.063: Vi1 PPP: Treating connection as a callout

*Feb 28 22:55:08.063: Vi1 PPP: Phase is ESTABLISHING, Active Open [0 sess, 0 loa

d]

*Feb 28 22:55:08.067: Vi1 PPP: No remote authentication for call-out

*Feb 28 22:55:08.067: Vi1 LCP: O CONFREQ [Closed] id 1 len 10

*Feb 28 22:55:08.067: Vi1 LCP: MagicNumber 0x05CE8AB4 (0x050605CE8AB4)

*Feb 28 22:55:08.091: Vi1 LCP: I CONFREQ [REQsent] id 112 len 18

*Feb 28 22:55:08.091: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 22:55:08.091: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 22:55:08.091: Vi1 LCP: MagicNumber 0x08250D35 (0x050608250D35)

*Feb 28 22:55:08.095: Vi1 LCP: O CONFNAK [REQsent] id 112 len 8

*Feb 28 22:55:08.095: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 22:55:08.095: Vi1 LCP: I CONFACK [REQsent] id 1 len 10

*Feb 28 22:55:08.095: Vi1 LCP: MagicNumber 0x05CE8AB4 (0x050605CE8AB4)

*Feb 28 22:55:08.123: Vi1 LCP: I CONFREQ [ACKrcvd] id 113 len 18

*Feb 28 22:55:08.123: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 22:55:08.123: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 22:55:08.127: Vi1 LCP: MagicNumber 0x08250D35 (0x050608250D35)

*Feb 28 22:55:08.127: Vi1 LCP: O CONFNAK [ACKrcvd] id 113 len 8

*Feb 28 22:55:08.127: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 22:55:08.139: Vi1 LCP: I CONFREQ [ACKrcvd] id 114 len 18

*Feb 28 22:55:08.139: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 22:55:08.139: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 22:55:08.143: Vi1 LCP: MagicNumber 0x08250D35 (0x050608250D35)

*Feb 28 22:55:08.143: Vi1 LCP: O CONFNAK [ACKrcvd] id 114 len 8

*Feb 28 22:55:08.143: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 22:55:08.155: Vi1 LCP: I CONFREQ [ACKrcvd] id 115 len 18

*Feb 28 22:55:08.155: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 22:55:08.159: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 22:55:08.159: Vi1 LCP: MagicNumber 0x08250D35 (0x050608250D35)

*Feb 28 22:55:08.159: Vi1 LCP: O CONFNAK [ACKrcvd] id 115 len 8

*Feb 28 22:55:08.159: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 22:55:08.171: Vi1 LCP: I CONFREQ [ACKrcvd] id 116 len 18

*Feb 28 22:55:08.175: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 22:55:08.175: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 22:55:08.175: Vi1 LCP: MagicNumber 0x08250D35 (0x050608250D35)

*Feb 28 22:55:08.175: Vi1 LCP: O CONFNAK [ACKrcvd] id 116 len 8

*Feb 28 22:55:08.175: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 22:55:08.191: Vi1 LCP: I CONFREQ [ACKrcvd] id 117 len 18

*Feb 28 22:55:08.191: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 22:55:08.191: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 22:55:08.191: Vi1 LCP: MagicNumber 0x08250D35 (0x050608250D35)

*Feb 28 22:55:08.191: Vi1 LCP: O CONFREJ [ACKrcvd] id 117 len 8

*Feb 28 22:55:08.191: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 22:55:08.223: Vi1 LCP: I CONFREQ [ACKrcvd] id 118 len 14

*Feb 28 22:55:08.223: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 22:55:08.223: Vi1 LCP: MagicNumber 0x08250D35 (0x050608250D35)

*Feb 28 22:55:08.223: Vi1 LCP: O CONFACK [ACKrcvd] id 118 len 14

*Feb 28 22:55:08.227: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 22:55:08.227: Vi1 LCP: MagicNumber 0x08250D35 (0x050608250D35)

*Feb 28 22:55:08.227: Vi1 LCP: State is Open

*Feb 28 22:55:08.227: Vi1 PPP: Phase is AUTHENTICATING, by the peer [0 sess, 0 l

oad]

*Feb 28 22:55:08.231: Vi1 PAP: O AUTH-REQ id 20 len 22 from "aq15a6"

*Feb 28 22:55:09.474: Vi1 PAP: I AUTH-ACK id 20 len 13 msg is "choice: "

*Feb 28 22:55:09.474: Vi1 PPP: Phase is UP [0 sess, 0 load]

*Feb 28 22:55:09.474: Vi1 IPCP: O CONFREQ [Closed] id 1 len 10

*Feb 28 22:55:09.478: Vi1 IPCP: Address 0.0.0.0 (0x030600000000)

*Feb 28 22:55:09.478: Vi1 LCP: I TERMREQ [Open] id 119 len 4

*Feb 28 22:55:09.478: Vi1 LCP: O TERMACK [Open] id 119 len 4

*Feb 28 22:55:10.475: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Ac

cess1, changed state to up

*Feb 28 22:55:11.473: Vi1 IPCP: TIMEout: State REQsent

*Feb 28 22:55:11.473: Vi1 IPCP: O CONFREQ [REQsent] id 2 len 10

*Feb 28 22:55:11.473: Vi1 IPCP: Address 0.0.0.0 (0x030600000000)

*Feb 28 22:55:11.477: Vi1 LCP: TIMEout: State TERMsent

*Feb 28 22:55:11.477: Vi1 LCP: State is Closed

*Feb 28 22:55:11.477: Vi1 IPCP: State is Closed

*Feb 28 22:55:11.477: Vi1 PPP: Phase is DOWN [0 sess, 0 load]

*Feb 28 22:55:11.477: %DIALER-6-UNBIND: Interface Vi1 unbound from profile Di1

*Feb 28 22:55:11.481: Vi1 PPP: Phase is ESTABLISHING, Passive Open [0 sess, 0 lo

ad]

*Feb 28 22:55:11.481: Vi1 PPP: No remote authentication for call-out

*Feb 28 22:55:11.481: Vi1 LCP: State is Listen

*Feb 28 22:55:11.573: Vi1 LCP: State is Closed

*Feb 28 22:55:11.577: Vi1 PPP: Phase is DOWN [0 sess, 0 load]

*Feb 28 22:55:12.478: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access1, changed state to down

6 Replies 6

makchitale
Level 6
Level 6

Feb 28 22:55:08.227: Vi1 LCP: State is Open

*Feb 28 22:55:08.227: Vi1 PPP: Phase is AUTHENTICATING, by the peer [0 sess, 0 load]

*Feb 28 22:55:08.231: Vi1 PAP: O AUTH-REQ id 20 len 22 from "aq15a6"

*Feb 28 22:55:09.474: Vi1 PAP: I AUTH-ACK id 20 len 13 msg is "choice: "

*Feb 28 22:55:09.474: Vi1 PPP: Phase is UP [0 sess, 0 load]

*Feb 28 22:55:09.474: Vi1 IPCP: O CONFREQ [Closed] id 1 len 10

*Feb 28 22:55:09.478: Vi1 IPCP: Address 0.0.0.0 (0x030600000000)<===

*Feb 28 22:55:09.478: Vi1 LCP: I TERMREQ [Open] id 119 len 4 <====

The problem seems to be during IPCP on the aggregation router, we request an IP address from the ISP (send out 0.0.0.0) but immediately get back an Termination request (TERMREQ).

Thanks, Mak.

Mak,

Thanks for you response. The reason I was using dhcp instead of the static address we requested was that the subnet mask they claim I need to use is 255.255.255.255 but the router won't accept it. So I thought I would tackle the auth problem first then the mask problem. The interesting thing is that a Linksys BEFSR11 will get an address ok but the 2610 fails. As soon as I brought this up with the ISP they said then it not our problem. If I could find a way determining the mask if it in fact is not 255.255.255.255 then I could go the static route since it appears that the auth is working.

Thanks

Lars

In IPCP negotation we do not negotiate the address subnet mask....I am not very clear with what the ISP is telling you, can you try out the following:

conf term

interface loopback10

ip address x.x.x.x 255.255.255.255 (where x.x.x.x is the static IP address given by the ISP)

int dialer 1

ip unnumbered loopback10

Capture debug ppp nego with these commands added.

Thanks, Mak.

Mak,

Here is the debug and the relevant parts of the config.

Thanks

Lars

interface Loopback10

ip address 66.112.64.166 255.255.255.255

interface Ethernet0/1

no ip address

ip nat outside

no ip route-cache

no ip mroute-cache

shutdown

half-duplex

pppoe enable

pppoe-client dial-pool-number 1

no cdp enable

interface Dialer1

ip unnumbered Loopback10

ip mtu 1492

ip nat outside

encapsulation ppp

no ip mroute-cache

dialer pool 1

dialer-group 1

no cdp enable

ppp pap sent-username xzy09875 password 7 065E0a73441d0F0107

*Feb 28 18:15:56.507: %LINK-3-UPDOWN: Interface Ethernet0/1, changed state to up

*Feb 28 18:15:57.508: %LINEPROTO-5-UPDOWN: Line protocol on Interface Ethernet0/

1, changed state to up

*Feb 28 18:16:05.369: Vi1 PPP: Phase is DOWN, Setup [0 sess, 0 load]

*Feb 28 18:16:05.373: %DIALER-6-BIND: Interface Vi1 bound to profile Di1

*Feb 28 18:16:05.377: %LINK-3-UPDOWN: Interface Virtual-Access1, changed state t

o up

*Feb 28 18:16:05.393: Vi1 PPP: Treating connection as a callout

*Feb 28 18:16:05.397: Vi1 PPP: Phase is ESTABLISHING, Active Open [0 sess, 0 loa

d]

*Feb 28 18:16:05.397: Vi1 PPP: No remote authentication for call-out

*Feb 28 18:16:05.397: Vi1 LCP: O CONFREQ [Closed] id 1 len 10

*Feb 28 18:16:05.397: Vi1 LCP: MagicNumber 0x04CF1187 (0x050604CF1187)

*Feb 28 18:16:05.421: Vi1 LCP: I CONFREQ [REQsent] id 158 len 18

*Feb 28 18:16:05.421: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 18:16:05.421: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 18:16:05.421: Vi1 LCP: MagicNumber 0x083046E2 (0x0506083046E2)

*Feb 28 18:16:05.421: Vi1 LCP: O CONFNAK [REQsent] id 158 len 8

*Feb 28 18:16:05.425: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 18:16:05.425: Vi1 LCP: I CONFACK [REQsent] id 1 len 10

*Feb 28 18:16:05.425: Vi1 LCP: MagicNumber 0x04CF1187 (0x050604CF1187)

*Feb 28 18:16:05.437: Vi1 LCP: I CONFREQ [ACKrcvd] id 159 len 18

*Feb 28 18:16:05.437: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 18:16:05.437: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 18:16:05.437: Vi1 LCP: MagicNumber 0x083046E2 (0x0506083046E2)

*Feb 28 18:16:05.441: Vi1 LCP: O CONFNAK [ACKrcvd] id 159 len 8

*Feb 28 18:16:05.441: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 18:16:05.453: Vi1 LCP: I CONFREQ [ACKrcvd] id 160 len 18

*Feb 28 18:16:05.453: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 18:16:05.453: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 18:16:05.453: Vi1 LCP: MagicNumber 0x083046E2 (0x0506083046E2)

*Feb 28 18:16:05.457: Vi1 LCP: O CONFNAK [ACKrcvd] id 160 len 8

*Feb 28 18:16:05.457: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 18:16:05.469: Vi1 LCP: I CONFREQ [ACKrcvd] id 161 len 18

*Feb 28 18:16:05.469: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 18:16:05.469: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 18:16:05.473: Vi1 LCP: MagicNumber 0x083046E2 (0x0506083046E2)

*Feb 28 18:16:05.473: Vi1 LCP: O CONFNAK [ACKrcvd] id 161 len 8

*Feb 28 18:16:05.473: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 18:16:05.489: Vi1 LCP: I CONFREQ [ACKrcvd] id 162 len 18

*Feb 28 18:16:05.489: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 18:16:05.489: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 18:16:05.489: Vi1 LCP: MagicNumber 0x083046E2 (0x0506083046E2)

*Feb 28 18:16:05.489: Vi1 LCP: O CONFNAK [ACKrcvd] id 162 len 8

*Feb 28 18:16:05.493: Vi1 LCP: MRU 1500 (0x010405DC)

*Feb 28 18:16:05.522: Vi1 LCP: I CONFREQ [ACKrcvd] id 163 len 18

*Feb 28 18:16:05.522: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 18:16:05.522: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 18:16:05.522: Vi1 LCP: MagicNumber 0x083046E2 (0x0506083046E2)

*Feb 28 18:16:05.522: Vi1 LCP: O CONFREJ [ACKrcvd] id 163 len 8

*Feb 28 18:16:05.526: Vi1 LCP: MRU 1492 (0x010405D4)

*Feb 28 18:16:05.538: Vi1 LCP: I CONFREQ [ACKrcvd] id 164 len 14

*Feb 28 18:16:05.538: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 18:16:05.538: Vi1 LCP: MagicNumber 0x083046E2 (0x0506083046E2)

*Feb 28 18:16:05.538: Vi1 LCP: O CONFACK [ACKrcvd] id 164 len 14

*Feb 28 18:16:05.538: Vi1 LCP: AuthProto PAP (0x0304C023)

*Feb 28 18:16:05.542: Vi1 LCP: MagicNumber 0x083046E2 (0x0506083046E2)

*Feb 28 18:16:05.542: Vi1 LCP: State is Open

*Feb 28 18:16:05.542: Vi1 PPP: Phase is AUTHENTICATING, by the peer [0 sess, 0 l

oad]

*Feb 28 18:16:05.542: Vi1 PAP: O AUTH-REQ id 5 len 22 from "ctr09875"

*Feb 28 18:16:06.788: Vi1 PAP: I AUTH-ACK id 5 len 13 msg is "choice: "

*Feb 28 18:16:06.788: Vi1 PPP: Phase is UP [0 sess, 0 load]

*Feb 28 18:16:06.788: Vi1 IPCP: O CONFREQ [Closed] id 1 len 10

*Feb 28 18:16:06.792: Vi1 IPCP: Address 66.112.64.166 (0x0306427040A6)

*Feb 28 18:16:06.792: Vi1 LCP: I TERMREQ [Open] id 165 len 4

*Feb 28 18:16:06.792: Vi1 LCP: O TERMACK [Open] id 165 len 4

*Feb 28 18:16:07.789: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Ac

cess1, changed state to up

*Feb 28 18:16:08.787: Vi1 IPCP: TIMEout: State REQsent

*Feb 28 18:16:08.787: Vi1 IPCP: O CONFREQ [REQsent] id 2 len 10

*Feb 28 18:16:08.787: Vi1 IPCP: Address 66.112.64.166 (0x0306427040A6)

*Feb 28 18:16:08.791: Vi1 LCP: TIMEout: State TERMsent

*Feb 28 18:16:08.791: Vi1 LCP: State is Closed

*Feb 28 18:16:08.791: Vi1 IPCP: State is Closed

*Feb 28 18:16:08.791: Vi1 PPP: Phase is DOWN [0 sess, 0 load]

*Feb 28 18:16:08.791: %DIALER-6-UNBIND: Interface Vi1 unbound from profile Di1

*Feb 28 18:16:08.795: Vi1 PPP: Phase is ESTABLISHING, Passive Open [0 sess, 0 lo

ad]

*Feb 28 18:16:08.795: Vi1 PPP: No remote authentication for call-out

*Feb 28 18:16:08.795: Vi1 LCP: State is Listen

*Feb 28 18:16:08.887: Vi1 LCP: State is Closed

*Feb 28 18:16:08.887: Vi1 PPP: Phase is DOWN [0 sess, 0 load]

*Feb 28 18:16:09.793: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Ac

cess1, changed state to down

We see the same point of failure here....if the ISP is looking for a static address, we are sending it but still get a TERMREQ from their end during IPCP phase.

Just curious, I see different username sent & configured under the dialer1.

Thanks, Mak.

Mak,

I just changed it for posting. I am still using the same username and password. I will try the ISP again tomorrow and see how far I get.

Thanks again

Lars