From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mail-pf1-x42a.google.com (mail-pf1-x42a.google.com [IPv6:2607:f8b0:4864:20::42a]) by sourceware.org (Postfix) with ESMTPS id 1B31C3857C49 for ; Fri, 16 Feb 2024 15:58:50 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.2 sourceware.org 1B31C3857C49 Authentication-Results: sourceware.org; dmarc=pass (p=none dis=none) header.from=linaro.org Authentication-Results: sourceware.org; spf=pass smtp.mailfrom=linaro.org ARC-Filter: OpenARC Filter v1.0.0 sourceware.org 1B31C3857C49 Authentication-Results: server2.sourceware.org; arc=none smtp.remote-ip=2607:f8b0:4864:20::42a ARC-Seal: i=1; a=rsa-sha256; d=sourceware.org; s=key; t=1708099133; cv=none; b=RCQpS/ylgIFLt3ZdnOw6PGoIkCm3O6wxfZjXqMScy0v/VDi7PEAF3cF6WqQL8ZfJ53GI6ark4QpycQsavVRCqPoEXLRLPr+nTNI9s8WpC5iWA+m/BD1NqTM4IZ8HLJIWbtNPRzPxIUYg6ZXJlsaCNR0Y1L3jNajuvsDI2kY4Se0= ARC-Message-Signature: i=1; a=rsa-sha256; d=sourceware.org; s=key; t=1708099133; c=relaxed/simple; bh=Z6n3uVbScVUYCftTb30sks+3R5SqtpnvVdPED8qO8iU=; h=DKIM-Signature:Message-ID:Date:MIME-Version:Subject:To:From; b=hE4EZp1zUvFDIf5HT06KUHiaTmZhc3HkOYVIhRhoRjhirsq701ekDFUpPe4Z2BaFPag0wlp3vUpc1V1FRJefQPDIRJ4N8vn4EaomUgOzCkm464iYIRSqQWQpKla4QIWfTSRfBMjFaSrycZTxZv4nulRY4s+Dlh82EhqlAQAzYIs= ARC-Authentication-Results: i=1; server2.sourceware.org Received: by mail-pf1-x42a.google.com with SMTP id d2e1a72fcca58-6e0f4e3bc59so557340b3a.0 for ; Fri, 16 Feb 2024 07:58:50 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; t=1708099129; x=1708703929; darn=sourceware.org; h=content-transfer-encoding:in-reply-to:organization:from:references :to:content-language:subject:user-agent:mime-version:date:message-id :from:to:cc:subject:date:message-id:reply-to; bh=vWWIZavoVLALaWdAxLXudPhcL2SyITg78/1WXynfSPY=; b=k07dLfeIwp+OOhU8vHwWBU9h/TscIm5qRA7zCceL0j4N68+uDzKECUVbUkyoh1nEx2 c3wZeCYToVseCpWRSWyG2Dc9YY/rwWcB/MbMhFCJyIr2qagY6LUps6qLr85tTIG3HSUO Y2hKzqJbvHMqHQqIto3iOf/w8CiEVp65BzvFvvfx+ciMZBHzT+nPGNuqCFI6xoP6f1nj NpbCYM5k1H1xJkmGITmYbCrQPhTJZLPEdQbjKQT2+AzP2HFEKv5Wr4rPkas9NkHHnEkl 8fJSm2KvLMGYQ+9pDVgU4/irxyYIUP0xIqtuLHLZOUTOJYtiXwcZPq+OqfxW1tFQndBk +3PA== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1708099129; x=1708703929; h=content-transfer-encoding:in-reply-to:organization:from:references :to:content-language:subject:user-agent:mime-version:date:message-id :x-gm-message-state:from:to:cc:subject:date:message-id:reply-to; bh=vWWIZavoVLALaWdAxLXudPhcL2SyITg78/1WXynfSPY=; b=lKnRnm9l2lhxOla8AbxuQ0TX+78ukDSglgUF4AM8O0ha6OFORb1KNRIqPE7qG5Ob11 fKXVXrUyQ/GGvWZmxc7sJOzvM1Hb3hXOC7pgBo+pvyD+UpkIMx7Xut+WbFnrERB1VtLw iz/zFP3gyjJ7wOCQCHwOC769R6XUsg3MocQJd6Fcp8wBcp8rWDkiqzPYxYP2xEmNhJFX A9wP8QZ1wcdxmEOvi7NxjwxeVae4R9k1AjrMYWvYZyi2b5n3SxTKwmGkyg1iO+JzCsqP MhNd9JEbvP+OISPYZ1kqrWoHHuRXqmlCOcK9zhN1hpNjuUrA8D2UuXOWPxKStQ8UW4Q2 SfFA== X-Forwarded-Encrypted: i=1; AJvYcCUquqxVsvw9HQuTr05+/DTQnUdZJY1oY94n8WqYhyJ/46yG1ErAbIcR419s1ZrdAs6nF/rh1sL6EDNOZNYCL262mQsYsF4poic1 X-Gm-Message-State: AOJu0Yy16msTtGqeLg9A+xZqiy7RYFCO5HKFNqE8z0gyXBMPkXQ3+jDF BXisajOjWEluVMlLkZ7XTJMkzBCAmAgAUzQSmO8pziW7yhRv1oGr1mW6KZJbPzl7Jcnc3Pbh3T8 A X-Google-Smtp-Source: AGHT+IFUAuFyWIpoxZ74wNjttwtBQgZ2ToibFUbf+sPeL7KqJJvwzbyUnUGQVMVe7SZiuHnQc/KwbQ== X-Received: by 2002:a05:6a20:93aa:b0:1a0:7fa2:305 with SMTP id x42-20020a056a2093aa00b001a07fa20305mr5307001pzh.47.1708099128976; Fri, 16 Feb 2024 07:58:48 -0800 (PST) Received: from ?IPV6:2804:1b3:a7c0:8177:542a:9f26:15a9:5ce4? ([2804:1b3:a7c0:8177:542a:9f26:15a9:5ce4]) by smtp.gmail.com with ESMTPSA id hq24-20020a056a00681800b006e09e975596sm118780pfb.38.2024.02.16.07.58.47 (version=TLS1_3 cipher=TLS_AES_128_GCM_SHA256 bits=128/128); Fri, 16 Feb 2024 07:58:48 -0800 (PST) Message-ID: Date: Fri, 16 Feb 2024 12:58:46 -0300 MIME-Version: 1.0 User-Agent: Mozilla Thunderbird Subject: Re: [PATCH 11/11] syslog: Use a printf buffer directly to construct the entire packet Content-Language: en-US To: Florian Weimer , libc-alpha@sourceware.org References: From: Adhemerval Zanella Netto Organization: Linaro In-Reply-To: Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 7bit X-Spam-Status: No, score=-12.7 required=5.0 tests=BAYES_00,DKIM_SIGNED,DKIM_VALID,DKIM_VALID_AU,DKIM_VALID_EF,GIT_PATCH_0,RCVD_IN_DNSWL_NONE,SPF_HELO_NONE,SPF_PASS,TXREP,T_SCC_BODY_TEXT_LINE autolearn=ham autolearn_force=no version=3.4.6 X-Spam-Checker-Version: SpamAssassin 3.4.6 (2021-04-09) on server2.sourceware.org List-Id: On 09/02/24 12:26, Florian Weimer wrote: > This defers buffer management largely to the asprintf implementation. > It is quite close to the original implementation around > open_memstream, except that an on-stack buffer is used for shorter > messages, and that strftime no longer writes directly into the > buffer. > > The new version no longer uses the (slow) %n format specifier. > It also fixes an issue in the localtime_r failure path, where > the message is prefixed with ": " due to an incorrect placement > of the %n specifier. > --- > misc/syslog.c | 184 ++++++++++++++++---------------------------------- > 1 file changed, 58 insertions(+), 126 deletions(-) > > diff --git a/misc/syslog.c b/misc/syslog.c > index 68ee3aef5f..50cb252f47 100644 > --- a/misc/syslog.c > +++ b/misc/syslog.c > @@ -38,13 +38,11 @@ static char sccsid[] = "@(#)syslog.c 8.4 (Berkeley) 3/18/94"; > #include > #include > #include > -#include > -#include > #include > -#include > #include > #include > #include > +#include > > static int LogType = SOCK_DGRAM; /* type of socket connection */ > static int LogFile = -1; /* fd for log */ > @@ -60,27 +58,23 @@ __libc_lock_define_initialized (static, syslog_lock) > static void openlog_internal (const char *, int, int); > static void closelog_internal (void); > > -struct cleanup_arg > +/* Unlock and deallocate the buffer. */ > +static void > +cancel_handler_buf (void *ptr) > { > - void *buf; > - struct sigaction *oldaction; > -}; > + __libc_lock_unlock (syslog_lock); > + > + struct __printf_buffer_asprintf *buf = ptr; > + __printf_buffer_asprintf_free (buf); > +} > > +/* Only unlock. */ > static void > cancel_handler (void *ptr) > { > - /* Restore the old signal handler. */ > - struct cleanup_arg *clarg = (struct cleanup_arg *) ptr; > - > - if (clarg != NULL) > - /* Free the memstream buffer, */ > - free (clarg->buf); > - > - /* Free the lock. */ > __libc_lock_unlock (syslog_lock); > } > > - > /* > * syslog, vsyslog -- > * print message on log file; output is intended for syslogd(8). > @@ -122,16 +116,21 @@ __vsyslog_chk (int pri, int flag, const char *fmt, va_list ap) > __vsyslog_internal (pri, fmt, ap, (flag > 0) ? PRINTF_FORTIFY : 0); > } > > +/* Send the buffer contents over the syslog socket. */ > +static ssize_t > +__syslog_send (struct __printf_buffer *buf) > +{ > + /* Send the trailing NUL byte for LogType == SOCK_STREAM only. */ > + return __send (LogFile, buf->write_base, > + buf->write_ptr - buf->write_base - (LogType != SOCK_STREAM), > + MSG_NOSIGNAL) Maybe encapsulate this on a function (__printf_buffer_write_len or something)? I think we should avoid mess the internal printf buffer state where possible. > +} > + > void > __vsyslog_internal (int pri, const char *fmt, va_list ap, > unsigned int mode_flags) > { > - /* Try to use a static buffer as an optimization. */ > - char bufs[1024]; > - char *buf = bufs; > - size_t bufsize; > - > - int msgoff; > + ptrdiff_t msgoff; > int saved_errno = errno; > > #define INTERNALLOG LOG_ERR|LOG_CONS|LOG_PERROR|LOG_PID > @@ -144,8 +143,9 @@ __vsyslog_internal (int pri, const char *fmt, va_list ap, > > /* Prepare for multiple users. We have to take care: most syscalls we are > using are cancellation points. */ > - struct cleanup_arg clarg = { NULL, NULL }; > - __libc_cleanup_push (cancel_handler, &clarg); > + struct __printf_buffer_asprintf buf; > + __printf_buffer_asprintf_init (&buf); > + __libc_cleanup_push (cancel_handler_buf, &buf); > __libc_lock_lock (syslog_lock); > > /* Check priority against setlogmask values. */ > @@ -173,122 +173,56 @@ __vsyslog_internal (int pri, const char *fmt, va_list ap, > __strftime_l (timestamp, sizeof timestamp, "%h %e %T ", now_tmp, > _nl_C_locobj_ptr); > > -#define SYSLOG_HEADER(__pri, __timestamp, __msgoff, pid) \ > - "<%d>%s%n%s%s%.0d%s: ", \ > - __pri, __timestamp, __msgoff, \ > - LogTag == NULL ? __progname : LogTag, \ > - "[" + (pid == 0), pid, "]" + (pid == 0) > + __printf_buffer (&buf.base, "<%d>", pri); > > -#define SYSLOG_HEADER_WITHOUT_TS(__pri, __msgoff) \ > - "<%d>: %n", __pri, __msgoff > - > - int l, vl; > if (has_ts) > - l = __snprintf (bufs, sizeof bufs, > - SYSLOG_HEADER (pri, timestamp, &msgoff, pid)); > - else > - l = __snprintf (bufs, sizeof bufs, > - SYSLOG_HEADER_WITHOUT_TS (pri, &msgoff)); > - if (l < 0) > - goto out; > - > - char *pos; > - size_t len; > - > - if (l < sizeof bufs) > { > - /* At this point, there is still a chance that we can print the > - remaining part of the log into bufs and use that. */ > - pos = bufs + l; > - len = sizeof (bufs) - l; > + __printf_buffer_puts (&buf.base, timestamp); > + msgoff = buf.base.write_ptr - buf.base.write_base; > + __printf_buffer_puts (&buf.base, LogTag == NULL ? __progname : LogTag); > + if (pid != 0) > + __printf_buffer (&buf.base, "[%d]", pid); > + __printf_buffer_putc (&buf.base, ':'); > + __printf_buffer_putc (&buf.base, ' '); > } > else > { > - buf = NULL; > - /* We already know that bufs is too small to use for this log message. > - The next vsnprintf into bufs is used only to calculate the total > - required buffer length. We will discard bufs contents and allocate > - an appropriately sized buffer later instead. */ > - pos = bufs; > - len = sizeof (bufs); > + msgoff = buf.base.write_ptr - buf.base.write_base; > + __printf_buffer_putc (&buf.base, ':'); > + __printf_buffer_putc (&buf.base, ' '); > } Maybe move the ': ' appending after the if/else: if (has_ts) { [...] } else [...] __printf_buffer_puts (&buf.base, ": "); > > - { > - va_list apc; > - va_copy (apc, ap); > - > - /* Restore errno for %m format. */ > - __set_errno (saved_errno); > - > - vl = __vsnprintf_internal (pos, len, fmt, apc, mode_flags); > - va_end (apc); > + /* Do not count the bytes written to the buffer so far. This value > + is negative and accounts for the existing buffer contents, which > + is not upposed to be visible to the caller. */ s/upposed/supposed > + buf.base.written = buf.base.write_base - buf.base.write_ptr; Maybe encapsulate this on a function (__printf_buffer_reset_pos or something)? > > - if (vl < 0 || vl >= INT_MAX - l) > - goto out; > + errno = saved_errno; > + __vprintf_buffer (&buf.base, fmt, ap, mode_flags); > > - if (vl >= len) > - buf = NULL; > - > - bufsize = l + vl; > - } > - > - if (buf == NULL) > - { > - buf = malloc ((bufsize + 1) * sizeof (char)); > - if (buf != NULL) > - { > - /* Tell the cancellation handler to free this buffer. */ > - clarg.buf = buf; > + /* We may need the terminator if we are sending over a SOCK_STREAM > + connection. Add this unconditionally to simplify error handling. */ > + __printf_buffer_putc (&buf.base, '\0'); > Ok. > - int cl; > - if (has_ts) > - cl = __snprintf (buf, l + 1, > - SYSLOG_HEADER (pri, timestamp, &msgoff, pid)); > - else > - cl = __snprintf (buf, l + 1, > - SYSLOG_HEADER_WITHOUT_TS (pri, &msgoff)); > - if (cl != l) > - goto out; > - > - va_list apc; > - va_copy (apc, ap); > - cl = __vsnprintf_internal (buf + l, bufsize - l + 1, fmt, apc, > - mode_flags); > - va_end (apc); > - > - if (cl != vl) > - goto out; > - } > - else > - { > - int bl; > - /* Nothing much to do but emit an error message. */ > - bl = __snprintf (bufs, sizeof bufs, > - "out of memory[%d]", __getpid ()); > - if (bl < 0 || bl >= sizeof bufs) > - goto out; > - > - bufsize = bl; > - buf = bufs; > - msgoff = 0; > - } > - } > + if (__printf_buffer_has_failed (&buf.base)) > + goto out; > > /* Output to stderr if requested. */ > if (LogStat & LOG_PERROR) > - __dprintf (STDERR_FILENO, "%s%s", buf + msgoff, > - "\n" + (buf[bufsize - 1] == '\n')); > + { > + /* The buffer always starts with '<' and a digit, so there are > + at least two bytes, and -2 is valid offset from the next > + to-be-written byte. -2 accounts for the NUL byte. */ > + int has_nl = buf.base.write_ptr[-2] == '\n'; > + __dprintf (STDERR_FILENO, "%s%s", buf.base.write_base + msgoff, > + "\n" + has_nl); > + } > > /* Get connected, output the message to the local logger. */ > if (!connected) > openlog_internal (NULL, LogStat | LOG_NDELAY, LogFacility); > > - /* If we have a SOCK_STREAM connection, also send ASCII NUL as a record > - terminator. */ > - if (LogType == SOCK_STREAM) > - ++bufsize; > - > - if (!connected || __send (LogFile, buf, bufsize, MSG_NOSIGNAL) < 0) > + if (!connected || __syslog_send (&buf.base) < 0) > { > if (connected) > { > @@ -297,7 +231,7 @@ __vsyslog_internal (int pri, const char *fmt, va_list ap, > openlog_internal (NULL, LogStat | LOG_NDELAY, LogFacility); > } > > - if (!connected || __send (LogFile, buf, bufsize, MSG_NOSIGNAL) < 0) > + if (!connected || __syslog_send (&buf.base) < 0) > { > closelog_internal (); /* attempt re-open next time */ > /* > @@ -311,7 +245,7 @@ __vsyslog_internal (int pri, const char *fmt, va_list ap, > (fd = __open (_PATH_CONSOLE, O_WRONLY | O_NOCTTY > | O_CLOEXEC, 0)) >= 0) > { > - __dprintf (fd, "%s\r\n", buf + msgoff); > + __dprintf (fd, "%s\r\n", buf.base.write_base + msgoff); > __close (fd); > } > } > @@ -321,9 +255,7 @@ out: > /* End of critical section. */ > __libc_cleanup_pop (0); > __libc_lock_unlock (syslog_lock); > - > - if (buf != bufs) > - free (buf); > + __printf_buffer_asprintf_free (&buf); > } > > /* AF_UNIX address of local logger */