* [PATCH] log: Don't prefix message with timestamp on --debug if it's a continuation
@ 2024-08-12 8:24 Stefano Brivio
2024-08-12 9:49 ` David Gibson
0 siblings, 1 reply; 2+ messages in thread
From: Stefano Brivio @ 2024-08-12 8:24 UTC (permalink / raw)
To: passt-dev
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>
---
flow.c | 3 ++-
log.c | 14 ++++++++------
log.h | 22 +++++++++++-----------
3 files changed, 21 insertions(+), 18 deletions(-)
diff --git a/flow.c b/flow.c
index bd5fa2b..687e9fd 100644
--- a/flow.c
+++ b/flow.c
@@ -279,7 +279,8 @@ void flow_log_(const struct flow_common *f, int pri, const char *fmt, ...)
else
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);
}
/**
diff --git a/log.c b/log.c
index 0c377cc..e7202d0 100644
--- a/log.c
+++ b/log.c
@@ -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
* @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()
* @format: Message
* @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;
const struct timespec *now;
@@ -265,7 +266,7 @@ void vlogmsg(bool newline, int pri, const char *format, va_list ap)
now = logtime(&ts);
- if (debug_print) {
+ if (debug_print && !cont) {
char timestr[LOGTIME_STRLEN];
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
* @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()
* @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_start(ap, format);
- vlogmsg(newline, pri, format, ap);
+ vlogmsg(newline, cont, pri, format, ap);
va_end(ap);
}
@@ -318,10 +320,10 @@ void logmsg_perror(int pri, const char *format, ...)
va_list ap;
va_start(ap, format);
- vlogmsg(false, pri, format, ap);
+ vlogmsg(false, false, pri, format, ap);
va_end(ap);
- logmsg(true, pri, ": %s", strerror(errno_copy));
+ logmsg(true, true, pri, ": %s", strerror(errno_copy));
}
/**
diff --git a/log.h b/log.h
index ba17f79..a30b091 100644
--- a/log.h
+++ b/log.h
@@ -13,21 +13,21 @@
#define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
#define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE))
-void vlogmsg(bool newline, int pri, const char *format, va_list ap);
-void logmsg(bool newline, int pri, const char *format, ...)
- __attribute__((format(printf, 3, 4)));
+void vlogmsg(bool newline, bool cont, int pri, const char *format, va_list ap);
+void logmsg(bool newline, bool cont, int pri, const char *format, ...)
+ __attribute__((format(printf, 4, 5)));
void logmsg_perror(int pri, const char *format, ...)
__attribute__((format(printf, 2, 3)));
-#define err(...) logmsg(true, LOG_ERR, __VA_ARGS__)
-#define warn(...) logmsg(true, LOG_WARNING, __VA_ARGS__)
-#define info(...) logmsg(true, LOG_INFO, __VA_ARGS__)
-#define debug(...) logmsg(true, LOG_DEBUG, __VA_ARGS__)
+#define err(...) logmsg(true, false, LOG_ERR, __VA_ARGS__)
+#define warn(...) logmsg(true, false, LOG_WARNING, __VA_ARGS__)
+#define info(...) logmsg(true, false, LOG_INFO, __VA_ARGS__)
+#define debug(...) logmsg(true, false, LOG_DEBUG, __VA_ARGS__)
-#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
-#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
-#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
-#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
+#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
+#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
+#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
+#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
#define die(...) \
do { \
--
@@ -13,21 +13,21 @@
#define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
#define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE))
-void vlogmsg(bool newline, int pri, const char *format, va_list ap);
-void logmsg(bool newline, int pri, const char *format, ...)
- __attribute__((format(printf, 3, 4)));
+void vlogmsg(bool newline, bool cont, int pri, const char *format, va_list ap);
+void logmsg(bool newline, bool cont, int pri, const char *format, ...)
+ __attribute__((format(printf, 4, 5)));
void logmsg_perror(int pri, const char *format, ...)
__attribute__((format(printf, 2, 3)));
-#define err(...) logmsg(true, LOG_ERR, __VA_ARGS__)
-#define warn(...) logmsg(true, LOG_WARNING, __VA_ARGS__)
-#define info(...) logmsg(true, LOG_INFO, __VA_ARGS__)
-#define debug(...) logmsg(true, LOG_DEBUG, __VA_ARGS__)
+#define err(...) logmsg(true, false, LOG_ERR, __VA_ARGS__)
+#define warn(...) logmsg(true, false, LOG_WARNING, __VA_ARGS__)
+#define info(...) logmsg(true, false, LOG_INFO, __VA_ARGS__)
+#define debug(...) logmsg(true, false, LOG_DEBUG, __VA_ARGS__)
-#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
-#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
-#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
-#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
+#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
+#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
+#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
+#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
#define die(...) \
do { \
--
2.43.0
^ permalink raw reply related [flat|nested] 2+ messages in thread* Re: [PATCH] log: Don't prefix message with timestamp on --debug if it's a continuation
2024-08-12 8:24 [PATCH] log: Don't prefix message with timestamp on --debug if it's a continuation Stefano Brivio
@ 2024-08-12 9:49 ` David Gibson
0 siblings, 0 replies; 2+ messages in thread
From: David Gibson @ 2024-08-12 9:49 UTC (permalink / raw)
To: Stefano Brivio; +Cc: passt-dev
[-- Attachment #1: Type: text/plain, Size: 5548 bytes --]
On Mon, Aug 12, 2024 at 10:24:58AM +0200, Stefano Brivio wrote:
> 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>
> ---
> flow.c | 3 ++-
> log.c | 14 ++++++++------
> log.h | 22 +++++++++++-----------
> 3 files changed, 21 insertions(+), 18 deletions(-)
>
> diff --git a/flow.c b/flow.c
> index bd5fa2b..687e9fd 100644
> --- a/flow.c
> +++ b/flow.c
> @@ -279,7 +279,8 @@ void flow_log_(const struct flow_common *f, int pri, const char *fmt, ...)
> else
> 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);
> }
>
> /**
> diff --git a/log.c b/log.c
> index 0c377cc..e7202d0 100644
> --- a/log.c
> +++ b/log.c
> @@ -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
> * @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()
> * @format: Message
> * @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;
> const struct timespec *now;
> @@ -265,7 +266,7 @@ void vlogmsg(bool newline, int pri, const char *format, va_list ap)
>
> now = logtime(&ts);
>
> - if (debug_print) {
> + if (debug_print && !cont) {
> char timestr[LOGTIME_STRLEN];
>
> 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
> * @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()
> * @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_start(ap, format);
> - vlogmsg(newline, pri, format, ap);
> + vlogmsg(newline, cont, pri, format, ap);
> va_end(ap);
> }
>
> @@ -318,10 +320,10 @@ void logmsg_perror(int pri, const char *format, ...)
> va_list ap;
>
> va_start(ap, format);
> - vlogmsg(false, pri, format, ap);
> + vlogmsg(false, false, pri, format, ap);
> va_end(ap);
>
> - logmsg(true, pri, ": %s", strerror(errno_copy));
> + logmsg(true, true, pri, ": %s", strerror(errno_copy));
> }
>
> /**
> diff --git a/log.h b/log.h
> index ba17f79..a30b091 100644
> --- a/log.h
> +++ b/log.h
> @@ -13,21 +13,21 @@
> #define LOGFILE_CUT_RATIO 30 /* When full, cut ~30% size */
> #define LOGFILE_SIZE_MIN (5UL * MAX(BUFSIZ, PAGE_SIZE))
>
> -void vlogmsg(bool newline, int pri, const char *format, va_list ap);
> -void logmsg(bool newline, int pri, const char *format, ...)
> - __attribute__((format(printf, 3, 4)));
> +void vlogmsg(bool newline, bool cont, int pri, const char *format, va_list ap);
> +void logmsg(bool newline, bool cont, int pri, const char *format, ...)
> + __attribute__((format(printf, 4, 5)));
> void logmsg_perror(int pri, const char *format, ...)
> __attribute__((format(printf, 2, 3)));
>
> -#define err(...) logmsg(true, LOG_ERR, __VA_ARGS__)
> -#define warn(...) logmsg(true, LOG_WARNING, __VA_ARGS__)
> -#define info(...) logmsg(true, LOG_INFO, __VA_ARGS__)
> -#define debug(...) logmsg(true, LOG_DEBUG, __VA_ARGS__)
> +#define err(...) logmsg(true, false, LOG_ERR, __VA_ARGS__)
> +#define warn(...) logmsg(true, false, LOG_WARNING, __VA_ARGS__)
> +#define info(...) logmsg(true, false, LOG_INFO, __VA_ARGS__)
> +#define debug(...) logmsg(true, false, LOG_DEBUG, __VA_ARGS__)
>
> -#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
> -#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
> -#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
> -#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
> +#define err_perror(...) logmsg_perror( LOG_ERR, __VA_ARGS__)
> +#define warn_perror(...) logmsg_perror( LOG_WARNING, __VA_ARGS__)
> +#define info_perror(...) logmsg_perror( LOG_INFO, __VA_ARGS__)
> +#define debug_perror(...) logmsg_perror( LOG_DEBUG, __VA_ARGS__)
>
> #define die(...) \
> do { \
--
David Gibson (he or they) | I'll have my music baroque, and my code
david AT gibson.dropbear.id.au | minimalist, thank you, not the other way
| around.
http://www.ozlabs.org/~dgibson
[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 833 bytes --]
^ permalink raw reply [flat|nested] 2+ messages in thread
end of thread, other threads:[~2024-08-12 9:50 UTC | newest]
Thread overview: 2+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2024-08-12 8:24 [PATCH] log: Don't prefix message with timestamp on --debug if it's a continuation Stefano Brivio
2024-08-12 9:49 ` David Gibson
Code repositories for project(s) associated with this public inbox
https://passt.top/passt
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for IMAP folder(s).