From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mail-pf1-x429.google.com (mail-pf1-x429.google.com [IPv6:2607:f8b0:4864:20::429]) by sourceware.org (Postfix) with ESMTPS id 89769385E037 for ; Wed, 14 Feb 2024 15:16:52 +0000 (GMT) DMARC-Filter: OpenDMARC Filter v1.4.2 sourceware.org 89769385E037 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 89769385E037 Authentication-Results: server2.sourceware.org; arc=none smtp.remote-ip=2607:f8b0:4864:20::429 ARC-Seal: i=1; a=rsa-sha256; d=sourceware.org; s=key; t=1707923815; cv=none; b=k7Hz3r5lKSkwXvW9YStQXDzFrcEqj4PsqgFMR9MZcOMHssACQpzVLJjnWoDMaOKDtat9kpPgC8YUoombx+kKQG8gzeWwiSYPHqDx37OQDWqUecRd89fzKHvy/hxQ+35U+Vc//IH7lq1FVWB2RUNhDbOS+budAf7Jth35laCXYgA= ARC-Message-Signature: i=1; a=rsa-sha256; d=sourceware.org; s=key; t=1707923815; c=relaxed/simple; bh=oCDYx+3nJmXHjNx6tGtZNpSnZ86U4A3LWJGHqyseXd8=; h=DKIM-Signature:Message-ID:Date:MIME-Version:Subject:To:From; b=GySVqT5FMVBfFymJVw9b3JQGynFjUigJAX7IoiXETB5G7prKzBT5wIuLXE7KTbmCryHc3wwL312Njy9S88EXDvw+3AGQl9srtexFlR4eIxkbaACoLIMaiaXqERBq+0pgHCH0BDeG82fh7WpKdttrrE79HhedoxTYoJoIKVAMqs0= ARC-Authentication-Results: i=1; server2.sourceware.org Received: by mail-pf1-x429.google.com with SMTP id d2e1a72fcca58-6da4a923b1bso1921663b3a.2 for ; Wed, 14 Feb 2024 07:16:52 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; t=1707923811; x=1708528611; 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=n8eVVhYBdHksETrnF5h0vzB0uNwuxtQoAMOqr3VCnM0=; b=pV4GePGAdNibI3NwaxFrCNxb2duQ9jMFcrld8iZl7t+xDEUOgbFU0HnanA3mMc1ipk Q5+uTDv1QbJksx/sX7jhlAdoxEmnV92bPLSCcFSctZpboeC63VjVdigUN5I8ee1qvAXx SBXy1ibPEZHhY6yFDOj5eaPMLycFDGhPaTiVX+8yU7ckzFIvg0EugP8ULiTW4Pi6uqCp hxeC7QN+gRXK74jgyuNTN+1HQyV7uEytVyZeq4k5/gZvBeJ5lDpVwD3AHr5iZ4fKl0LA +OvNdoLtzAd68MUmWaasDgWPJ+3AaQVz4Onh8Taa06EIm9mrnrJ8nwZPen0DGZ8JO2dJ hsPw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1707923811; x=1708528611; 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=n8eVVhYBdHksETrnF5h0vzB0uNwuxtQoAMOqr3VCnM0=; b=ULsoLtj82+CBDBu2V7nOkOFkVS7aPICbjcuEwCf+YHKhjOcPBZOY+frTDaZZhF7hI4 g1g1in0XMrvdrv5edcK37W1mJBJbt2XTvydg1hq4su3+1Z/l8KTvtdugiYV1EZXnfBtW V4KHy1kXMrYAVGg06tKbTvBnZRAGvw/+UVA8ZSw3bA+Xjghd44eTp2NIQ7S5b76ekiuy hLn6QwWUsEfow5ropFiZvBphu+N/WZ+mP8OqoTfLkr0njy5aeo+CmHPH/duhLiD/AuW4 0IECShMMsQxmQ4fHOuq64T0TXTB83vq0uP1spD6UTyXc5C30hX+JfZKUFmbtib89libm a7qw== X-Forwarded-Encrypted: i=1; AJvYcCU51lqIN3yOmDsreVpsuJ5YMFPce01ABxoPsnL8w3KxDJrrYCJCTgvZrXm+wi4wBWAAyvuhm8Wf02d1IeG5/wnQOpXHVBWCHkCb X-Gm-Message-State: AOJu0YztAP5Bdn91WNXfG7pgU8vgk0t2HgwlE8Dwnb4HYjIFlH/wkYKw T9O0kfvrZiBeBGL99Xo9gniOMGxDSQ1g0FeVg5Ah6OWnhyDHUc2VncPRPfqxeh2laZTcXVzW6sG p X-Google-Smtp-Source: AGHT+IFmQSh1SdXU0KLIv4Yq5fv7gErBUr7y8HguWKO5EeewmYOoHcigm6BLv2BGUHfeu20Md2E6Rg== X-Received: by 2002:a05:6a20:9d90:b0:1a0:5c37:9201 with SMTP id mu16-20020a056a209d9000b001a05c379201mr3345169pzb.52.1707923811485; Wed, 14 Feb 2024 07:16:51 -0800 (PST) X-Forwarded-Encrypted: i=1; AJvYcCUZ8IvSMJX2QJKGSobI9Vbxi4/jxUQyhvg20EHVsgYQ/erZIH+vmgDWAPVx6SSuTKyHpaqcZFCFbx/dji9N+8v0sLwxBap+DFGU Received: from ?IPV6:2804:1b3:a7c0:8177:d08d:6747:e5f5:d1e5? ([2804:1b3:a7c0:8177:d08d:6747:e5f5:d1e5]) by smtp.gmail.com with ESMTPSA id it18-20020a056a00459200b006e118d2db93sm274750pfb.125.2024.02.14.07.16.50 (version=TLS1_3 cipher=TLS_AES_128_GCM_SHA256 bits=128/128); Wed, 14 Feb 2024 07:16:50 -0800 (PST) Message-ID: Date: Wed, 14 Feb 2024 12:16:49 -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.0 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. What I am not sure if this is really the direction we want for internal FILE usage. I had the impression that the printf buffer internal API was mainly meant to improve the old FILE implementation and its historical drawnbacks and limitations. For internal usage we would continue to use standard FILE API, should we move to always use printf buffers instead? I am asking because it is a lot of code and refactoring for a specific code that I would like to avoid change due the recent issues. Most of complication is the static buffer optimization, so maybe we should just remove it? Also, since the motivation for this change is just to remove the %n requirement, maybe we can just not enable it on syslog instead (since we now that the internal calls should not act as a gadget)? diff --git a/misc/syslog.c b/misc/syslog.c index 68ee3aef5f..53a17e612b 100644 --- a/misc/syslog.c +++ b/misc/syslog.c @@ -122,6 +122,29 @@ __vsyslog_chk (int pri, int flag, const char *fmt, va_list ap) __vsyslog_internal (pri, fmt, ap, (flag > 0) ? PRINTF_FORTIFY : 0); } +#if __USE_FORTIFY_LEVEL > 1 +static int +syslog_snprintf_chk (char *s, size_t maxlen, size_t slen, const char *format, + ...) +{ + if (__glibc_unlikely (slen < maxlen)) + __chk_fail (); + + /* Avoid the costly %n fortify check, so do not pass PRINTF_FORTIFY. */ + va_list ap; + va_start (ap, format); + int ret = __vsnprintf_internal (s, maxlen, format, ap, 0); + va_end (ap); + + return ret; +} +# define syslog_snprintf(str, len, ...) \ + syslog_snprintf_chk (str, len, __glibc_objsize (str), __VA_ARGS__) +#else +# define syslog_snprintf(str, len, ...) \ + __snprintf (str, len, __VA_ARGS__) +#endif + void __vsyslog_internal (int pri, const char *fmt, va_list ap, unsigned int mode_flags) @@ -184,11 +207,11 @@ __vsyslog_internal (int pri, const char *fmt, va_list ap, int l, vl; if (has_ts) - l = __snprintf (bufs, sizeof bufs, - SYSLOG_HEADER (pri, timestamp, &msgoff, pid)); + l = syslog_snprintf (bufs, sizeof bufs, + SYSLOG_HEADER (pri, timestamp, &msgoff, pid)); else - l = __snprintf (bufs, sizeof bufs, - SYSLOG_HEADER_WITHOUT_TS (pri, &msgoff)); + l = syslog_snprintf (bufs, sizeof bufs, + SYSLOG_HEADER_WITHOUT_TS (pri, &msgoff)); if (l < 0) goto out; @@ -242,11 +265,11 @@ __vsyslog_internal (int pri, const char *fmt, va_list ap, int cl; if (has_ts) - cl = __snprintf (buf, l + 1, - SYSLOG_HEADER (pri, timestamp, &msgoff, pid)); + cl = syslog_snprintf (buf, l + 1, + SYSLOG_HEADER (pri, timestamp, &msgoff, pid)); else - cl = __snprintf (buf, l + 1, - SYSLOG_HEADER_WITHOUT_TS (pri, &msgoff)); + cl = syslog_snprintf (buf, l + 1, + SYSLOG_HEADER_WITHOUT_TS (pri, &msgoff)); if (cl != l) goto out; @@ -263,8 +286,8 @@ __vsyslog_internal (int pri, const char *fmt, va_list ap, { int bl; /* Nothing much to do but emit an error message. */ - bl = __snprintf (bufs, sizeof bufs, - "out of memory[%d]", __getpid ()); + bl = syslog_snprintf (bufs, sizeof bufs, + "out of memory[%d]", __getpid ()); if (bl < 0 || bl >= sizeof bufs) goto out; > --- > 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); > +} > + > 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, ' '); > } > > - { > - 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. */ > + buf.base.written = buf.base.write_base - buf.base.write_ptr; > > - 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'); > > - 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 */