Re: [PATCH v3 05/15] flow, tcp, tcp_splice: Uniform debug helpers for new flows

[Stefano Brivio <sbrivio@redhat.com>]

On Thu, 21 Dec 2023 18:02:27 +1100
David Gibson <david@gibson.dropbear.id.au> wrote:

> When debugging passt/pasta, and the flow table in particular, one of the
> most obvious things to know is when a new flow is initiated, along with the
> details of its interface, addresses and ports.  Once we've determined to
> what interface the flow should be forwarded, it's useful to know the
> details of how it will appear on that other interface.
> 
> To help present that information uniformly, introduce FLOW_NEW_DBG() and
> FLOW_FWD_DBG() helpers and use them for TCP connections, both "tap" and
> spliced.
> 
> Signed-off-by: David Gibson <david@gibson.dropbear.id.au>
> ---
>  flow.c       | 40 ++++++++++++++++++++++++++++++++++++++++
>  flow.h       | 16 ++++++++++++++++
>  tcp.c        | 11 +++++++++--
>  tcp_splice.c |  3 ++-
>  4 files changed, 67 insertions(+), 3 deletions(-)
> 
> diff --git a/flow.c b/flow.c
> index b9c4a18..bc8cfc6 100644
> --- a/flow.c
> +++ b/flow.c
> @@ -9,6 +9,7 @@
>  #include <unistd.h>
>  #include <string.h>
>  #include <errno.h>
> +#include <arpa/inet.h>
>  
>  #include "util.h"
>  #include "passt.h"
> @@ -50,6 +51,45 @@ void flow_log_(const struct flow_common *f, int pri, const char *fmt, ...)
>  	logmsg(pri, "Flow %u (%s): %s", flow_idx(f), FLOW_TYPE(f), msg);
>  }
>  
> +/**
> + * flow_new_dbg() - Print debug message for new flow
> + * @f:		Common flow structure
> + * @side:	Which side initiated the new flow
> + */
> +void flow_new_dbg(const struct flow_common *f, unsigned side)
> +{
> +	char ebuf[INET6_ADDRSTRLEN], fbuf[INET6_ADDRSTRLEN];
> +	const struct flowside *fside = &f->side[side];
> +
> +	flow_log_(f, LOG_DEBUG, "New %s from %s/%u: [%s]:%hu <-> [%s]:%hu",

I think we should always print the connection index too (passed from
the macro, or passing 'conn' as argument here) -- especially if we want
to correlate this to what flow_fwd_dbg() will print later.

It's also useful if anything goes wrong with the flow table itself.

Sure, address/ports pairs should now be sufficient to uniquely identify
a flow, and the flow table should be otherwise transparent, but the idea
behind debugging is that there's a bug somewhere.

> +		  flow_type_str[f->type], pif_name(fside->pif), side,
> +		  inet_ntop(AF_INET6, &fside->faddr, fbuf, sizeof(fbuf)),
> +		  fside->fport,
> +		  inet_ntop(AF_INET6, &fside->eaddr, ebuf, sizeof(ebuf)),
> +		  fside->eport);
> +}
> +
> +/**
> + * flow_fwd_dbg() - Print debug message for newly forwarded flow
> + * @f:		Common flow structure
> + * @side:	Which side was the flow forwarded to
> + */
> +void flow_fwd_dbg(const struct flow_common *f, unsigned side)
> +{
> +	char ebuf[INET6_ADDRSTRLEN], fbuf[INET6_ADDRSTRLEN];
> +	const struct flowside *fside = &f->side[side];
> +
> +	inet_ntop(AF_INET6, &fside->eaddr, ebuf, sizeof(ebuf));
> +	inet_ntop(AF_INET6, &fside->faddr, fbuf, sizeof(fbuf));
> +
> +	flow_log_(f, LOG_DEBUG, "Forwarded to %s/%u: [%s]:%hu <-> [%s]:%hu",
> +		  pif_name(fside->pif), side,
> +		  inet_ntop(AF_INET6, &fside->faddr, fbuf, sizeof(fbuf)),
> +		  fside->fport,
> +		  inet_ntop(AF_INET6, &fside->eaddr, ebuf, sizeof(ebuf)),
> +		  fside->eport);
> +}
> +
>  /** flowside_from_sock - Initialize flowside to match an existing socket
>   * @fside:	flowside to initialize
>   * @pif:	pif id of this flowside
> diff --git a/flow.h b/flow.h
> index 37885b2..e7c4484 100644
> --- a/flow.h
> +++ b/flow.h
> @@ -97,6 +97,22 @@ struct flow_common {
>  #define FLOW_TABLE_PRESSURE		30	/* % of FLOW_MAX */
>  #define FLOW_FILE_PRESSURE		30	/* % of c->nofile */
>  
> +/** flow_complete - Check if common parts of flow are fully initialized
> + * @flow:	flow to check
> + */
> +static inline bool flow_complete(const struct flow_common *f)
> +{
> +	return f->type != FLOW_TYPE_NONE && f->type < FLOW_NUM_TYPES &&
> +		flowside_complete(&f->side[0]) &&
> +		flowside_complete(&f->side[1]);

Preferably align next lines after "return ".

-- 
Stefano