log: Don't prefix message with timestamp on --debug if it's a continuation

If we prefix the second part of messages printed through
logmsg_perror() by the timestamp, on debug, we'll have two timestamps
and a weird separator in the result, such as this beauty:

  0.0013: Failed to clone process with detached namespaces0.0013: : Operation not permitted

Add a parameter to logmsg() and vlogmsg() which indicates a message
continuation. If that's set, don't print the timestamp in vlogmsg().

Link: https://github.com/moby/moby/issues/48257#issuecomment-2282875092
Signed-off-by: Stefano Brivio <sbrivio@redhat.com>
Reviewed-by: David Gibson <david@gibson.dropbear.id.au>
This commit is contained in:
Stefano Brivio 2024-08-12 10:20:34 +02:00
parent baccfb95ce
commit fecb1b65b1
3 changed files with 21 additions and 18 deletions

3
flow.c
View file

@ -279,7 +279,8 @@ void flow_log_(const struct flow_common *f, int pri, const char *fmt, ...)
else else
type_or_state = FLOW_TYPE(f); type_or_state = FLOW_TYPE(f);
logmsg(true, pri, "Flow %u (%s): %s", flow_idx(f), type_or_state, msg); logmsg(true, false, pri,
"Flow %u (%s): %s", flow_idx(f), type_or_state, msg);
} }
/** /**

14
log.c
View file

@ -253,11 +253,12 @@ static void logfile_write(bool newline, int pri, const struct timespec *now,
/** /**
* vlogmsg() - Print or send messages to log or output files as configured * vlogmsg() - Print or send messages to log or output files as configured
* @newline: Append newline at the end of the message, if missing * @newline: Append newline at the end of the message, if missing
* @cont: Continuation of a previous message, on the same line
* @pri: Facility and level map, same as priority for vsyslog() * @pri: Facility and level map, same as priority for vsyslog()
* @format: Message * @format: Message
* @ap: Variable argument list * @ap: Variable argument list
*/ */
void vlogmsg(bool newline, int pri, const char *format, va_list ap) void vlogmsg(bool newline, bool cont, int pri, const char *format, va_list ap)
{ {
bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1; bool debug_print = (log_mask & LOG_MASK(LOG_DEBUG)) && log_file == -1;
const struct timespec *now; const struct timespec *now;
@ -265,7 +266,7 @@ void vlogmsg(bool newline, int pri, const char *format, va_list ap)
now = logtime(&ts); now = logtime(&ts);
if (debug_print) { if (debug_print && !cont) {
char timestr[LOGTIME_STRLEN]; char timestr[LOGTIME_STRLEN];
logtime_fmt(timestr, sizeof(timestr), now); logtime_fmt(timestr, sizeof(timestr), now);
@ -295,15 +296,16 @@ void vlogmsg(bool newline, int pri, const char *format, va_list ap)
/** /**
* logmsg() - vlogmsg() wrapper for variable argument lists * logmsg() - vlogmsg() wrapper for variable argument lists
* @newline: Append newline at the end of the message, if missing * @newline: Append newline at the end of the message, if missing
* @cont: Continuation of a previous message, on the same line
* @pri: Facility and level map, same as priority for vsyslog() * @pri: Facility and level map, same as priority for vsyslog()
* @format: Message * @format: Message
*/ */
void logmsg(bool newline, int pri, const char *format, ...) void logmsg(bool newline, bool cont, int pri, const char *format, ...)
{ {
va_list ap; va_list ap;
va_start(ap, format); va_start(ap, format);
vlogmsg(newline, pri, format, ap); vlogmsg(newline, cont, pri, format, ap);
va_end(ap); va_end(ap);
} }
@ -318,10 +320,10 @@ void logmsg_perror(int pri, const char *format, ...)
va_list ap; va_list ap;
va_start(ap, format); va_start(ap, format);
vlogmsg(false, pri, format, ap); vlogmsg(false, false, pri, format, ap);
va_end(ap); va_end(ap);
logmsg(true, pri, ": %s", strerror(errno_copy)); logmsg(true, true, pri, ": %s", strerror(errno_copy));
} }
/** /**

22
log.h
View file

@ -13,21 +13,21 @@
#define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */ #define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
#define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE)) #define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE))
void vlogmsg(bool newline, int pri, const char *format, va_list ap); void vlogmsg(bool newline, bool cont, int pri, const char *format, va_list ap);
void logmsg(bool newline, int pri, const char *format, ...) void logmsg(bool newline, bool cont, int pri, const char *format, ...)
__attribute__((format(printf, 3, 4))); __attribute__((format(printf, 4, 5)));
void logmsg_perror(int pri, const char *format, ...) void logmsg_perror(int pri, const char *format, ...)
__attribute__((format(printf, 2, 3))); __attribute__((format(printf, 2, 3)));
#define err(...) logmsg(true, LOG_ERR, __VA_ARGS__) #define err(...) logmsg(true, false, LOG_ERR, __VA_ARGS__)
#define warn(...) logmsg(true, LOG_WARNING, __VA_ARGS__) #define warn(...) logmsg(true, false, LOG_WARNING, __VA_ARGS__)
#define info(...) logmsg(true, LOG_INFO, __VA_ARGS__) #define info(...) logmsg(true, false, LOG_INFO, __VA_ARGS__)
#define debug(...) logmsg(true, LOG_DEBUG, __VA_ARGS__) #define debug(...) logmsg(true, false, LOG_DEBUG, __VA_ARGS__)
#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__) #define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__) #define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__) #define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__) #define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
#define die(...) \ #define die(...) \
do { \ do { \