Dmitry Katsubo via Postfix-users:
> Dear Postfix team,
>
> In some rare cases when OS is CPU-loaded, the log is overflowed with the
> following messages from Postfix, which fills up log space very quickly:
>
> 2023-12-24 18:04:41.016972 postfix/tlsmgr[105819]: warning: end-of-input
> while reading request from tlsmgr socket: Application error
> 2023-12-24 18:04:41.017479 postfix/tlsmgr[105819]: warning: end-of-input
> while reading request from tlsmgr socket: Application error
What OS is this? The OS claims that pending data is available on a
socket, and then a short moment later says that there is none.
- A tlsmgr client sends a request to the tlsmgr service.
- In some tlsmgr server process, an event loop wakes up after a
socket becomes readable (depending on the OS this uses epoll(),
/dev/poll, kqueue() or select()).
- The event loop code determines that there is pending data ussing
Postfix peekfd().
- The event loop code calls tlsmgr server code to handle the request.
- That code verifies again that the socket is readable with poll()
or select() (it is), and verifies again with Postfix peekfd()
that there is pending data (SURPRISE! there isn't).
Postfix implements peekfd() with:
return (ioctl(fd, FIONREAD, (char *) &count) < 0 ? -1 : count);
The "Application error" in the warning means that ioctl(FIONREAD)
left the errno at a zero value.
On your system, two identical calls of ioctl(FIONREAD) produce
different results in the above sequence of calls of
- wake up from epoll() or /dev/poll or kqueue() or select(),
- call ioctl(),
- call poll() or select(),
- call ioctl() again.
Data that is pending according to the first ioctl() call is
not pending according to the second ioctl() call.
This happens not just once, but often enough to spam your logs badly.
With the patch below I can add a call to close the socket after such
an anomaly, but there is no guarantee that it will solve any problem.
Let me know if this makes any difference at all.
Wietse
--- ./src/tlsmgr/tlsmgr.c- 2021-12-19 17:04:54.000000000 -0500
+++ ./src/tlsmgr/tlsmgr.c 2023-12-25 10:35:41.378826883 -0500
@@ -819,12 +819,15 @@
}
/*
- * Protocol error.
+ * Protocol error. Or, the OS lied and data that was once pending is no
+ * longer available. Close the stream before the OS changes its little
+ * mind again. The client can reconnect if it still wants to talk to us.
*/
else {
attr_print(client_stream, ATTR_FLAG_NONE,
SEND_ATTR_INT(MAIL_ATTR_STATUS, TLS_MGR_STAT_FAIL),
ATTR_TYPE_END);
+ multi_server_disconnect(client_stream);
}
vstream_fflush(client_stream);
}
_______________________________________________
Postfix-users mailing list -- postfix-users@postfix.org
To unsubscribe send an email to postfix-users-le...@postfix.org
