Skip to content

Commit

Permalink
Harden debug printf PID support (Issue #1066)
Browse files Browse the repository at this point in the history
  • Loading branch information
@michaelrsweet
michaelrsweet committed Nov 15, 2024
1 parent c1f6194 commit 0da38a5
Show file tree
Hide file tree
Showing 2 changed files with 103 additions and 126 deletions.
5 changes: 3 additions & 2 deletions CHANGES.md
View file
Original file line number Diff line number Diff line change
@@ -1,8 +1,8 @@
CHANGES - OpenPrinting CUPS 2.5b1 - (TBA)
==============================================

Changes in CUPS v2.5b1 (TBA)
----------------------------
Changes in CUPS v2.5b1 (YYYY-MM-DD)
-----------------------------------

- Added multiple language support for IPP Everywhere.
- Added `cupsConcatString`, `cupsCopyString`, and `cupsFormatString` string
Expand Down Expand Up @@ -114,6 +114,7 @@ Changes in CUPS v2.5b1 (TBA)
- Fixed sending response headers to client (Issue #927)
- Fixed `Host` header regression (Issue #967)
- Fixed DNS-SD lookups of local services with Avahi (Issue #970)
- Fixed debug printfs PID substitution support (Issue #1066)
- Fixed CGI program initialization and validation of form checkbox and text
fields.
- Fixed finishing support in ippeveps.
Expand Down
224 changes: 100 additions & 124 deletions cups/debug.c
View file
Original file line number Diff line number Diff line change
@@ -1,28 +1,24 @@
/*
* Debugging functions for CUPS.
*
* Copyright © 2020-2024 by OpenPrinting.
* Copyright © 2008-2018 by Apple Inc.
*
* Licensed under Apache License v2.0. See the file "LICENSE" for more
* information.
*/

/*
* Include necessary headers...
*/
//
// Debugging functions for CUPS.
//
// Copyright © 2020-2024 by OpenPrinting.
// Copyright © 2008-2018 by Apple Inc.
//
// Licensed under Apache License v2.0. See the file "LICENSE" for more
// information.
//

#include "cups-private.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 */
_cups_gettimeofday(struct timeval *tv, /* I - Timeval struct */
void *tz) /* I - Timezone */
int // O - 0 on success, -1 on failure
_cups_gettimeofday(struct timeval *tv, // I - Timeval struct
void *tz) // I - Timezone
{
struct _timeb timebuffer; /* Time buffer struct */
struct _timeb timebuffer; // Time buffer struct
_ftime(&timebuffer);
tv->tv_sec = (long)timebuffer.time;
tv->tv_usec = timebuffer.millitm * 1000;
Expand All @@ -31,79 +27,73 @@ _cups_gettimeofday(struct timeval *tv, /* I - Timeval struct */
#else
# include <sys/time.h>
# include <unistd.h>
#endif /* _WIN32 */
#endif // _WIN32
#include <regex.h>
#include <fcntl.h>


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

int _cups_debug_fd = -1;
/* Debug log file descriptor */
// Debug log file descriptor
int _cups_debug_level = 1;
/* Log level (0 to 9) */
// Log level (0 to 9)


/*
* Local globals...
*/
//
// Local globals...
//

static regex_t *debug_filter = NULL;
/* Filter expression for messages */
static int debug_init = 0; /* Did we initialize debugging? */
// Filter expression for messages
static int debug_init = 0; // Did we initialize debugging?
static cups_mutex_t debug_init_mutex = CUPS_MUTEX_INITIALIZER,
/* Mutex to control initialization */
// Mutex to control initialization
debug_log_mutex = CUPS_MUTEX_INITIALIZER;
/* Mutex to serialize log entries */
// Mutex to serialize log entries


/*
* 'debug_thread_id()' - Return an integer representing the current thread.
*/
//
// 'debug_thread_id()' - Return an integer representing the current thread.
//

static int /* O - Local thread ID */
static int // O - Local thread ID
debug_thread_id(void)
{
_cups_globals_t *cg = _cupsGlobals(); /* Global data */
_cups_globals_t *cg = _cupsGlobals(); // Global data


return (cg->thread_id);
}


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

void
_cups_debug_printf(const char *format, /* I - Printf-style format string */
...) /* I - Additional arguments as needed */
_cups_debug_printf(const char *format, // I - Printf-style format string
...) // I - Additional arguments as needed
{
int result = 0; /* Filter result */
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 */
int result = 0; // Filter result
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...
*/

// See if we need to do any logging...
if (!debug_init)
_cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"), getenv("CUPS_DEBUG_FILTER"), 0);

if (_cups_debug_fd < 0)
return;

/*
* Filter as needed...
*/

// Filter as needed...
if (isdigit(format[0]))
level = *format++ - '0';
else
Expand All @@ -120,15 +110,9 @@ _cups_debug_printf(const char *format, /* I - Printf-style format string */
if (result)
return;

/*
* Format the message...
*/

// Format the message...
gettimeofday(&curtime, NULL);
snprintf(buffer, sizeof(buffer), "T%03d %02d:%02d:%02d.%03d ",
debug_thread_id(), (int)((curtime.tv_sec / 3600) % 24),
(int)((curtime.tv_sec / 60) % 60),
(int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000));
snprintf(buffer, sizeof(buffer), "T%03d %02d:%02d:%02d.%03d ", debug_thread_id(), (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 = cupsFormatStringv(buffer + 19, sizeof(buffer) - 20, format, ap) + 19;
Expand All @@ -145,44 +129,35 @@ _cups_debug_printf(const char *format, /* I - Printf-style format string */
buffer[bytes] = '\0';
}

/*
* Write it out...
*/

// Write it out...
cupsMutexLock(&debug_log_mutex);
write(_cups_debug_fd, buffer, (size_t)bytes);
cupsMutexUnlock(&debug_log_mutex);
}


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

void
_cups_debug_puts(const char *s) /* I - String to output */
_cups_debug_puts(const char *s) // I - String to output
{
int result = 0; /* Filter result */
struct timeval curtime; /* Current time */
char buffer[2048]; /* Output buffer */
ssize_t bytes; /* Number of bytes in buffer */
int level; /* Log level in message */
int result = 0; // Filter result
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...
*/

// See if we need to do any logging...
if (!debug_init)
_cups_debug_set(getenv("CUPS_DEBUG_LOG"), getenv("CUPS_DEBUG_LEVEL"), getenv("CUPS_DEBUG_FILTER"), 0);

if (_cups_debug_fd < 0)
return;

/*
* Filter as needed...
*/

// Filter as needed...
if (isdigit(s[0]))
level = *s++ - '0';
else
Expand All @@ -199,16 +174,9 @@ _cups_debug_puts(const char *s) /* I - String to output */
if (result)
return;

/*
* Format the message...
*/

// Format the message...
gettimeofday(&curtime, NULL);
bytes = snprintf(buffer, sizeof(buffer), "T%03d %02d:%02d:%02d.%03d %s",
debug_thread_id(), (int)((curtime.tv_sec / 3600) % 24),
(int)((curtime.tv_sec / 60) % 60),
(int)(curtime.tv_sec % 60), (int)(curtime.tv_usec / 1000),
s);
bytes = snprintf(buffer, sizeof(buffer), "T%03d %02d:%02d:%02d.%03d %s", debug_thread_id(), (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))
{
Expand All @@ -221,34 +189,28 @@ _cups_debug_puts(const char *s) /* I - String to output */
buffer[bytes] = '\0';
}

/*
* Write it out...
*/

// Write it out...
cupsMutexLock(&debug_log_mutex);
write(_cups_debug_fd, buffer, (size_t)bytes);
cupsMutexUnlock(&debug_log_mutex);
}


/*
* '_cups_debug_set()' - Enable or disable debug logging.
*/
//
// '_cups_debug_set()' - Enable or disable debug logging.
//

void
_cups_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 */
_cups_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
{
cupsMutexLock(&debug_init_mutex);

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

// Restore debug settings to defaults...
if (_cups_debug_fd != -1)
{
close(_cups_debug_fd);
Expand All @@ -263,24 +225,38 @@ _cups_debug_set(const char *logfile, /* I - Log file or NULL */

_cups_debug_level = 1;

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

// Open logs, set log levels, etc.
if (!logfile)
{
_cups_debug_fd = -1;
}
else if (!strcmp(logfile, "-"))
{
_cups_debug_fd = 2;
}
else
{
char buffer[1024]; /* Filename buffer */
char filename[1024], // Filename buffer
*fileptr; // Pointer into filename buffer
const char *pidptr; // Pointer to "%d", if any
size_t pidoffset; // Offset to "%d"...

snprintf(buffer, sizeof(buffer), logfile, getpid());
if ((pidptr = strstr(logfile, "%d")) != NULL && (pidoffset = (size_t)(pidptr - logfile)) < (sizeof(filename) - 10 - strlen(pidptr)))
{
// Substitute process ID in filename string...
memcpy(filename, logfile, pidoffset);
fileptr = filename + pidoffset;
snprintf(fileptr, sizeof(filename) - (size_t)(fileptr - filename), "%d", (int)getpid());
fileptr += strlen(fileptr);
cupsCopyString(fileptr, pidptr + 2, sizeof(filename) - (size_t)(fileptr - filename));

logfile = filename;
}

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

if (level)
Expand Down Expand Up @@ -308,19 +284,19 @@ _cups_debug_set(const char *logfile, /* I - Log file or NULL */


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

void
_cups_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 */
_cups_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 */
#endif // DEBUG

0 comments on commit 0da38a5

Please sign in to comment.