* Re: [PATCH v1 2/2] tap, tcp, udp: Use rate-limited logging
2026-04-01 18:29 [PATCH v1 2/2] tap, tcp, udp: Use rate-limited logging Anshu Kumari
@ 2026-04-02 15:10 ` Laurent Vivier
2026-04-02 15:33 ` Stefano Brivio
2026-04-06 8:12 ` Stefano Brivio
1 sibling, 1 reply; 5+ messages in thread
From: Laurent Vivier @ 2026-04-02 15:10 UTC (permalink / raw)
To: Anshu Kumari, sbrivio, passt-dev; +Cc: david
On 4/1/26 20:29, Anshu Kumari wrote:
> Now that rate-limited logging macros are available, promote several
> debug messages to higher severity levels. These messages were
> previously kept at debug to prevent guests from flooding host
> logs, but with rate limiting they can safely be made visible in
> normal operation.
>
> In tap.c, refactor tap4_is_fragment() to use warn_ratelimit() instead
> of its ad-hoc rate limiting, and promote the guest MAC address change
> message to info level.
>
> In tcp.c, promote the invalid TCP SYN endpoint message to warn level.
>
> In udp.c and udp_flow.c, promote flow allocation failures and dropped
> datagram messages to warn level, and rate-limit the unrecoverable
> socket error message.
>
> Link: https://bugs.passt.top/show_bug.cgi?id=134
> Signed-off-by: Anshu Kumari <anskuma@redhat.com>
As the patch 1/2 is already merged, you don't need to number this one 2/2.
> ---
>
> - Inside udp.c
> - David: should this be changed to warn_ratelimit? I am not sure about it
> debug("%s error on UDP socket %i: %s",
> str_ee_origin(ee), s, strerror_(ee->ee_errno));
>
> ---
> tap.c | 14 ++++----------
> tcp.c | 2 +-
> udp.c | 6 +++---
> udp_flow.c | 4 ++--
> 4 files changed, 10 insertions(+), 16 deletions(-)
>
> diff --git a/tap.c b/tap.c
> index 1049e02..f569b61 100644
> --- a/tap.c
> +++ b/tap.c
> @@ -686,17 +686,11 @@ static bool tap4_is_fragment(const struct iphdr *iph,
> const struct timespec *now)
> {
> if (ntohs(iph->frag_off) & ~IP_DF) {
> - /* Ratelimit messages */
> - static time_t last_message;
> static unsigned num_dropped;
>
> num_dropped++;
> - if (now->tv_sec - last_message > FRAGMENT_MSG_RATE) {
the #define FRAGMENT_MSG_RATE can be removed from the file as it is unused now.
> - warn("Can't process IPv4 fragments (%u dropped)",
> - num_dropped);
> - last_message = now->tv_sec;
> - num_dropped = 0;
> - }
> + warn_ratelimit(now, "Can't process IPv4 fragments (%u dropped)",
> + num_dropped);
I don't think we should keep the num_dropped value here as it is never reset, the
"suppressed %u similar messages" will give the information.
> return true;
> }
> return false;
> @@ -1115,8 +1109,8 @@ void tap_add_packet(struct ctx *c, struct iov_tail *data,
> char bufmac[ETH_ADDRSTRLEN];
>
> memcpy(c->guest_mac, eh->h_source, ETH_ALEN);
> - debug("New guest MAC address observed: %s",
> - eth_ntop(c->guest_mac, bufmac, sizeof(bufmac)));
> + info_ratelimit(now, "New guest MAC address observed: %s",
> + eth_ntop(c->guest_mac, bufmac, sizeof(bufmac)));
> proto_update_l2_buf(c->guest_mac);
> }
>
> diff --git a/tcp.c b/tcp.c
> index 8ea9be8..3d3b80d 100644
> --- a/tcp.c
> +++ b/tcp.c
> @@ -1688,7 +1688,7 @@ static void tcp_conn_from_tap(const struct ctx *c, sa_family_t af,
> !inany_is_unicast(&ini->oaddr) || ini->oport == 0) {
> char sstr[INANY_ADDRSTRLEN], dstr[INANY_ADDRSTRLEN];
>
> - debug("Invalid endpoint in TCP SYN: %s:%hu -> %s:%hu",
> + warn_ratelimit(now, "Invalid endpoint in TCP SYN: %s:%hu -> %s:%hu",
> inany_ntop(&ini->eaddr, sstr, sizeof(sstr)), ini->eport,
> inany_ntop(&ini->oaddr, dstr, sizeof(dstr)), ini->oport);
You must align 'inany..." with the new place of '(' of warn_ratelimit
> goto cancel;
> diff --git a/udp.c b/udp.c
> index 1fc5a42..1ef5e7a 100644
> --- a/udp.c
> +++ b/udp.c
> @@ -871,7 +871,7 @@ void udp_sock_fwd(const struct ctx *c, int s, int rule_hint,
> /* Clear errors & carry on */
> if (udp_sock_errs(c, s, FLOW_SIDX_NONE,
> frompif, port) < 0) {
> - err(
> + err_ratelimit(now,
> "UDP: Unrecoverable error on listening socket: (%s port %hu)",
> pif_name(frompif), port);
> /* FIXME: what now? close/re-open socket? */
> @@ -898,7 +898,7 @@ void udp_sock_fwd(const struct ctx *c, int s, int rule_hint,
> pif_name(frompif), pif_name(topif));
> discard = true;
> } else {
> - debug("Discarding datagram without flow");
> + warn_ratelimit(now, "Discarding datagram without flow");
> discard = true;
> }
>
> @@ -1042,7 +1042,7 @@ int udp_tap_handler(const struct ctx *c, uint8_t pif,
> if (!(uflow = udp_at_sidx(tosidx))) {
> char sstr[INET6_ADDRSTRLEN], dstr[INET6_ADDRSTRLEN];
>
> - debug("Dropping datagram with no flow %s %s:%hu -> %s:%hu",
> + warn_ratelimit(now, "Dropping datagram with no flow %s %s:%hu -> %s:%hu",
> pif_name(pif),
> inet_ntop(af, saddr, sstr, sizeof(sstr)), src,
> inet_ntop(af, daddr, dstr, sizeof(dstr)), dst);
> diff --git a/udp_flow.c b/udp_flow.c
> index 7e2453e..9343b4b 100644
> --- a/udp_flow.c
> +++ b/udp_flow.c
> @@ -235,7 +235,7 @@ flow_sidx_t udp_flow_from_sock(const struct ctx *c, uint8_t pif,
> if (!(flow = flow_alloc())) {
> char sastr[SOCKADDR_STRLEN];
>
> - debug("Couldn't allocate flow for UDP datagram from %s %s",
> + warn_ratelimit(now, "Couldn't allocate flow for UDP datagram from %s %s",
> pif_name(pif), sockaddr_ntop(s_in, sastr, sizeof(sastr)));
> return FLOW_SIDX_NONE;
> }
> @@ -292,7 +292,7 @@ flow_sidx_t udp_flow_from_tap(const struct ctx *c,
> if (!(flow = flow_alloc())) {
> char sstr[INET6_ADDRSTRLEN], dstr[INET6_ADDRSTRLEN];
>
> - debug("Couldn't allocate flow for UDP datagram from %s %s:%hu -> %s:%hu",
> + warn_ratelimit(now, "Couldn't allocate flow for UDP datagram from %s %s:%hu -> %s:%hu",
> pif_name(pif),
> inet_ntop(af, saddr, sstr, sizeof(sstr)), srcport,
> inet_ntop(af, daddr, dstr, sizeof(dstr)), dstport);
Thanks,
Laurent
^ permalink raw reply [flat|nested] 5+ messages in thread* Re: [PATCH v1 2/2] tap, tcp, udp: Use rate-limited logging
2026-04-01 18:29 [PATCH v1 2/2] tap, tcp, udp: Use rate-limited logging Anshu Kumari
2026-04-02 15:10 ` Laurent Vivier
@ 2026-04-06 8:12 ` Stefano Brivio
2026-04-07 0:46 ` David Gibson
1 sibling, 1 reply; 5+ messages in thread
From: Stefano Brivio @ 2026-04-06 8:12 UTC (permalink / raw)
To: Anshu Kumari; +Cc: passt-dev, lvivier, david
On Wed, 1 Apr 2026 23:59:10 +0530
Anshu Kumari <anskuma@redhat.com> wrote:
> Now that rate-limited logging macros are available, promote several
> debug messages to higher severity levels. These messages were
> previously kept at debug to prevent guests from flooding host
> logs, but with rate limiting they can safely be made visible in
> normal operation.
>
> In tap.c, refactor tap4_is_fragment() to use warn_ratelimit() instead
> of its ad-hoc rate limiting, and promote the guest MAC address change
> message to info level.
>
> In tcp.c, promote the invalid TCP SYN endpoint message to warn level.
>
> In udp.c and udp_flow.c, promote flow allocation failures and dropped
> datagram messages to warn level, and rate-limit the unrecoverable
> socket error message.
>
> Link: https://bugs.passt.top/show_bug.cgi?id=134
By the way of this ticket, I forgot to mention that as it came up after
a discussion on a series by Volker (Volker Diels-Grabsch <v@njh.eu>),
it would be nice to Cc: him on the next version of this patch.
> Signed-off-by: Anshu Kumari <anskuma@redhat.com>
> ---
>
> - Inside udp.c
> - David: should this be changed to warn_ratelimit? I am not sure about it
> debug("%s error on UDP socket %i: %s",
> str_ee_origin(ee), s, strerror_(ee->ee_errno));
I had a closer look, and it looks like we're hitting that part for any
error reported via ICMP that can be associated to a given UDP socket, so
I would say it's part of our regular networking operation, and we
should keep it as debug().
> ---
> tap.c | 14 ++++----------
> tcp.c | 2 +-
> udp.c | 6 +++---
> udp_flow.c | 4 ++--
> 4 files changed, 10 insertions(+), 16 deletions(-)
>
> diff --git a/tap.c b/tap.c
> index 1049e02..f569b61 100644
> --- a/tap.c
> +++ b/tap.c
> @@ -686,17 +686,11 @@ static bool tap4_is_fragment(const struct iphdr *iph,
> const struct timespec *now)
> {
> if (ntohs(iph->frag_off) & ~IP_DF) {
> - /* Ratelimit messages */
> - static time_t last_message;
> static unsigned num_dropped;
>
> num_dropped++;
> - if (now->tv_sec - last_message > FRAGMENT_MSG_RATE) {
> - warn("Can't process IPv4 fragments (%u dropped)",
> - num_dropped);
> - last_message = now->tv_sec;
> - num_dropped = 0;
> - }
> + warn_ratelimit(now, "Can't process IPv4 fragments (%u dropped)",
> + num_dropped);
> return true;
> }
> return false;
> @@ -1115,8 +1109,8 @@ void tap_add_packet(struct ctx *c, struct iov_tail *data,
> char bufmac[ETH_ADDRSTRLEN];
>
> memcpy(c->guest_mac, eh->h_source, ETH_ALEN);
> - debug("New guest MAC address observed: %s",
> - eth_ntop(c->guest_mac, bufmac, sizeof(bufmac)));
> + info_ratelimit(now, "New guest MAC address observed: %s",
> + eth_ntop(c->guest_mac, bufmac, sizeof(bufmac)));
Similar to the other call Laurent commented on, this should be:
info_ratelimit(now, "New guest MAC address observed: %s",
eth_ntop(c->guest_mac, bufmac, sizeof(bufmac)));
so that arguments visually align with each other. This is the style (somewhat)
suggested at:
https://docs.kernel.org/process/coding-style.html#breaking-long-lines-and-strings
which is the one we follow.
> proto_update_l2_buf(c->guest_mac);
> }
>
> diff --git a/tcp.c b/tcp.c
> index 8ea9be8..3d3b80d 100644
> --- a/tcp.c
> +++ b/tcp.c
> @@ -1688,7 +1688,7 @@ static void tcp_conn_from_tap(const struct ctx *c, sa_family_t af,
> !inany_is_unicast(&ini->oaddr) || ini->oport == 0) {
> char sstr[INANY_ADDRSTRLEN], dstr[INANY_ADDRSTRLEN];
>
> - debug("Invalid endpoint in TCP SYN: %s:%hu -> %s:%hu",
> + warn_ratelimit(now, "Invalid endpoint in TCP SYN: %s:%hu -> %s:%hu",
> inany_ntop(&ini->eaddr, sstr, sizeof(sstr)), ini->eport,
> inany_ntop(&ini->oaddr, dstr, sizeof(dstr)), ini->oport);
> goto cancel;
> diff --git a/udp.c b/udp.c
> index 1fc5a42..1ef5e7a 100644
> --- a/udp.c
> +++ b/udp.c
> @@ -871,7 +871,7 @@ void udp_sock_fwd(const struct ctx *c, int s, int rule_hint,
> /* Clear errors & carry on */
> if (udp_sock_errs(c, s, FLOW_SIDX_NONE,
> frompif, port) < 0) {
> - err(
> + err_ratelimit(now,
> "UDP: Unrecoverable error on listening socket: (%s port %hu)",
> pif_name(frompif), port);
> /* FIXME: what now? close/re-open socket? */
> @@ -898,7 +898,7 @@ void udp_sock_fwd(const struct ctx *c, int s, int rule_hint,
> pif_name(frompif), pif_name(topif));
> discard = true;
> } else {
> - debug("Discarding datagram without flow");
> + warn_ratelimit(now, "Discarding datagram without flow");
> discard = true;
> }
>
> @@ -1042,7 +1042,7 @@ int udp_tap_handler(const struct ctx *c, uint8_t pif,
> if (!(uflow = udp_at_sidx(tosidx))) {
> char sstr[INET6_ADDRSTRLEN], dstr[INET6_ADDRSTRLEN];
>
> - debug("Dropping datagram with no flow %s %s:%hu -> %s:%hu",
> + warn_ratelimit(now, "Dropping datagram with no flow %s %s:%hu -> %s:%hu",
> pif_name(pif),
> inet_ntop(af, saddr, sstr, sizeof(sstr)), src,
> inet_ntop(af, daddr, dstr, sizeof(dstr)), dst);
> diff --git a/udp_flow.c b/udp_flow.c
> index 7e2453e..9343b4b 100644
> --- a/udp_flow.c
> +++ b/udp_flow.c
> @@ -235,7 +235,7 @@ flow_sidx_t udp_flow_from_sock(const struct ctx *c, uint8_t pif,
> if (!(flow = flow_alloc())) {
> char sastr[SOCKADDR_STRLEN];
>
> - debug("Couldn't allocate flow for UDP datagram from %s %s",
> + warn_ratelimit(now, "Couldn't allocate flow for UDP datagram from %s %s",
> pif_name(pif), sockaddr_ntop(s_in, sastr, sizeof(sastr)));
> return FLOW_SIDX_NONE;
> }
> @@ -292,7 +292,7 @@ flow_sidx_t udp_flow_from_tap(const struct ctx *c,
> if (!(flow = flow_alloc())) {
> char sstr[INET6_ADDRSTRLEN], dstr[INET6_ADDRSTRLEN];
>
> - debug("Couldn't allocate flow for UDP datagram from %s %s:%hu -> %s:%hu",
> + warn_ratelimit(now, "Couldn't allocate flow for UDP datagram from %s %s:%hu -> %s:%hu",
> pif_name(pif),
> inet_ntop(af, saddr, sstr, sizeof(sstr)), srcport,
> inet_ntop(af, daddr, dstr, sizeof(dstr)), dstport);
Other than that, and other than the pending comments from Laurent, the
patch looks good to me! I would suggest maybe waiting about one more day
before posting the next version to give others better chances to review.
--
Stefano
^ permalink raw reply [flat|nested] 5+ messages in thread