ppd/debug.c

//
// Debugging functions for libppd.
//
// Copyright © 2008-2018 by Apple Inc.
//
// Licensed under Apache License v2.0.  See the file "LICENSE" for more
// information.
//

//
// Include necessary headers...
//

#include <ppd/string-private.h>
#include <ppd/debug-internal.h>
#ifdef _WIN32
#  include <sys/timeb.h>
#  include <time.h>
#  include <io.h>
#  define getpid (int)GetCurrentProcessId
int					// O  - 0 on success, -1 on failure
_ppd_gettimeofday(struct timeval *tv,	// I  - Timeval struct
		  void		  *tz)	// I  - Timezone
{
  struct _timeb timebuffer;		// Time buffer struct
  _ftime(&timebuffer);
  tv->tv_sec  = (long)timebuffer.time;
  tv->tv_usec = timebuffer.millitm * 1000;
  return 0;
}
#else
#  include <sys/time.h>
#  include <unistd.h>
#endif // _WIN32
#include <regex.h>
#include <fcntl.h>


#ifdef DEBUG
//
// Globals...
//

int			_ppd_debug_fd = -1;
					// Debug log file descriptor
int			_ppd_debug_level = 1;
					// Log level (0 to 9)


//
// Local globals...
//

static regex_t		*debug_filter = NULL;
					// Filter expression for messages
static int		debug_init = 0;	// Did we initialize debugging?


//
// '_ppd_debug_printf()' - Write a formatted line to the log.
//

void
_ppd_debug_printf(const char *format,	// I - Printf-style format string
		  ...)			// I - Additional arguments as needed
{
  va_list		ap;		// Pointer to arguments
  struct timeval	curtime;	// Current time
  char			buffer[2048];	// Output buffer
  ssize_t		bytes;		// Number of bytes in buffer
  int			level;		// Log level in message


  //
  // See if we need to do any logging...
  //

  if (!debug_init)
    _ppd_debug_set(getenv("PPD_DEBUG_LOG"), getenv("PPD_DEBUG_LEVEL"),
                    getenv("PPD_DEBUG_FILTER"), 0);

  if (_ppd_debug_fd < 0)
    return;

  //
  // Filter as needed...
  //

  if (isdigit(format[0]))
    level = *format++ - '0';
  else
    level = 0;

  if (level > _ppd_debug_level)
    return;

  if (debug_filter)
  {
    int	result;				// Filter result

    result = regexec(debug_filter, format, 0, NULL, 0);

    if (result)
      return;
  }

  //
  // Format the message...
  //

  gettimeofday(&curtime, NULL);
  snprintf(buffer, sizeof(buffer), "%02d:%02d:%02d.%03d  ",
           (int)((curtime.tv_sec / 3600) % 24),
	   (int)((curtime.tv_sec / 60) % 60),
	   (int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000));

  va_start(ap, format);
  bytes = _ppd_safe_vsnprintf(buffer + 19, sizeof(buffer) - 20, format, ap) +
    19;
  va_end(ap);

  if ((size_t)bytes >= (sizeof(buffer) - 1))
  {
    buffer[sizeof(buffer) - 2] = '\n';
    bytes = sizeof(buffer) - 1;
  }
  else if (buffer[bytes - 1] != '\n')
  {
    buffer[bytes++] = '\n';
    buffer[bytes]   = '\0';
  }

  //
  // Write it out...
  //

  write(_ppd_debug_fd, buffer, (size_t)bytes);
}


//
// '_ppd_debug_puts()' - Write a single line to the log.
//

void
_ppd_debug_puts(const char *s)		// I - String to output
{
  struct timeval	curtime;	// Current time
  char			buffer[2048];	// Output buffer
  ssize_t		bytes;		// Number of bytes in buffer
  int			level;		// Log level in message


  //
  // See if we need to do any logging...
  //

  if (!debug_init)
    _ppd_debug_set(getenv("PPD_DEBUG_LOG"), getenv("PPD_DEBUG_LEVEL"),
                    getenv("PPD_DEBUG_FILTER"), 0);

  if (_ppd_debug_fd < 0)
    return;

  //
  // Filter as needed...
  //

  if (isdigit(s[0]))
    level = *s++ - '0';
  else
    level = 0;

  if (level > _ppd_debug_level)
    return;

  if (debug_filter)
  {
    int	result;				// Filter result

    result = regexec(debug_filter, s, 0, NULL, 0);

    if (result)
      return;
  }

  //
  // Format the message...
  //

  gettimeofday(&curtime, NULL);
  bytes = snprintf(buffer, sizeof(buffer), "%02d:%02d:%02d.%03d  %s",
                   (int)((curtime.tv_sec / 3600) % 24),
		   (int)((curtime.tv_sec / 60) % 60),
		   (int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000),
		   s);

  if ((size_t)bytes >= (sizeof(buffer) - 1))
  {
    buffer[sizeof(buffer) - 2] = '\n';
    bytes = sizeof(buffer) - 1;
  }
  else if (buffer[bytes - 1] != '\n')
  {
    buffer[bytes++] = '\n';
    buffer[bytes]   = '\0';
  }

  //
  // Write it out...
  //

  write(_ppd_debug_fd, buffer, (size_t)bytes);
}


//
// '_ppd_debug_set()' - Enable or disable debug logging.
//

void
_ppd_debug_set(const char *logfile,	// I - Log file or NULL
	       const char *level,	// I - Log level or NULL
	       const char *filter,	// I - Filter string or NULL
	       int        force)	// I - Force initialization
{

  if (!debug_init || force)
  {
    //
    // Restore debug settings to defaults...
    //

    if (_ppd_debug_fd != -1)
    {
      close(_ppd_debug_fd);
      _ppd_debug_fd = -1;
    }

    if (debug_filter)
    {
      regfree((regex_t *)debug_filter);
      debug_filter = NULL;
    }

    _ppd_debug_level = 1;

    //
    // Open logs, set log levels, etc.
    //

    if (!logfile)
      _ppd_debug_fd = -1;
    else if (!strcmp(logfile, "-"))
      _ppd_debug_fd = 2;
    else
    {
      char	buffer[1024];		// Filename buffer

      snprintf(buffer, sizeof(buffer), "%s-%d", logfile, (int)getpid());

      if (buffer[0] == '+')
	_ppd_debug_fd = open(buffer + 1, O_WRONLY | O_APPEND | O_CREAT, 0644);
      else
	_ppd_debug_fd = open(buffer, O_WRONLY | O_TRUNC | O_CREAT, 0644);
    }

    if (level)
      _ppd_debug_level = atoi(level);

    if (filter)
    {
      if ((debug_filter = (regex_t *)calloc(1, sizeof(regex_t))) == NULL)
	fputs("Unable to allocate memory for PPD_DEBUG_FILTER - results not "
	      "filtered!\n", stderr);
      else if (regcomp(debug_filter, filter, REG_EXTENDED))
      {
	fputs("Bad regular expression in PPD_DEBUG_FILTER - results not "
	      "filtered!\n", stderr);
	free(debug_filter);
	debug_filter = NULL;
      }
    }

    debug_init = 1;
  }
}


#else
//
// '_ppd_debug_set()' - Enable or disable debug logging.
//

void
_ppd_debug_set(const char *logfile,	// I - Log file or NULL
	       const char *level,	// I - Log level or NULL
	       const char *filter,	// I - Filter string or NULL
	       int        force)	// I - Force initialization
{
  (void)logfile;
  (void)level;
  (void)filter;
  (void)force;
}
#endif // DEBUG


//
// '_ppd_safe_vsnprintf()' - Format a string into a fixed size buffer,
//                           quoting special characters.
//

ssize_t					// O - Number of bytes formatted
_ppd_safe_vsnprintf(
    char       *buffer,			// O - Output buffer
    size_t     bufsize,			// O - Size of output buffer
    const char *format,			// I - printf-style format string
    va_list    ap)			// I - Pointer to additional arguments
{
  char		*bufptr,		// Pointer to position in buffer
		*bufend,		// Pointer to end of buffer
		size,			// Size character (h, l, L)
		type;			// Format type character
  int		width,			// Width of field
		prec;			// Number of characters of precision
  char		tformat[100],		// Temporary format string for snprintf()
		*tptr,			// Pointer into temporary format
		temp[1024];		// Buffer for formatted numbers
  char		*s;			// Pointer to string
  ssize_t	bytes;			// Total number of bytes needed


  if (!buffer || bufsize < 2 || !format)
    return (-1);

  //
  // Loop through the format string, formatting as needed...
  //

  bufptr = buffer;
  bufend = buffer + bufsize - 1;
  bytes  = 0;

  while (*format)
  {
    if (*format == '%')
    {
      tptr = tformat;
      *tptr++ = *format++;

      if (*format == '%')
      {
        if (bufptr < bufend)
	  *bufptr++ = *format;
        bytes ++;
        format ++;
	continue;
      }
      else if (strchr(" -+#\'", *format))
        *tptr++ = *format++;

      if (*format == '*')
      {
	//
        // Get width from argument...
	//

	format ++;
	width = va_arg(ap, int);

	snprintf(tptr, sizeof(tformat) - (size_t)(tptr - tformat), "%d", width);
	tptr += strlen(tptr);
      }
      else
      {
	width = 0;

	while (isdigit(*format & 255))
	{
	  if (tptr < (tformat + sizeof(tformat) - 1))
	    *tptr++ = *format;

	  width = width * 10 + *format++ - '0';
	}
      }

      if (*format == '.')
      {
	if (tptr < (tformat + sizeof(tformat) - 1))
	  *tptr++ = *format;

        format ++;

        if (*format == '*')
	{
	  //
	  // Get precision from argument...
	  // 

	  format ++;
	  prec = va_arg(ap, int);

	  snprintf(tptr, sizeof(tformat) - (size_t)(tptr - tformat), "%d", prec);
	  tptr += strlen(tptr);
	}
	else
	{
	  prec = 0;

	  while (isdigit(*format & 255))
	  {
	    if (tptr < (tformat + sizeof(tformat) - 1))
	      *tptr++ = *format;

	    prec = prec * 10 + *format++ - '0';
	  }
	}
      }

      if (*format == 'l' && format[1] == 'l')
      {
        size = 'L';

	if (tptr < (tformat + sizeof(tformat) - 2))
	{
	  *tptr++ = 'l';
	  *tptr++ = 'l';
	}

	format += 2;
      }
      else if (*format == 'h' || *format == 'l' || *format == 'L')
      {
	if (tptr < (tformat + sizeof(tformat) - 1))
	  *tptr++ = *format;

        size = *format++;
      }
      else
        size = 0;

      if (!*format)
        break;

      if (tptr < (tformat + sizeof(tformat) - 1))
        *tptr++ = *format;

      type  = *format++;
      *tptr = '\0';

      switch (type)
      {
	case 'E' : // Floating point formats
	case 'G' :
	case 'e' :
	case 'f' :
	case 'g' :
	    if ((size_t)(width + 2) > sizeof(temp))
	      break;

	    snprintf(temp, sizeof(temp), tformat, va_arg(ap, double));

            bytes += (int)strlen(temp);

            if (bufptr)
	    {
	      strlcpy(bufptr, temp, (size_t)(bufend - bufptr));
	      bufptr += strlen(bufptr);
	    }
	    break;

        case 'B' : // Integer formats
	case 'X' :
	case 'b' :
        case 'd' :
	case 'i' :
	case 'o' :
	case 'u' :
	case 'x' :
	    if ((size_t)(width + 2) > sizeof(temp))
	      break;

#  ifdef HAVE_LONG_LONG
            if (size == 'L')
	      snprintf(temp, sizeof(temp), tformat, va_arg(ap, long long));
	    else
#  endif // HAVE_LONG_LONG
            if (size == 'l')
	      snprintf(temp, sizeof(temp), tformat, va_arg(ap, long));
	    else
	      snprintf(temp, sizeof(temp), tformat, va_arg(ap, int));

            bytes += (int)strlen(temp);

	    if (bufptr)
	    {
	      strlcpy(bufptr, temp, (size_t)(bufend - bufptr));
	      bufptr += strlen(bufptr);
	    }
	    break;

	case 'p' : // Pointer value
	    if ((size_t)(width + 2) > sizeof(temp))
	      break;

	    snprintf(temp, sizeof(temp), tformat, va_arg(ap, void *));

            bytes += (int)strlen(temp);

	    if (bufptr)
	    {
	      strlcpy(bufptr, temp, (size_t)(bufend - bufptr));
	      bufptr += strlen(bufptr);
	    }
	    break;

        case 'c' : // Character or character array
	    bytes += width;

	    if (bufptr)
	    {
	      if (width <= 1)
	        *bufptr++ = (char)va_arg(ap, int);
	      else
	      {
		if ((bufptr + width) > bufend)
		  width = (int)(bufend - bufptr);

		memcpy(bufptr, va_arg(ap, char *), (size_t)width);
		bufptr += width;
	      }
	    }
	    break;

	case 's' : // String
	    if ((s = va_arg(ap, char *)) == NULL)
	      s = "(null)";

	    //
	    // Copy the C string, replacing control chars and \ with
	    // C character escapes...
	    //

            for (bufend --; *s && bufptr < bufend; s ++)
	    {
	      if (*s == '\n')
	      {
	        *bufptr++ = '\\';
		*bufptr++ = 'n';
		bytes += 2;
	      }
	      else if (*s == '\r')
	      {
	        *bufptr++ = '\\';
		*bufptr++ = 'r';
		bytes += 2;
	      }
	      else if (*s == '\t')
	      {
	        *bufptr++ = '\\';
		*bufptr++ = 't';
		bytes += 2;
	      }
	      else if (*s == '\\')
	      {
	        *bufptr++ = '\\';
		*bufptr++ = '\\';
		bytes += 2;
	      }
	      else if (*s == '\'')
	      {
	        *bufptr++ = '\\';
		*bufptr++ = '\'';
		bytes += 2;
	      }
	      else if (*s == '\"')
	      {
	        *bufptr++ = '\\';
		*bufptr++ = '\"';
		bytes += 2;
	      }
	      else if ((*s & 255) < ' ')
	      {
	        if ((bufptr + 2) >= bufend)
	          break;

	        *bufptr++ = '\\';
		*bufptr++ = '0';
		*bufptr++ = '0' + *s / 8;
		*bufptr++ = '0' + (*s & 7);
		bytes += 4;
	      }
	      else
	      {
	        *bufptr++ = *s;
		bytes ++;
	      }
            }

            bufend ++;
	    break;

	case 'n' : // Output number of chars so far
	    *(va_arg(ap, int *)) = (int)bytes;
	    break;
      }
    }
    else
    {
      bytes ++;

      if (bufptr < bufend)
        *bufptr++ = *format;

      format ++;
    }
  }

  //
  // Nul-terminate the string and return the number of characters needed.
  //

  *bufptr = '\0';

  return (bytes);
}