Re: [PATCH v2 07/12] packet: Remove unhelpful packet_get_try() macro

[Stefano Brivio <sbrivio@redhat.com>]

On Fri, 20 Dec 2024 19:35:30 +1100
David Gibson <david@gibson.dropbear.id.au> wrote:

> Two places in the code use the packet_get_try() variant on packet_get().
> The difference is that packet_get_try() passes a NULL 'func' to
> packet_get_do(), which suppresses log messages.  The places we use this
> are ones where we expect to sometimes have a failure retreiving the packet
> range, even in normal cases.  So, suppressing the log messages seems like
> it makes sense, except:
> 
> 1) It suppresses log messages on all errors.  We (somewhat) expect to hit
>    the case where the requested range is not within the received packet.
>    However, it also suppresses message in cases where the requested packet
>    index doesn't exist, the requested range has a nonsensical length or
>    doesn't lie in even the right vague part of memory.  None of those
>    latter cases are expected, and the message would be helpful if we ever
>    actually hit them.
> 
> 2) The suppressed messages aren't actually that disruptive.  For the case
>    in ip.c, we'd log only if we run out of IPv6 packet before reaching a
>    (non-option) L4 header.  That shouldn't be the case in normal operation
>    so getting a message (at trave level) is not unreasonable.
>    For the case in dhcpv6.c we do suppress a message every time we look for
>    but don't find a specific DHCPv6 option.  That can happen in perfectly
>    ok cases, but, again these are trace() level and DHCPv6 transactions
>    aren't that common.  Suppressing the message for this case doesn't
>    seem worth the drawbacks of (1).

The reason why I implemented packet_get_try() is that the messages from
packet_get_do() indicate serious issues, and if I'm debugging something
by looking at traces it's not great to have messages indicating that we
hit a serious issue while we're simply validating identity associations.

It's not about the amount of logged messages, it's about the type of
message being logged and the distracting noise possibly resulting in a
substantial time waste.

About 1): dhcpv6_opt() always picks pool index 0, and the base offset
was already checked by the caller. In ipv6_l4hdr(), the index was
already validated by a previous call to packet_get(), and the starting
offset as well.

I guess the main reason to have this patch in this series is to make a
later change simpler, but I'm not sure which one, so I don't know what
to suggest as an alternative.

> Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
> ---
>  dhcpv6.c |  2 +-
>  ip.c     |  2 +-
>  packet.c | 18 +++++-------------
>  packet.h |  3 ---
>  4 files changed, 7 insertions(+), 18 deletions(-)
> 
> diff --git a/dhcpv6.c b/dhcpv6.c
> index 0523bba8..c0d05131 100644
> --- a/dhcpv6.c
> +++ b/dhcpv6.c
> @@ -271,7 +271,7 @@ static struct opt_hdr *dhcpv6_opt(const struct pool *p, size_t *offset,
>  	if (!*offset)
>  		*offset = sizeof(struct udphdr) + sizeof(struct msg_hdr);
>  
> -	while ((o = packet_get_try(p, 0, *offset, sizeof(*o), &left))) {
> +	while ((o = packet_get(p, 0, *offset, sizeof(*o), &left))) {
>  		unsigned int opt_len = ntohs(o->l) + sizeof(*o);
>  
>  		if (ntohs(o->l) > left)
> diff --git a/ip.c b/ip.c
> index 2cc7f654..e391f81b 100644
> --- a/ip.c
> +++ b/ip.c
> @@ -51,7 +51,7 @@ char *ipv6_l4hdr(const struct pool *p, int idx, size_t offset, uint8_t *proto,
>  	if (!IPV6_NH_OPT(nh))
>  		goto found;
>  
> -	while ((o = packet_get_try(p, idx, offset, sizeof(*o), dlen))) {
> +	while ((o = packet_get(p, idx, offset, sizeof(*o), dlen))) {
>  		nh = o->nexthdr;
>  		hdrlen = (o->hdrlen + 1) * 8;
>  
> diff --git a/packet.c b/packet.c
> index bcac0375..c921aa15 100644
> --- a/packet.c
> +++ b/packet.c
> @@ -112,27 +112,19 @@ void *packet_get_do(const struct pool *p, size_t idx, size_t offset,
>  	char *ptr;
>  
>  	if (idx >= p->size || idx >= p->count) {
> -		if (func) {
> -			trace("packet %zu from pool size: %zu, count: %zu, "
> -			      "%s:%i", idx, p->size, p->count, func, line);
> -		}
> +		trace("packet %zu from pool size: %zu, count: %zu, %s:%i",
> +		      idx, p->size, p->count, func, line);

If you change this, the documentation of the arguments for
packet_get_do() should be updated as well.

>  		return NULL;
>  	}
>  
>  	if (len > PACKET_MAX_LEN) {
> -		if (func) {
> -			trace("packet data length %zu, %s:%i",
> -			      len, func, line);
> -		}
> +		trace("packet data length %zu, %s:%i", len, func, line);
>  		return NULL;
>  	}
>  
>  	if (len + offset > p->pkt[idx].iov_len) {
> -		if (func) {
> -			trace("data length %zu, offset %zu from length %zu, "
> -			      "%s:%i", len, offset, p->pkt[idx].iov_len,
> -			      func, line);
> -		}
> +		trace("data length %zu, offset %zu from length %zu, %s:%i",
> +		      len, offset, p->pkt[idx].iov_len, func, line);
>  		return NULL;
>  	}
>  
> diff --git a/packet.h b/packet.h
> index 05d37695..f95cda08 100644
> --- a/packet.h
> +++ b/packet.h
> @@ -45,9 +45,6 @@ void pool_flush(struct pool *p);
>  #define packet_get(p, idx, offset, len, left)				\
>  	packet_get_do(p, idx, offset, len, left, __func__, __LINE__)
>  
> -#define packet_get_try(p, idx, offset, len, left)			\
> -	packet_get_do(p, idx, offset, len, left, NULL, 0)
> -
>  #define PACKET_POOL_DECL(_name, _size, _buf)				\
>  struct _name ## _t {							\
>  	char *buf;							\

-- 
Stefano