Re: [PATCH v1 2/2] tap, tcp, udp: Use rate-limited logging

[Laurent Vivier <lvivier@redhat.com>]

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