Issue with disconnection between radsecproxy client and freeradius server

[James Wood]

I'm not sure if this is a radsecproxy or freeradius issue so I've posted
something similar in the radsecproxy list also, but I would appreciate it
if you can advise.

I am using radsecproxy 1.9.1 as a radsec TLS client on an openwrt (latest
snapshot) embedded device, and freeradius 3.2.7. I have radsec in general
working fine on this server but now trying to get radsec support on openwrt.

radsecproxy initially connects just fine, but after 30 seconds it
disconnects and then has a fit and spams the syslog forever until restart.
It does this whether or not I connect a client to authenticate. I can
authenticate a client just fine on radsec before that initial 30 second
period so unsure what's going on here.

It does seem like it's related to the idle_timeout setting, but according
to the radsecproxy code it should just reconnect every 30s but can't. I
don't want to set an idle_timeout of 0 ideally, would you agree this is not
preferred behaviour?

Debug log from freeradius:

Listening on auth+acct proto tcp address * port 2083 (TLS) bound to server
default
Ready to process requests
... new connection request on TCP socket
Listening on auth+acct from client (78.32.xx.xx, 44103) -> (*, 2083,
virtual-server=default)
Waking up in 0.2 seconds.
(0) (TLS) RADIUS/TLS -Initiating new session
(0) (TLS) RADIUS/TLS - Handshake state - before SSL initialization
(0) (TLS) RADIUS/TLS - Handshake state - Server before SSL initialization
(0) (TLS) RADIUS/TLS - Handshake state - Server before SSL initialization
(0) (TLS) RADIUS/TLS - recv TLS 1.3 Handshake, ClientHello
(0) (TLS) RADIUS/TLS - Handshake state - Server SSLv3/TLS read client hello
(0) (TLS) RADIUS/TLS - send TLS 1.3 Handshake, ServerHello
(0) (TLS) RADIUS/TLS - Handshake state - Server SSLv3/TLS write server hello
(0) (TLS) RADIUS/TLS - send TLS 1.3 ChangeCipherSpec
(0) (TLS) RADIUS/TLS - Handshake state - Server SSLv3/TLS write change
cipher spec
(0) (TLS) RADIUS/TLS - send TLS 1.3 Handshake, EncryptedExtensions
(0) (TLS) RADIUS/TLS - Handshake state - Server TLSv1.3 write encrypted
extensions
(0) (TLS) RADIUS/TLS - send TLS 1.3 Handshake, Certificate
(0) (TLS) RADIUS/TLS - Handshake state - Server SSLv3/TLS write certificate
(0) (TLS) RADIUS/TLS - send TLS 1.3 Handshake, CertificateVerify
(0) (TLS) RADIUS/TLS - Handshake state - Server TLSv1.3 write server
certificate verify
(0) (TLS) RADIUS/TLS - send TLS 1.3 Handshake, Finished
(0) (TLS) RADIUS/TLS - Handshake state - Server SSLv3/TLS write finished
(0) (TLS) RADIUS/TLS - Handshake state - Server TLSv1.3 early data
(0) (TLS) RADIUS/TLS - Server : Need to read more data: TLSv1.3 early data
(0) (TLS) RADIUS/TLS - In Handshake Phase
Waking up in 0.2 seconds.
(0) (TLS) RADIUS/TLS - Handshake state - Server TLSv1.3 early data
(0) (TLS) RADIUS/TLS - recv TLS 1.3 Handshake, Finished
(0) (TLS) RADIUS/TLS - Handshake state - Server SSLv3/TLS read finished
(0) (TLS) RADIUS/TLS - Handshake state - SSL negotiation finished
successfully
(0) (TLS) RADIUS/TLS - Connection Established
(0)   TLS-Session-Cipher-Suite = "TLS_AES_256_GCM_SHA384"
(0)   TLS-Session-Version = "TLS 1.3"
(0) (TLS) RADIUS/TLS - Application data.
(0) (TLS) OpenSSL says that it needs to read more data.
Waking up in 0.1 seconds.
Waking up in 29.4 seconds.
Reached idle timeout on socket auth+acct from client (78.32.xx.xx, 44103)
-> (*, 2083, virtual-server=default)
 ... shutting down socket auth+acct from client (78.32.xx.xx, 44103) -> (*,
2083, virtual-server=default)
... cleaning up socket auth+acct from client (78.32.xx.xx, 44103) -> (*,
2083, virtual-server=default)



Debug log from radseproxy for completeness:

Sat Mar 22 12:43:01 2025 daemon.info radsecproxy[4861]: radsecproxy 1.9.1
starting
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: resolvehostport:
(src info not available) -> 0.0.0.0
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: tlsconnect: called
from clientwr
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: udp server writer,
waiting for signal
Sat Mar 22 12:43:01 2025 daemon.info radsecproxy[4861]: tlsconnect: trying
to open TLS connection to server myradsec (radsec.myradsec.xyz port 2083)
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: resolvehostport:
127.0.0.1 -> 127.0.0.1
Sat Mar 22 12:43:01 2025 daemon.info radsecproxy[4861]: disable_DF_bit:
disabling DF bit (Linux variant)
Sat Mar 22 12:43:01 2025 daemon.warn radsecproxy[4861]: createlistener:
listening for udp on 127.0.0.1:1812
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: resolvehostport:
127.0.0.1 -> 127.0.0.1
Sat Mar 22 12:43:01 2025 daemon.info radsecproxy[4861]: disable_DF_bit:
disabling DF bit (Linux variant)
Sat Mar 22 12:43:01 2025 daemon.warn radsecproxy[4861]: createlistener:
listening for udp on 127.0.0.1:1813
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: Connection up
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: verifyconfcert:
verify certificate for host myradsec, subject CN=*.myradsec.xyz
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: matchtregex:
matching *.myradsec.xyz
Sat Mar 22 12:43:01 2025 daemon.debug radsecproxy[4861]: verifyconfcert:
CN:/.myradsec\.xyz$/ matching for host myradsec (CN=*.myradsec.xyz)
Sat Mar 22 12:43:01 2025 daemon.warn radsecproxy[4861]: tlsconnect: TLS
connection to myradsec (radsec.myradsec.xyz port 2083), subject CN=*.
myradsec.xyz up
Sat Mar 22 12:43:31 2025 daemon.err radsecproxy[4861]: sslreadtimeout: SSL:
error:0A000126:SSL routines::unexpected eof while reading
Sat Mar 22 12:43:31 2025 daemon.info radsecproxy[4861]: sslreadtimeout:
connection closed by remote host
Sat Mar 22 12:43:31 2025 daemon.err radsecproxy[4861]: sslreadtimeout: SSL:
error:0A000197:SSL routines::shutdown while in init
Sat Mar 22 12:43:31 2025 daemon.err radsecproxy[4861]: sslreadtimeout:
connection lost: No error information
Sat Mar 22 12:43:31 2025 daemon.err radsecproxy[4861]: sslreadtimeout: SSL:
error:0A000197:SSL routines::shutdown while in init
Sat Mar 22 12:43:31 2025 daemon.err radsecproxy[4861]: sslreadtimeout:
connection lost: No error information
Sat Mar 22 12:43:31 2025 daemon.info radsecproxy[4861]: TLS Connection
lost: Broken pipe
Sat Mar 22 12:43:31 2025 daemon.info radsecproxy[4861]: TLS Connection
lost: hang up
Sat Mar 22 12:43:31 2025 daemon.info radsecproxy[4861]: TLS Connection
lost: hang up
Sat Mar 22 12:43:31 2025 daemon.info radsecproxy[4861]: TLS Connection
lost: hang up


Any idea how I can further debug or any suggestions?

Thanks

-- 


Visit purple.ai <https://purple.ai/>

Purple on LinkedIn 
<https://uk.linkedin.com/company/purple-wifi>

Email disclaimer 
<http://www.purple.ai/email-disclaimer/>