Greetings,
chrony 4.7 and 4.8 (and possibly others) have an issue with
test/util/socket.c's self test,
UNLESS running under "truss" (think strace in the Linux world).
Apparently we're looking at OS-specific differences WRT non-blocking
accept()ed sockets for TCP between FreeBSD and, say, Linux, or with
something that a syscall tracer will cause to be retried.
$ truss test/unit/socket.test
=> passes
close(3) = 0 (0x0)
close(4) = 0 (0x0)
PASS
write(1,"PASS\n",5) = 5 (0x5)
exit(0x0)
process exit, rval = 0
$ test/unit/socket.test
=> prints Testing socket FAIL (on line 75)
FAIL (on line 75).
Building with debug enabled and -d on the command line yields:
...
2025-08-27T14:39:14Z D:../../socket.c:813:(log_message) Received
message from 127.0.0.1:57724 fd=3 len=16
2025-08-27T14:39:14Z D:../../socket.c:813:(log_message) Sent message
to 127.0.0.1:57724 fd=3 len=16
2025-08-27T14:39:14Z D:../../socket.c:1648:(SCK_Receive) Received data
fd=4 len=16
2025-08-27T14:39:14Z D:../../socket.c:595:(open_ip_socket) Opened
UDPv4 socket fd=3 local=127.0.0.1:28164
2025-08-27T14:39:14Z D:../../socket.c:595:(open_ip_socket) Opened
UDPv4 socket fd=4 remote=127.0.0.1:28164
2025-08-27T14:39:14Z D:../../socket.c:1674:(SCK_Send) Sent data fd=4
len=16
2025-08-27T14:39:14Z D:../../socket.c:813:(log_message) Received
message from 127.0.0.1:39243 fd=3 len=16
2025-08-27T14:39:14Z D:../../socket.c:813:(log_message) Sent message
to 127.0.0.1:39243 fd=3 len=16
2025-08-27T14:39:14Z D:../../socket.c:1648:(SCK_Receive) Received data
fd=4 len=16
2025-08-27T14:39:14Z D:../../socket.c:595:(open_ip_socket) Opened
UDPv4 socket fd=3 local=127.0.0.1:41555
2025-08-27T14:39:14Z D:../../socket.c:595:(open_ip_socket) Opened
UDPv4 socket fd=4 remote=127.0.0.1:41555
2025-08-27T14:39:14Z D:../../socket.c:1674:(SCK_Send) Sent data fd=4
len=16
2025-08-27T14:39:14Z D:../../socket.c:813:(log_message) Received
message from 127.0.0.1:19472 fd=3 len=16
2025-08-27T14:39:14Z D:../../socket.c:813:(log_message) Sent message
to 127.0.0.1:19472 fd=3 len=16
2025-08-27T14:39:14Z D:../../socket.c:1648:(SCK_Receive) Received data
fd=4 len=16
2025-08-27T14:39:14Z D:../../socket.c:595:(open_ip_socket) Opened
TCPv4 socket fd=3 local=127.0.0.1:6992
2025-08-27T14:39:14Z D:../../socket.c:595:(open_ip_socket) Opened
TCPv4 socket fd=4 remote=127.0.0.1:6992
2025-08-27T14:39:14Z D:../../socket.c:1674:(SCK_Send) Sent data fd=4
len=16
2025-08-27T14:39:14Z D:../../socket.c:813:(log_message) Received
message fd=5 len=16
2025-08-27T14:39:14Z D:../../socket.c:813:(log_message) Sent message
fd=5 len=16
2025-08-27T14:39:14Z D:../../socket.c:1648:(SCK_Receive) Received data
fd=4 len=16
2025-08-27T14:39:14Z D:../../socket.c:595:(open_ip_socket) Opened
TCPv4 socket fd=3 local=127.0.0.1:27407
2025-08-27T14:39:14Z D:../../socket.c:595:(open_ip_socket) Opened
TCPv4 socket fd=4 remote=127.0.0.1:27407 local=127.0.0.1:17334
2025-08-27T14:39:14Z D:../../socket.c:1674:(SCK_Send) Sent data fd=4
len=16
2025-08-27T14:39:14Z D:../../socket.c:752:(handle_recv_error) Could
not receive message fd=5 : Resource temporarily unavailable
FAIL (on line 75)
Debugging this, SCK_AcceptConnection unconditionally sets O_NONBLOCK on
the socket,
and recvmsg() (FreeBSD offers recvmmsg() but chrony doesn't use it, see
below) "Resource temporarily unavailable" is EAGAIN.
I will disable the socket.c unit test on FreeBSD port for the time being.
Speaking of which, configure states that FreeBSD 11.0 had a broken
recvmmsg() - have there been bug reports at the time or fixes? Have we
retried this on 13.5, 14.2, 14.3? What do we need to look for?
Cheers,
Matthias
