From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from mail.ozlabs.org (gandalf.ozlabs.org [150.107.74.76]) by passt.top (Postfix) with ESMTPS id A459C5A004E for ; Mon, 12 Aug 2024 11:50:07 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gibson.dropbear.id.au; s=202312; t=1723456191; bh=zlZmrRswHFZ+98rO/V1FL5RS3kKmV5+mUz+3Ohq+sqc=; h=Date:From:To:Cc:Subject:References:In-Reply-To:From; b=YNFGyjVVf7GY8YNutqDgXUzr20houAk2EV/wRvtwfe/H8tcE9tzyhfQycoVAuecmt reH2Um7GRg2VYnR4sNo6UCR4WCf0+R7p/WH3yfkdmq008NTFd2nwnqOW6w0YtgAAyB YdpX9rK2zaBXcR5H/5i0o0XO+DEDqvTaWDaGukTM3phlek85xxAT/pGO1LuQPE6gtu waxIesSGfAvu/X6L+V1jZ141ImxtU88D7M4OmYF3FB3peFPXyznafR3V30Vh4LveLq xLuwL24hiT2xTBCkZ19Yu8+LiROOyppYd2TrfsVwippvmYCH68BCHVm5fdakbH0BRX RfXAbeNDq+q6g== Received: by gandalf.ozlabs.org (Postfix, from userid 1007) id 4Wj8rH1VW1z4x8r; Mon, 12 Aug 2024 19:49:51 +1000 (AEST) Date: Mon, 12 Aug 2024 19:49:41 +1000 From: David Gibson To: Stefano Brivio Subject: Re: [PATCH] log: Don't prefix message with timestamp on --debug if it's a continuation Message-ID: References: <20240812082458.2504291-1-sbrivio@redhat.com> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha256; protocol="application/pgp-signature"; boundary="Xw9hbP7RO4LWZJW8" Content-Disposition: inline In-Reply-To: <20240812082458.2504291-1-sbrivio@redhat.com> Message-ID-Hash: MOOR37PM7JKAITE2IXAT53L2OPZ6CPH4 X-Message-ID-Hash: MOOR37PM7JKAITE2IXAT53L2OPZ6CPH4 X-MailFrom: dgibson@gandalf.ozlabs.org X-Mailman-Rule-Misses: dmarc-mitigation; no-senders; approved; emergency; loop; banned-address; member-moderation; nonmember-moderation; administrivia; implicit-dest; max-recipients; max-size; news-moderation; no-subject; digests; suspicious-header CC: passt-dev@passt.top X-Mailman-Version: 3.3.8 Precedence: list List-Id: Development discussion and patches for passt Archived-At: Archived-At: List-Archive: List-Archive: List-Help: List-Owner: List-Post: List-Subscribe: List-Unsubscribe: --Xw9hbP7RO4LWZJW8 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable 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: >=20 > 0.0013: Failed to clone process with detached namespaces0.0013: : Opera= tion not permitted >=20 > Add a parameter to logmsg() and vlogmsg() which indicates a message > continuation. If that's set, don't print the timestamp in vlogmsg(). >=20 > Link: https://github.com/moby/moby/issues/48257#issuecomment-2282875092 > Signed-off-by: Stefano Brivio Reviewed-by: David Gibson > --- > flow.c | 3 ++- > log.c | 14 ++++++++------ > log.h | 22 +++++++++++----------- > 3 files changed, 21 insertions(+), 18 deletions(-) >=20 > 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 =3D FLOW_TYPE(f); > =20 > - 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); > } > =20 > /** > 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, co= nst struct timespec *now, > /** > * vlogmsg() - Print or send messages to log or output files as configur= ed > * @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_li= st ap) > { > bool debug_print =3D (log_mask & LOG_MASK(LOG_DEBUG)) && log_file =3D= =3D -1; > const struct timespec *now; > @@ -265,7 +266,7 @@ void vlogmsg(bool newline, int pri, const char *forma= t, va_list ap) > =20 > now =3D logtime(&ts); > =20 > - if (debug_print) { > + if (debug_print && !cont) { > char timestr[LOGTIME_STRLEN]; > =20 > logtime_fmt(timestr, sizeof(timestr), now); > @@ -295,15 +296,16 @@ void vlogmsg(bool newline, int pri, const char *for= mat, 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; > =20 > va_start(ap, format); > - vlogmsg(newline, pri, format, ap); > + vlogmsg(newline, cont, pri, format, ap); > va_end(ap); > } > =20 > @@ -318,10 +320,10 @@ void logmsg_perror(int pri, const char *format, ...) > va_list ap; > =20 > va_start(ap, format); > - vlogmsg(false, pri, format, ap); > + vlogmsg(false, false, pri, format, ap); > va_end(ap); > =20 > - logmsg(true, pri, ": %s", strerror(errno_copy)); > + logmsg(true, true, pri, ": %s", strerror(errno_copy)); > } > =20 > /** > 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)) > =20 > -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_li= st 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))); > =20 > -#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__) > =20 > -#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__) > =20 > #define die(...) \ > do { \ --=20 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 --Xw9hbP7RO4LWZJW8 Content-Type: application/pgp-signature; name="signature.asc" -----BEGIN PGP SIGNATURE----- iQIzBAEBCAAdFiEEO+dNsU4E3yXUXRK2zQJF27ox2GcFAma52qcACgkQzQJF27ox 2GeOJw/+JN3m6UdtvGMaGSCAbmPNGh19zypk+OCdh/7GZ/J69FqhkZP08MzgH9Kn MFO0BQUApk/0sKUBKCy6+zkMsabbYixC5aH/7XWogvoJD1YtTIb/iDiDcAZt35xk Xu4WVseo3RdSvQpzhqR3GVW0EGghSgUcobimzu2Fqw7XmeYkslN9zFvsW8IffsY4 urW+yReL5Mj0ENuN8SdJBj7QmTDOBn5ZvAOU5yA3LjD1CCw54DklRMm+3cLTqtaa bl6WKemUTIQRpdrYisuN3kfWIxw1pEY+mwugLFTyMm5T0d5namud9skWxZ3Bjdhc JKJar2L38294sytWRFPRjXfP5C0g9GJLpQqVlAka9R9YIxwqmSD/gVWwMdt9BSBk i5JFg8TBZUf/2qekXVcQyEFWuFgDVmdpUg2Dgr4eOfnbYP85j4R0Tez+qB0c5Jtu /+LgnUrWL45AQkOeeT3Wo2ge3hIA8vy6AUMYYbpLOFtwbH7OPHrnsI9WTF4Qu93G pSkr5a7yCwhXaEQb3V1CN4VFrsIE/mNfw7oGkLOx7g7gOEfsBmRHVsbod1lwVoJ8 s1YznFSzVRTlkvs9ziiedqvb6o5ZggLfz2M7j/a1GQX+cA5/Uhi0gTxunzYEbORE qU72B4vP/TQZOaJswrFwJFaWlrP1CHEaNDtDsbtbs6peAg34WKY= =Krw+ -----END PGP SIGNATURE----- --Xw9hbP7RO4LWZJW8--