From mboxrd@z Thu Jan 1 00:00:00 1970 Authentication-Results: passt.top; dmarc=none (p=none dis=none) header.from=gibson.dropbear.id.au Authentication-Results: passt.top; dkim=pass (2048-bit key; secure) header.d=gibson.dropbear.id.au header.i=@gibson.dropbear.id.au header.a=rsa-sha256 header.s=202606 header.b=ETuCCuJH; dkim-atps=neutral Received: from mail.ozlabs.org (mail.ozlabs.org [IPv6:2404:9400:2221:ea00::3]) by passt.top (Postfix) with ESMTPS id 5C3E35A026E for ; Wed, 17 Jun 2026 05:08:57 +0200 (CEST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gibson.dropbear.id.au; s=202606; t=1781665732; bh=FtBXl6Yp/oL8VHU3X/N1tVJC+0jYsUasfFXHGJcgWjQ=; h=Date:From:To:Cc:Subject:References:In-Reply-To:From; b=ETuCCuJH/RiXD+S40pgJEed7mgQUJceQCjjflwLOLRIbwAmpWTfBXuEeY1SxXWpvF cH9FAe+3+hNk+gExWwuHsHivP/Ol8fugBt+w6GHo5zxXYnBzgbVGqBko/CO1/6hKEo wIy/vv573WlsOOEEhi1yimRSzyuVZniM+emA9NNuihczvKdqWoJoUYHWkywQi6/hFb APCjgWryF+OW1MaoRTfANxUy8P1i6gyUw5EXFZYbttgSFJKvUjuDxYroEwSfeHo7gp wYyxloYq9Gvxz7ABmrvvf09PU0XhvBB2+JYSevoIdXvtnTOiU40b23qp1SqR8lUctp jgYklGLL+VpoQ== Received: by gandalf.ozlabs.org (Postfix, from userid 1007) id 4gg82X6YJmz58nx; Wed, 17 Jun 2026 13:08:52 +1000 (AEST) Date: Wed, 17 Jun 2026 12:15:54 +1000 From: David Gibson To: Stefano Brivio Subject: Re: [PATCH 2/4] flow: Include flow details with higher priority log messages Message-ID: References: <20260609023226.86058-1-david@gibson.dropbear.id.au> <20260609023226.86058-3-david@gibson.dropbear.id.au> <20260617010911.771f33a8@elisabeth> MIME-Version: 1.0 Content-Type: multipart/signed; micalg=pgp-sha512; protocol="application/pgp-signature"; boundary="RNqXr5damWec76m8" Content-Disposition: inline In-Reply-To: <20260617010911.771f33a8@elisabeth> Message-ID-Hash: TYBPT3JOZKEUUK5YUTQDEKVZFJRLFDUU X-Message-ID-Hash: TYBPT3JOZKEUUK5YUTQDEKVZFJRLFDUU 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: --RNqXr5damWec76m8 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline Content-Transfer-Encoding: quoted-printable On Wed, Jun 17, 2026 at 01:09:11AM +0200, Stefano Brivio wrote: > On Tue, 9 Jun 2026 12:32:24 +1000 > David Gibson wrote: >=20 > > Currently flow_log() and related functions / macros have a 'details' > > parameter which indicates whether to add extra messages with details of= the > > flow's addresses. This is still a bit awkward to invoke, and only used= in > > a few places. Change the logic, to automatically include the details if > > and only if the log priority is greater than LOG_DEBUG. > >=20 > > Rationale: > >=20 > > If at debug log level, there are already a bunch of debug messages trac= king > > the flow life cycle, which include those details (we make sure to retain > > those). It's usually pretty easy to cross reference a specific flow de= bug > > message with the flow's history including the details. > >=20 > > If at higher log level, and we generate a flow-connected error or warni= ng > > we don't have those life cycle messages. So, just giving the flow index > > doesn't really tell you anything about which flow tripped the error. > > Adding the address details make the error message significantly more > > useful. > >=20 > > Signed-off-by: David Gibson > > --- > > flow.c | 2 +- > > flow.h | 22 +++++++++++----------- > > udp.c | 5 ++--- > > 3 files changed, 14 insertions(+), 15 deletions(-) > >=20 > > diff --git a/flow.c b/flow.c > > index 6cf3905a..dd92bad7 100644 > > --- a/flow.c > > +++ b/flow.c > > @@ -550,7 +550,7 @@ norule: > > /* This shouldn't happen, because if there's no rule for it we should > > * have no listening socket that would let us get here > > */ > > - flow_log(flow, LOG_DEBUG, false, true, "Missing forward rule"); > > + flow_dbg(flow, "Missing forward rule"); > > =20 > > nofwd: > > flow_err(flow, "No rules to forward %s %s [%s]:%hu -> [%s]:%hu", > > diff --git a/flow.h b/flow.h > > index d168a35a..e055defb 100644 > > --- a/flow.h > > +++ b/flow.h > > @@ -283,19 +283,19 @@ int flow_migrate_target(struct ctx *c, const stru= ct migrate_stage *stage, > > void flow_log__(const struct flow_common *f, int pri, bool perror, boo= l details, > > enum flow_state state, const char *fmt, ...); > > =20 > > -#define flow_log_(f_, pri_, perror_, details_, ...) \ > > - flow_log__((f_), (pri_), (perror_), (details_), (f_)->state, \ > > - __VA_ARGS__) > > +#define flow_log_(f_, pri_, perror_, ...) \ > > + flow_log__((f_), (pri_), (perror_), (pri_) > LOG_DEBUG, \ >=20 > On one hand, this looks quite practical, and we need the effects of > this change anyway. On the other hand, it's a bit sneaky to do this > implicitly. I wonder: >=20 > > + (f_)->state, __VA_ARGS__) > > =20 > > -#define flow_log(flow_, pri_, perror_, details_, ...) \ > > - flow_log_(&(flow_)->f, (pri_), (perror_), (details_), __VA_ARGS__) > > +#define flow_log(flow_, pri_, perror_, ...) \ > > + flow_log_(&(flow_)->f, (pri_), (perror_), __VA_ARGS__) > > =20 > > #define flow_dbg(flow_, ...) \ > > - flow_log((flow_), LOG_DEBUG, false, false, __VA_ARGS__) > > + flow_log((flow_), LOG_DEBUG, false, __VA_ARGS__) > > #define flow_warn(flow_, ...) \ > > - flow_log((flow_), LOG_WARNING, false, false, __VA_ARGS__) > > + flow_log((flow_), LOG_WARNING, false, __VA_ARGS__) > > #define flow_err(flow_, ...) \ > > - flow_log((flow_), LOG_ERR, false, false, __VA_ARGS__) > > + flow_log((flow_), LOG_ERR, false, __VA_ARGS__) > > #define flow_trace(flow_, ...) \ > > do { \ > > if (log_trace) \ > > @@ -303,11 +303,11 @@ void flow_log__(const struct flow_common *f, int = pri, bool perror, bool details, > > } while (0) > > =20 > > #define flow_dbg_perror(flow_, ...) \ > > - flow_log((flow_), LOG_DEBUG, true, false, __VA_ARGS__) > > + flow_log((flow_), LOG_DEBUG, true, __VA_ARGS__) > > #define flow_warn_perror(flow_, ...) \ > > - flow_log((flow_), LOG_WARNING, true, false, __VA_ARGS__) > > + flow_log((flow_), LOG_WARNING, true, __VA_ARGS__) > > #define flow_perror(flow_, ...) \ > > - flow_log((flow_), LOG_ERR, true, false, __VA_ARGS__) > > + flow_log((flow_), LOG_ERR, true, __VA_ARGS__) > > =20 > > #define flow_dbg_ratelimit(flow_, now_, ...) \ > > logmsg_ratelimit(flow_dbg, debug, (now_), (flow_), __VA_ARGS__) > > diff --git a/udp.c b/udp.c > > index f29ca3da..caeedf8f 100644 > > --- a/udp.c > > +++ b/udp.c > > @@ -943,8 +943,7 @@ void udp_sock_handler(const struct ctx *c, union ep= oll_ref ref, > > =20 > > if (events & EPOLLERR) { > > if (udp_sock_errs(c, ref.fd, ref.flowside, PIF_NONE, 0) < 0) { > > - flow_log(uflow, LOG_ERR, false, true, > > - "Unrecoverable error on flow socket"); > > + flow_err(uflow, "Unrecoverable error on flow socket"); >=20 > ...what if this, and... >=20 > > goto fail; > > } > > } > > @@ -975,7 +974,7 @@ void udp_sock_handler(const struct ctx *c, union ep= oll_ref ref, > > udp_buf_sock_to_tap(c, s, n, tosidx); > > } > > } else { > > - flow_log(uflow, LOG_ERR, false, true, > > + flow_err(uflow, >=20 > ...this would both become flow_err_details()? That's roughly what we used to have. > There might be future > cases where we already print flow details separately, even above > LOG_DEBUG, and in those cases we could keep calling flow_err() without > the details. =2E. or we could remove the separate print of the details, knowing it was included in flow_err()? Or maybe I don't quite grasp the case you're describing. > Not a strong preference from my side, I also see the value of keeping > this terse like the current patch does. Terse is nice, but for me the bigger advantage is it's much harder to forget to include relevant details in an error/warning message. Part of the context of this is debugging https://github.com/podman-container-tools/podman/issues/23739 where we were seeing an error message that was somewhat useful, but would have been much more useful if we knew the details of the flow it applied to. >=20 > > "No support for forwarding UDP from %s to %s", > > pif_name(pif_at_sidx(ref.flowside)), > > pif_name(topif)); >=20 > --=20 > Stefano >=20 --=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 --RNqXr5damWec76m8 Content-Type: application/pgp-signature; name=signature.asc -----BEGIN PGP SIGNATURE----- iQIzBAEBCgAdFiEEO+dNsU4E3yXUXRK2zQJF27ox2GcFAmoyA00ACgkQzQJF27ox 2Gea3g//WUDJoX2X/G+3w2u3FogAnHTrDwsQNoG7xmcZoakZzyOPLsGyQNTgPJx+ nlNr4SN2u8rqF01ZLopslfswhk3WrRJfg/wgXk+RWHjotumk7PIycbJqtwMkgEM4 KXVtIQA5hnN5hIDr7OxhFSap/fju/1HVZ8AWmyUIANzPO/uIb7cfQdJybjVi/bq3 GPhmwMKdw1Jih/hAvOhdpLMBDjGw89dvTjfa1QO/bmoo1Rn7LCbcKtX+exk999WI /ZtjI6aJfkshqYY2ZS13L75igoy+Yazg7V7DZ8C6TD4N2JPVjwKgjGXLrs2he0qN PfMUTrnX33rSol5E6sY4If+22v/MZLcPdNyhMSgdyt4vED/Fki0UDF9fsf/JEtQ+ 1K8EMHmT+8eV/ER8sSzQC6roJpSXjcyUuyC2yNga3LMkbq23t6TT1TvrBduYILoY nXxtvGvkvRBNhtHWPHyFhzXHPcGXGailWQOOUzAJ9rIzrAhsZ80hGY9Bkuer94B1 XFryGQO+2bGVpkyRirRmRlERlqH8FbePlr4lEyrNn/LdpTSaKu6UhY+Ge6ag4HMb 18HuSle4Odhx8HiujfwRhk1wMz3Yu/j6aRuBLfv5AUNQ2hqUDdoRUTLyCWsWMVCS sBssxcDgR0HbvVUn2+FDNkJUEHmmm+ctxyB4gU/iXMiA/cFzTY4= =L88O -----END PGP SIGNATURE----- --RNqXr5damWec76m8--