[PATCH 4/4] os/log: refactor logging

[Peter Hutterer]

On Wed, Apr 18, 2012 at 05:51:53PM +0800, Daniel Kurtz wrote:
> It is not safe to ever use an arbitrary (possibly user supplied) string as
> part of the format for a *sprintf() call.
> 
> For example:
>   1. Name a Bluetooth keyboard "%n%n%n%n%n%n%n%n"
>   2. Pair it with a computer running X and try to use it
>   3. X is not happy when trying to do the following in xf86-input-evdev:
>      xf86IDrvMsg(pInfo, X_CONFIG, "Device: \"%s\"\n", device);
>      because LogVHdrMessageVerb() has put the %n from the device name
>      into a format string.
> 
> Instead, build up a log message in place by appending successive formatted
> strings by sncprintf'ing to the end of the previous.
> 
> Signed-off-by: Daniel Kurtz <djkurtz at chromium.org>

verified and all 4 merged, thanks. took me a while to find the actual issue
because I was looking in the wrong place. for the archives: The culprit here
was not the user-supplied format string but rather xf86IDrvMsg using the
device's name, assembling a format string in the form of
    <driver>: <name>: message
i.e.
    "evdev: %n%n%n%n: Device \"%s\"\n"
and using that as format string to LogVWrite.

Cheers,
  Peter

> ---
>  os/log.c |   97 +++++++++++++++++++++++++++++--------------------------------
>  1 files changed, 46 insertions(+), 51 deletions(-)
> 
> diff --git a/os/log.c b/os/log.c
> index 36378e4..2c13c1a 100644
> --- a/os/log.c
> +++ b/os/log.c
> @@ -268,36 +268,19 @@ LogSetParameter(LogParameter param, int value)
>  }
>  
>  /* This function does the actual log message writes. */
> -
> -void
> -LogVWrite(int verb, const char *f, va_list args)
> +static void
> +LogSWrite(int verb, const char *buf, size_t len, Bool end_line)
>  {
> -    static char tmpBuffer[1024];
> -    int len = 0;
>      static Bool newline = TRUE;
>  
> -    if (verb > logFileVerbosity && verb > logVerbosity)
> -        return;
> -
> -    /*
> -     * Since a va_list can only be processed once, write the string to a
> -     * buffer, and then write the buffer out to the appropriate output
> -     * stream(s).
> -     */
> -    if (verb < 0 || logFileVerbosity >= verb || logVerbosity >= verb) {
> -        len = Xvscnprintf(tmpBuffer, sizeof(tmpBuffer), f, args);
> -        /* If message is truncated, terminate with '\n' */
> -        if (sizeof(tmpBuffer) - len == 1)
> -            tmpBuffer[len - 1] = '\n';
> -    }
> -    if ((verb < 0 || logVerbosity >= verb) && len > 0)
> -        fwrite(tmpBuffer, len, 1, stderr);
> -    if ((verb < 0 || logFileVerbosity >= verb) && len > 0) {
> +    if (verb < 0 || logVerbosity >= verb)
> +        fwrite(buf, len, 1, stderr);
> +    if (verb < 0 || logFileVerbosity >= verb) {
>          if (logFile) {
>              if (newline)
>                  fprintf(logFile, "[%10.3f] ", GetTimeInMillis() / 1000.0);
> -            newline = (tmpBuffer[len - 1] == '\n');
> -            fwrite(tmpBuffer, len, 1, logFile);
> +            newline = end_line;
> +            fwrite(buf, len, 1, logFile);
>              if (logFlush) {
>                  fflush(logFile);
>  #ifndef WIN32
> @@ -315,13 +298,19 @@ LogVWrite(int verb, const char *f, va_list args)
>                      FatalError("realloc() failed while saving log messages\n");
>              }
>              bufferUnused -= len;
> -            memcpy(saveBuffer + bufferPos, tmpBuffer, len);
> +            memcpy(saveBuffer + bufferPos, buf, len);
>              bufferPos += len;
>          }
>      }
>  }
>  
>  void
> +LogVWrite(int verb, const char *f, va_list args)
> +{
> +    return LogVMessageVerb(X_NONE, verb, f, args);
> +}
> +
> +void
>  LogWrite(int verb, const char *f, ...)
>  {
>      va_list args;
> @@ -376,22 +365,28 @@ void
>  LogVMessageVerb(MessageType type, int verb, const char *format, va_list args)
>  {
>      const char *type_str;
> -    char tmpFormat[1024];
> -    const char *new_format;
> +    char buf[1024];
> +    const size_t size = sizeof(buf);
> +    Bool newline;
> +    size_t len = 0;
>  
>      type_str = LogMessageTypeVerbString(type, verb);
>      if (!type_str)
>          return;
>  
> -    /* if type_str is not "", prepend it and ' ', to format */
> -    if (type_str[0] == '\0')
> -        new_format = format;
> -    else {
> -        new_format = tmpFormat;
> -        snprintf(tmpFormat, sizeof(tmpFormat), "%s %s", type_str, format);
> -    }
> +    /* if type_str is not "", prepend it and ' ', to message */
> +    if (type_str[0] != '\0')
> +        len += Xscnprintf(&buf[len], size - len, "%s ", type_str);
> +
> +    if (size - len > 1)
> +        len += Xvscnprintf(&buf[len], size - len, format, args);
> +
> +    /* Force '\n' at end of truncated line */
> +    if (size - len == 1)
> +        buf[len - 1] = '\n';
>  
> -    LogVWrite(verb, new_format, args);
> +    newline = (buf[len - 1] == '\n');
> +    LogSWrite(verb, buf, len, newline);
>  }
>  
>  /* Log message with verbosity level specified. */
> @@ -421,31 +416,31 @@ LogVHdrMessageVerb(MessageType type, int verb, const char *msg_format,
>                     va_list msg_args, const char *hdr_format, va_list hdr_args)
>  {
>      const char *type_str;
> -    char tmpFormat[1024];
> -    char *tmpFormat_end = &tmpFormat[sizeof(tmpFormat)];
> -    char *p;
> -    int left;
> +    char buf[1024];
> +    const size_t size = sizeof(buf);
> +    Bool newline;
> +    size_t len = 0;
>  
>      type_str = LogMessageTypeVerbString(type, verb);
>      if (!type_str)
>          return;
>  
> -    /* if type_str != "", copy it and ' ' to tmpFormat; set p after ' ' */
> -    p = tmpFormat;
> +    /* if type_str is not "", prepend it and ' ', to message */
>      if (type_str[0] != '\0')
> -        p += snprintf(tmpFormat, sizeof(tmpFormat), "%s ", type_str);
> +        len += Xscnprintf(&buf[len], size - len, "%s ", type_str);
> +
> +    if (hdr_format && size - len > 1)
> +        len += Xvscnprintf(&buf[len], size - len, hdr_format, hdr_args);
>  
> -    /* append as much of hdr as fits after type_str (if there was one) */
> -    left = tmpFormat_end - p;
> -    if (left > 1)
> -        p += vsnprintf(p, left, hdr_format, hdr_args);
> +    if (msg_format && size - len > 1)
> +        len += Xvscnprintf(&buf[len], size - len, msg_format, msg_args);
>  
> -    /* append as much of msg_format as will fit after hdr */
> -    left = tmpFormat_end - p;
> -    if (left > 1)
> -        snprintf(p, left, "%s", msg_format);
> +    /* Force '\n' at end of truncated line */
> +    if (size - len == 1)
> +        buf[len - 1] = '\n';
>  
> -    LogVWrite(verb, tmpFormat, msg_args);
> +    newline = (buf[len - 1] == '\n');
> +    LogSWrite(verb, buf, len, newline);
>  }
>  
>  void
> -- 
> 1.7.7.3
>