[11/11] syslog: Use a printf buffer directly to construct the entire packet

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(-)

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 <paths.h>
>  #include <stdarg.h>
>  #include <stdlib.h>
> -#include <stdio.h>
> -#include <stdio_ext.h>
>  #include <sys/socket.h>
> -#include <sys/uio.h>
>  #include <sys/un.h>
>  #include <syslog.h>
>  #include <limits.h>
> +#include <printf_buffer.h>
>  
>  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  */

* Adhemerval Zanella Netto:

> 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?

There are currently no internal uses (that I can see) of _IO_strfile for
writing purposes.  The psiginfo function uses __fmemopen, but that seems
excessive.  The syslog implementation was the only user of
open_memstream.  The reason for the open_memstream removal was
allocation removal, which makes sense for a logging function.

We must have manual constructs that use some printf function variant to
write to temporary buffers elsewhere.  One example is
stdio-common/psignal.c.  I can't find others outside sunrpc/ right now,
but they likely exist.  Switching those to fmemopen/open_memstream would
introduce the allocation issue as well, and dynamically sized printf
buffers could be a replacement.

I know that musl uses its _IO_strfile equivalent in such cases, but our
libio implementation is much more heavyweight, and it's hard to review
if new direct low-level uses of the libio internals are actually
correct.

> 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?

Pretty much all buffer management code is deleted.  We now have even
fewer code of that than in the previous open_memstream-based function.

> 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)?  

That doesn't remove the complicated buffer management.

Thanks,
Florian

On 15/02/24 10:02, Florian Weimer wrote:
> * Adhemerval Zanella Netto:
> 
>> 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?
> 
> There are currently no internal uses (that I can see) of _IO_strfile for
> writing purposes.  The psiginfo function uses __fmemopen, but that seems
> excessive.  The syslog implementation was the only user of
> open_memstream.  The reason for the open_memstream removal was
> allocation removal, which makes sense for a logging function.
> 
> We must have manual constructs that use some printf function variant to
> write to temporary buffers elsewhere.  One example is
> stdio-common/psignal.c.  I can't find others outside sunrpc/ right now,
> but they likely exist.  Switching those to fmemopen/open_memstream would
> introduce the allocation issue as well, and dynamically sized printf
> buffers could be a replacement.

For unbounded messages I tend to agree that fmemopen/open_memstream might
be not the best option.  I would like to avoid having a another internal
API for such cases, but it seems that printf buffer is a slight better
option indeed.

> 
> I know that musl uses its _IO_strfile equivalent in such cases, but our
> libio implementation is much more heavyweight, and it's hard to review
> if new direct low-level uses of the libio internals are actually
> correct.
> 
>> 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?
> 
> Pretty much all buffer management code is deleted.  We now have even
> fewer code of that than in the previous open_memstream-based function.
> 
>> 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)?  
> 
> That doesn't remove the complicated buffer management.

Right, the resulting code does seems simplified.

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 <paths.h>
>  #include <stdarg.h>
>  #include <stdlib.h>
> -#include <stdio.h>
> -#include <stdio_ext.h>
>  #include <sys/socket.h>
> -#include <sys/uio.h>
>  #include <sys/un.h>
>  #include <syslog.h>
>  #include <limits.h>
> +#include <printf_buffer.h>
>  
>  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  */