FreeRADIUS / freeradius-server

FreeRADIUS - A multi-protocol policy server.
http://freeradius.org
GNU General Public License v2.0
2.1k stars 1.08k forks source link

[defect]: session-state is empty in post_auth section after proxying request to home server, branch 3.2.x #5288

Open vo-va opened 8 months ago

vo-va commented 8 months ago

What type of defect/bug is this?

Unexpected behaviour (obvious or verified by project member)

How can the issue be reproduced?

I am still not sure if this is a true issue or just a change that will be a new and standard flow.


Run 2 servers proxy and home server. Configure proxy server and supplicant in such way that the request will be proxied to the home server. In post_auth section use debug_all statement to see all dicts, request, reply, session-state etc.

The radius server compiled with commit from the HEAD of the branch 3.2.x will show that session-state is empty The radius server compiled from this commit 27e4c6764eac8343eb4811a91bef5c364f8e7426 will show data in session-state dict.


I am using session-state to store the inner user name in a custom attribute. It is like "permanent" storage, to not lose it for example by data from a reply from the home server.

The "proxy" server knows some additional about the user with the "inner username" name, like the VLAN number and attaches it to the final reply. So in the post_auth section, I am sending a request to the Python module and trying to use data from session-state.

Log output from the FreeRADIUS daemon

The first log output from the server compiled with commit 27e4c6764eac8343eb4811a91bef5c364f8e7426, I hid some private info, but I hope it still will be able to demonstrate the changes.

(9)   post-auth {
(9)     policy debug_all {
(9)       policy debug_control {

(9)         ...

(9)       policy debug_session_state {
(9)         if ("%{debug_attr:session-state:}" == '') {
(9)         Attributes matching "session-state:"
(9)           &session-state:Framed-MTU = 994
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - recv TLS 1.2 Handshake, ClientHello
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, ServerHello
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, Certificate
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - recv TLS 1.2 Handshake, ClientKeyExchange
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - recv TLS 1.2 ChangeCipherSpec
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - recv TLS 1.2 Handshake, Finished
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 ChangeCipherSpec
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, Finished
(9)           &session-state:TLS-Session-Cipher-Suite = ECDHE-RSA-AES256-GCM-SHA384
(9)           &session-state:TLS-Session-Version = TLS 1.2
(9)           &session-state:Supplicant-Inner-User-Name := testing_remote
(9)         EXPAND %{debug_attr:session-state:}
(9)            -->
(9)         if ("%{debug_attr:session-state:}" == '')  -> TRUE
(9)         if ("%{debug_attr:session-state:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:session-state:}" == '')  = noop
(9)       } # policy debug_session_state = noop
(9)     } # policy debug_all = noop
(9)     update request {
(9)       EXPAND %l
(9)          --> 1706791193
(9)       Supplicant-Timestamp := 1706791193
(9)       EXPAND %{Packet-Type}
(9)          --> Access-Request
(9)       Supplicant-Packet-Type := Access-Request
(9)       EXPAND %{reply:Packet-Type}
(9)          --> Access-Accept
(9)       Supplicant-Auth-Result := Access-Accept
(9)     } # update request = noop
(9)     policy copyback_user_identity {
(9)       if (&session-state:Supplicant-Inner-User-Name){
(9)       if (&session-state:Supplicant-Inner-User-Name) -> TRUE
(9)       if (&session-state:Supplicant-Inner-User-Name) {
(9)         update request {
(9)           User-Name := &session-state:Supplicant-Inner-User-name -> 'testing_remote'
(9)         } # update request = noop
(9)       } # if (&session-state:Supplicant-Inner-User-Name) = noop
(9)       ... skipping else: Preceding "if" was taken
(9)       if (&session-state:Inner-Reply-Message){
(9)       if (&session-state:Inner-Reply-Message) -> FALSE
(9)     } # policy copyback_user_identity = noop

Next is the python module that uses User-Name from request dict, and set the final vlan number that will be returned in reply to supplicant

*** post_auth ***
Waking up in 0.1 seconds.
b'Success!'
***************
post_auth - 'reply:Tunnel-Private-Group-id' := '888'
post_auth - 'reply:Tunnel-Type' := 'VLAN'

... HERE I've hid my private data 

post_auth - 'config:Cleartext-Password' := 'testing'
(9)     [python_auth] = updated
(9)     policy debug_all {
(9)       policy debug_control {
(9)         if ("%{debug_attr:control:}" == '') {
(9)         Attributes matching "control:"
(9)           &control:Auth-Type = eap
(9)           &control:Cleartext-Password = testing
(9)         EXPAND %{debug_attr:control:}
(9)            -->
(9)         if ("%{debug_attr:control:}" == '')  -> TRUE
(9)         if ("%{debug_attr:control:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:control:}" == '')  = noop
(9)       } # policy debug_control = noop
(9)       policy debug_request {
(9)         if ("%{debug_attr:request:}" == '') {
(9)         Attributes matching "request:"
(9)           &request:User-Name := testing_remote
(9)           &request:NAS-IP-Address = 127.0.0.1
(9)           &request:Calling-Station-Id = 02-00-00-00-00-01
(9)           &request:Framed-MTU = 1400
(9)           &request:NAS-Port-Type = Wireless-802.11
(9)           &request:Service-Type = Framed-User
(9)           &request:Connect-Info = CONNECT 11Mbps 802.11b
(9)           &request:NAS-Identifier = foo
(9)           &request:EAP-Message = 0x026f002e19001703030023c4d5558a056ecdd9b3281b86b83ee953b6cfed72d64a95d62fcedea5dd4c0283bbf769
(9)           &request:State = 0x53ee07385b811ef9038f051504df3865
(9)           &request:Message-Authenticator = 0xa43ca46ea92fe54774329c94692c3b4c
(9)           &request:Event-Timestamp = Feb  1 2024 12:39:53 UTC
(9)           &request:Supplicant-Radius-Ip := 0.0.0.0
(9)           &request:Supplicant-Radius-Port := 1812
(9)           &request:Selected-EAP-Module := eap
(9)           &request:EAP-Type = PEAP
(9)           &request:Supplicant-Timestamp := 1706791193
(9)           &request:Supplicant-Packet-Type := Access-Request
(9)           &request:Supplicant-Auth-Result := Access-Accept
(9)         EXPAND %{debug_attr:request:}
(9)            -->
(9)         if ("%{debug_attr:request:}" == '')  -> TRUE
(9)         if ("%{debug_attr:request:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:request:}" == '')  = noop
(9)       } # policy debug_request = noop
(9)       policy debug_coa {
(9)         if ("%{debug_attr:coa:}" == '') {
(9)         Attributes matching "coa:"
(9)           WARNING: List "coa" is not available
(9)         EXPAND %{debug_attr:coa:}
(9)            -->
(9)         if ("%{debug_attr:coa:}" == '')  -> TRUE
(9)         if ("%{debug_attr:coa:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:coa:}" == '')  = noop
(9)       } # policy debug_coa = noop
(9)       policy debug_reply {
(9)         if ("%{debug_attr:reply:}" == '') {
(9)         Attributes matching "reply:"
(9)           &reply:User-Name = testing_remote
(9)           &reply:Tunnel-Private-Group-Id:-128 = 888
(9)           &reply:Tunnel-Type:-128 = VLAN
(9)           &reply:Tunnel-Medium-Type:-128 = IEEE-802

(9)           ...  private data

(9)         EXPAND %{debug_attr:reply:}
(9)            -->
(9)         if ("%{debug_attr:reply:}" == '')  -> TRUE
(9)         if ("%{debug_attr:reply:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:reply:}" == '')  = noop
(9)       } # policy debug_reply = noop
(9)       policy debug_session_state {
(9)         if ("%{debug_attr:session-state:}" == '') {
(9)         Attributes matching "session-state:"
(9)           &session-state:Framed-MTU = 994
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - recv TLS 1.2 Handshake, ClientHello
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, ServerHello
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, Certificate
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, ServerKeyExchange
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, ServerHelloDone
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - recv TLS 1.2 Handshake, ClientKeyExchange
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - recv TLS 1.2 ChangeCipherSpec
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - recv TLS 1.2 Handshake, Finished
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 ChangeCipherSpec
(9)           &session-state:TLS-Session-Information = (TLS) PEAP - send TLS 1.2 Handshake, Finished
(9)           &session-state:TLS-Session-Cipher-Suite = ECDHE-RSA-AES256-GCM-SHA384
(9)           &session-state:TLS-Session-Version = TLS 1.2
(9)           &session-state:Supplicant-Inner-User-Name := testing_remote
(9)         EXPAND %{debug_attr:session-state:}
(9)            -->
(9)         if ("%{debug_attr:session-state:}" == '')  -> TRUE
(9)         if ("%{debug_attr:session-state:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:session-state:}" == '')  = noop
(9)       } # policy debug_session_state = noop
(9)     } # policy debug_all = noop
(9)     [exec] = noop

The logs from the branch 3.2.x

(9)   post-auth {
(9)     policy debug_all {
(9)       policy debug_control {

(9)         ...

(9)       policy debug_session_state {
(9)         if ("%{debug_attr:session-state:}" == '') {
(9)         Attributes matching "session-state:"
(9)         EXPAND %{debug_attr:session-state:}
(9)            -->
(9)         if ("%{debug_attr:session-state:}" == '')  -> TRUE
(9)         if ("%{debug_attr:session-state:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:session-state:}" == '')  = noop
(9)       } # policy debug_session_state = noop
(9)     } # policy debug_all = noop
(9)     update request {
(9)       EXPAND %l
(9)          --> 1706792357
(9)       Supplicant-Timestamp := 1706792357
(9)       EXPAND %{Packet-Type}
(9)          --> Access-Request
(9)       Supplicant-Packet-Type := Access-Request
(9)       EXPAND %{reply:Packet-Type}
(9)          --> Access-Accept
(9)       Supplicant-Auth-Result := Access-Accept
(9)     } # update request = noop
(9)     policy copyback_user_identity {
(9)       if (&session-state:Supplicant-Inner-User-Name){
(9)       if (&session-state:Supplicant-Inner-User-Name) -> FALSE
(9)       else {
(9)         update request {
(9)           No attributes updated for RHS &session-state:Supplicant-User-name
(9)         } # update request = noop
(9)       } # else = noop
(9)       if (&session-state:Inner-Reply-Message){
(9)       if (&session-state:Inner-Reply-Message) -> FALSE
(9)     } # policy copyback_user_identity = noop
(9)     

Next is the python module

*** post_auth ***
b'Success!'
Supplicant not found: {'Username': 'anonymous'}
***************
(9)     [python_auth] = noop
(9)     policy debug_all {
(9)       policy debug_control {
(9)         if ("%{debug_attr:control:}" == '') {
(9)         Attributes matching "control:"
(9)           &control:Auth-Type = eap
(9)         EXPAND %{debug_attr:control:}
(9)            -->
(9)         if ("%{debug_attr:control:}" == '')  -> TRUE
(9)         if ("%{debug_attr:control:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:control:}" == '')  = noop
(9)       } # policy debug_control = noop
(9)       policy debug_request {
(9)         if ("%{debug_attr:request:}" == '') {
(9)         Attributes matching "request:"
(9)           &request:User-Name = anonymous
(9)           &request:NAS-IP-Address = 127.0.0.1
(9)           &request:Calling-Station-Id = 02-00-00-00-00-01
(9)           &request:Framed-MTU = 1400
(9)           &request:NAS-Port-Type = Wireless-802.11
(9)           &request:Service-Type = Framed-User
(9)           &request:Connect-Info = CONNECT 11Mbps 802.11b
(9)           &request:NAS-Identifier = foo
(9)           &request:EAP-Message = 0x02a3002e1900170303002397fb91e7e2f86749fe4a28447d4d131fc0e6b11745c3920832786df5d54a67e740dd83
(9)           &request:State = 0x72f6ca727a55d31bce85c802c9bfc809
(9)           &request:Message-Authenticator = 0x6c0c7e0a74502046da42a4147921e52e
(9)           &request:Event-Timestamp = Feb  1 2024 12:59:17 UTC
(9)           &request:Supplicant-Radius-Ip := 0.0.0.0
(9)           &request:Supplicant-Radius-Port := 1812
(9)           &request:Selected-EAP-Module := eap
(9)           &request:EAP-Type = PEAP
(9)           &request:Supplicant-Timestamp := 1706792357
(9)           &request:Supplicant-Packet-Type := Access-Request
(9)           &request:Supplicant-Auth-Result := Access-Accept
(9)         EXPAND %{debug_attr:request:}
(9)            -->
(9)         if ("%{debug_attr:request:}" == '')  -> TRUE
(9)         if ("%{debug_attr:request:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:request:}" == '')  = noop
(9)       } # policy debug_request = noop
(9)       policy debug_coa {
(9)         if ("%{debug_attr:coa:}" == '') {
(9)         Attributes matching "coa:"
(9)           WARNING: List "coa" is not available
(9)         EXPAND %{debug_attr:coa:}
(9)            -->
(9)         if ("%{debug_attr:coa:}" == '')  -> TRUE
(9)         if ("%{debug_attr:coa:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:coa:}" == '')  = noop
(9)       } # policy debug_coa = noop
(9)       policy debug_reply {
(9)         if ("%{debug_attr:reply:}" == '') {
(9)         Attributes matching "reply:"
(9)           &reply:User-Name = testing_remote
(9)           &reply:Tunnel-Private-Group-Id:0 = 143
(9)           &reply:Tunnel-Type:0 = VLAN
(9)           &reply:Tunnel-Medium-Type:0 = IEEE-802
(9)           &reply:Idle-Timeout = 1800

(9)           ...

(9)         EXPAND %{debug_attr:reply:}
(9)            -->
(9)         if ("%{debug_attr:reply:}" == '')  -> TRUE
(9)         if ("%{debug_attr:reply:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:reply:}" == '')  = noop
(9)       } # policy debug_reply = noop
(9)       policy debug_session_state {
(9)         if ("%{debug_attr:session-state:}" == '') {
(9)         Attributes matching "session-state:"
(9)         EXPAND %{debug_attr:session-state:}
(9)            -->
(9)         if ("%{debug_attr:session-state:}" == '')  -> TRUE
(9)         if ("%{debug_attr:session-state:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:session-state:}" == '')  = noop
(9)       } # policy debug_session_state = noop
(9)     } # policy debug_all = noop
(9)     [exec] = noop


### Relevant log output from client utilities

_No response_

### Backtrace from LLDB or GDB

_No response_
alandekok commented 8 months ago

v3.2.x is a stable release, and should not have breaking changes. So this is a regression which needs to be fixed.

We'll look at adding test cases for proxying, to ensure that the behavior is correct, and stays correct.

The intent behind the change was to prevent the server from mangling the State attribute when it was proxying requests. We had reports that was happening.

alandekok commented 8 months ago

I've reverted the change which broke it, and pushed other changes which should help.

Please test and see if they work. Ideally, test one commit, and if it works, test the next commit. That way if anything goes wrong, we know exactly which change has the issue.

vo-va commented 8 months ago

Thank you, I've tested new commits, this commit 30939dbccd0225583a14c560fac4e26401d8252b that reverts changes seems fixing my issue

Other commits after it, return the issue back. First I've tried this commit ead182d119071e79bc34edde7d27f64e3368b344 and then a9582fbd9d9884996a525d27a1fd249f29b55787 (HEAD)

From my research on what my code do I see that I also save inner user names from "EAP" virtual site, using this statement. Sorry, yesterday I've mentioned that this issue is probably just from proxying request to the home server.

# Used in inner tunnel to save inner identity
save_reply_to_outer_session_state {
    update outer.session-state {
       Supplicant-Inner-User-Name  := User-Name

    }
}

I guess it should be ok, because it explicitly updates the "outer" state.

And I see the saved state in the post_proxy section. But after that when flow again passed to the "authorize" section in debug output I don't see any data in session-state.

The logs below are from this version FreeRADIUS Version 3.2.4 (git #a9582fb),

(8) server test_server {
(8)   # Executing section post-proxy from file /usr/local/etc/raddb/sites-enabled/testing-stie
(8)     post-proxy {
(8)       policy debug_all {
(8)         policy debug_control {

(8)           ...

(8)         policy debug_session_state {
(8)           if ("%{debug_attr:session-state:}" == '') {
(8)           Attributes matching "session-state:"
(8)             &session-state:Supplicant-Inner-User-Name := testing_remote
(8)           EXPAND %{debug_attr:session-state:}
(8)              -->
(8)           if ("%{debug_attr:session-state:}" == '')  -> TRUE
(8)           if ("%{debug_attr:session-state:}" == '')  {
(8)             [noop] = noop
(8)           } # if ("%{debug_attr:session-state:}" == '')  = noop
(8)         } # policy debug_session_state = noop
(8)       } # policy debug_all = noop
(8) eap: Doing post-proxy callback
(8) eap: Passing reply from proxy back into the tunnel
(8) eap: Got tunneled reply RADIUS code 2
(8) eap:   EAP-Message = 0x03470004
(8) eap:   Message-Authenticator = 0xaadde6e4069235e0c490ac8307eec991
(8) eap:   User-Name = "testing_remote"
(8) eap:   Proxy-State = 0x38
(8) eap:   Tunnel-Private-Group-Id:0 = "143"
(8) eap:   Tunnel-Type:0 = VLAN
(8) eap:   Tunnel-Medium-Type:0 = IEEE-802
(8) eap:   Idle-Timeout = 1800
(8) eap: Tunneled authentication was successful
(8) eap: SUCCESS
(8) eap: Saving tunneled attributes for later
(8) eap: Reply was handled
(8) eap: Sending EAP Request (code 1) ID 72 length 46
(8) eap: EAP session adding &reply:State = 0x78a3542570eb4d7c
(8)       [eap] = ok
(8)       policy debug_all {

(8)        ...

(8)         policy debug_session_state {
(8)           if ("%{debug_attr:session-state:}" == '') {
(8)           Attributes matching "session-state:"
(8)             &session-state:Supplicant-Inner-User-Name := testing_remote
(8)           EXPAND %{debug_attr:session-state:}
(8)              -->
(8)           if ("%{debug_attr:session-state:}" == '')  -> TRUE
(8)           if ("%{debug_attr:session-state:}" == '')  {
(8)             [noop] = noop
(8)           } # if ("%{debug_attr:session-state:}" == '')  = noop
(8)         } # policy debug_session_state = noop
(8)       } # policy debug_all = noop
(8)     } # post-proxy = ok
(8) }
(8) session-state: Saving cached attributes
(8)   Supplicant-Inner-User-Name := "testing_remote"
(8) Using Post-Auth-Type Challenge
(8) Post-Auth-Type sub-section not found.  Ignoring.
(8) # Executing group from file /usr/local/etc/raddb/sites-enabled/testing-stie
(8) Sent Access-Challenge Id 8 from 172.23.0.8:1812 to 172.23.0.7:47083 length 104
(8)   EAP-Message = 0x0148002e190017030300236b2141dae5fdf09f6a070ab31f0c3a74e207119546ed1ffec61ae800f8a5975398c9d9
(8)   Message-Authenticator = 0x00000000000000000000000000000000
(8)   State = 0x78a3542570eb4d7c50d2562f57f0bc6c
(8) Finished request
Thread 1 waiting to be assigned a request
Thread 4 got semaphore
Thread 4 handling request 9, (3 handled so far)
(9) Received Access-Request Id 9 from 172.23.0.7:47083 to 172.23.0.8:1812 length 187
(9)   User-Name = "anonymous"
(9)   NAS-IP-Address = 127.0.0.1
(9)   Calling-Station-Id = "02-00-00-00-00-01"
(9)   Framed-MTU = 1400
(9)   NAS-Port-Type = Wireless-802.11
(9)   Service-Type = Framed-User
(9)   Connect-Info = "CONNECT 11Mbps 802.11b"
(9)   NAS-Identifier = "foo"
(9)   EAP-Message = 0x0248002e190017030300238c4c625c9e63a2d149dbf423a9bc565cdf2c9b7cd5ff9f4b88f1857faf95b593cdc03b
(9)   State = 0x78a3542570eb4d7c50d2562f57f0bc6c
(9)   Message-Authenticator = 0x27d44ab4fd98452503396f4592937a91
(9) session-state: No cached attributes
(9) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/testing-stie
(9)   authorize {
(9)     policy debug_all {

(9)       ...

(9)       policy debug_session_state {
(9)         if ("%{debug_attr:session-state:}" == '') {
(9)         Attributes matching "session-state:"
(9)         EXPAND %{debug_attr:session-state:}
(9)            -->
(9)         if ("%{debug_attr:session-state:}" == '')  -> TRUE
(9)         if ("%{debug_attr:session-state:}" == '')  {
(9)           [noop] = noop
(9)         } # if ("%{debug_attr:session-state:}" == '')  = noop
(9)       } # policy debug_session_state = noop
(9)     } # policy debug_all = noop
(9)     [preprocess] = ok
alandekok commented 8 months ago

Ah... you're proxying the inner-tunnel data, and not doing normal proxying. That will change the requirements.

I'll take a look and push a different fix.

alandekok commented 7 months ago

I'm working on some other issues for a bit, but I hope to have a fix next week.

alandekok commented 7 months ago

I've pushed a fix which I think should help. Please check, and we'll add it to the next release.

alandekok commented 5 months ago

Do you have any feedback on the issue? Does the patch fix it?

vo-va commented 1 month ago

@alandekok Hi, sorry for the long delay in replying.

It seems it is still not working as before. Just to clarify what is not working:

In the virtual server responsible for EAP/PEAP, I am trying to save the real username into the outer.session-state dictionary. Then, in the virtual site that is expecting a reply from the EAP/PEAP virtual site, I am trying to read the value from session-state, dropping the outer. prefix."

I hope that this is a correct way.

I've tested on 5ff76f921c7d46b8eebea5d42b2639538efff7f8 commit and on current HEAD of v3.2.x branch