Received-SPF: pass (google.com: domain of linux-nfs-owner@vger.kernel.org designates 23.128.96.18 as permitted sender) client-ip=23.128.96.18;
From:   Chuck Lever III <chuck.lever@oracle.com>
To:     Chris Down <chris@chrisdown.name>
CC:     Linux NFS Mailing List <linux-nfs@vger.kernel.org>,
        Linux-Net <netdev@vger.kernel.org>,
        LKML <linux-kernel@vger.kernel.org>,
        Bruce Fields <bfields@redhat.com>,
        Trond Myklebust <trond.myklebust@hammerspace.com>,
        "David S. Miller" <davem@davemloft.net>
Subject: Re: [PATCH] SUNRPC: Output oversized frag reclen as ASCII if
 printable
Thread-Topic: [PATCH] SUNRPC: Output oversized frag reclen as ASCII if
 printable
Thread-Index: AQHXHM/NVCtugqioaUyypXdJqaYWcqqLZvMA
Date:   Fri, 19 Mar 2021 14:58:14 +0000
Message-ID: <3844BF67-8820-4D6C-95BA-8BA0B0956BD0@oracle.com>
References: <YFS7L4FIQBDtIY9d@chrisdown.name>
In-Reply-To: <YFS7L4FIQBDtIY9d@chrisdown.name>
Accept-Language: en-US
Content-Language: en-US
Content-Type: text/plain; charset="us-ascii"
Content-ID: <96D966773025584A9C79AA4F046D2A71@namprd10.prod.outlook.com>
Content-Transfer-Encoding: quoted-printable
MIME-Version: 1.0
X-MS-Exchange-CrossTenant-Network-Message-Id: 61a9c25c-7655-43cd-70fb-08d8eae76c78
X-MS-Exchange-CrossTenant-originalarrivaltime: 19 Mar 2021 14:58:14.9599
 (UTC)
X-MS-Exchange-CrossTenant-fromentityheader: Hosted
X-MS-Exchange-CrossTenant-id: 4e2c6054-71cb-48f1-bd6c-3a9705aca71b
X-MS-Exchange-CrossTenant-mailboxtype: HOSTED
X-MS-Exchange-CrossTenant-userprincipalname: 0uiVPlz6iXR8hcajzqudS7Qob1XVEDDJf42OI4ixxzBmue+u6Zlov4AdscynxNI1UyHhP5PF+gJv+h/KGhuxMA==
X-MS-Exchange-Transport-CrossTenantHeadersStamped: BYAPR10MB2439
X-Proofpoint-Virus-Version: vendor=nai engine=6200 definitions=9928 signatures=668683
X-Proofpoint-Spam-Details: rule=notspam policy=default score=0 mlxscore=0 adultscore=0 malwarescore=0
 spamscore=0 phishscore=0 mlxlogscore=999 suspectscore=0 bulkscore=0
 classifier=spam adjust=0 reason=mlx scancount=1 engine=8.12.0-2009150000
 definitions=main-2103190107
X-Proofpoint-Virus-Version: vendor=nai engine=6200 definitions=9928 signatures=668683
X-Proofpoint-Spam-Details: rule=notspam policy=default score=0 suspectscore=0 impostorscore=0
 malwarescore=0 adultscore=0 mlxscore=0 clxscore=1011 mlxlogscore=999
 lowpriorityscore=0 phishscore=0 priorityscore=1501 spamscore=0 bulkscore=0
 classifier=spam adjust=0 reason=mlx scancount=1 engine=8.12.0-2009150000
 definitions=main-2103190107
Precedence: bulk
List-ID: <linux-nfs.vger.kernel.org>
X-Mailing-List: linux-nfs@vger.kernel.org

Hi Chris-

> On Mar 19, 2021, at 10:54 AM, Chris Down <chris@chrisdown.name> wrote:
>=20
> 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.
>=20
> 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.


> To allow users to more easily understand and debug these cases, add the
> number interpreted as ASCII if all characters are printable:
>=20
>    RPC: fragment too large: 1195725856 (ASCII "GET ")
>=20
> 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.
>=20
> Signed-off-by: Chris Down <chris@chrisdown.name>
> Cc: Chuck Lever <chuck.lever@oracle.com>
> Cc: J. Bruce Fields <bfields@redhat.com>
> Cc: Trond Myklebust <trond.myklebust@hammerspace.com>
> Cc: David S. Miller <davem@davemloft.net>
> ---
> net/sunrpc/svcsock.c | 39 +++++++++++++++++++++++++++++++++++++--
> 1 file changed, 37 insertions(+), 2 deletions(-)
>=20
> 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>
>=20
> #include <linux/sunrpc/types.h>
> #include <linux/sunrpc/clnt.h>
> @@ -863,6 +864,34 @@ static void svc_tcp_clear_pages(struct svc_sock *svs=
k)
> 	svsk->sk_datalen =3D 0;
> }
>=20
> +/* 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. Fo=
r
> + * example, if someone tries to send a HTTP GET request to us, we'll int=
erpret
> + * it as a 1195725856-sized fragment (ie. (u32)'GET '), and print a rate=
limited
> + * 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 nul=
l
> + * 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 =3D cpu_to_be32(svc_sock_reclen(svsk));
> +	char *len_be_ascii =3D (char *)&len_be;
> +	size_t i;
> +
> +	for (i =3D 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 *s=
vsk,
> 				   struct svc_rqst *rqstp)
> {
> 	ssize_t want, len;
> +	char *reclen_ascii;
>=20
> 	/* 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);
>=20
> err_too_large:
> -	net_notice_ratelimited("svc: %s %s RPC fragment too large: %d\n",
> +	reclen_ascii =3D 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;
> --=20
> 2.30.2
>=20

--
Chuck Lever