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

No Peer Address from RADIUS to PPP Subscriber

Hello community,

We use C8500 for PPPoE subscribers. Configuration via bba-group and virtual-template with aaa (Freeradius).

Freeradius receives the user and responds with an Access-Accept. According to the log, an IP address is also selected and is part of the Access-Accept response. However, no IP address is assigned to the client from the BRAS.

The log shows that no peer address is assigned.

Software:
Freeradius 3.2.1
C8500: 17.12.04b

Debugging options

PPP:
  PPP authentication debugging is on
  PPP protocol negotiation debugging is on

PPPoE:
  PPPoE protocol events debugging is on
  PPPoE data packets debugging is on
  PPPoE protocol errors debugging is on
  PPPoE elog debugging is on

Radius protocol debugging is on
Radius protocol brief debugging is on
Radius protocol verbose debugging is on
Radius elog debugging debugging is on

Config for bba and virtual-template (Without radius server options)

bba-group pppoe global
 vendor-tag circuit-id service
 vendor-tag remote-id service
 vendor-tag dsl-sync-rate service
 ac name MY-BRAS
 sessions pre-auth limit ignore
 pado delay 0
!
bba-group pppoe BBA-PPPOE-61
 virtual-template 61
 vendor-tag remote-id service
 vendor-tag dsl-sync-rate service
 nas-port-id format c
 sessions per-mac limit 10
!
interface Virtual-Template61
 description PPPoE Template VLAN61
 mtu 1492
 ip unnumbered Loopback1
 no peer default ip address
 ppp authentication ms-chap-v2 pap pppoe-aaa-test
 ppp accounting pppoe-aaa-test
 ppp ipcp dns 8.8.8.8 1.1.1.1
 ppp ipcp mask 255.255.255.128
 ppp ipcp address required
 ppp ipcp address unique
 ip virtual-reassembly
!

Radius logs with access-request, access-accept and stop

Tue May 13 10:00:19 2025
        Packet-Type = Access-Request
        Framed-Protocol = PPP
        User-Name = "user1@login.mydomain.com"
        NAS-Port-Type = PPPoEoE
        NAS-Port = 4031774720
        NAS-Port-Id = "ether 15/0/5:4096.0 0/0/0/0/0/0"
        Cisco-AVPair = "client-mac-address=e028.6ddc.9128"
        Service-Type = Framed-User
        NAS-IP-Address = 10.0.25.8
        Event-Timestamp = "May 13 2025 10:00:19 CEST"
        Timestamp = 1747130419


Tue May 13 10:00:19 2025
        Packet-Type = Access-Accept
        Framed-Protocol = PPP
        Acct-Interim-Interval = 600
        WISPr-Bandwidth-Max-Down = 1034240
        WISPr-Bandwidth-Max-Up = 1034240
        Session-Timeout = 604800
        Reply-Message = "PublicIPv4Pool"
        Service-Type = Framed-User
        Framed-IP-Address = 117.213.182.129
        Timestamp = 1747130419

Tue May 13 10:00:19 2025
        Acct-Session-Id = "ether 15/0/5:4096.0 0/0/0/0/0/0_0000106F"
        Framed-Protocol = PPP
        Cisco-AVPair = "ppp-disconnect-cause=Peer address required"
        User-Name = "user1@login.mydomain.com"
        Acct-Authentic = RADIUS
        Cisco-AVPair = "connect-progress=Call Up"
        Cisco-AVPair = "nas-tx-speed=1000000000"
        Cisco-AVPair = "nas-tx-speed-kbps=1000000"
        Cisco-AVPair = "nas-rx-speed=1000000000"
        Cisco-AVPair = "nas-rx-speed-kbps=1000000"
        Acct-Session-Time = 0
        Acct-Input-Octets = 0
        Acct-Output-Octets = 12
        Acct-Input-Packets = 0
        Acct-Output-Packets = 1
        Acct-Terminate-Cause = NAS-Error
        Cisco-AVPair = "disc-cause-ext=PPP LCP Close"
        Acct-Status-Type = Stop
        NAS-Port-Type = PPPoEoE
        NAS-Port = 4031774720
        NAS-Port-Id = "ether 15/0/5:4096.0 0/0/0/0/0/0"
        Cisco-AVPair = "client-mac-address=e028.6ddc.9128"
        Service-Type = Framed-User
        NAS-IP-Address = 10.0.25.8
        Acct-Delay-Time = 0
        Event-Timestamp = "May 13 2025 10:00:19 CEST"
        Acct-Unique-Session-Id = "6a7908e054ac176ddbf15999ec417ef2"
        Timestamp = 1747130419

Debug output from C8500

May 13 10:00:19.079: PPPoE 0: I PADI  R:e028.6ddc.9128 L:ffff.ffff.ffff BD61
May 13 10:00:19.079:  Service tag: NULL Tag
May 13 10:00:19.079: PPPoE 0: O PADO, R:9433.d8ba.11bf L:e028.6ddc.9128 BD61
May 13 10:00:19.079:  Service tag: NULL Tag
May 13 10:00:19.080: PPPoE 0: I PADR  R:e028.6ddc.9128 L:9433.d8ba.11bf BD61
May 13 10:00:19.080:  Service tag: NULL Tag
May 13 10:00:19.080: [182]PPPoE 182: Access IE handle allocated
May 13 10:00:19.080: [182]PPPoE 182: AAA get retrieved attrs
May 13 10:00:19.080: [182]PPPoE 182: AAA get nas port details
May 13 10:00:19.080: [182]PPPoE 182: Error adjusting nas port format did
May 13 10:00:19.080: dyn_attrs->xmit_rate: 1000000000 dyn_attrs->rcv_rate: 1000000000
May 13 10:00:19.080: [182]PPPoE 182: AAA get dynamic attrs
May 13 10:00:19.080: [182]PPPoE 182: AAA unique ID DD allocated
May 13 10:00:19.080: [182]PPPoE 182: No AAA accounting method list
May 13 10:00:19.080: [182]PPPoE 182: Service request sent to SSS
May 13 10:00:19.080: [182]PPPoE 182: Created, Service: None R:9433.d8ba.11bf L:e028.6ddc.9128 BD61
May 13 10:00:19.081: SSS PM [uid:182][7EAF93F2C758][AAA ID:221]: AAA author NOT needed
May 13 10:00:19.081: [182]PPPoE 182: State NAS_PORT_POLICY_INQUIRY    Event SSS MORE KEYS
May 13 10:00:19.081: PPP: Alloc Context [7EAF7F0E70F8]
May 13 10:00:19.081: ppp182 PPP: Phase is ESTABLISHING
May 13 10:00:19.081: [182]PPPoE 182: data path set to PPP
May 13 10:00:19.081: [182]PPPoE 182: Segment (SSS class): PROVISION
May 13 10:00:19.081: [182]PPPoE 182: State PROVISION_PPP    Event SSM PROVISIONED
May 13 10:00:19.081: [182]PPPoE 182: O PADS  R:e028.6ddc.9128 L:9433.d8ba.11bf BD61
May 13 10:00:19.081: [182]PPPoE 182: Unable to Add ANCP Line attributes to the PPPoE Authen attributes
May 13 10:00:19.081: ppp182 PPP: Using vpn set call direction
May 13 10:00:19.081: ppp182 PPP: Treating connection as a callin
May 13 10:00:19.081: ppp182 PPP: Session handle[F50000B6] Session id[182]
May 13 10:00:19.081: ppp182 LCP: Event[OPEN] State[Initial to Starting]
May 13 10:00:19.081: ppp182 PPP LCP: Enter passive mode, state[Stopped]
May 13 10:00:19.081: ppp182 LCP: I CONFREQ [Stopped] id 1 len 14
May 13 10:00:19.082: ppp182 LCP:    MRU 1492 (0x010405D4)
May 13 10:00:19.082: ppp182 LCP:    MagicNumber 0x0158605F (0x05060158605F)
May 13 10:00:19.082: ppp182 LCP: O CONFREQ [Stopped] id 1 len 19
May 13 10:00:19.082: ppp182 LCP:    MRU 1492 (0x010405D4)
May 13 10:00:19.082: ppp182 LCP:    AuthProto MS-CHAP-V2 (0x0305C22381)
May 13 10:00:19.082: ppp182 LCP:    MagicNumber 0xD84DCEB9 (0x0506D84DCEB9)
May 13 10:00:19.082: [182]PPPoE 182: O
May 13 10:00:19.082: ppp182 LCP: O CONFACK [Stopped] id 1 len 14
May 13 10:00:19.082: ppp182 LCP:    MRU 1492 (0x010405D4)
May 13 10:00:19.082: ppp182 LCP:    MagicNumber 0x0158605F (0x05060158605F)
May 13 10:00:19.082: [182]PPPoE 182: O
May 13 10:00:19.082: ppp182 LCP: Event[Receive ConfReq+] State[Stopped to ACKsent]
May 13 10:00:19.082: ppp182 LCP: I CONFNAK [ACKsent] id 1 len 9
May 13 10:00:19.082: ppp182 LCP:    AuthProto CHAP (0x0305C22305)
May 13 10:00:19.082: ppp182 LCP: O CONFREQ [ACKsent] id 2 len 18
May 13 10:00:19.082: ppp182 LCP:    MRU 1492 (0x010405D4)
May 13 10:00:19.082: ppp182 LCP:    AuthProto PAP (0x0304C023)
May 13 10:00:19.082: ppp182 LCP:    MagicNumber 0xD84DCEB9 (0x0506D84DCEB9)
May 13 10:00:19.082: [182]PPPoE 182: O
May 13 10:00:19.082: ppp182 LCP: Event[Receive ConfNak/Rej] State[ACKsent to ACKsent]
May 13 10:00:19.083: ppp182 LCP: I CONFACK [ACKsent] id 2 len 18
May 13 10:00:19.083: ppp182 LCP:    MRU 1492 (0x010405D4)
May 13 10:00:19.083: ppp182 LCP:    AuthProto PAP (0x0304C023)
May 13 10:00:19.083: ppp182 LCP:    MagicNumber 0xD84DCEB9 (0x0506D84DCEB9)
May 13 10:00:19.083: ppp182 LCP: Event[Receive ConfAck] State[ACKsent to Open]
May 13 10:00:19.083: ppp182 PPP: Queue PAP code[1] id[1]
May 13 10:00:19.090: ppp182 PPP: Phase is AUTHENTICATING, by this end
May 13 10:00:19.090: ppp182 PAP: Redirect packet to ppp182
May 13 10:00:19.090: ppp182 PAP: I AUTH-REQ id 1 len 38 from "user1@login.mydomain.com"
May 13 10:00:19.090: ppp182 PAP: Authenticating peer user1@login.mydomain.com
May 13 10:00:19.090: ppp182 PPP: Phase is FORWARDING, Attempting Forward
May 13 10:00:19.090: ppp182 LCP: State is Open
May 13 10:00:19.090: ppp182 PPP: Phase is AUTHENTICATING, Unauthenticated User
May 13 10:00:19.090: ppp182 PPP: Sent PAP LOGIN Request
May 13 10:00:19.090: RADIUS/ENCODE(000000DD):Orig. component type = PPPoE
May 13 10:00:19.090: RADIUS: DSL line rate attributes successfully added
May 13 10:00:19.090: RADIUS/ENCODE: Skip encoding 0 length AAA attribute formatted-clid
May 13 10:00:19.090: RADIUS: Format E value 0xF for character S with bitmask 0xF
May 13 10:00:19.090: RADIUS: Format E port 0xF with bit 4 processed
May 13 10:00:19.090: RADIUS: Format E value 0x0 for character A with bitmask 0xF
May 13 10:00:19.090: RADIUS: Format E port 0xF0 with bit 8 processed
May 13 10:00:19.090: RADIUS: Format E value 0x5 for character P with bitmask 0xF
May 13 10:00:19.090: RADIUS: Format E port 0xF05 with bit 12 processed
May 13 10:00:19.090: RADIUS: Format E value 0x0 for character V with bitmask 0xFFFFF
May 13 10:00:19.090: RADIUS: Format E port 0xF0500000 with bit 32 processed
May 13 10:00:19.090: RADIUS(000000DD): Config NAS IP: 10.0.25.8
May 13 10:00:19.090: vrfid: [65535]  ipv6 tableid : [0]
May 13 10:00:19.090: idb is NULL
May 13 10:00:19.090: RADIUS(000000DD): Config NAS IPv6: ::
May 13 10:00:19.090: RADIUS(000000DD): Send Access-Request to 192.168.203.132:1812 id 1645/164, len 168
May 13 10:00:19.090: RADIUS(000000DD): Sending a IPv4 Radius Packet
May 13 10:00:19.091: RADIUS(000000DD): Started 5 sec timeout
May 13 10:00:19.096: RADIUS: Received from id 1645/164 192.168.203.132:1812, Access-Accept, len 90
May 13 10:00:19.096: RADIUS/DECODE: unsupported WISPr VSA 8; IGNORE
May 13 10:00:19.096: RADIUS/DECODE: unsupported WISPr VSA 7; IGNORE
RADIUS/DECODE: Reply-Message fragments, 14, total 14 bytes
May 13 10:00:19.096: ppp182 PPP: Received LOGIN Response PASS
May 13 10:00:19.096: ppp182 PPP: Phase is FORWARDING, Attempting Forward
May 13 12:00:19.098: %SYS-5-CONFIG_P: Configured programmatically by process VTEMPLATE Background Mgr from console as console
May 13 10:00:19.098: [182]PPPoE 182: State LCP_NEGOTIATION    Event SSS CONNECT LOCAL
May 13 10:00:19.099: [182]PPPoE 182: Segment (SSS class): UPDATED
May 13 10:00:19.099: [182]PPPoE 182: Segment (SSS class): BOUND
May 13 10:00:19.099: [182]PPPoE 182: data path set to Virtual Acess
May 13 10:00:19.099: [182]PPPoE 182: State LCP_NEGOTIATION    Event SSM UPDATED
May 13 10:00:19.099: Vi2.1 PPP: Phase is AUTHENTICATING, Authenticated User
May 13 10:00:19.099: Vi2.1 PAP: O AUTH-ACK id 1 len 5
May 13 10:00:19.099: [182]PPPoE 182: O
May 13 10:00:19.099: dyn_attrs->xmit_rate: 1000000000 dyn_attrs->rcv_rate: 1000000000
May 13 10:00:19.099: [182]PPPoE 182: AAA get dynamic attrs
May 13 10:00:19.100: Vi2.1 PPP: Phase is UP
May 13 10:00:19.100: Vi2.1 IPCP: Protocol configured, start CP. state[Initial]
May 13 10:00:19.100: Vi2.1 IPCP: Event[OPEN] State[Initial to Starting]
May 13 10:00:19.100: Vi2.1 IPCP: O CONFREQ [Starting] id 1 len 10
May 13 10:00:19.100: Vi2.1 IPCP:    Address 117.213.177.74 (0x0306D971B14A)
May 13 10:00:19.100: [182]PPPoE 182: O
May 13 10:00:19.100: Vi2.1 IPCP: Event[UP] State[Starting to REQsent]
May 13 10:00:19.100: RADIUS/ENCODE(000000DD):Orig. component type = PPPoE
May 13 10:00:19.100: RADIUS/ENCODE(000000DD): Acct-session-id pre-pended with Nas Port = ether 15/0/5:4096.0 0/0/0/0/0/0
May 13 10:00:19.100: RADIUS/ENCODE: Skip encoding 0 length AAA attribute formatted-clid
May 13 10:00:19.100: RADIUS: Format E value 0xF for character S with bitmask 0xF
May 13 10:00:19.100: RADIUS: Format E port 0xF with bit 4 processed
May 13 10:00:19.100: RADIUS: Format E value 0x0 for character A with bitmask 0xF
May 13 10:00:19.100: RADIUS: Format E port 0xF0 with bit 8 processed
May 13 10:00:19.100: RADIUS: Format E value 0x5 for character P with bitmask 0xF
May 13 10:00:19.100: RADIUS: Format E port 0xF05 with bit 12 processed
May 13 10:00:19.100: RADIUS: Format E value 0x0 for character V with bitmask 0xFFFFF
May 13 10:00:19.100: RADIUS: Format E port 0xF0500000 with bit 32 processed
May 13 10:00:19.100: RADIUS(000000DD): Config NAS IP: 10.0.25.8
May 13 10:00:19.100: vrfid: [65535]  ipv6 tableid : [0]
May 13 10:00:19.100: idb is NULL
May 13 10:00:19.100: RADIUS(000000DD): Config NAS IPv6: ::
May 13 10:00:19.100: [182]PPPoE 182: State PTA_BINDING    Event STATIC BIND RESPONSE
May 13 10:00:19.100: [182]PPPoE 182: Connected PTA
May 13 10:00:19.100: RADIUS(000000DD): Send Accounting-Request to 192.168.203.132:1813 id 1646/129, len 242
May 13 10:00:19.100: RADIUS(000000DD): Sending a IPv4 Radius Packet
May 13 10:00:19.100: RADIUS(000000DD): Started 5 sec timeout
May 13 10:00:19.100: Vi2.1 IPCP: I CONFREQ [REQsent] id 2 len 22
May 13 10:00:19.100: Vi2.1 IPCP:    Address 0.0.0.0 (0x030600000000)
May 13 10:00:19.100: Vi2.1 IPCP:    PrimaryDNS 0.0.0.0 (0x810600000000)
May 13 10:00:19.100: Vi2.1 IPCP:    SecondaryDNS 0.0.0.0 (0x830600000000)
May 13 10:00:19.100: Vi2.1 IPCP AUTHOR: Done. Her address 0.0.0.0, we want 0.0.0.0
May 13 10:00:19.100: Vi2.1 IPCP: No peer address configured
May 13 10:00:19.100: Vi2.1 IPCP: Neither side knows remote address
May 13 10:00:19.100: Vi2.1 IPCP: Dual NCP check. V6 status from Ctx 1
May 13 10:00:19.100: Vi2.1 PPP DISC: Peer address required
May 13 10:00:19.100: Vi2.1 PPP: Sending Acct Event[Down] id[DD]
May 13 10:00:19.100: dyn_attrs->xmit_rate: 1000000000 dyn_attrs->rcv_rate: 1000000000
May 13 10:00:19.100: [182]PPPoE 182: AAA get dynamic attrs
May 13 10:00:19.100: PPP: NET STOP send to AAA.
May 13 10:00:19.100: Vi2.1 IPCP: O TERMREQ [REQsent] id 2 len 4
May 13 10:00:19.100: [182]PPPoE 182: O
May 13 10:00:19.100: Vi2.1 IPCP: Event[CLOSE] State[REQsent to Closing]
May 13 10:00:19.100: Vi2.1 IPV6CP: LCP not open, discarding packet
May 13 10:00:19.100: Vi2.1 IPCP: Event[DOWN] State[Closing to Initial]
May 13 10:00:19.100: Vi2.1 IPCP: Event[CLOSE] State[Initial to Initial]
May 13 10:00:19.101: Vi2.1 LCP: O TERMREQ [Open] id 3 len 4
May 13 10:00:19.101: [182]PPPoE 182: O
May 13 10:00:19.101: Vi2.1 LCP: Event[CLOSE] State[Open to Closing]
May 13 10:00:19.101: Vi2.1 PPP: Phase is TERMINATING
May 13 10:00:19.101: RADIUS/ENCODE(000000DD):Orig. component type = PPPoE
May 13 10:00:19.101: RADIUS/ENCODE(000000DD): Acct-session-id pre-pended with Nas Port = ether 15/0/5:4096.0 0/0/0/0/0/0
May 13 10:00:19.101: RADIUS/ENCODE: Skip encoding 0 length AAA attribute formatted-clid
May 13 10:00:19.101: RADIUS: Format E value 0xF for character S with bitmask 0xF
May 13 10:00:19.101: RADIUS: Format E port 0xF with bit 4 processed
May 13 10:00:19.101: RADIUS: Format E value 0x0 for character A with bitmask 0xF
May 13 10:00:19.101: RADIUS: Format E port 0xF0 with bit 8 processed
May 13 10:00:19.101: RADIUS: Format E value 0x5 for character P with bitmask 0xF
May 13 10:00:19.101: RADIUS: Format E port 0xF05 with bit 12 processed
May 13 10:00:19.101: RADIUS: Format E value 0x0 for character V with bitmask 0xFFFFF
May 13 10:00:19.101: RADIUS: Format E port 0xF0500000 with bit 32 processed
May 13 10:00:19.101: RADIUS(000000DD): Config NAS IP: 10.0.25.8
May 13 10:00:19.101: vrfid: [65535]  ipv6 tableid : [0]
May 13 10:00:19.101: idb is NULL
May 13 10:00:19.101: RADIUS(000000DD): Config NAS IPv6: ::
May 13 10:00:19.101: RADIUS(000000DD): Send Accounting-Request to 192.168.203.132:1813 id 1646/130, len 492
May 13 10:00:19.101: RADIUS(000000DD): Sending a IPv4 Radius Packet
May 13 10:00:19.101: RADIUS(000000DD): Started 5 sec timeout
May 13 10:00:19.101: Vi2.1 LCP: I TERMACK [Closing] id 3 len 4
May 13 10:00:19.101: Vi2.1 LCP: Event[Receive TermAck] State[Closing to Closed]
May 13 10:00:19.101: Vi2.1 LCP: Event[DOWN] State[Closed to Initial]
May 13 10:00:19.101: ppp_session_ntfy delete, topswidb Vi2.1, va Vi2.1, platform notify 0
May 13 10:00:19.101: Vi2.1 PPP: Phase is DOWN
May 13 10:00:19.101: [182]PPPoE 182: State LOCALLY_TERMINATED    Event PPP DISCONNECT
May 13 10:00:19.101: [182]PPPoE 182: O PADT  R:e028.6ddc.9128 L:9433.d8ba.11bf BD61
May 13 10:00:19.101: [182]PPPoE 182: Destroying  R:e028.6ddc.9128 L:9433.d8ba.11bf BD61
May 13 10:00:19.101: PPPoE: Returning Vaccess Virtual-Access2.1
May 13 10:00:19.102: [182]PPPoE 182: AAA account stopped
May 13 10:00:19.102: PPPoE 182: I PADT  R:e028.6ddc.9128 L:9433.d8ba.11bf BD61
May 13 10:00:19.102: [182]PPPoE 182: Segment (SSS class): UNBOUND
May 13 10:00:19.102: [182]PPPoE 182: Vi2.1 Block vaccess from being freed.
May 13 10:00:19.103: [182]PPPoE 182: Segment (SSS class): UNPROVISION
May 13 12:00:19.103: %SYS-5-CONFIG_P: Configured programmatically by process VTEMPLATE Background Mgr from console as console
May 13 10:00:19.104: RADIUS: Removing all radius source-int. pointing to Virtual-Access2.1

Here is the important point, but why? 

May 13 10:00:19.100: Vi2.1 IPCP: I CONFREQ [REQsent] id 2 len 22
May 13 10:00:19.100: Vi2.1 IPCP:    Address 0.0.0.0 (0x030600000000)
May 13 10:00:19.100: Vi2.1 IPCP:    PrimaryDNS 0.0.0.0 (0x810600000000)
May 13 10:00:19.100: Vi2.1 IPCP:    SecondaryDNS 0.0.0.0 (0x830600000000)
May 13 10:00:19.100: Vi2.1 IPCP AUTHOR: Done. Her address 0.0.0.0, we want 0.0.0.0
May 13 10:00:19.100: Vi2.1 IPCP: No peer address configured
May 13 10:00:19.100: Vi2.1 IPCP: Neither side knows remote address

Thank you and best regards
Michael

 

 

 

0 Replies 0