[c-nsp] PPPoE and FreeRadius - yet again
William Jackson
wjackson at sapphire.gi
Wed Oct 18 11:40:34 EDT 2006
Thanks for those pointers, it seems there is some issue with the NCP
part of PPP.
Is see that the IPCP has all values at 0.0.0.0:
*Oct 18 15:30:14.394: RADIUS: Received from id 1645/74
85.xxx.xxx.27:1812, Access-Accept, len 44
*Oct 18 15:30:14.394: RADIUS: authenticator 04 87 D8 77 3E 54 0D 40 -
30 D6 88 EC 78 79 6F 2C
*Oct 18 15:30:14.394: RADIUS: Service-Type [6] 6 Framed
[2]
*Oct 18 15:30:14.394: RADIUS: Framed-Protocol [7] 6 PPP
[1]
*Oct 18 15:30:14.394: RADIUS: Framed-IP-Address [8] 6
85.xxx.xxx.12
*Oct 18 15:30:14.394: RADIUS: Framed-IP-Netmask [9] 6
255.255.255.255
*Oct 18 15:30:14.394: RADIUS(0000005D): Received from id 1645/74
*Oct 18 15:30:14.394: ppp83 PPP/AAA: Check Attr: service-type
*Oct 18 15:30:14.394: ppp83 PPP/AAA: Check Attr: Framed-Protocol
*Oct 18 15:30:14.394: ppp83 PPP/AAA: Check Attr: addr
*Oct 18 15:30:14.394: ppp83 PPP/AAA: Check Attr: netmask
*Oct 18 15:30:14.394: ppp83 PPP: Phase is FORWARDING, Attempting Forward
*Oct 18 15:30:14.394: ppp83 PPP: Send Message[Connect Local]
*Oct 18 15:30:14.394: [83]PPPoE 83: State LCP_NEGOTIATION Event
PPP_LOCAL
*Oct 18 15:30:14.394: PPPoE 83/SB: Sent vtemplate request on base Vi1
*Oct 18 15:30:14.406: [83]PPPoE 83: State VACCESS_REQUESTED Event
VA_RESP
*Oct 18 15:30:14.406: [83]PPPoE 83: Vi1.1 interface obtained
*Oct 18 15:30:14.406: ppp83 PPP: Bind to [Virtual-Access1.1]
*Oct 18 15:30:14.406: AAA/BIND(0000005D): Bind i/f Virtual-Access1.1
*Oct 18 15:30:14.406: Vi1.1 PPP: Send Message[Static Bind Response]
*Oct 18 15:30:14.406: [83]PPPoE 83: State PTA_BINDING Event STAT_BIND
*Oct 18 15:30:14.406: [83]PPPoE 83: data path set to Virtual Acess
*Oct 18 15:30:14.406: [83]PPPoE 83: Connected PTA
*Oct 18 15:30:14.406: Vi1.1 PPP: Phase is AUTHENTICATING, Authenticated
User
*Oct 18 15:30:14.406: Vi1.1 AAA/AUTHOR/LCP: Process Author
*Oct 18 15:30:14.406: Vi1.1 AAA/AUTHOR/LCP: Process Attr: service-type
*Oct 18 15:30:14.406: Vi1.1 PAP: O AUTH-ACK id 132 len 5
*Oct 18 15:30:14.406: [83]PPPoE 83: AAA get dynamic attrs
*Oct 18 15:30:14.406: [83]PPPoE 83: AAA get dynamic attrs
*Oct 18 15:30:14.406: Vi1.1 PPP: Phase is UP
*Oct 18 15:30:14.406: Vi1.1 PPP: Process pending ncp packets
*Oct 18 15:30:14.406: RADIUS/ENCODE(0000005D):Orig. component type =
PPoE
*Oct 18 15:30:14.406: RADIUS/ENCODE(0000005D): Acct-session-id
pre-pended with Nas Port = 0/0/0/0
*Oct 18 15:30:14.418: Vi1.1 IPCP: I CONFREQ [Not negotiated] id 3 len 34
*Oct 18 15:30:14.418: Vi1.1 IPCP: Address 0.0.0.0 (0x030600000000)
*Oct 18 15:30:14.418: Vi1.1 IPCP: PrimaryDNS 0.0.0.0 (0x810600000000)
*Oct 18 15:30:14.418: Vi1.1 IPCP: PrimaryWINS 0.0.0.0
(0x820600000000)
*Oct 18 15:30:14.418: Vi1.1 IPCP: SecondaryDNS 0.0.0.0
(0x830600000000)
*Oct 18 15:30:14.418: Vi1.1 IPCP: SecondaryWINS 0.0.0.0
(0x840600000000)
*Oct 18 15:30:14.418: Vi1.1 LCP: O PROTREJ [Open] id 2 len 40 protocol
IPCP
*Oct 18 15:30:14.418: Vi1.1 LCP: (0x80210103002203060000000081060000)
*Oct 18 15:30:14.418: Vi1.1 LCP: (0x00008206000000008306000000008406)
*Oct 18 15:30:14.418: Vi1.1 LCP: (0x00000000)
*Oct 18 15:30:14.470: Vi1.1 LCP: I TERMREQ [Open] id 4 len 16
(0x0DC850AF003CCD7400000000)
*Oct 18 15:30:14.470: Vi1.1 LCP: O TERMACK [Open] id 4 len 4
*Oct 18 15:30:14.470: Vi1.1 PPP: Sending Acct Event[Down] id[5D]
*Oct 18 15:30:14.470: [83]PPPoE 83: AAA get dynamic attrs
*Oct 18 15:30:14.470: [83]PPPoE 83: AAA get dynamic attrs
*Oct 18 15:30:14.470: Vi1.1 PPP: Phase is TERMINATING
*Oct 18 15:30:14.470: RADIUS/ENCODE(0000005D):Orig. component type =
PPoE
*Oct 18 15:30:14.470: RADIUS/ENCODE(0000005D): Acct-session-id
pre-pended with Nas Port = 0/0/0/0
*Oct 18 15:30:14.470: RADIUS(0000005D): Config NAS IP: 85.xxx.xxx.6
*Oct 18 15:30:14.470: RADIUS(0000005D): sending
*Oct 18 15:30:14.470: RADIUS(0000005D): Send Accounting-Request to
85.xxx.xxx.27:1813 id 1646/176, len 138
*Oct 18 15:30:14.470: RADIUS: authenticator 74 3A 6C FF 4F 62 08 3B -
EF E7 62 6E 60 CC 8A 45
*Oct 18 15:30:14.470: RADIUS: Acct-Session-Id [44] 18
"0/0/0/0_000000E6"
*Oct 18 15:30:14.470: RADIUS: Framed-Protocol [7] 6 PPP
[1]
*Oct 18 15:30:14.470: RADIUS: User-Name [1] 7 "pppoe"
*Oct 18 15:30:14.470: RADIUS: Acct-Authentic [45] 6 RADIUS
[1]
*Oct 18 15:30:14.470: RADIUS: Acct-Session-Time [46] 6 0
*Oct 18 15:30:14.470: RADIUS: Acct-Input-Octets [42] 6 54
*Oct 18 15:30:14.470: RADIUS: Acct-Output-Octets [43] 6 48
*Oct 18 15:30:14.470: RADIUS: Acct-Input-Packets [47] 6 2
*Oct 18 15:30:14.470: RADIUS: Acct-Output-Packets [48] 6 2
*Oct 18 15:30:14.470: RADIUS: Acct-Terminate-Cause[49] 6
user-request [1]
*Oct 18 15:30:14.470: RADIUS: Acct-Status-Type [40] 6 Stop
[2]
*Oct 18 15:30:14.470: RADIUS: NAS-Port-Type [61] 6 Virtual
[5]
*Oct 18 15:30:14.470: RADIUS: NAS-Port [5] 6 0
*Oct 18 15:30:14.470: RADIUS: NAS-Port-Id [87] 9 "0/0/0/0"
*Oct 18 15:30:14.470: RADIUS: Service-Type [6] 6 Framed
[2]
*Oct 18 15:30:14.474: RADIUS: NAS-IP-Address [4] 6
85.xxx.xxx.6
*Oct 18 15:30:14.474: RADIUS: Acct-Delay-Time [41] 6 0
*Oct 18 15:30:14.486: PPPoE 83: I PADT R:0001.4a07.3cd7
L:0016.c789.fe42 Fa0
*Oct 18 15:30:14.486: Vi1.1 PPP: Received Disconnect from Lower Layer
*Oct 18 15:30:14.486: Vi1.1 LCP: O TERMREQ [TERMsent] id 2 len 4
*Oct 18 15:30:14.486: [83]PPPoE 83: Destroying R:0001.4a07.3cd7
L:0016.c789.fe42 Fa0
*Oct 18 15:30:14.486: PPPoE: Returning Vaccess Virtual-Access1.1
*Oct 18 15:30:14.486: Vi1.1 PPP: Block vaccess from being freed [0x8]
*Oct 18 15:30:14.486: [83]PPPoE 83: AAA get dynamic attrs
*Oct 18 15:30:14.486: [83]PPPoE 83: AAA get dynamic attrs
*Oct 18 15:30:14.486: [83]PPPoE 83: AAA account stopped
*Oct 18 15:30:14.486: Vi1.1 LCP: State is Closed
*Oct 18 15:30:14.486: Vi1.1 PPP: Phase is DOWN
*Oct 18 15:30:14.486: Vi1.1 PPP: Unlocked by [0x8] Still Locked by [0x0]
*Oct 18 15:30:14.486: Vi1.1 PPP: Free previously blocked vaccess
*Oct 18 15:30:14.494: RADIUS: Received from id 1646/176
85.xxx.xxx.27:1813, Accounting-response, len 20
*Oct 18 15:30:14.498: RADIUS: authenticator 2B D2 62 A6 71 53 CD CF -
60 1F 92 A9 E2 AB B7 D0
-----Original Message-----
From: Oliver Boehmer (oboehmer) [mailto:oboehmer at cisco.com]
Sent: 18 October 2006 17:09
To: William Jackson; cisco-nsp at puck.nether.net
Subject: RE: [c-nsp] PPPoE and FreeRadius - yet again
cisco-nsp-bounces at puck.nether.net <> wrote on :
> Hi I'm stuck and need some guidance:
>
>
[...]
> Packet-Type = Access-Accept
> Wed Oct 18 16:26:26 2006
> Service-Type = Framed-User
> Framed-Protocol = PPP
> Framed-IP-Address = 85.xxx.xxx.12
> Framed-IP-Netmask = 255.255.255.255
> Framed-Routing = Broadcast-Listen
> Framed-Compression = Van-Jacobson-TCP-IP
>
> It seems that the router isn't receiving the attributes?
>
>
> I cannot seem to find a single decent guide on this, any
> ideas on where to look next?
please enable "debug ppp neg", "debug radius" as well as "debug aaa
authorization" (maybe along with "debug aaa per-user") which should
throw some errors when applying the attributes. Can't spot any obvious
errors, not sure why you configured Framed-Routing (are you running a
routing protocol over this session?), and you possibly want to remove
VJ-compression as this causes the pkts to be process-switched (seriously
limiting the box' scalability).
Above debugs should provide more clue..
oli
More information about the cisco-nsp
mailing list