MEDIUM: log: add support for logging to existing file descriptors

In certain situations it would be desirable to log to an existing file
descriptor, the most common case being a pipe between containers or
processes. The main issue with pipes is that using write() on them will
randomly truncate messages. But there is a trick. By using writev(), we
can atomically deliver or drop a message, which perfectly fits the
purpose. The only caveat is that large messages (4096 bytes on modern
operating systems) may be interleaved with messages from other processes
if using nbproc for example. In practice such messages are rare and most
of the time when users need such type of logging, the load is low enough
for a single process to be running so this is not really a problem.

This logging method thus uses unbuffered writev() calls and is uses more
CPU than if it used its own buffer with large writes at once, though this
is not a problem for moderate loads.

Logging to a file descriptor attached to a file also works with the side
effect that the process is significantly slowed down during disk accesses
and that it's not possible to rotate the file without restarting the
process. For this reason this option is not offered as a configuration
option, since it would confuse most users, but one could decide to
redirect haproxy's output to a file during debugging sessions. Two aliases
"stdout" and "stderr" are provided, but keep in mind that these are closed
by default in daemon mode.

When logging to a pipe or socket at a high enough rate, some logs will be
dropped and the number of dropped messages is reported in "show info".
This commit is contained in:
Willy Tarreau 2018-11-12 07:34:59 +01:00
parent 13ef773722
commit 5a32ecc6cf
2 changed files with 66 additions and 10 deletions

View File

@ -837,11 +837,30 @@ log <address> [len <length>] [format <format>] <facility> [max level [min level]
no port is specified, 514 is used by default (the standard syslog
port).
- A filesystem path to a UNIX domain socket, keeping in mind
- A filesystem path to a datagram UNIX domain socket, keeping in mind
considerations for chroot (be sure the path is accessible inside
the chroot) and uid/gid (be sure the path is appropriately
writable).
- A file descriptor number in the form "fd@<number>", which may point
to a pipe, terminal, or socket. In this case unbuffered logs are used
and one writev() call per log is performed. This is a bit expensive
but acceptable for most workloads. Messages sent this way will not be
truncated but may be dropped, in which case the DroppedLogs counter
will be incremented. The writev() call is atomic even on pipes for
messages up to PIPE_BUF size, which POSIX recommends to be at least
512 and which is 4096 bytes on most modern operating systems. Any
larger message may be interleaved with messages from other processes.
Exceptionally for debugging purposes the file descriptor may also be
directed to a file, but doing so will significantly slow haproxy down
as non-blocking calls will be ignored. Also there will be no way to
purge nor rotate this file without restarting the process. Note that
the configured syslog format is preserved, so the output is suitable
for use with a TCP syslog server.
- "stdout" / "stderr", which are respectively aliases for "fd@1" and
"fd@2", see above.
You may want to reference some environment variables in the address
parameter, see section 2.3 about environment variables.
@ -5101,8 +5120,29 @@ no log
inside the chroot) and uid/gid (be sure the path is
appropriately writable).
You may want to reference some environment variables in the
address parameter, see section 2.3 about environment variables.
- A file descriptor number in the form "fd@<number>", which may
point to a pipe, terminal, or socket. In this case unbuffered
logs are used and one writev() call per log is performed. This
is a bit expensive but acceptable for most workloads. Messages
sent this way will not be truncated but may be dropped, in
which case the DroppedLogs counter will be incremented. The
writev() call is atomic even on pipes for messages up to
PIPE_BUF size, which POSIX recommends to be at least 512 and
which is 4096 bytes on most modern operating systems. Any
larger message may be interleaved with messages from other
processes. Exceptionally for debugging purposes the file
descriptor may also be directed to a file, but doing so will
significantly slow haproxy down as non-blocking calls will be
ignored. Also there will be no way to purge nor rotate this
file without restarting the process. Note that the configured
syslog format is preserved, so the output is suitable for use
with a TCP syslog server.
- "stdout" / "stderr", which are respectively aliases for "fd@1"
and "fd@2", see above.
You may want to reference some environment variables in the
address parameter, see section 2.3 about environment variables.
<length> is an optional maximum line length. Log lines larger than this
value will be truncated before being sent. The reason is that

View File

@ -754,6 +754,12 @@ int parse_logsrv(char **args, struct list *logsrvs, int do_del, char **err)
goto error;
}
/* take care of "stdout" and "stderr" as regular aliases for fd@1 / fd@2 */
if (strcmp(args[1], "stdout") == 0)
args[1] = "fd@1";
else if (strcmp(args[1], "stderr") == 0)
args[1] = "fd@2";
logsrv = calloc(1, sizeof(*logsrv));
if (!logsrv) {
memprintf(err, "out of memory");
@ -1342,9 +1348,13 @@ void __send_log(struct proxy *p, int level, char *message, size_t size, char *sd
if (unlikely(*plogfd < 0)) {
/* socket not successfully initialized yet */
int proto = logsrv->addr.ss_family == AF_UNIX ? 0 : IPPROTO_UDP;
if ((*plogfd = socket(logsrv->addr.ss_family, SOCK_DGRAM, proto)) < 0) {
if (logsrv->addr.ss_family == AF_UNSPEC) {
/* the socket's address is a file descriptor */
*plogfd = ((struct sockaddr_in *)&logsrv->addr)->sin_addr.s_addr;
fcntl(*plogfd, F_SETFL, O_NONBLOCK);
}
else if ((*plogfd = socket(logsrv->addr.ss_family, SOCK_DGRAM,
(logsrv->addr.ss_family == AF_UNIX) ? 0 : IPPROTO_UDP)) < 0) {
static char once;
if (!once) {
@ -1473,10 +1483,16 @@ void __send_log(struct proxy *p, int level, char *message, size_t size, char *sd
iovec[7].iov_base = "\n"; /* insert a \n at the end of the message */
iovec[7].iov_len = 1;
msghdr.msg_name = (struct sockaddr *)&logsrv->addr;
msghdr.msg_namelen = get_addr_len(&logsrv->addr);
if (logsrv->addr.ss_family == AF_UNSPEC) {
/* the target is a direct file descriptor */
sent = writev(*plogfd, iovec, 8);
}
else {
msghdr.msg_name = (struct sockaddr *)&logsrv->addr;
msghdr.msg_namelen = get_addr_len(&logsrv->addr);
sent = sendmsg(*plogfd, &msghdr, MSG_DONTWAIT | MSG_NOSIGNAL);
sent = sendmsg(*plogfd, &msghdr, MSG_DONTWAIT | MSG_NOSIGNAL);
}
if (sent < 0) {
static char once;
@ -1485,7 +1501,7 @@ void __send_log(struct proxy *p, int level, char *message, size_t size, char *sd
HA_ATOMIC_ADD(&dropped_logs, 1);
else if (!once) {
once = 1; /* note: no need for atomic ops here */
ha_alert("sendmsg() failed in logger #%d: %s (errno=%d)\n",
ha_alert("sendmsg()/writev() failed in logger #%d: %s (errno=%d)\n",
nblogger, strerror(errno), errno);
}
}