cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
609
Views
0
Helpful
2
Replies
Highlighted
Beginner

PPPoE Authentication Failure

I have the following PPPoE configuration on a router:

 

aaa new-model
!
aaa authentication ppp default group radius
aaa authentication dot1x default group radius
aaa authorization network default group radius 
aaa accounting delay-start
aaa accounting dot1x default start-stop group radius
aaa accounting network default start-stop group radius
!
aaa session-id common
!
bba-group pppoe global
 virtual-template 1
interface GigabitEthernet0/1/0
 description PPPoE
 ip address 172.16.153.1 255.255.255.252
 ip rip advertise 4
 load-interval 30
 duplex auto
 speed auto
 pppoe enable group global
!
interface Virtual-Template1
 mtu 1492
 ip unnumbered GigabitEthernet0/1/0
 peer default ip address pool CLIENT
 ppp authentication pap chap
!
ip local pool CLIENT 172.16.153.129 172.16.153.254
!
radius-server attribute 6 on-for-login-auth
radius-server attribute nas-port-id include vendor-class-id plus remote-id plus circuit-id 
!
radius server radius1
 address ipv4 172.16.152.190 auth-port 1812 acct-port 1813
 key 7 myserverkey
!
radius server radius2
 address ipv4 10.1.115.183 auth-port 1812 acct-port 1813
 key 7 myserverkey
!

I am trying to authenticate with PPPoE using a computer plugged into GigabitEthernet0/1/0 (Windows 10). My credentials are rejected, even though the RADIUS server passes an Access-Accept method and the router seems to recognize it:

 

*Aug 22 10:23:53.130:  Service tag: NULL Tag
*Aug 22 10:23:53.130: PPPoE : encap string prepared
contiguous pak, size 20
*Aug 22 10:23:53.130: [11]PPPoE 11: Access IE handle allocated
*Aug 22 10:23:53.130: [11]PPPoE 11: AAA get retrieved attrs
*Aug 22 10:23:53.130: [11]PPPoE 11: AAA get nas port details
*Aug 22 10:23:53.130: [11]PPPoE 11: Error adjusting nas port format did 
*Aug 22 10:23:53.130: AAA/BIND(0001703E): Bind i/f Virtual-Template1 
*Aug 22 10:23:53.130: [11]PPPoE 11: AAA get dynamic attrs
*Aug 22 10:23:53.130: [11]PPPoE 11: AAA unique ID 1703E allocated
*Aug 22 10:23:53.130: [11]PPPoE 11: AAA method list  set
*Aug 22 10:23:53.134: [11]PPPoE 11: Service request sent to SSS
*Aug 22 10:23:53.134: [11]PPPoE 11: Created, Service: None R:aaaa.bbbb.b8c0 L:aaaa.bbbb.6343 Gi0/1/0
*Aug 22 10:23:53.134: [11]PPPoE 11: State NAS_PORT_POLICY_INQUIRY    Event SSS MORE KEYS
*Aug 22 10:23:53.134: PPP: Alloc Context [18E79F0]
*Aug 22 10:23:53.134: ppp11 PPP: Phase is ESTABLISHING
*Aug 22 10:23:53.134: [11]PPPoE 11: data path set to PPP
*Aug 22 10:23:53.134: [11]PPPoE 11: Segment (SSS class): PROVISION
*Aug 22 10:23:53.134: [11]PPPoE 11: State PROVISION_PPP    Event SSM PROVISIONED
*Aug 22 10:23:53.134: [11]PPPoE 11: O PADS  R:aaaa.bbbb.6343 L:aaaa.bbbb.b8c0 Gi0/1/0
contiguous pak, size 60
*Aug 22 10:23:53.134: ppp11 PPP: Using vpn set call direction
*Aug 22 10:23:53.134: ppp11 PPP: Treating connection as a callin
*Aug 22 10:23:53.134: ppp11 PPP: Session handle[A300000B] Session id[11]
*Aug 22 10:23:53.134: ppp11 LCP: Event[OPEN] State[Initial to Starting]
*Aug 22 10:23:53.134: ppp11 PPP LCP: Enter passive mode, state[Stopped]
*Aug 22 10:23:53.154: ppp11 LCP: I CONFREQ [Stopped] id 0 len 21
*Aug 22 10:23:53.154: ppp11 LCP:    MRU 1480 (0x010405C8)
*Aug 22 10:23:53.154: ppp11 LCP:    MagicNumber 0x6C6B106A (0x05066C6B106A)
*Aug 22 10:23:53.154: ppp11 LCP:    PFC (0x0702)
*Aug 22 10:23:53.154: ppp11 LCP:    ACFC (0x0802)
*Aug 22 10:23:53.154: ppp11 LCP:    Callback 6 (0x0D0306)
*Aug 22 10:23:53.154: ppp11 LCP: O CONFREQ [Stopped] id 1 len 18
*Aug 22 10:23:53.154: ppp11 LCP:    MRU 1492 (0x010405D4)
*Aug 22 10:23:53.154: ppp11 LCP:    AuthProto PAP (0x0304C023)
*Aug 22 10:23:53.154: ppp11 LCP:    MagicNumber 0x44BA631C (0x050644BA631C)
*Aug 22 10:23:53.154: ppp11 LCP: O CONFREJ [Stopped] id 0 len 7
*Aug 22 10:23:53.154: ppp11 LCP:    Callback 6 (0x0D0306)
*Aug 22 10:23:53.154: ppp11 LCP: Event[Receive ConfReq-] State[Stopped to REQsent]
*Aug 22 10:23:53.190: ppp11 LCP: I CONFACK [REQsent] id 1 len 18
*Aug 22 10:23:53.190: ppp11 LCP:    MRU 1492 (0x010405D4)
*Aug 22 10:23:53.190: ppp11 LCP:    AuthProto PAP (0x0304C023)
*Aug 22 10:23:53.190: ppp11 LCP:    MagicNumber 0x44BA631C (0x050644BA631C)
*Aug 22 10:23:53.190: ppp11 LCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]
*Aug 22 10:23:53.190: ppp11 LCP: I CONFREQ [ACKrcvd] id 1 len 18
*Aug 22 10:23:53.190: ppp11 LCP:    MRU 1480 (0x010405C8)
*Aug 22 10:23:53.190: ppp11 LCP:    MagicNumber 0x6C6B106A (0x05066C6B106A)
*Aug 22 10:23:53.190: ppp11 LCP:    PFC (0x0702)
*Aug 22 10:23:53.190: ppp11 LCP:    ACFC (0x0802)
*Aug 22 10:23:53.190: ppp11 LCP: O CONFNAK [ACKrcvd] id 1 len 8
*Aug 22 10:23:53.190: ppp11 LCP:    MRU 1492 (0x010405D4)
*Aug 22 10:23:53.190: ppp11 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
*Aug 22 10:23:53.198: ppp11 LCP: I CONFREQ [ACKrcvd] id 2 len 18
*Aug 22 10:23:53.198: ppp11 LCP:    MRU 1480 (0x010405C8)
*Aug 22 10:23:53.198: ppp11 LCP:    MagicNumber 0x6C6B106A (0x05066C6B106A)
*Aug 22 10:23:53.198: ppp11 LCP:    PFC (0x0702)
*Aug 22 10:23:53.198: ppp11 LCP:    ACFC (0x0802)
*Aug 22 10:23:53.198: ppp11 LCP: O CONFNAK [ACKrcvd] id 2 len 8
*Aug 22 10:23:53.198: ppp11 LCP:    MRU 1492 (0x010405D4)
*Aug 22 10:23:53.198: ppp11 LCP: Event[Receive ConfReq-] State[ACKrcvd to ACKrcvd]
*Aug 22 10:23:53.202: ppp11 LCP: I CONFREQ [ACKrcvd] id 3 len 18
*Aug 22 10:23:53.202: ppp11 LCP:    MRU 1492 (0x010405D4)
*Aug 22 10:23:53.202: ppp11 LCP:    MagicNumber 0x6C6B106A (0x05066C6B106A)
*Aug 22 10:23:53.202: ppp11 LCP:    PFC (0x0702)
*Aug 22 10:23:53.202: ppp11 LCP:    ACFC (0x0802)
*Aug 22 10:23:53.202: ppp11 LCP: O CONFACK [ACKrcvd] id 3 len 18
*Aug 22 10:23:53.202: ppp11 LCP:    MRU 1492 (0x010405D4)
*Aug 22 10:23:53.202: ppp11 LCP:    MagicNumber 0x6C6B106A (0x05066C6B106A)
*Aug 22 10:23:53.202: ppp11 LCP:    PFC (0x0702)
*Aug 22 10:23:53.202: ppp11 LCP:    ACFC (0x0802)
*Aug 22 10:23:53.202: ppp11 LCP: Event[Receive ConfReq+] State[ACKrcvd to Open]
*Aug 22 10:23:53.206: ppp11 LCP: I IDENTIFY [Open] id 4 len 18 magic 0x6C6B106AMSRASV5.20
*Aug 22 10:23:53.206: ppp11 LCP: I IDENTIFY [Open] id 5 len 31 magic 0x6C6B106AMSRAS-0-DESKTOP-0D1C4OS
*Aug 22 10:23:53.206: ppp11 LCP: I IDENTIFY [Open] id 6 len 24 magic 0x6C6B106A:TKbbJ,I*+RB_\$_
*Aug 22 10:23:53.210: ppp11 PPP: Queue PAP code[1] id[37]
*Aug 22 10:23:53.226: ppp11 PPP: Phase is AUTHENTICATING, by this end
*Aug 22 10:23:53.226: ppp11 PAP: Redirect packet to ppp11
*Aug 22 10:23:53.226: ppp11 PAP: I AUTH-REQ id 37 len 35 from "pppoetest@myrealm"
*Aug 22 10:23:53.226: ppp11 PAP: Authenticating peer pppoetest@myrealm
*Aug 22 10:23:53.226: ppp11 PPP: Phase is FORWARDING, Attempting Forward
*Aug 22 10:23:53.226: ppp11 LCP: State is Open
*Aug 22 10:23:53.226: ppp11 PPP: Phase is AUTHENTICATING, Unauthenticated User
*Aug 22 10:23:53.226: AAA/AUTHEN/PPP (0001703E): Pick method list 'default' 
*Aug 22 10:23:53.226: ppp11 PPP: Sent PAP LOGIN Request
*Aug 22 10:23:53.226: RADIUS/ENCODE(0001703E):Orig. component type = PPPoE
*Aug 22 10:23:53.226: RADIUS: DSL line rate attributes successfully added
*Aug 22 10:23:53.226: RADIUS(0001703E): Config NAS IP: 0.0.0.0
*Aug 22 10:23:53.226: RADIUS(0001703E): Config NAS IPv6: ::
*Aug 22 10:23:53.226: RADIUS/ENCODE(0001703E): acct_session_id: 94260
*Aug 22 10:23:53.226: RADIUS(0001703E): sending
*Aug 22 10:23:53.226: RADIUS/ENCODE: Best Local IP-Address 172.16.152.1 for Radius-Server 172.16.152.190
*Aug 22 10:23:53.226: RADIUS(0001703E): Send Access-Request to 172.16.152.190:1812 id 1645/11, len 145
*Aug 22 10:23:53.226: RADIUS:  authenticator 40 B1 36 F0 2D 32 66 89 - 73 26 DA 6D 62 C5 84 75
*Aug 22 10:23:53.226: RADIUS:  Framed-Protocol     [7]   6   PPP                       [1]
*Aug 22 10:23:53.226: RADIUS:  User-Name           [1]   27  "pppoetest@myrealm"
*Aug 22 10:23:53.226: RADIUS:  User-Password       [2]   18  *
*Aug 22 10:23:53.226: RADIUS:  NAS-Port-Type       [61]  6   Virtual                   [5]
*Aug 22 10:23:53.226: RADIUS:  NAS-Port            [5]   6   0                         
*Aug 22 10:23:53.226: RADIUS:  NAS-Port-Id         [87]  9   "0/0/1/0"
*Aug 22 10:23:53.226: RADIUS:  Vendor, Cisco       [26]  41  
*Aug 22 10:23:53.226: RADIUS:   Cisco AVpair       [1]   35  "client-mac-address=aaaa.bbbb.6343"
*Aug 22 10:23:53.226: RADIUS:  Service-Type        [6]   6   Framed                    [2]
*Aug 22 10:23:53.226: RADIUS:  NAS-IP-Address      [4]   6   172.16.152.1             
*Aug 22 10:23:53.226: RADIUS(0001703E): Sending a IPv4 Radius Packet
*Aug 22 10:23:53.226: RADIUS(0001703E): Started 5 sec timeout
*Aug 22 10:23:53.274: AAA/BIND(0001703F): Bind i/f  
*Aug 22 10:23:53.274: AAA/AUTHEN/LOGIN (0001703F): Pick method list ' Permanent Local' 
*Aug 22 10:23:53.446: AAA/AUTHEN/LOGIN (0001703C): Pick method list ' Permanent Local' 
*Aug 22 10:23:53.558: RADIUS: Received from id 1645/11 172.16.152.190:1812, Access-Accept, len 195
*Aug 22 10:23:53.558: RADIUS:  authenticator 53 ED 22
*Aug 22 10:23:53.558: RADIUS:  Framed-Protocol     [7]   6   PPP                       [1]
*Aug 22 10:23:53.558: RADIUS:  Framed-Compression  [13]  6   VJ TCP/IP Header Compressi[1]
*Aug 22 10:23:53.558: RADIUS:  Framed-IP-Address   [8]   6   255.255.255.254           
*Aug 22 10:23:53.558: RADIUS:  Framed-IP-Netmask   [9]   6   255.255.255.255           
*Aug 22 10:23:53.558: RADIUS:  Framed-MTU          [12]  6   1452                      
*Aug 22 10:23:53.558: RADIUS:  Service-Type        [6]   6   Framed                    [2]
*Aug 22 10:23:53.558: RADIUS:  Session-Timeout     [27]  6   86400                     
*Aug 22 10:23:53.558: RADIUS:  Idle-Timeout        [28]  6   86400                     
*Aug 22 10:23:53.558: RADIUS:  Acct-Interim-Interva[85]  6   3600                      
*Aug 22 10:23:53.558: RADIUS:  Vendor, Cisco       [26]  37  
*Aug 22 10:23:53.558: RADIUS:   Cisco AVpair       [1]   31  "ip:ip-unnumbered=Loopback1245"
*Aug 22 10:23:53.558: RADIUS:  Vendor, Cisco       [26]  32  
*Aug 22 10:23:53.558: RADIUS:   Cisco AVpair       [1]   26  "ip:addr-pool=ippool1"
*Aug 22 10:23:53.558: RADIUS:  Vendor, Cisco       [26]  52  
*Aug 22 10:23:53.558: RADIUS:   Cisco AVpair       [1]   46  "ip:dns-servers=172.16.152.2  10.1.166.127"
*Aug 22 10:23:53.558: RADIUS(0001703E): Received from id 1645/11
*Aug 22 10:23:53.558: ppp11 PPP: Received LOGIN Response PASS
*Aug 22 10:23:53.558: ppp11 PPP: Phase is FORWARDING, Attempting Forward
*Aug 22 10:23:53.562: [11]PPPoE 11: State LCP_NEGOTIATION    Event SSS DISCONNECT
*Aug 22 10:23:53.562: ppp11 PPP DISC: Lower Layer disconnected
*Aug 22 10:23:53.562: ppp11 PPP: Sending Acct Event[Down] id[1703E]
*Aug 22 10:23:53.562: [11]PPPoE 11: AAA get dynamic attrs
*Aug 22 10:23:53.562: [11]PPPoE 11: AAA get dynamic attrs
*Aug 22 10:23:53.562: PPP: NET STOP send to AAA.
*Aug 22 10:23:53.562: ppp11 PAP: O AUTH-NAK id 37 len 27 msg is "Authentication failure"
*Aug 22 10:23:53.562: ppp11 LCP: O TERMREQ [Open] id 2 len 4
*Aug 22 10:23:53.562: ppp11 LCP: Event[CLOSE] State[Open to Closing]
*Aug 22 10:23:53.562: ppp11 PPP: Phase is TERMINATING
*Aug 22 10:23:53.562: [11]PPPoE 11: O PADT  R:aaaa.bbbb.6343 L:aaaa.bbbb.b8c0 Gi0/1/0
contiguous pak, size 60
*Aug 22 10:23:53.562: [11]PPPoE 11: Destroying  R:aaaa.bbbb.6343 L:aaaa.bbbb.b8c0 Gi0/1/0
*Aug 22 10:23:53.562: [11]PPPoE 11: AAA get dynamic attrs
*Aug 22 10:23:53.562: [11]PPPoE 11: AAA account stopped
*Aug 22 10:23:53.562: [11]PPPoE 11: Segment (SSS class): UNPROVISION
*Aug 22 10:23:53.562: ppp11 LCP: Event[CLOSE] State[Closing to Closing]
*Aug 22 10:23:53.562: ppp11 LCP: Event[DOWN] State[Closing to Initial]
*Aug 22 10:23:53.562: ppp11 PPP: Phase is DOWN
*Aug 22 10:23:53.566: PPPoE 11: I PADT  R:aaaa.bbbb.6343 L:aaaa.bbbb.b8c0 Gi0/1/0
contiguous pak, size 60
*Aug 22 10:23:56.702: AAA/BIND(00017040): Bind i/f  

What am I doing wrong here? The router appears to accept the user, but then rejects the user and terminates the connection. Are there additional debug commands I should use?

2 REPLIES 2
Highlighted
Hall of Fame Master

Hello Lionel,

I would not expect to see an IP address defined under gi0/1/0.

 

However, the Radius server is attempting to push some configuration statements to your router :

 

*Aug 22 10:23:53.558: RADIUS:   Cisco AVpair       [1]   31  "ip:ip-unnumbered=Loopback1245"
*Aug 22 10:23:53.558: RADIUS:  Vendor, Cisco       [26]  32  
*Aug 22 10:23:53.558: RADIUS:   Cisco AVpair       [1]   26  "ip:addr-pool=ippool1"

 

Can you check if the loop1245 and the the ip address pool ipool1 exists in your router configuration ?

 

Because if they do not exist this can be the root cause of your issue

 

Hope to help

Giuseppe

 

Highlighted

Thank you, Giuseppe.

 

In fact, they do not exist. These attributes are from a different setup. I have created them now and assigned the IP address to the Loopback instead of the client interface.

 

I will test again tomorrow as the router is at a different site and I need to cable into the router.

 

AAA authentication test works in either case (whether Loopback/pool exists or not):

 

#test aaa group radius pppoetest@myrealm test new-code
User successfully authenticated

USER ATTRIBUTES

Framed-Protocol      0   1 [PPP]
addr                 0   255.255.255.254
netmask              0   255.255.255.255
Framed-MTU           0   1452 (0x5AC)
link-compression     0   4 [vj]
service-type         0   2 [Framed]
timeout              0   86400 (0x15180)
idletime             0   86400 (0x15180)
acct-interval        0   3600 (0xE10)
ip-unnumbered        0   "Loopback1245"
addr-pool            0   "ippool1"
dns-servers          0   "172.16.152.2  10.1.166.127"
noescape             0   True
autocmd              0   " ppp negotiate"
Content for Community-Ad