Issue with %{home_server_dynamic:name} dynamic home server and accounting

13 Jul 2024

      I'm using this code as per the documentation in order to support dynamic
home servers:

--------
if (User-Name =~ /@(.*)$/) {
        switch "%{home_server_dynamic:%{1}}" {
            case "1" {
                # Proxy to this one particular home server
                update control {
                    &Home-Server-Name := "%{1}"
                }
            }

            case "0" {
                # Proxy with home server pool, failover, etc.
                update control {
                    &Proxy-To-Realm := "%{1}"
                }
            }

            case {
                # no home server exists, ask DNS
                update control {
                    &Temp-Home-Server-String :=
`%{config:confdir}/mods-config/realm/freeradius-naptr-to-home-server.sh -d
%{config:confdir} %{1} aaa+auth:radius.tls.tcp`
                }

                if ("%{control:Temp-Home-Server-String}" == "" ) {
                    reject
                } else {
                    update control {
                        &Home-Server-Name := "%{1}"
                    }
                }
            }
        }
    }
--------

If there is no existing dynamic server in the home_servers folder it works
fine and dynamically creates it (i.e. home_servers/openroaming.goog), all
good:

--------
Sat Jul 13 19:28:14 2024 : Debug: (0)       if (User-Name =~ /@(.*)$/)  ->
TRUE
Sat Jul 13 19:28:14 2024 : Debug: (0)       if (User-Name =~ /@(.*)$/)  {
Sat Jul 13 19:28:14 2024 : Debug: (0)         switch
%{home_server_dynamic:%{1}} {
Sat Jul 13 19:28:14 2024 : Debug: (0)         EXPAND
%{home_server_dynamic:%{1}}
Sat Jul 13 19:28:14 2024 : Debug: (0)            -->
Sat Jul 13 19:28:14 2024 : Debug: (0)           case {
Sat Jul 13 19:28:14 2024 : Debug: (0)             update control {
Sat Jul 13 19:28:14 2024 : Debug: (0)               Executing:
%{config:confdir}/mods-config/realm/freeradius-naptr-to-home-server.sh -d
%{config:confdir} %{1} aaa+auth:radius.tls.tcp:
Sat Jul 13 19:28:14 2024 : Debug:
%{config:confdir}/mods-config/realm/freeradius-naptr-to-home-server.sh
Sat Jul 13 19:28:14 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:14 2024 : Debug: xlat --> config
Sat Jul 13 19:28:14 2024 : Debug: {
Sat Jul 13 19:28:14 2024 : Debug:       literal --> confdir
Sat Jul 13 19:28:14 2024 : Debug: }
Sat Jul 13 19:28:14 2024 : Debug: literal -->
/mods-config/realm/freeradius-naptr-to-home-server.sh
Sat Jul 13 19:28:14 2024 : Debug: confdir
Sat Jul 13 19:28:14 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:14 2024 : Debug: literal --> confdir
Sat Jul 13 19:28:14 2024 : Debug: (0)               EXPAND confdir
Sat Jul 13 19:28:14 2024 : Debug: (0)                  --> confdir
Sat Jul 13 19:28:14 2024 : Debug: (0)               EXPAND
%{config:confdir}/mods-config/realm/freeradius-naptr-to-home-server.sh
Sat Jul 13 19:28:14 2024 : Debug: (0)                  -->
/usr/local/etc/raddb/mods-config/realm/freeradius-naptr-to-home-server.sh
Sat Jul 13 19:28:14 2024 : Debug: %{config:confdir}
Sat Jul 13 19:28:14 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:14 2024 : Debug: xlat --> config
Sat Jul 13 19:28:14 2024 : Debug: {
Sat Jul 13 19:28:14 2024 : Debug:       literal --> confdir
Sat Jul 13 19:28:14 2024 : Debug: }
Sat Jul 13 19:28:14 2024 : Debug: confdir
Sat Jul 13 19:28:14 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:14 2024 : Debug: literal --> confdir
Sat Jul 13 19:28:14 2024 : Debug: (0)               EXPAND confdir
Sat Jul 13 19:28:14 2024 : Debug: (0)                  --> confdir
Sat Jul 13 19:28:14 2024 : Debug: (0)               EXPAND %{config:confdir}
Sat Jul 13 19:28:14 2024 : Debug: (0)                  -->
/usr/local/etc/raddb
Sat Jul 13 19:28:14 2024 : Debug: %{1}
Sat Jul 13 19:28:14 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:14 2024 : Debug: regex-var --> 1
Sat Jul 13 19:28:14 2024 : Debug: (0)               EXPAND %{1}
Sat Jul 13 19:28:14 2024 : Debug: (0)                  --> openroaming.goog
Sat Jul 13 19:28:14 2024 : Debug: Waking up in 0.3 seconds.
Sat Jul 13 19:28:14 2024 : Debug:  ... new connection request on command
socket
Sat Jul 13 19:28:14 2024 : Debug: Listening on command file
/usr/local/var/run/radiusd/radiusd.sock
Sat Jul 13 19:28:14 2024 : Debug: Waking up in 0.2 seconds.
Sat Jul 13 19:28:14 2024 : Debug: radmin> add home_server file
/usr/local/etc/raddb/home_servers/openroaming.goog
Sat Jul 13 19:28:14 2024 : Debug: including configuration file
/usr/local/etc/raddb/home_servers/openroaming.goog
Sat Jul 13 19:28:14 2024 : Debug: including configuration file
/usr/local/etc/raddb/home_servers/tls.conf
Sat Jul 13 19:28:14 2024 : Debug:  home_server openroaming.goog {
Sat Jul 13 19:28:14 2024 : Debug:       nonblock = no
Sat Jul 13 19:28:14 2024 : Debug:       ipaddr = radsec.openroaming.goog
IPv4 address [146.148.44.172]
Sat Jul 13 19:28:14 2024 : Debug:       port = 2083
Sat Jul 13 19:28:14 2024 : Debug:       type = "auth"
Sat Jul 13 19:28:14 2024 : Debug:       proto = "tcp"
Sat Jul 13 19:28:14 2024 : Debug:       secret = "radsec"
Sat Jul 13 19:28:14 2024 : Debug:       response_window = 30.000000
Sat Jul 13 19:28:14 2024 : Debug:       response_timeouts = 1
Sat Jul 13 19:28:14 2024 : Debug:       max_outstanding = 65536
Sat Jul 13 19:28:14 2024 : Debug:       zombie_period = 40
Sat Jul 13 19:28:14 2024 : Debug:       status_check = "none"
Sat Jul 13 19:28:14 2024 : Debug:       ping_interval = 30
Sat Jul 13 19:28:14 2024 : Debug:       check_timeout = 4
Sat Jul 13 19:28:14 2024 : Debug:       num_answers_to_alive = 3
Sat Jul 13 19:28:14 2024 : Debug:       revive_interval = 300
Sat Jul 13 19:28:14 2024 : Debug:   limit {
Sat Jul 13 19:28:14 2024 : Debug:       max_connections = 16
Sat Jul 13 19:28:14 2024 : Debug:       max_requests = 0
Sat Jul 13 19:28:14 2024 : Debug:       lifetime = 0
Sat Jul 13 19:28:14 2024 : Debug:       idle_timeout = 0
Sat Jul 13 19:28:14 2024 : Debug:   }
Sat Jul 13 19:28:14 2024 : Debug:   coa {
Sat Jul 13 19:28:14 2024 : Debug:       irt = 2
Sat Jul 13 19:28:14 2024 : Debug:       mrt = 16
Sat Jul 13 19:28:14 2024 : Debug:       mrc = 5
Sat Jul 13 19:28:14 2024 : Debug:       mrd = 30
Sat Jul 13 19:28:14 2024 : Debug:   }
Sat Jul 13 19:28:14 2024 : Debug:   recv_coa {
Sat Jul 13 19:28:14 2024 : Debug:   }
Sat Jul 13 19:28:14 2024 : Debug:  }
Sat Jul 13 19:28:14 2024 : Debug:   tls {
Sat Jul 13 19:28:14 2024 : Debug:       verify_depth = 0
Sat Jul 13 19:28:14 2024 : Debug:       pem_file_type = yes
Sat Jul 13 19:28:14 2024 : Debug:       private_key_file =
"/usr/local/etc/raddb/certs/x.key"
Sat Jul 13 19:28:14 2024 : Debug:       certificate_file =
"/usr/local/etc/raddb/certs/x.crt"
Sat Jul 13 19:28:14 2024 : Debug:       ca_file =
"/usr/local/etc/raddb/certs/ca/x.ca"
Sat Jul 13 19:28:14 2024 : Debug:       private_key_password = ""
Sat Jul 13 19:28:14 2024 : Debug:       fragment_size = 8192
Sat Jul 13 19:28:14 2024 : Debug:       include_length = yes
Sat Jul 13 19:28:14 2024 : Debug:       check_crl = no
Sat Jul 13 19:28:14 2024 : Debug:       cipher_list = "ALL"
Sat Jul 13 19:28:14 2024 : Debug:       ca_path_reload_interval = 0
Sat Jul 13 19:28:14 2024 : Debug:       ecdh_curve = "prime256v1"
Sat Jul 13 19:28:14 2024 : Debug:       tls_max_version = "1.3"
Sat Jul 13 19:28:14 2024 : Debug:       tls_min_version = "1.2"
Sat Jul 13 19:28:14 2024 : Debug:   }
Sat Jul 13 19:28:15 2024 : Debug: (0)               Program returned code
(0) and output 'openroaming.goog'
Sat Jul 13 19:28:15 2024 : Debug: (0)
&Temp-Home-Server-String := openroaming.goog
Sat Jul 13 19:28:15 2024 : Debug: (0)             } # update control = noop
Sat Jul 13 19:28:15 2024 : Debug: (0)             if
("%{control:Temp-Home-Server-String}" == "" ) {
Sat Jul 13 19:28:15 2024 : Debug: (0)             if
("%{control:Temp-Home-Server-String}" == "" )  -> FALSE
Sat Jul 13 19:28:15 2024 : Debug: (0)             else {
Sat Jul 13 19:28:15 2024 : Debug: (0)               update control {
Sat Jul 13 19:28:15 2024 : Debug: (0)                 EXPAND %{1}
Sat Jul 13 19:28:15 2024 : Debug: (0)                    -->
openroaming.goog
Sat Jul 13 19:28:15 2024 : Debug: (0)                 &Home-Server-Name :=
openroaming.goog
Sat Jul 13 19:28:15 2024 : Debug: (0)               } # update control =
noop
Sat Jul 13 19:28:15 2024 : Debug: (0)             } # else = noop
Sat Jul 13 19:28:15 2024 : Debug: (0)           } # case = noop
Sat Jul 13 19:28:15 2024 : Debug: (0)         } # switch
%{home_server_dynamic:%{1}} = noop
Sat Jul 13 19:28:15 2024 : Debug: (0)       } # if (User-Name =~ /@(.*)$/)
 = noop
--------

It then does it's normal EAP transaction to/from the client, and on each
incoming request during the negotiation, it's correctly detecting that the
home_server file exists, so does not perform the lookup again as expected,
i.e.:

--------
Sat Jul 13 19:28:15 2024 : Debug: (1)       if (User-Name =~ /@(.*)$/) {
Sat Jul 13 19:28:15 2024 : Debug: (1)       if (User-Name =~ /@(.*)$/)  ->
TRUE
Sat Jul 13 19:28:15 2024 : Debug: (1)       if (User-Name =~ /@(.*)$/)  {
Sat Jul 13 19:28:15 2024 : Debug: (1)         switch
%{home_server_dynamic:%{1}} {
Sat Jul 13 19:28:15 2024 : Debug: (1)         EXPAND
%{home_server_dynamic:%{1}}
Sat Jul 13 19:28:15 2024 : Debug: (1)            --> 1
Sat Jul 13 19:28:15 2024 : Debug: (1)           case 1 {
Sat Jul 13 19:28:15 2024 : Debug: (1)             update control {
Sat Jul 13 19:28:15 2024 : Debug: (1)               EXPAND %{1}
Sat Jul 13 19:28:15 2024 : Debug: (1)                  --> openroaming.goog
Sat Jul 13 19:28:15 2024 : Debug: (1)               &Home-Server-Name :=
openroaming.goog
Sat Jul 13 19:28:15 2024 : Debug: (1)             } # update control = noop
Sat Jul 13 19:28:15 2024 : Debug: (1)           } # case 1 = noop
Sat Jul 13 19:28:15 2024 : Debug: (1)         } # switch
%{home_server_dynamic:%{1}} = noop
Sat Jul 13 19:28:15 2024 : Debug: (1)       } # if (User-Name =~ /@(.*)$/)
 = noop
----------

Once the EAP stuff is all done, it fires off the request to the dynamic
home_server:

----------
Sat Jul 13 19:28:15 2024 : Debug: (0) Proxying due to Home-Server-Name
Sat Jul 13 19:28:15 2024 : Debug: (0) Starting proxy to home server
146.148.44.172 port 2083
Sat Jul 13 19:28:15 2024 : Debug: (0) proxy: Trying to allocate ID (0/2)
Sat Jul 13 19:28:15 2024 : Debug: (0) proxy: Trying to open a new listener
to the home server
Sat Jul 13 19:28:15 2024 : Debug: Waking up in 0.1 seconds.
Sat Jul 13 19:28:15 2024 : Info:  ... shutting down socket command file
/usr/local/var/run/radiusd/radiusd.sock
Sat Jul 13 19:28:15 2024 : Debug: ... cleaning up socket command file
/usr/local/var/run/radiusd/radiusd.sock
Sat Jul 13 19:28:15 2024 : Debug: Waking up in 0.1 seconds.
Sat Jul 13 19:28:15 2024 : Debug: (TLS) Trying new outgoing proxy
connection to proxy (0.0.0.0, 0) -> home_server (146.148.44.172, 2083)
[snip]
Sat Jul 13 19:28:16 2024 : Auth: (4) Login OK: [anonymous@openroaming.goog]
Sat Jul 13 19:28:16 2024 : Debug: (4) Sent Access-Accept Id 35
Sat Jul 13 19:28:16 2024 : Debug: (4)   MS-MPPE-Recv-Key =
0xaf73c99cadd7b68fe589b4a55648308437e348ce1a733f77623ef0d69faa32d4
Sat Jul 13 19:28:16 2024 : Debug: (4)   MS-MPPE-Send-Key =
0x2f965f6006a00599da680104627ddc25271e67dc3bc5f8e1491668d39e04cc77
Sat Jul 13 19:28:16 2024 : Debug: (4)   EAP-Message = 0x031a0004
Sat Jul 13 19:28:16 2024 : Debug: (4)   Message-Authenticator =
0x1e4dbd72d829dc1f639bf159e99556ce
Sat Jul 13 19:28:16 2024 : Debug: (4)   User-Name = "
anonymous@openroaming.goog"
--------

And the user is authed successfully.

Now, when the accounting start packet comes in, it fails to see that the
home_server file exists, tries to create it again, fails, then doesn't
proxy it:

--------
Sat Jul 13 19:28:17 2024 : Debug: (8)       if (User-Name =~ /@(.*)$/) {
Sat Jul 13 19:28:17 2024 : Debug: (8)       if (User-Name =~ /@(.*)$/)  ->
TRUE
Sat Jul 13 19:28:17 2024 : Debug: (8)       if (User-Name =~ /@(.*)$/)  {
Sat Jul 13 19:28:17 2024 : Debug: (8)         switch
%{home_server_dynamic:%{1}} {
Sat Jul 13 19:28:17 2024 : Debug: (8)         EXPAND
%{home_server_dynamic:%{1}}
Sat Jul 13 19:28:17 2024 : Debug: (8)            -->
Sat Jul 13 19:28:17 2024 : Debug: (8)           case {
Sat Jul 13 19:28:17 2024 : Debug: (8)             update control {
Sat Jul 13 19:28:17 2024 : Debug: (8)               Executing:
%{config:confdir}/mods-config/realm/freeradius-naptr-to-home-server.sh -d
%{config:confdir} %{1} aaa+auth:radius.tls.tcp:
Sat Jul 13 19:28:17 2024 : Debug:
%{config:confdir}/mods-config/realm/freeradius-naptr-to-home-server.sh
Sat Jul 13 19:28:17 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:17 2024 : Debug: xlat --> config
Sat Jul 13 19:28:17 2024 : Debug: {
Sat Jul 13 19:28:17 2024 : Debug:       literal --> confdir
Sat Jul 13 19:28:17 2024 : Debug: }
Sat Jul 13 19:28:17 2024 : Debug: literal -->
/mods-config/realm/freeradius-naptr-to-home-server.sh
Sat Jul 13 19:28:17 2024 : Debug: confdir
Sat Jul 13 19:28:17 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:17 2024 : Debug: literal --> confdir
Sat Jul 13 19:28:17 2024 : Debug: (8)               EXPAND confdir
Sat Jul 13 19:28:17 2024 : Debug: (8)                  --> confdir
Sat Jul 13 19:28:17 2024 : Debug: (8)               EXPAND
%{config:confdir}/mods-config/realm/freeradius-naptr-to-home-server.sh
Sat Jul 13 19:28:17 2024 : Debug: (8)                  -->
/usr/local/etc/raddb/mods-config/realm/freeradius-naptr-to-home-server.sh
Sat Jul 13 19:28:17 2024 : Debug: %{config:confdir}
Sat Jul 13 19:28:17 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:17 2024 : Debug: xlat --> config
Sat Jul 13 19:28:17 2024 : Debug: {
Sat Jul 13 19:28:17 2024 : Debug:       literal --> confdir
Sat Jul 13 19:28:17 2024 : Debug: }
Sat Jul 13 19:28:17 2024 : Debug: confdir
Sat Jul 13 19:28:17 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:17 2024 : Debug: literal --> confdir
Sat Jul 13 19:28:17 2024 : Debug: (8)               EXPAND confdir
Sat Jul 13 19:28:17 2024 : Debug: (8)                  --> confdir
Sat Jul 13 19:28:17 2024 : Debug: (8)               EXPAND %{config:confdir}
Sat Jul 13 19:28:17 2024 : Debug: (8)                  -->
/usr/local/etc/raddb
Sat Jul 13 19:28:17 2024 : Debug: %{1}
Sat Jul 13 19:28:17 2024 : Debug: Parsed xlat tree:
Sat Jul 13 19:28:17 2024 : Debug: regex-var --> 1
Sat Jul 13 19:28:17 2024 : Debug: (8)               EXPAND %{1}
Sat Jul 13 19:28:17 2024 : Debug: (8)                  --> openroaming.goog
Sat Jul 13 19:28:17 2024 : Debug: Waking up in 0.3 seconds.
Sat Jul 13 19:28:17 2024 : Debug:  ... new connection request on command
socket
Sat Jul 13 19:28:17 2024 : Debug: Listening on command file
/usr/local/var/run/radiusd/radiusd.sock
Sat Jul 13 19:28:17 2024 : Debug: Waking up in 0.2 seconds.
Sat Jul 13 19:28:17 2024 : Debug: radmin> add home_server file
/usr/local/etc/raddb/home_servers/openroaming.goog
Sat Jul 13 19:28:17 2024 : Debug: including configuration file
/usr/local/etc/raddb/home_servers/openroaming.goog
Sat Jul 13 19:28:17 2024 : Debug: including configuration file
/usr/local/etc/raddb/home_servers/tls.conf
Sat Jul 13 19:28:17 2024 : Debug:  home_server openroaming.goog {
Sat Jul 13 19:28:17 2024 : Debug:       nonblock = no
Sat Jul 13 19:28:17 2024 : Debug:       ipaddr = radsec.openroaming.goog
IPv4 address [146.148.44.172]
Sat Jul 13 19:28:17 2024 : Debug:       port = 2083
Sat Jul 13 19:28:17 2024 : Debug:       type = "auth"
Sat Jul 13 19:28:17 2024 : Debug:       proto = "tcp"
Sat Jul 13 19:28:17 2024 : Debug:       secret = "radsec"
Sat Jul 13 19:28:17 2024 : Debug:       response_window = 30.000000
Sat Jul 13 19:28:17 2024 : Debug:       response_timeouts = 1
Sat Jul 13 19:28:17 2024 : Debug:       max_outstanding = 65536
Sat Jul 13 19:28:17 2024 : Debug:       zombie_period = 40
Sat Jul 13 19:28:17 2024 : Debug:       status_check = "none"
Sat Jul 13 19:28:17 2024 : Debug:       ping_interval = 30
Sat Jul 13 19:28:17 2024 : Debug:       check_timeout = 4
Sat Jul 13 19:28:17 2024 : Debug:       num_answers_to_alive = 3
Sat Jul 13 19:28:17 2024 : Debug:       revive_interval = 300
Sat Jul 13 19:28:17 2024 : Debug:   limit {
Sat Jul 13 19:28:17 2024 : Debug:       max_connections = 16
Sat Jul 13 19:28:17 2024 : Debug:       max_requests = 0
Sat Jul 13 19:28:17 2024 : Debug:       lifetime = 0
Sat Jul 13 19:28:17 2024 : Debug:       idle_timeout = 0
Sat Jul 13 19:28:17 2024 : Debug:   }
Sat Jul 13 19:28:17 2024 : Debug:   coa {
Sat Jul 13 19:28:17 2024 : Debug:       irt = 2
Sat Jul 13 19:28:17 2024 : Debug:       mrt = 16
Sat Jul 13 19:28:17 2024 : Debug:       mrc = 5
Sat Jul 13 19:28:17 2024 : Debug:       mrd = 30
Sat Jul 13 19:28:17 2024 : Debug:   }
Sat Jul 13 19:28:17 2024 : Debug:   recv_coa {
Sat Jul 13 19:28:17 2024 : Debug:   }
Sat Jul 13 19:28:17 2024 : Debug:  }
Sat Jul 13 19:28:17 2024 : Debug:   tls {
Sat Jul 13 19:28:17 2024 : Debug:       verify_depth = 0
Sat Jul 13 19:28:17 2024 : Debug:       pem_file_type = yes
Sat Jul 13 19:28:17 2024 : Debug:       private_key_file =
"/usr/local/etc/raddb/certs/x.key"
Sat Jul 13 19:28:17 2024 : Debug:       certificate_file =
"/usr/local/etc/raddb/certs/x.crt"
Sat Jul 13 19:28:17 2024 : Debug:       ca_file =
"/usr/local/etc/raddb/certs/ca/x.ca"
Sat Jul 13 19:28:17 2024 : Debug:       private_key_password = ""
Sat Jul 13 19:28:17 2024 : Debug:       fragment_size = 8192
Sat Jul 13 19:28:17 2024 : Debug:       include_length = yes
Sat Jul 13 19:28:17 2024 : Debug:       check_crl = no
Sat Jul 13 19:28:17 2024 : Debug:       cipher_list = "ALL"
Sat Jul 13 19:28:17 2024 : Debug:       ca_path_reload_interval = 0
Sat Jul 13 19:28:17 2024 : Debug:       ecdh_curve = "prime256v1"
Sat Jul 13 19:28:17 2024 : Debug:       tls_max_version = "1.3"
Sat Jul 13 19:28:17 2024 : Debug:       tls_min_version = "1.2"
Sat Jul 13 19:28:17 2024 : Debug:   }
Sat Jul 13 19:28:17 2024 : Error: /usr/local/etc/raddb/home_servers/
openroaming.goog[1]: Duplicate home server name openroaming.goog
ERROR: Unable to add home server - Failed adding home_server to the
internal data structures
--------

Is this a bug, or am I missing something? It appears
%{home_server_dynamic:%{1} is not working for accounting packets. Is it
because type = "auth" is configured in the dynamically created home_server
file and it doesn't realise it should also use it for accounting? p.s. it
seems the dynamic home_server files do not allow type = "auth+acct", is
that correct? You can't create two home_server files with the same name
either, so what should I do?

The %{home_server_dynamic:%{1} check in subsequent authentication packets
works as expected so it only seems to affect accounting.

Thanks,

James

James Wood

James Wood

Alan DeKok

Alan DeKok

James Wood

James Wood

Alan DeKok

James Wood

James Wood

Alan DeKok

James Wood

Alan DeKok

James Wood

tags

participants (2)