Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[defect]: Proxying EAP sessions fails when using eap in pre-proxy #5486

Closed
meadmaker opened this issue Jan 6, 2025 · 0 comments
Closed

[defect]: Proxying EAP sessions fails when using eap in pre-proxy #5486

meadmaker opened this issue Jan 6, 2025 · 0 comments
Labels
defect category: a defect or misbehaviour

Comments

@meadmaker
Copy link
Contributor

What type of defect/bug is this?

Unexpected behaviour (obvious or verified by project member)

How can the issue be reproduced?

This issue applies to the 3.2.x branch.

  1. Add eap to the pre-proxy section of the default site.
  2. Create a home_server, home_server_pool, and realm entry in proxy.conf to define proxying requests to a home_server.
  3. Create a client in clients.conf to accept connections.
  4. Generate a RADIUS/EAP authentication session for the realm that will be proxied. I used rad_eap_test.

Any EAP authentication to be proxied will fail before the proxying happens, in the first packet of the EAP/RADIUS authentication.

Log output from the FreeRADIUS daemon

The most relevant line of the output is:

eap: EAP length does not match attribute length

The full output is:

root@bf3e4ff0358d:/etc/freeradius# raddebug -t 0
(721) Mon Jan  6 04:04:48 2025: Debug: Received Access-Request Id 0 from 172.16.128.101:42788 to 172.16.128.10:1812 length 145
(721) Mon Jan  6 04:04:48 2025: Debug:   User-Name = "bob@testing.id"
(721) Mon Jan  6 04:04:48 2025: Debug:   NAS-IP-Address = 127.0.0.1
(721) Mon Jan  6 04:04:48 2025: Debug:   Calling-Station-Id = "70-6F-6C-69-73-68"
(721) Mon Jan  6 04:04:48 2025: Debug:   Framed-MTU = 1400
(721) Mon Jan  6 04:04:48 2025: Debug:   NAS-Port-Type = Wireless-802.11
(721) Mon Jan  6 04:04:48 2025: Debug:   Service-Type = Framed-User
(721) Mon Jan  6 04:04:48 2025: Debug:   Connect-Info = "rad_eap_test + eapol_test"
(721) Mon Jan  6 04:04:48 2025: Debug:   EAP-Message = 0x02b7001301626f624074657374696e672e6964
(721) Mon Jan  6 04:04:48 2025: Debug:   Message-Authenticator = 0x27def39f84d9349d5e9a4d61034900d6
(721) Mon Jan  6 04:04:48 2025: Debug: # Executing section authorize from file /etc/freeradius/sites-enabled/default
(721) Mon Jan  6 04:04:48 2025: Debug:   authorize {
(721) Mon Jan  6 04:04:48 2025: Debug:     policy filter_username {
(721) Mon Jan  6 04:04:48 2025: Debug:       if (&User-Name) {
(721) Mon Jan  6 04:04:48 2025: Debug:       if (&User-Name)  -> TRUE
(721) Mon Jan  6 04:04:48 2025: Debug:       if (&User-Name)  {
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ / /) {
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ / /)  -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /@[^@]*@/ ) {
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /@[^@]*@/ )  -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /\.\./ ) {
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /\.\./ )  -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))  {
(721) Mon Jan  6 04:04:48 2025: Debug:         if ((&User-Name =~ /@/) && (&User-Name !~ /@(.+)\.(.+)$/))   -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /\.$/)  {
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /\.$/)   -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /@\./)  {
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /@\./)   -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:       } # if (&User-Name)  = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     } # policy filter_username = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     policy additional_filter_username {
(721) Mon Jan  6 04:04:48 2025: Debug:       if (&User-Name) {
(721) Mon Jan  6 04:04:48 2025: Debug:       if (&User-Name)  -> TRUE
(721) Mon Jan  6 04:04:48 2025: Debug:       if (&User-Name)  {
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /@.*([^a-zA-Z0-9\.-]).*/) {
(721) Mon Jan  6 04:04:48 2025: Debug:         if (&User-Name =~ /@.*([^a-zA-Z0-9\.-]).*/)  -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:       } # if (&User-Name)  = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     } # policy additional_filter_username = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     [preprocess] = ok
(721) Mon Jan  6 04:04:48 2025: Debug:     [chap] = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     [mschap] = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     [digest] = noop
(721) Mon Jan  6 04:04:48 2025: Debug: suffix: Checking for suffix after "@"
(721) Mon Jan  6 04:04:48 2025: Debug: suffix: Looking up realm "testing.id" for User-Name = "bob@testing.id"
(721) Mon Jan  6 04:04:48 2025: Debug: suffix: Found realm "testing.id"
(721) Mon Jan  6 04:04:48 2025: Debug: suffix: Adding Realm = "testing.id"
(721) Mon Jan  6 04:04:48 2025: Debug: suffix: Proxying request from user bob@testing.id to realm testing.id
(721) Mon Jan  6 04:04:48 2025: Debug: suffix: Preparing to proxy authentication request to realm "testing.id"

(721) Mon Jan  6 04:04:48 2025: Debug:     [suffix] = updated
(721) Mon Jan  6 04:04:48 2025: Debug:     update control {
(721) Mon Jan  6 04:04:48 2025: Debug:       EXPAND %{Calling-Station-ID} %{User-Name}
(721) Mon Jan  6 04:04:48 2025: Debug:          --> 70-6F-6C-69-73-68 bob@testing.id
(721) Mon Jan  6 04:04:48 2025: Debug:     } # update control = noop
(721) Mon Jan  6 04:04:48 2025: Debug: eap: Request is supposed to be proxied to Realm testing.id. Not doing EAP.
(721) Mon Jan  6 04:04:48 2025: Debug:     [eap] = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     [files] = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     [expiration] = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     [logintime] = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     [pap] = noop
(721) Mon Jan  6 04:04:48 2025: Debug:   } # authorize = updated
(721) Mon Jan  6 04:04:48 2025: Debug: Starting proxy to home server 172.16.128.100 port 1812
(721) Mon Jan  6 04:04:48 2025: Debug: server default {
(721) Mon Jan  6 04:04:48 2025: Debug:   # Executing section pre-proxy from file /etc/freeradius/sites-enabled/default
(721) Mon Jan  6 04:04:48 2025: Debug:     pre-proxy {
(721) Mon Jan  6 04:04:48 2025: Debug:       policy loop-control-vsa.pre-proxy {
(721) Mon Jan  6 04:04:48 2025: Debug:         if ( &Internet2-Loop-Detection && &Internet2-Loop-Detection == 1 ) {
(721) Mon Jan  6 04:04:48 2025: Debug:         if ( &Internet2-Loop-Detection && &Internet2-Loop-Detection == 1 )  -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:         else {
(721) Mon Jan  6 04:04:48 2025: Debug:           update proxy-request {
(721) Mon Jan  6 04:04:48 2025: Debug:           } # update proxy-request = noop
(721) Mon Jan  6 04:04:48 2025: Debug:         } # else = noop
(721) Mon Jan  6 04:04:48 2025: Debug:       } # policy loop-control-vsa.pre-proxy = noop
(721) Mon Jan  6 04:04:48 2025: Debug:       policy loop-control-proxy-state.pre-proxy {
(721) Mon Jan  6 04:04:48 2025: Debug:         if ( <integer>"%{Proxy-State[#]}" >= 10 ) {
(721) Mon Jan  6 04:04:48 2025: Debug:         EXPAND %{Proxy-State[#]}
(721) Mon Jan  6 04:04:48 2025: Debug:            --> 0
(721) Mon Jan  6 04:04:48 2025: Debug:         if ( <integer>"%{Proxy-State[#]}" >= 10 )  -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:       } # policy loop-control-proxy-state.pre-proxy = noop
(721) Mon Jan  6 04:04:48 2025: Debug: eap: EAP length does not match attribute length
(721) Mon Jan  6 04:04:48 2025: Debug:       [eap] = reject
(721) Mon Jan  6 04:04:48 2025: Debug:     } # pre-proxy = reject
(721) Mon Jan  6 04:04:48 2025: Debug: }
(721) Mon Jan  6 04:04:48 2025: Debug: There was no response configured: rejecting request
(721) Mon Jan  6 04:04:48 2025: Debug: Using Post-Auth-Type Reject
(721) Mon Jan  6 04:04:48 2025: Debug: # Executing group from file /etc/freeradius/sites-enabled/default
(721) Mon Jan  6 04:04:48 2025: Debug: attr_filter.access_reject: EXPAND %{User-Name}
(721) Mon Jan  6 04:04:48 2025: Debug: attr_filter.access_reject:    --> bob@testing.id
(721) Mon Jan  6 04:04:48 2025: Debug: attr_filter.access_reject: Matched entry DEFAULT at line 11
(721) Mon Jan  6 04:04:48 2025: Debug:     [attr_filter.access_reject] = updated
(721) Mon Jan  6 04:04:48 2025: Debug: eap: Request was previously rejected, inserting EAP-Failure
(721) Mon Jan  6 04:04:48 2025: Debug: eap: Sending EAP Failure (code 4) ID 183 length 4
(721) Mon Jan  6 04:04:48 2025: Debug:     [eap] = updated
(721) Mon Jan  6 04:04:48 2025: Debug:     policy remove_reply_message_if_eap {
(721) Mon Jan  6 04:04:48 2025: Debug:       if (&reply:EAP-Message && &reply:Reply-Message) {
(721) Mon Jan  6 04:04:48 2025: Debug:       if (&reply:EAP-Message && &reply:Reply-Message)  -> FALSE
(721) Mon Jan  6 04:04:48 2025: Debug:       else {
(721) Mon Jan  6 04:04:48 2025: Debug:         [noop] = noop
(721) Mon Jan  6 04:04:48 2025: Debug:       } # else = noop
(721) Mon Jan  6 04:04:48 2025: Debug:     } # policy remove_reply_message_if_eap = noop
(721) Mon Jan  6 04:04:48 2025: Debug:   } # Post-Auth-Type REJECT = updated
(721) Mon Jan  6 04:04:48 2025: Debug: EXPAND VISINST=%{client:instid},NEXTHOP=%{home_server:instid}
(721) Mon Jan  6 04:04:48 2025: Debug:    --> VISINST=docker-compose-rad-eap-test,NEXTHOP=testing
(721) Mon Jan  6 04:04:48 2025: Debug: Sent Access-Reject Id 0 from 172.16.128.10:1812 to 172.16.128.101:42788 length 50
(721) Mon Jan  6 04:04:48 2025: Debug:   Error-Cause = Invalid-EAP-Packet
(721) Mon Jan  6 04:04:48 2025: Debug:   EAP-Message = 0x04b70004
(721) Mon Jan  6 04:04:48 2025: Debug:   Message-Authenticator = 0x00000000000000000000000000000000
(721) Mon Jan  6 04:04:48 2025: Debug: Finished request


### Relevant log output from client utilities

`rad_eap_test` indicates authentication failure:

rad-eap-test-1 | access-reject; 0.00 sec |rtt=0ms;;;0;5000 accept=1;0.5:;0:;0;1


### Backtrace from LLDB or GDB

_No response_
@meadmaker meadmaker added the defect category: a defect or misbehaviour label Jan 6, 2025
alandekok pushed a commit that referenced this issue Jan 6, 2025
The calculation of EAP message length needs to total the length
of all the EAP message attributes, rather than the length of the
first EAP message attribute and all subsequent attributes of all
types.  Also, enhance the error message to include the calculated
lengths.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
defect category: a defect or misbehaviour
Projects
None yet
Development

No branches or pull requests

2 participants