PPPOE Setup - Cisco 10008

bcramer04 · ‎12-18-2012

Hello,

Working on setting up a Cisco 10008 with PPPOE and it seems like we kind of have it working but only one user can get on.

Here is part of the config:

Cisco-10008#show run

Building configuration...

Current configuration : 4134 bytes

!

version 12.2

no service pad

service timestamps debug datetime msec

service timestamps log datetime msec

service password-encryption

!

hostname Cisco-10008

!

boot-start-marker

boot system flash disk0:c10k4-p11-mz.122-33.SB11.bin

boot bootldr bootflash:c10k4-eboot-mz.122-33.SB11.bin

boot-end-marker

!

aaa new-model

!

aaa authentication ppp default group radius

aaa authorization network default group radius

aaa accounting delay-start

aaa accounting network default start-stop group radius

!

aaa session-id common

facility-alarm outlet-temperature major 58

facility-alarm outlet-temperature minor 48

facility-alarm intake-temperature major 51

facility-alarm intake-temperature minor 41

!

card 1 4jacket-1

card 1/0 SPA-5X1GE-V2

card 1/1 SPA-5X1GE-V2

card 1/2 SPA-5X1GE-V2

card 1/3 SPA-5X1GE-V2

qos match statistics per-match

ip subnet-zero

no ip routing

!

subscriber access pppoe pre-authorize nas-port-id default

multilink bundle-name authenticated

!

redundancy

mode sso

!

bba-group pppoe global

virtual-template 1

sessions max limit 8000

sessions per-vc limit 8

sessions per-mac limit 2

!

bba-group pppoe DSL

virtual-template 1

sessions per-vlan limit 30

sessions pre-auth limit ignore

!

interface GigabitEthernet1/2/0

no ip address

no ip route-cache

negotiation auto

pppoe enable group DSL

interface Virtual-Template1

mtu 1492

ip unnumbered Loopback0

peer default ip address pool pool1

ppp authentication chap

!

ip local pool pool1 192.168.0.1 192.168.0.100

ip classless

Cisco-10008#

Also is there a way to show a specific user once they are connected with PPPOE? I'm currently using "show aaa sessions", but was thinking it would be "show pppoe something"

Thanks!

Peter Paluch · ‎12-18-2012

Hello,

A couple of observations/suggestions:

You have no ip routing configured - why? Your device should definitely be configured with ip routing as it terminates the PPPoE sessions and will be routing the encapsulated IP packets
Add the ppp mtu adaptive on the Virtual-Template1 interface. It has been my observation that specifically Windows PPPoE clients like to dictate their own MTU/MRU and disconnect themselves if the PPPoE concentrator does not comply to their own idea of MTU/MRU.
Would you mind running debug pppoe events and debug pppoe packets when the second PPPoE client tries to log in and gets kicked out?

Also is there a way to show a specific user once they are connected with  PPPOE? I'm currently using "show aaa sessions", but was thinking it  would be "show pppoe something"

To my knowledge, IOSes indeed display the user in the show pppoe session command output.

Best regards,

Peter

bcramer04 · ‎12-18-2012

1. We have no routing setup yet. We are currently running a Redback SE800 and will be moving to the Cisco 10008. Once we are ready to move over, we will add the ip routing.

2. I added the ppp mtu adaptive command on the Virtual- Template 1 interface.

3. Here is the debug output:

Cisco-10008#ter mon

Cisco-10008#debug pppoe events

PPPoE protocol events debugging is on

Cisco-10008#debug pppoe packets

PPPoE control packets debugging is on

Cisco-10008#

*Dec 18 12:18:47.744: [859]PPPoE 859: Segement (SSS class): UPDATED

*Dec 18 12:18:47.744: [922]PPPoE 922: Segement (SSS class): UPDATED

*Dec 18 12:19:35.320: PPPoE 0: I PADI R:20aa.4b7d.7744 L:ffff.ffff.ffff Gi1/2/0

contiguous pak, size 60

FF FF FF FF FF FF 20 AA 4B 7D 77 44 88 63 11 09

00 00 00 0C 01 01 00 00 01 03 00 04 A4 0F 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 12:19:35.320: Service tag: NULL Tag

*Dec 18 12:19:35.320: PPPoE 0: O PADO, R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 12:19:35.320: Service tag: NULL Tag

contiguous pak, size 67

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 07

00 00 00 2F 01 01 00 00 01 03 00 04 A4 0F 00 00

01 02 00 0B 43 69 73 63 6F 2D 31 30 30 30 38 01

04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B 94

63 EE 2A

*Dec 18 12:19:35.332: PPPoE 0: I PADR R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

00 09 B6 8B F4 30 20 AA 4B 7D 77 44 88 63 11 19

00 00 00 20 01 01 00 00 01 03 00 04 A4 0F 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 12:19:35.332: Service tag: NULL Tag

*Dec 18 12:19:35.332: PPPoE : encap string prepared

*Dec 18 12:19:35.332: [923]PPPoE 923: Access IE handle allocated

*Dec 18 12:19:35.332: [923]PPPoE 923: AAA get retrieved attrs

*Dec 18 12:19:35.332: [923]PPPoE 923: AAA get nas port details

*Dec 18 12:19:35.332: [923]PPPoE 923: AAA get dynamic attrs

*Dec 18 12:19:35.332: [923]PPPoE 923: AAA unique ID allocated

*Dec 18 12:19:35.332: [923]PPPoE 923: AAA method list set

*Dec 18 12:19:35.332: [923]PPPoE 923: Service request sent to SSS

*Dec 18 12:19:35.332: [923]PPPoE 923: Created, Service: None R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 12:19:35.332: [923]PPPoE 923: State NAS_PORT_POLICY_INQUIRY Event SSS MORE KEYS

*Dec 18 12:19:35.332: [923]PPPoE 923: data path set to PPP

*Dec 18 12:19:35.332: [923]PPPoE 923: Segement (SSS class): PROVISION

*Dec 18 12:19:35.332: [923]PPPoE 923: State PROVISION_PPP Event SSM PROVISIONED

*Dec 18 12:19:35.332: [923]PPPoE 923: O PADS R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 65

03 9B 00 20 01 01 00 00 01 03 00 04 A4 0F 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 12:19:35.388: [923]PPPoE 923: State LCP_NEGOTIATION Event SSS CONNECT LOCAL

*Dec 18 12:19:35.388: [923]PPPoE 923: Segement (SSS class): UPDATED

*Dec 18 12:19:35.388: [923]PPPoE 923: Segment (SSS class): BOUND

*Dec 18 12:19:35.388: [923]PPPoE 923: data path set to Virtual Acess

*Dec 18 12:19:35.388: [923]PPPoE 923: State LCP_NEGOTIATION Event SSM UPDATED

*Dec 18 12:19:35.388: [923]PPPoE 923: AAA get dynamic attrs

*Dec 18 12:19:35.388: [923]PPPoE 923: State PTA_BINDING Event STATIC BIND RESPONSE

*Dec 18 12:19:35.388: [923]PPPoE 923: Connected PTA

*Dec 18 12:19:35.392: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to up

*Dec 18 12:19:36.392: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to up

*Dec 18 12:19:40.688: [922]PPPoE 922: AAA get dynamic attrs

*Dec 18 12:19:40.688: [922]PPPoE 922: State LOCALLY_TERMINATED Event PPP DISCONNECT

*Dec 18 12:19:40.688: [922]PPPoE 922: O PADT R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 A7

03 9A 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 12:19:40.688: [922]PPPoE 922: Destroying R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

*Dec 18 12:19:40.688: PPPoE: Returning Vaccess Virtual-Access5

*Dec 18 12:19:40.688: [922]PPPoE 922: AAA account stopped

*Dec 18 12:19:40.688: [922]PPPoE 922: Segement (SSS class): UNBOUND

*Dec 18 12:19:40.688: [922]PPPoE 922: Segement (SSS class): UNPROVISION

*Dec 18 12:19:40.692: %LINK-3-UPDOWN: Interface Virtual-Access5, changed state to down

*Dec 18 12:19:41.688: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access5, changed state to down

*Dec 18 12:20:34.280: [923]PPPoE 923: AAA get dynamic attrs

*Dec 18 12:20:34.540: PPPoE 0: I PADI R:20aa.4b7d.7744 L:ffff.ffff.ffff Gi1/2/0

contiguous pak, size 60

FF FF FF FF FF FF 20 AA 4B 7D 77 44 88 63 11 09

00 00 00 0C 01 01 00 00 01 03 00 04 12 12 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 12:20:34.540: Service tag: NULL Tag

*Dec 18 12:20:34.540: PPPoE 0: O PADO, R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 12:20:34.540: Service tag: NULL Tag

contiguous pak, size 67

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 07

00 00 00 2F 01 01 00 00 01 03 00 04 12 12 00 00

01 02 00 0B 43 69 73 63 6F 2D 31 30 30 30 38 01

04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B 94

63 EE 2A

*Dec 18 12:20:34.552: PPPoE 0: I PADR R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

00 09 B6 8B F4 30 20 AA 4B 7D 77 44 88 63 11 19

00 00 00 20 01 01 00 00 01 03 00 04 12 12 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 12:20:34.552: Service tag: NULL Tag

*Dec 18 12:20:34.552: PPPoE : encap string prepared

*Dec 18 12:20:34.552: [924]PPPoE 924: Access IE handle allocated

*Dec 18 12:20:34.552: [924]PPPoE 924: AAA get retrieved attrs

*Dec 18 12:20:34.552: [924]PPPoE 924: AAA get nas port details

*Dec 18 12:20:34.552: [924]PPPoE 924: AAA get dynamic attrs

*Dec 18 12:20:34.552: [924]PPPoE 924: AAA unique ID allocated

*Dec 18 12:20:34.552: [924]PPPoE 924: AAA method list set

*Dec 18 12:20:34.552: [924]PPPoE 924: Service request sent to SSS

*Dec 18 12:20:34.552: [924]PPPoE 924: Created, Service: None R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 12:20:34.552: [924]PPPoE 924: State NAS_PORT_POLICY_INQUIRY Event SSS MORE KEYS

*Dec 18 12:20:34.552: [924]PPPoE 924: data path set to PPP

*Dec 18 12:20:34.552: [924]PPPoE 924: Segement (SSS class): PROVISION

*Dec 18 12:20:34.552: [924]PPPoE 924: State PROVISION_PPP Event SSM PROVISIONED

*Dec 18 12:20:34.552: [924]PPPoE 924: O PADS R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 65

03 9C 00 20 01 01 00 00 01 03 00 04 12 12 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 12:20:34.624: [924]PPPoE 924: State LCP_NEGOTIATION Event SSS CONNECT LOCAL

*Dec 18 12:20:34.624: [924]PPPoE 924: Segement (SSS class): UPDATED

*Dec 18 12:20:34.624: [924]PPPoE 924: Segment (SSS class): BOUND

*Dec 18 12:20:34.624: [924]PPPoE 924: data path set to Virtual Acess

*Dec 18 12:20:34.624: [924]PPPoE 924: State LCP_NEGOTIATION Event SSM UPDATED

*Dec 18 12:20:34.624: [924]PPPoE 924: AAA get dynamic attrs

*Dec 18 12:20:34.624: [924]PPPoE 924: State PTA_BINDING Event STATIC BIND RESPONSE

*Dec 18 12:20:34.624: [924]PPPoE 924: Connected PTA

*Dec 18 12:20:34.628: %LINK-3-UPDOWN: Interface Virtual-Access5, changed state to up

*Dec 18 12:20:35.628: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access5, changed state to up

*Dec 18 12:20:36.272: [923]PPPoE 923: AAA get dynamic attrs

*Dec 18 12:20:36.272: [923]PPPoE 923: State LOCALLY_TERMINATED Event PPP DISCONNECT

*Dec 18 12:20:36.272: [923]PPPoE 923: O PADT R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 A7

03 9B 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 12:20:36.272: [923]PPPoE 923: Destroying R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

*Dec 18 12:20:36.272: PPPoE: Returning Vaccess Virtual-Access3

*Dec 18 12:20:36.272: [923]PPPoE 923: AAA account stopped

*Dec 18 12:20:36.272: [923]PPPoE 923: Segement (SSS class): UNBOUND

*Dec 18 12:20:36.272: [923]PPPoE 923: Segement (SSS class): UNPROVISION

*Dec 18 12:20:36.276: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to down

*Dec 18 12:20:37.272: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to down

Thanks,
Brandon

Peter Paluch · ‎12-18-2012

Hi Brandon,

Are you creating multiple PPPoE sessions from the same MAC address? If so, can you perhaps add the sessions per-mac limit 2 command into your bba-group pppoe DSL configuration? Alternatively, can you try creating two or more PPPoE sessions from different MAC addresses? Is it also possible that the AAA (the Radius) somehow requires that only a single login per MAC is allowed?

Best regards,

Peter

bcramer04 · ‎12-18-2012

I had 2 DSL modems/routers setup. For now, I have disconnected the other modem.

After about 60 Idle Time seconds it drops:

Cisco-10008#show aaa sessions

Total sessions since last reload: 966

Session Id: 1356

Unique Id: 951

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Session Id: 1391

Unique Id: 976

User Name: brandon@molalla.net

IP Address: 192.168.0.40

Idle Time: 59

CT Call Handle: 0

Cisco-10008#show aaa sessions

Total sessions since last reload: 966

Session Id: 1356

Unique Id: 951

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Session Id: 1391

Unique Id: 976

User Name: brandon@molalla.net

IP Address: 192.168.0.40

Idle Time: 59

CT Call Handle: 0

Cisco-10008#show aaa sessions

Total sessions since last reload: 966

Session Id: 1356

Unique Id: 951

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Session Id: 1391

Unique Id: 976

User Name: brandon@molalla.net

IP Address: 192.168.0.40

Idle Time: 60

CT Call Handle: 0

Cisco-10008#

*Dec 18 12:46:46.800: [946]PPPoE 946: AAA get dynamic attrs

*Dec 18 12:46:47.056: PPPoE 0: I PADI R:20aa.4b7d.7744 L:ffff.ffff.ffff Gi1/2/0

contiguous pak, size 60

FF FF FF FF FF FF 20 AA 4B 7D 77 44 88 63 11 09

00 00 00 0C 01 01 00 00 01 03 00 04 2B 16 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 12:46:47.056: Service tag: NULL Tag

*Dec 18 12:46:47.056: PPPoE 0: O PADO, R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 12:46:47.056: Service tag: NULL Tag

contiguous pak, size 67

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 07

00 00 00 2F 01 01 00 00 01 03 00 04 2B 16 00 00

01 02 00 0B 43 69 73 63 6F 2D 31 30 30 30 38 01

04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B 94

63 EE 2A

*Dec 18 12:46:47.064: PPPoE 0: I PADR R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

00 09 B6 8B F4 30 20 AA 4B 7D 77 44 88 63 11 19

00 00 00 20 01 01 00 00 01 03 00 04 2B 16 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 12:46:47.064: Service tag: NULL Tag

*Dec 18 12:46:47.064: PPPoE : encap string prepared

*Dec 18 12:46:47.068: [947]PPPoE 947: Access IE handle allocated

*Dec 18 12:46:47.068: [947]PPPoE 947: AAA get retrieved attrs

*Dec 18 12:46:47.068: [947]PPPoE 947: AAA get nas port details

*Dec 18 12:46:47.068: [947]PPPoE 947: AAA get dynamic attrs

*Dec 18 12:46:47.068: [947]PPPoE 947: AAA unique ID allocated

*Dec 18 12:46:47.068: [947]PPPoE 947: AAA method list set

*Dec 18 12:46:47.068: [947]PPPoE 947: Service request sent to SSS

*Dec 18 12:46:47.068: [947]PPPoE 947: Created, Service: None R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 12:46:47.068: [947]PPPoE 947: State NAS_PORT_POLICY_INQUIRY Event SSS MORE KEYS

*Dec 18 12:46:47.068: [947]PPPoE 947: data path set to PPP

*Dec 18 12:46:47.068: [947]PPPoE 947: Segement (SSS class): PROVISION

*Dec 18 12:46:47.068: [947]PPPoE 947: State PROVISION_PPP Event SSM PROVISIONED

*Dec 18 12:46:47.068: [947]PPPoE 947: O PADS R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 65

03 B3 00 20 01 01 00 00 01 03 00 04 2B 16 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 12:46:47.228: [947]PPPoE 947: State LCP_NEGOTIATION Event SSS CONNECT LOCAL

*Dec 18 12:46:47.228: [947]PPPoE 947: Segement (SSS class): UPDATED

*Dec 18 12:46:47.228: [947]PPPoE 947: Segment (SSS class): BOUND

*Dec 18 12:46:47.228: [947]PPPoE 947: data path set to Virtual Acess

*Dec 18 12:46:47.228: [947]PPPoE 947: State LCP_NEGOTIATION Event SSM UPDATED

*Dec 18 12:46:47.228: [947]PPPoE 947: AAA get dynamic attrs

*Dec 18 12:46:47.228: [947]PPPoE 947: State PTA_BINDING Event STATIC BIND RESPONSE

*Dec 18 12:46:47.228: [947]PPPoE 947: Connected PTA

*Dec 18 12:46:47.232: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to up

*Dec 18 12:46:48.232: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to up

*Dec 18 12:46:48.816: [946]PPPoE 946: AAA get dynamic attrs

*Dec 18 12:46:48.816: [946]PPPoE 946: State LOCALLY_TERMINATED Event PPP DISCONNECT

*Dec 18 12:46:48.816: [946]PPPoE 946: O PADT R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 A7

03 B2 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 12:46:48.816: [946]PPPoE 946: Destroying R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

*Dec 18 12:46:48.816: PPPoE: Returning Vaccess Virtual-Access4

*Dec 18 12:46:48.816: [946]PPPoE 946: AAA account stopped

*Dec 18 12:46:48.816: [946]PPPoE 946: Segement (SSS class): UNBOUND

*Dec 18 12:46:48.816: [946]PPPoE 946: Segement (SSS class): UNPROVISION

*Dec 18 12:46:48.820: %LINK-3-UPDOWN: Interface Virtual-Access4, changed state to down

*Dec 18 12:46:49.816: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access4, changed state to down

Cisco-10008#

*Dec 18 12:47:48.100: [947]PPPoE 947: AAA get dynamic attrs

*Dec 18 12:47:48.296: PPPoE 0: I PADI R:20aa.4b7d.7744 L:ffff.ffff.ffff Gi1/2/0

contiguous pak, size 60

FF FF FF FF FF FF 20 AA 4B 7D 77 44 88 63 11 09

00 00 00 0C 01 01 00 00 01 03 00 04 51 17 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 12:47:48.296: Service tag: NULL Tag

*Dec 18 12:47:48.296: PPPoE 0: O PADO, R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 12:47:48.296: Service tag: NULL Tag

contiguous pak, size 67

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 07

00 00 00 2F 01 01 00 00 01 03 00 04 51 17 00 00

01 02 00 0B 43 69 73 63 6F 2D 31 30 30 30 38 01

04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B 94

63 EE 2A

*Dec 18 12:47:48.308: PPPoE 0: I PADR R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

00 09 B6 8B F4 30 20 AA 4B 7D 77 44 88 63 11 19

00 00 00 20 01 01 00 00 01 03 00 04 51 17 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 12:47:48.308: Service tag: NULL Tag

*Dec 18 12:47:48.308: PPPoE : encap string prepared

*Dec 18 12:47:48.308: [948]PPPoE 948: Access IE handle allocated

*Dec 18 12:47:48.308: [948]PPPoE 948: AAA get retrieved attrs

*Dec 18 12:47:48.308: [948]PPPoE 948: AAA get nas port details

*Dec 18 12:47:48.308: [948]PPPoE 948: AAA get dynamic attrs

*Dec 18 12:47:48.308: [948]PPPoE 948: AAA unique ID allocated

*Dec 18 12:47:48.308: [948]PPPoE 948: AAA method list set

*Dec 18 12:47:48.308: [948]PPPoE 948: Service request sent to SSS

*Dec 18 12:47:48.308: [948]PPPoE 948: Created, Service: None R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 12:47:48.308: [948]PPPoE 948: State NAS_PORT_POLICY_INQUIRY Event SSS MORE KEYS

*Dec 18 12:47:48.308: [948]PPPoE 948: data path set to PPP

*Dec 18 12:47:48.308: [948]PPPoE 948: Segement (SSS class): PROVISION

*Dec 18 12:47:48.308: [948]PPPoE 948: State PROVISION_PPP Event SSM PROVISIONED

*Dec 18 12:47:48.308: [948]PPPoE 948: O PADS R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 65

03 B4 00 20 01 01 00 00 01 03 00 04 51 17 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 12:47:48.444: [948]PPPoE 948: State LCP_NEGOTIATION Event SSS CONNECT LOCAL

*Dec 18 12:47:48.444: [948]PPPoE 948: Segement (SSS class): UPDATED

*Dec 18 12:47:48.444: [948]PPPoE 948: Segment (SSS class): BOUND

*Dec 18 12:47:48.444: [948]PPPoE 948: data path set to Virtual Acess

*Dec 18 12:47:48.444: [948]PPPoE 948: State LCP_NEGOTIATION Event SSM UPDATED

*Dec 18 12:47:48.444: [948]PPPoE 948: AAA get dynamic attrs

*Dec 18 12:47:48.444: [948]PPPoE 948: State PTA_BINDING Event STATIC BIND RESPONSE

*Dec 18 12:47:48.444: [948]PPPoE 948: Connected PTA

*Dec 18 12:47:48.448: %LINK-3-UPDOWN: Interface Virtual-Access5, changed state to up

*Dec 18 12:47:49.448: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access5, changed state to up

*Dec 18 12:47:50.096: [947]PPPoE 947: AAA get dynamic attrs

*Dec 18 12:47:50.096: [947]PPPoE 947: State LOCALLY_TERMINATED Event PPP DISCONNECT

*Dec 18 12:47:50.096: [947]PPPoE 947: O PADT R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 A7

03 B3 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 12:47:50.096: [947]PPPoE 947: Destroying R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

*Dec 18 12:47:50.096: PPPoE: Returning Vaccess Virtual-Access3

*Dec 18 12:47:50.096: [947]PPPoE 947: AAA account stopped

*Dec 18 12:47:50.096: [947]PPPoE 947: Segement (SSS class): UNBOUND

*Dec 18 12:47:50.096: [947]PPPoE 947: Segement (SSS class): UNPROVISION

*Dec 18 12:47:50.100: %LINK-3-UPDOWN: Interface Virtual-Access3, changed state to down

*Dec 18 12:47:51.096: %LINEPROTO-5-UPDOWN: Line protocol on Interface Virtual-Access3, changed state to down

Peter Paluch · ‎12-18-2012

Brandon,

This is strange. Could you modify your AAA configuration a bit as follows? I am trying to isolate whether the problem lies in the AAA or somewhere in the PPP/PPPoE configuration.

no aaa authentication ppp default group radius

no aaa authorization network default group radius

aaa authentication ppp default local

username user1 password user1

username user2 password user2

This should force the router to authenticate the PPPoE sessions using the local database. Use the user1 and user2 logins/passwords to authenticate the PPPoE to the router. Let's see if this can make the session more stable.

Best regards,

Peter

bcramer04 · ‎12-18-2012

Here is the current running config:

Cisco-10008#show run

Building configuration...

Current configuration : 4054 bytes

!

version 12.2

no service pad

service timestamps debug datetime msec

service timestamps log datetime msec

service password-encryption

!

hostname Cisco-10008

!

boot-start-marker

boot system flash disk0:c10k4-p11-mz.122-33.SB11.bin

boot bootldr bootflash:c10k4-eboot-mz.122-33.SB11.bin

boot-end-marker

!

aaa new-model

!

aaa authentication ppp default local

aaa accounting delay-start

aaa accounting network default start-stop group radius

!

aaa session-id common

facility-alarm outlet-temperature major 58

facility-alarm outlet-temperature minor 48

facility-alarm intake-temperature major 51

facility-alarm intake-temperature minor 41

!

card 1 4jacket-1

card 1/0 SPA-5X1GE-V2

card 1/1 SPA-5X1GE-V2

card 1/2 SPA-5X1GE-V2

card 1/3 SPA-5X1GE-V2

qos match statistics per-match

ip subnet-zero

no ip routing

!

subscriber access pppoe pre-authorize nas-port-id default

multilink bundle-name authenticated

username user1 password 7 105B1A1C1746

username user2 password 7 150718091678

!

redundancy

mode sso

!

bba-group pppoe DSL

virtual-template 1

sessions per-vlan limit 30

sessions pre-auth limit ignore

!

interface Loopback0

no ip address

!

interface FastEthernet0/0/0

ip address 192.168.7.27 255.255.254.0

no ip route-cache

media-type rj45

speed auto

full-duplex

!

interface GigabitEthernet1/0/0

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/0/1

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/0/2

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/0/3

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/0/4

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/1/0

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/1/1

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/1/2

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/1/3

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/1/4

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/2/0

no ip address

no ip route-cache

negotiation auto

pppoe enable group DSL

!

interface GigabitEthernet1/2/1

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/2/2

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/2/3

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/2/4

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/3/0

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/3/1

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/3/2

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/3/3

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface GigabitEthernet1/3/4

no ip address

no ip route-cache

shutdown

negotiation auto

!

interface Virtual-Template1

mtu 1492

ip unnumbered Loopback0

peer default ip address pool pool1

ppp mtu adaptive

ppp authentication chap

ppp ipcp dns 216.134.160.6 216.134.160.13

!

ip local pool pool1 192.168.0.1 192.168.0.100

ip classless

!

no ip http server

!

snmp-server community RO

!

radius-server host 192.168.7.153 auth-port 1812 acct-port 1813 key 7 095F45101D0C0117

radius-server unique-ident 3

!

control-plane

!

line con 0

stopbits 1

line aux 0

stopbits 1

line vty 0 4

session-timeout 1200

line vty 5 15

session-timeout 120

!

end

Cisco-10008#

Debug:

Cisco-10008#show aaa session

Total sessions since last reload: 1005

Session Id: 1356

Unique Id: 951

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Session Id: 1416

Unique Id: 997

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Cisco-10008#

*Dec 18 13:13:31.332: PPPoE 0: I PADI R:20aa.4b7d.7744 L:ffff.ffff.ffff Gi1/2/0

contiguous pak, size 60

FF FF FF FF FF FF 20 AA 4B 7D 77 44 88 63 11 09

00 00 00 0C 01 01 00 00 01 03 00 04 EB 18 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 13:13:31.332: Service tag: NULL Tag

*Dec 18 13:13:31.332: PPPoE 0: O PADO, R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 13:13:31.332: Service tag: NULL Tag

contiguous pak, size 67

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 07

00 00 00 2F 01 01 00 00 01 03 00 04 EB 18 00 00

01 02 00 0B 43 69 73 63 6F 2D 31 30 30 30 38 01

04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B 94

63 EE 2A

*Dec 18 13:13:31.340: PPPoE 0: I PADR R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

00 09 B6 8B F4 30 20 AA 4B 7D 77 44 88 63 11 19

00 00 00 20 01 01 00 00 01 03 00 04 EB 18 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 13:13:31.340: Service tag: NULL Tag

*Dec 18 13:13:31.340: PPPoE : encap string prepared

*Dec 18 13:13:31.340: [985]PPPoE 985: Access IE handle allocated

*Dec 18 13:13:31.340: [985]PPPoE 985: AAA get retrieved attrs

*Dec 18 13:13:31.340: [985]PPPoE 985: AAA get nas port details

*Dec 18 13:13:31.340: [985]PPPoE 985: AAA get dynamic attrs

*Dec 18 13:13:31.340: [985]PPPoE 985: AAA unique ID allocated

*Dec 18 13:13:31.340: [985]PPPoE 985: AAA method list set

*Dec 18 13:13:31.340: [985]PPPoE 985: Service request sent to SSS

*Dec 18 13:13:31.340: [985]PPPoE 985: Created, Service: None R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 13:13:31.340: [985]PPPoE 985: State NAS_PORT_POLICY_INQUIRY Event SSS MORE KEYS

*Dec 18 13:13:31.340: [985]PPPoE 985: data path set to PPP

*Dec 18 13:13:31.340: [985]PPPoE 985: Segement (SSS class): PROVISION

*Dec 18 13:13:31.340: [985]PPPoE 985: State PROVISION_PPP Event SSM PROVISIONED

*Dec 18 13:13:31.340: [985]PPPoE 985: O PADS R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 65

03 D9 00 20 01 01 00 00 01 03 00 04 EB 18 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 13:13:31.380: [985]PPPoE 985: AAA get dynamic attrs

*Dec 18 13:13:31.392: [985]PPPoE 985: State LCP_NEGOTIATION Event PPP DISCONNECT

*Dec 18 13:13:31.392: [985]PPPoE 985: O PADT R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 A7

03 D9 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 13:13:31.392: [985]PPPoE 985: Destroying R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

*Dec 18 13:13:31.392: [985]PPPoE 985: AAA get dynamic attrs

*Dec 18 13:13:31.392: [985]PPPoE 985: AAA account stopped

*Dec 18 13:13:31.392: [985]PPPoE 985: Segement (SSS class): UNPROVISION

*Dec 18 13:13:31.816: PPPoE 0: I PADI R:20aa.4b7d.7744 L:ffff.ffff.ffff Gi1/2/0

contiguous pak, size 60

FF FF FF FF FF FF 20 AA 4B 7D 77 44 88 63 11 09

00 00 00 0C 01 01 00 00 01 03 00 04 77 1A 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 13:13:31.816: Service tag: NULL Tag

*Dec 18 13:13:31.816: PPPoE 0: O PADO, R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 13:13:31.816: Service tag: NULL Tag

contiguous pak, size 67

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 07

00 00 00 2F 01 01 00 00 01 03 00 04 77 1A 00 00

01 02 00 0B 43 69 73 63 6F 2D 31 30 30 30 38 01

04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B 94

63 EE 2A

*Dec 18 13:13:31.820: PPPoE 0: I PADR R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

00 09 B6 8B F4 30 20 AA 4B 7D 77 44 88 63 11 19

00 00 00 20 01 01 00 00 01 03 00 04 77 1A 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 13:13:31.820: Service tag: NULL Tag

*Dec 18 13:13:31.820: PPPoE : encap string prepared

*Dec 18 13:13:31.820: [986]PPPoE 986: Access IE handle allocated

*Dec 18 13:13:31.820: [986]PPPoE 986: AAA get retrieved attrs

*Dec 18 13:13:31.820: [986]PPPoE 986: AAA get nas port details

*Dec 18 13:13:31.820: [986]PPPoE 986: AAA get dynamic attrs

*Dec 18 13:13:31.820: [986]PPPoE 986: AAA unique ID allocated

*Dec 18 13:13:31.820: [986]PPPoE 986: AAA method list set

*Dec 18 13:13:31.820: [986]PPPoE 986: Service request sent to SSS

*Dec 18 13:13:31.820: [986]PPPoE 986: Created, Service: None R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 18 13:13:31.820: [986]PPPoE 986: State NAS_PORT_POLICY_INQUIRY Event SSS MORE KEYS

*Dec 18 13:13:31.824: [986]PPPoE 986: data path set to PPP

*Dec 18 13:13:31.824: [986]PPPoE 986: Segement (SSS class): PROVISION

*Dec 18 13:13:31.824: [986]PPPoE 986: State PROVISION_PPP Event SSM PROVISIONED

*Dec 18 13:13:31.824: [986]PPPoE 986: O PADS R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 65

03 DA 00 20 01 01 00 00 01 03 00 04 77 1A 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 18 13:13:31.860: [986]PPPoE 986: AAA get dynamic attrs

*Dec 18 13:13:31.872: [986]PPPoE 986: State LCP_NEGOTIATION Event PPP DISCONNECT

*Dec 18 13:13:31.872: [986]PPPoE 986: O PADT R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 A7

03 DA 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 18 13:13:31.872: [986]PPPoE 986: Destroying R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

*Dec 18 13:13:31.872: [986]PPPoE 986: AAA get dynamic attrs

*Dec 18 13:13:31.872: [986]PPPoE 986: AAA account stopped

*Dec 18 13:13:31.872: [986]PPPoE 986: Segement (SSS class): UNPROVISION

I dont see the user1 under show aaa sessions anymore.

Cisco-10008#show aaa sessions

Total sessions since last reload: 1010

Session Id: 1356

Unique Id: 951

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Session Id: 1416

Unique Id: 997

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Cisco-10008#

Peter Paluch · ‎12-19-2012

Hello Brandon,

Interesting. Let's try to focus on what is happening inside the PPP session itself. Can you please leave the existing debugs in place, and in addition, add the next two?

debug ppp negotiation

debug ppp authentication

Sorry for delays in responding...

Best regards,

Peter

bcramer04 · ‎12-19-2012

I added that user1 to my router, but I forgot to remove the @molalla.net part.

Here is the debug with just user1:

Cisco-10008#

*Dec 19 04:08:21.184: Vi2.1 LCP: I TERMREQ [Open] id 2 len 16

*Dec 19 04:08:21.184: Vi2.1 LCP: (0x557365722072657175657374)

*Dec 19 04:08:21.184: Vi2.1 IPCP: Event[DOWN] State[Stopped to Starting]

*Dec 19 04:08:21.184: Vi2.1 IPCP: Event[CLOSE] State[Starting to Initial]

*Dec 19 04:08:21.184: Vi2.1 LCP: O TERMACK [Open] id 2 len 4

*Dec 19 04:08:21.184: Vi2.1 LCP: Event[Receive TermReq] State[Open to Stopping]

*Dec 19 04:08:21.184: Vi2.1 PPP DISC: Received LCP TERMREQ from peer

*Dec 19 04:08:21.184: Vi2.1 PPP: Sending Acct Event[Down] id[E26]

*Dec 19 04:08:21.184: [582]PPPoE 3587: AAA get dynamic attrs

*Dec 19 04:08:21.184: Vi2.1 PPP: Phase is TERMINATING

*Dec 19 04:08:21.368: PPPoE 0: I PADI R:20aa.4b7d.7744 L:ffff.ffff.ffff Gi1/2/0

contiguous pak, size 60

FF FF FF FF FF FF 20 AA 4B 7D 77 44 88 63 11 09

00 00 00 0C 01 01 00 00 01 03 00 04 6F 17 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 19 04:08:21.368: Service tag: NULL Tag

*Dec 19 04:08:21.368: PPPoE 0: O PADO, R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 19 04:08:21.368: Service tag: NULL Tag

contiguous pak, size 67

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 07

00 00 00 2F 01 01 00 00 01 03 00 04 6F 17 00 00

01 02 00 0B 43 69 73 63 6F 2D 31 30 30 30 38 01

04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B 94

63 EE 2A

*Dec 19 04:08:21.372: PPPoE 0: I PADR R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

00 09 B6 8B F4 30 20 AA 4B 7D 77 44 88 63 11 19

00 00 00 20 01 01 00 00 01 03 00 04 6F 17 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 19 04:08:21.372: Service tag: NULL Tag

*Dec 19 04:08:21.372: PPPoE : encap string prepared

*Dec 19 04:08:21.372: [583]PPPoE 3588: Access IE handle allocated

*Dec 19 04:08:21.372: [583]PPPoE 3588: AAA get retrieved attrs

*Dec 19 04:08:21.372: [583]PPPoE 3588: AAA get nas port details

*Dec 19 04:08:21.372: [583]PPPoE 3588: AAA get dynamic attrs

*Dec 19 04:08:21.372: [583]PPPoE 3588: AAA unique ID allocated

*Dec 19 04:08:21.372: [583]PPPoE 3588: AAA method list set

*Dec 19 04:08:21.372: [583]PPPoE 3588: Service request sent to SSS

*Dec 19 04:08:21.372: [583]PPPoE 3588: Created, Service: None R:0009.b68b.f430 L:20aa.4b7d.7744 Gi1/2/0

*Dec 19 04:08:21.376: [583]PPPoE 3588: State NAS_PORT_POLICY_INQUIRY Event SSS MORE KEYS

*Dec 19 04:08:21.376: PPP: Alloc Context [5107314C]

*Dec 19 04:08:21.376: ppp583 PPP: Phase is ESTABLISHING

*Dec 19 04:08:21.376: [583]PPPoE 3588: data path set to PPP

*Dec 19 04:08:21.376: [583]PPPoE 3588: Segement (SSS class): PROVISION

*Dec 19 04:08:21.376: [583]PPPoE 3588: State PROVISION_PPP Event SSM PROVISIONED

*Dec 19 04:08:21.376: [583]PPPoE 3588: O PADS R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 65

0E 04 00 20 01 01 00 00 01 03 00 04 6F 17 00 00

01 04 00 10 D9 56 A7 49 99 CD 2C DD 20 7C 6B 9B

94 63 EE 2A 00 00 00 00 00 00 00 00

*Dec 19 04:08:21.376: ppp583 PPP: Using vpn set call direction

*Dec 19 04:08:21.376: ppp583 PPP: Treating connection as a callin

*Dec 19 04:08:21.376: ppp583 PPP: Session handle[E2000DFC] Session id[583]

*Dec 19 04:08:21.376: ppp583 LCP: Event[OPEN] State[Initial to Starting]

*Dec 19 04:08:21.376: ppp583 PPP LCP: Enter passive mode, state[Stopped]

*Dec 19 04:08:21.456: ppp583 LCP: I CONFREQ [Stopped] id 1 len 14

*Dec 19 04:08:21.456: ppp583 LCP: MRU 1492 (0x010405D4)

*Dec 19 04:08:21.456: ppp583 LCP: MagicNumber 0x437EAB7A (0x0506437EAB7A)

*Dec 19 04:08:21.456: ppp583 LCP: O CONFREQ [Stopped] id 1 len 19

*Dec 19 04:08:21.456: ppp583 LCP: MRU 1492 (0x010405D4)

*Dec 19 04:08:21.456: ppp583 LCP: AuthProto CHAP (0x0305C22305)

*Dec 19 04:08:21.456: ppp583 LCP: MagicNumber 0x1384888F (0x05061384888F)

*Dec 19 04:08:21.456: ppp583 LCP: O CONFACK [Stopped] id 1 len 14

*Dec 19 04:08:21.456: ppp583 LCP: MRU 1492 (0x010405D4)

*Dec 19 04:08:21.456: ppp583 LCP: MagicNumber 0x437EAB7A (0x0506437EAB7A)

*Dec 19 04:08:21.456: ppp583 LCP: Event[Receive ConfReq+] State[Stopped to ACKsent]

*Dec 19 04:08:21.464: ppp583 LCP: I CONFACK [ACKsent] id 1 len 19

*Dec 19 04:08:21.464: ppp583 LCP: MRU 1492 (0x010405D4)

*Dec 19 04:08:21.464: ppp583 LCP: AuthProto CHAP (0x0305C22305)

*Dec 19 04:08:21.464: ppp583 LCP: MagicNumber 0x1384888F (0x05061384888F)

*Dec 19 04:08:21.464: ppp583 LCP: Event[Receive ConfAck] State[ACKsent to Open]

*Dec 19 04:08:21.484: ppp583 PPP: Phase is AUTHENTICATING, by this end

*Dec 19 04:08:21.484: ppp583 CHAP: O CHALLENGE id 1 len 32 from "Cisco-10008"

*Dec 19 04:08:21.484: ppp583 LCP: State is Open

*Dec 19 04:08:21.488: ppp583 CHAP: I RESPONSE id 1 len 26 from "user1"

*Dec 19 04:08:21.488: ppp583 PPP: Phase is FORWARDING, Attempting Forward

*Dec 19 04:08:21.488: ppp583 PPP: Phase is AUTHENTICATING, Unauthenticated User

*Dec 19 04:08:21.488: ppp583 PPP: Sent CHAP LOGIN Request

*Dec 19 04:08:21.488: ppp583 PPP: Received LOGIN Response PASS

*Dec 19 04:08:21.488: ppp583 PPP: Phase is FORWARDING, Attempting Forward

*Dec 19 04:08:21.492: [583]PPPoE 3588: State LCP_NEGOTIATION Event SSS CONNECT LOCAL

*Dec 19 04:08:21.492: [583]PPPoE 3588: Segement (SSS class): UPDATED

*Dec 19 04:08:21.492: [583]PPPoE 3588: Segment (SSS class): BOUND

*Dec 19 04:08:21.492: [583]PPPoE 3588: data path set to Virtual Acess

*Dec 19 04:08:21.492: [583]PPPoE 3588: State LCP_NEGOTIATION Event SSM UPDATED

*Dec 19 04:08:21.492: Vi2.2 PPP: Phase is AUTHENTICATING, Authenticated User

*Dec 19 04:08:21.492: Vi2.2 CHAP: O SUCCESS id 1 len 4

*Dec 19 04:08:21.492: [583]PPPoE 3588: AAA get dynamic attrs

*Dec 19 04:08:21.492: Vi2.2 PPP: Phase is UP

*Dec 19 04:08:21.492: Vi2.2 IPCP: Protocol configured, start CP. state[Initial]

*Dec 19 04:08:21.492: Vi2.2 IPCP: Event[OPEN] State[Initial to Starting]

*Dec 19 04:08:21.492: Vi2.2 IPCP: O CONFREQ [Starting] id 1 len 10

*Dec 19 04:08:21.492: Vi2.2 IPCP: Address 127.0.0.254 (0x03067F0000FE)

*Dec 19 04:08:21.492: Vi2.2 IPCP: Event[UP] State[Starting to REQsent]

*Dec 19 04:08:21.492: [583]PPPoE 3588: State PTA_BINDING Event STATIC BIND RESPONSE

*Dec 19 04:08:21.492: [583]PPPoE 3588: Connected PTA

*Dec 19 04:08:21.500: Vi2.2 IPCP: I CONFREQ [REQsent] id 1 len 22

*Dec 19 04:08:21.500: Vi2.2 IPCP: Address 0.0.0.0 (0x030600000000)

*Dec 19 04:08:21.500: Vi2.2 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)

*Dec 19 04:08:21.500: Vi2.2 IPCP: SecondaryDNS 0.0.0.0 (0x830600000000)

*Dec 19 04:08:21.500: Vi2.2 IPCP AUTHOR: Done. Her address 0.0.0.0, we want 0.0.0.0

*Dec 19 04:08:21.500: Vi2.2 IPCP: Pool returned 192.168.0.64

*Dec 19 04:08:21.500: Vi2.2 IPCP: O CONFNAK [REQsent] id 1 len 22

*Dec 19 04:08:21.500: Vi2.2 IPCP: Address 192.168.0.64 (0x0306C0A80040)

*Dec 19 04:08:21.500: Vi2.2 IPCP: PrimaryDNS 216.134.160.6 (0x8106D886A006)

*Dec 19 04:08:21.500: Vi2.2 IPCP: SecondaryDNS 216.134.160.13 (0x8306D886A00D)

*Dec 19 04:08:21.500: Vi2.2 IPCP: Event[Receive ConfReq-] State[REQsent to REQsent]

*Dec 19 04:08:21.500: Vi2.2 IPV6CP: I CONFREQ [UNKNOWN] id 1 len 14

*Dec 19 04:08:21.500: Vi2.2 IPV6CP: Interface-Id 190B:5AB0:FDF3:9E21 (0x010A190B5AB0FDF39E21)

*Dec 19 04:08:21.500: Vi2.2 LCP: O PROTREJ [Open] id 2 len 20 protocol IPV6CP (0x01010010010A190B5AB0FDF39E21)

*Dec 19 04:08:21.500: Vi2.2 IPCP: I CONFACK [REQsent] id 1 len 10

*Dec 19 04:08:21.500: Vi2.2 IPCP: Address 127.0.0.254 (0x03067F0000FE)

*Dec 19 04:08:21.500: Vi2.2 IPCP: Event[Receive ConfAck] State[REQsent to ACKrcvd]

*Dec 19 04:08:21.508: Vi2.2 IPCP: I CONFREQ [ACKrcvd] id 2 len 22

*Dec 19 04:08:21.508: Vi2.2 IPCP: Address 192.168.0.64 (0x0306C0A80040)

*Dec 19 04:08:21.508: Vi2.2 IPCP: PrimaryDNS 216.134.160.6 (0x8106D886A006)

*Dec 19 04:08:21.508: Vi2.2 IPCP: SecondaryDNS 216.134.160.13 (0x8306D886A00D)

*Dec 19 04:08:21.508: Vi2.2 IPCP: O CONFACK [ACKrcvd] id 2 len 22

*Dec 19 04:08:21.508: Vi2.2 IPCP: Address 192.168.0.64 (0x0306C0A80040)

*Dec 19 04:08:21.508: Vi2.2 IPCP: PrimaryDNS 216.134.160.6 (0x8106D886A006)

*Dec 19 04:08:21.508: Vi2.2 IPCP: SecondaryDNS 216.134.160.13 (0x8306D886A00D)

*Dec 19 04:08:21.508: Vi2.2 IPCP: Event[Receive ConfReq+] State[ACKrcvd to Open]

*Dec 19 04:08:21.516: Vi2.2 IPCP: State is Open

*Dec 19 04:08:21.516: Vi2.2 IPCP: Add link info for cef entry 192.168.0.64

*Dec 19 04:08:21.516: Vi2.2 Added to neighbor route AVL tree: topoid 0, address 192.168.0.64

*Dec 19 04:08:21.516: Vi2.2 IPCP: Route not installed to 192.168.0.64

*Dec 19 04:08:21.520: Vi2.2 IPCP: I TERMREQ [Open] id 3 len 34

*Dec 19 04:08:21.520: Vi2.2 IPCP: (0x556E617574686F72697A65642072656D)

*Dec 19 04:08:21.520: Vi2.2 IPCP: (0x6F74652049502061646472657373)

*Dec 19 04:08:21.520: Vi2.2 IPCP: Remove link info for cef entry 192.168.0.64

*Dec 19 04:08:21.520: Vi2.2 IPCP: O TERMACK [Open] id 3 len 4

*Dec 19 04:08:21.520: Vi2.2 IPCP: Event[Receive TermReq] State[Open to Stopping]

*Dec 19 04:08:21.520: Vi2.2 Deleted neighbor route from AVL tree: topoid 0, address 192.168.0.64

*Dec 19 04:08:21.520: Vi2.2 IPCP: Remove route to 192.168.0.64

*Dec 19 04:08:23.180: Vi2.1 LCP: Event[Timeout-] State[Stopping to Stopped]

*Dec 19 04:08:23.180: Vi2.1 LCP: Event[DOWN] State[Stopped to Starting]

*Dec 19 04:08:23.180: Vi2.1 PPP: Phase is DOWN

*Dec 19 04:08:23.180: [582]PPPoE 3587: State LOCALLY_TERMINATED Event PPP DISCONNECT

*Dec 19 04:08:23.180: [582]PPPoE 3587: O PADT R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

contiguous pak, size 60

20 AA 4B 7D 77 44 00 09 B6 8B F4 30 88 63 11 A7

0E 03 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00

*Dec 19 04:08:23.180: [582]PPPoE 3587: Destroying R:20aa.4b7d.7744 L:0009.b68b.f430 Gi1/2/0

*Dec 19 04:08:23.180: PPPoE: Returning Vaccess Virtual-Access2.1

*Dec 19 04:08:23.180: [582]PPPoE 3587: AAA get dynamic attrs

*Dec 19 04:08:23.180: [582]PPPoE 3587: AAA account stopped

*Dec 19 04:08:23.180: [582]PPPoE 3587: Segement (SSS class): UNBOUND

*Dec 19 04:08:23.180: [582]PPPoE 3587: Segement (SSS class): UNPROVISION

*Dec 19 04:08:23.436: Vi2.1 PPP: Free Context [51072F9C]

*Dec 19 04:08:23.532: Vi2.2 IPCP: Event[Timeout-] State[Stopping to Stopped]

Cisco-10008#show aaa session

Total sessions since last reload: 3613

Session Id: 4022

Unique Id: 3603

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Session Id: 4047

Unique Id: 3623

User Name: user1

IP Address: 192.168.0.64

Idle Time: 0

CT Call Handle: 0

Cisco-10008#

Still dropping the session from what it looks like:

Cisco-10008#show aaa session

Total sessions since last reload: 3615

Session Id: 4022

Unique Id: 3603

User Name: admin

IP Address: 192.168.7.170

Idle Time: 0

CT Call Handle: 0

Session Id: 4051

Unique Id: 3625

User Name: user1

IP Address: 0.0.0.0

Idle Time: 0

CT Call Handle: 0

Cisco-10008#

Thanks,

Brandon

Peter Paluch · ‎12-19-2012

Hello Brandon,

There is a series of puzzling facts depicted in this debug and preceding configuration.

Your Loopback0 interface has no IP address configured, yet you are using that on the Virtual-Template1 in the ip unnumbered command. Assign an IP address to the Lo0 interface please.
Your router appears to announce its own IP address of 127.0.0.254 to the PPPoE client. However, 127.0.0.254 is an internal loopback address that should never, ever, be used on a physical link. This may be related either to the missing IP address on the Lo0 interface, or to the fact that you have the IP routing deactivated. I strongly suggest activating the IP routing using the ip routing command - having an access concentrator for PPPoE sessions without IP routing enabled is highly irregular.
The PPP link termination is caused by your router receiving the TERMREQ LCP command from the client. In essence, it is your client who requests the termination of the session, not your router. This may be related to you advertising the 127.0.0.254 address as your own address.

Can you implement the suggested changes and retest the behavior please? Thank you!

Best regards,

Peter