[defect]: freeradius 3.2 git closes listening tcp (radsec) sockets

[haegar]

What type of defect/bug is this?

Crash or memory corruption (segv, abort, etc...)

How can the issue be reproduced?

I was testing on v3.2.8 plus git commit a0df1bf (just before the Protocl-Error changes start, which I don't need and feel too new to me), and discovered a new bug since 3.2.8 that my listening tcp radsec ports get closed shortly after freeradius start:

Oct 22 15:26:20 Listening on auth address * port 3812 bound to server deviceauth_eap
Oct 22 15:26:20 Listening on acct address * port 3813 bound to server deviceauth_eap
Oct 22 15:26:20 Listening on auth address :: port 3812 bound to server deviceauth_eap
Oct 22 15:26:20 Listening on acct address :: port 3813 bound to server deviceauth_eap
Oct 22 15:26:20 Listening on auth+acct proto tcp address * port 2083 (TLS) bound to server default
Oct 22 15:26:20 Listening on auth+acct proto tcp address :: port 2083 (TLS) bound to server default
Oct 22 15:26:20 Listening on command file /var/run/freeradius/freeradius.sock
Oct 22 15:26:20 Listening on auth address * port 2812 bound to server forward
Oct 22 15:26:20 Listening on acct address * port 2813 bound to server forward
Oct 22 15:26:20 Listening on auth address :: port 2812 bound to server forward
Oct 22 15:26:20 Listening on acct address :: port 2813 bound to server forward
Oct 22 15:26:20 Listening on auth address * port 1812 bound to server default
Oct 22 15:26:20 Listening on acct address * port 1813 bound to server default
Oct 22 15:26:20 Listening on auth address :: port 1812 bound to server default
Oct 22 15:26:20 Listening on acct address :: port 1813 bound to server default
Oct 22 15:26:20 Listening on auth proto tcp address * port 1812 bound to server default
Oct 22 15:26:20 Listening on acct proto tcp address * port 1813 bound to server default
Oct 22 15:26:20 Listening on auth proto tcp address :: port 1812 bound to server default
Oct 22 15:26:20 Listening on acct proto tcp address :: port 1813 bound to server default
Oct 22 15:26:20 Listening on auth address 127.0.0.1 port 28120 bound to server inner-tunnel
Oct 22 15:26:20 Listening on status address 127.0.0.1 port 18120 bound to server status
Oct 22 15:26:20 Listening on proxy address * port 44448
Oct 22 15:26:20 Listening on proxy address :: port 56027
Oct 22 15:26:20 Waking up in 0.9 seconds.
Oct 22 15:26:21 Reached idle timeout on socket acct proto tcp address :: port 1813 bound to server default
Oct 22 15:26:21 ... shutting down socket acct proto tcp address :: port 1813 bound to server default
Oct 22 15:26:21 ... cleaning up socket acct proto tcp address :: port 1813 bound to server default
Oct 22 15:26:21 Reached maximum lifetime on socket auth+acct proto tcp address :: port 2083 (TLS) bound to server default
Oct 22 15:26:21 ... shutting down socket auth+acct proto tcp address :: port 2083 (TLS) bound to server default
Oct 22 15:26:21 ... cleaning up socket auth+acct proto tcp address :: port 2083 (TLS) bound to server default
Oct 22 15:26:21 Reached idle timeout on socket auth proto tcp address * port 1812 bound to server default
Oct 22 15:26:21 ... shutting down socket auth proto tcp address * port 1812 bound to server default
Oct 22 15:26:21 ... cleaning up socket auth proto tcp address * port 1812 bound to server default
Oct 22 15:26:21 Reached idle timeout on socket acct proto tcp address * port 1813 bound to server default
Oct 22 15:26:21 ... shutting down socket acct proto tcp address * port 1813 bound to server default
Oct 22 15:26:21 ... cleaning up socket acct proto tcp address * port 1813 bound to server default
Oct 22 15:26:21 Reached idle timeout on socket auth proto tcp address :: port 1812 bound to server default
Oct 22 15:26:21 ... shutting down socket auth proto tcp address :: port 1812 bound to server default
Oct 22 15:26:21 ... cleaning up socket auth proto tcp address :: port 1812 bound to server default
Oct 22 15:26:21 Reached maximum lifetime on socket auth+acct proto tcp address * port 2083 (TLS) bound to server default
Oct 22 15:26:21 ... shutting down socket auth+acct proto tcp address * port 2083 (TLS) bound to server default
Oct 22 15:26:21 ... cleaning up socket auth+acct proto tcp address * port 2083 (TLS) bound to server default
Oct 22 15:26:21 Ready to process requests
Oct 22 15:26:22 Threads: total/active/spare threads = 5/0/5

Going back to git commit 9bd33a0 - just before "do a better job of enforcing lifetime && idle_timeout" and "always set tcp cleanup routine" makes it completely work for me again.

So it looks like the tcp idle/lifetime settings also get applied to listening sockets, which I think should not be the case, a listening socket is not supposed to get closed at all while the daemon is running.

P.S.: Compiled against libkqueue 2.6.3, in case that makes a difference.

Log output from the FreeRADIUS daemon

Relevant parts see above.

Relevant log output from client utilities

Unrelated to client activities

Backtrace from LLDB or GDB

[haegar]

Thanks Alan, fix looks good!
(Tested with git ce2bdff from an hour ago)