On Fri, Mar 19, 2021 at 02:58:14PM +0000, Chuck Lever III wrote:
> Hi Chris-
>
> > On Mar 19, 2021, at 10:54 AM, Chris Down <chris@xxxxxxxxxxxxxx> wrote:
> >
> > The reclen is taken directly from the first four bytes of the message
> > with the highest bit stripped, which makes it ripe for protocol mixups.
> > For example, if someone tries to send a HTTP GET request to us, we'll
> > interpret it as a 1195725856-sized fragment (ie. (u32)'GET '), and print
> > a ratelimited KERN_NOTICE with that number verbatim.
> >
> > This can be confusing for downstream users, who don't know what messages
> > like "fragment too large: 1195725856" actually mean, or that they
> > indicate some misconfigured infrastructure elsewhere.
>
> One wonders whether that error message is actually useful at all.
> We could, for example, turn this into a tracepoint, or just get
> rid of it.
Just going on vague memories here, but: I think we've seen both spurious
and real bugs reported based on this.
I'm inclined to go with a dprintk or tracepoint but not removing it
entirely.
--b.
>
>
> > To allow users to more easily understand and debug these cases, add the
> > number interpreted as ASCII if all characters are printable:
> >
> > RPC: fragment too large: 1195725856 (ASCII "GET ")
> >
> > If demand grows elsewhere, a new printk format that takes a number and
> > outputs it in various formats is also a possible solution. For now, it
> > seems reasonable to put this here since this particular code path is the
> > one that has repeatedly come up in production.
> >
> > Signed-off-by: Chris Down <chris@xxxxxxxxxxxxxx>
> > Cc: Chuck Lever <chuck.lever@xxxxxxxxxx>
> > Cc: J. Bruce Fields <bfields@xxxxxxxxxx>
> > Cc: Trond Myklebust <trond.myklebust@xxxxxxxxxxxxxxx>
> > Cc: David S. Miller <davem@xxxxxxxxxxxxx>
> > ---
> > net/sunrpc/svcsock.c | 39 +++++++++++++++++++++++++++++++++++++--
> > 1 file changed, 37 insertions(+), 2 deletions(-)
> >
> > diff --git a/net/sunrpc/svcsock.c b/net/sunrpc/svcsock.c
> > index 2e2f007dfc9f..046b1d104340 100644
> > --- a/net/sunrpc/svcsock.c
> > +++ b/net/sunrpc/svcsock.c
> > @@ -46,6 +46,7 @@
> > #include <linux/uaccess.h>
> > #include <linux/highmem.h>
> > #include <asm/ioctls.h>
> > +#include <linux/ctype.h>
> >
> > #include <linux/sunrpc/types.h>
> > #include <linux/sunrpc/clnt.h>
> > @@ -863,6 +864,34 @@ static void svc_tcp_clear_pages(struct svc_sock *svsk)
> > svsk->sk_datalen = 0;
> > }
> >
> > +/* The reclen is taken directly from the first four bytes of the message with
> > + * the highest bit stripped, which makes it ripe for protocol mixups. For
> > + * example, if someone tries to send a HTTP GET request to us, we'll interpret
> > + * it as a 1195725856-sized fragment (ie. (u32)'GET '), and print a ratelimited
> > + * KERN_NOTICE with that number verbatim.
> > + *
> > + * To allow users to more easily understand and debug these cases, this
> > + * function decodes the purported length as ASCII, and returns it if all
> > + * characters were printable. Otherwise, we return NULL.
> > + *
> > + * WARNING: Since we reuse the u32 directly, the return value is not null
> > + * terminated, and must be printed using %.*s with
> > + * sizeof(svc_sock_reclen(svsk)).
> > + */
> > +static char *svc_sock_reclen_ascii(struct svc_sock *svsk)
> > +{
> > + u32 len_be = cpu_to_be32(svc_sock_reclen(svsk));
> > + char *len_be_ascii = (char *)&len_be;
> > + size_t i;
> > +
> > + for (i = 0; i < sizeof(len_be); i++) {
> > + if (!isprint(len_be_ascii[i]))
> > + return NULL;
> > + }
> > +
> > + return len_be_ascii;
> > +}
> > +
> > /*
> > * Receive fragment record header into sk_marker.
> > */
> > @@ -870,6 +899,7 @@ static ssize_t svc_tcp_read_marker(struct svc_sock *svsk,
> > struct svc_rqst *rqstp)
> > {
> > ssize_t want, len;
> > + char *reclen_ascii;
> >
> > /* If we haven't gotten the record length yet,
> > * get the next four bytes.
> > @@ -898,9 +928,14 @@ static ssize_t svc_tcp_read_marker(struct svc_sock *svsk,
> > return svc_sock_reclen(svsk);
> >
> > err_too_large:
> > - net_notice_ratelimited("svc: %s %s RPC fragment too large: %d\n",
> > + reclen_ascii = svc_sock_reclen_ascii(svsk);
> > + net_notice_ratelimited("svc: %s %s RPC fragment too large: %d%s%.*s%s\n",
> > __func__, svsk->sk_xprt.xpt_server->sv_name,
> > - svc_sock_reclen(svsk));
> > + svc_sock_reclen(svsk),
> > + reclen_ascii ? " (ASCII \"" : "",
> > + (int)sizeof(u32),
> > + reclen_ascii ?: "",
> > + reclen_ascii ? "\")" : "");
> > set_bit(XPT_CLOSE, &svsk->sk_xprt.xpt_flags);
> > err_short:
> > return -EAGAIN;
> > --
> > 2.30.2
> >
>
> --
> Chuck Lever
>
>
>
