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

[Stefano Brivio <sbrivio@redhat.com>]

On Thu, 2 Jan 2025 13:15:40 +1100
David Gibson <david@gibson.dropbear.id.au> wrote:

> On Wed, Jan 01, 2025 at 10:54:37PM +0100, Stefano Brivio wrote:
> > 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.  
> 
> I'm not following your argument here.  It's exactly because (most of)
> the message indicate serious issues that I don't want to suppress
> them.  I don't know what you mean by "validating identity
> associations".

But dhcpv6_opt() trying to get data that doesn't exist is *not* an
issue, including not a serious one, so if I'm debugging something with
--trace and I see one of these messages I'll shout at "memory" or
"packet" badness and waste time thinking it's an actual issue.

Validating identity associations (IA_NA, IA_TA, RFC 3315) is what
dhcpv6_ia_notonlink() does. That's the most common case where we'll
routinely call dhcpv6_opt() to fetch data which isn't there.

> > 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.  
> 
> Right, but dhcpv6_opt() is called in a loop, that only stops when it
> returns NULL.  So, by construction the last call to dhcpv6_opt(),
> which terminates the loop, _will_ have a failing call to packet_get().
> At this point - at least assuming a correctly constructed packet - the
> offset will point to just past the last option, which should be
> exactly at the end of the packet.

Yes, I get that, and:

- I would be happy if that one were *not* reported as failure

- the calls before that one should always be enough to check if we have
  an actual issue with the packet

> > In ipv6_l4hdr(), the index was
> > already validated by a previous call to packet_get(), and the starting
> > offset as well.  
> 
> Not AFAICT, the initial packet_get just validates the basic IPv6
> header.  The calls to packet_get_try() in the loop validate additional
> IP options.  I don't think it will ever fail on a well-constructed
> packet, but it could on a bogus (or truncated) packet, where the
> nexthdr field indicates an option that's actually missing.
> 
> This is kind of my point: it will only trip on a badly constructed
> packet, in which case I don't think we want to suppress messages.

There, I used packet_get_try() because a missing option or payload
doesn't indicate a bad packet at the _data_ level.

On the other hand, it's bad at the network level anyway, because option
59 *must* be there otherwise (I just realised), so while I'd still
prefer another wording of the warning (not mentioning packet/buffer
ranges... something more network-y), I would be fine with it.

> > 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.  
> 
> Mostly the next one - making more distinction between the different
> error severities that can occur here.  Having to deal with the
> possibility of func being NULL complicates things.

I fail to see that much of a complication as a result, and I'd still
very much prefer to *not* have a warning for that case in dhcpv6_opt()
(and a slight preference to have a different message for ipv6_l4hdr()),
but if it really adds a ton of lines for whatever reason I'm missing,
so be it...

> > > 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.  
> 
> Fixed.  The doc for packet_add_do() also changed, where it was already wrong.
> 
> > >  		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