[PATCH] nbd-server: Silence server warnings on port probes

Eric Blake posted 1 patch 1 week ago
nbd/server.c | 26 +++++++++++++++++---------
1 file changed, 17 insertions(+), 9 deletions(-)
[PATCH] nbd-server: Silence server warnings on port probes
Posted by Eric Blake 1 week ago
While testing the use of qemu-nbd in a Pod of a Kubernetes cluster, I
got LOTS of log messages of the forms:

qemu-nbd: option negotiation failed: Failed to read flags: Unexpected end-of-file before all data were read
qemu-nbd: option negotiation failed: Failed to read flags: Unable to read from socket: Connection reset by peer

While it is nice to warn about clients that aren't following protocol
(in case it helps diagnosing bugs in those clients), a mere port probe
(where the client never write()s any bytes, and where we might even
hit EPIPE in trying to send our greeting to the client) is NOT
abnormal, but merely serves to pollute the log.  And Kubernetes
_really_ likes to do port probes to determine whether a given Pod is
up and running.

Easy ways to demonstrate the above port probes:
$ qemu-nbd -r -f raw path/to/file &
$ nc localhost 10809 </dev/null
$ bash -c 'exec </dev/tcp/localhost/10809'
$ kill $!

Silence the noise by not capturing errors until after our first
successful read() from a client.

Signed-off-by: Eric Blake <eblake@redhat.com>
---
 nbd/server.c | 26 +++++++++++++++++---------
 1 file changed, 17 insertions(+), 9 deletions(-)

diff --git a/nbd/server.c b/nbd/server.c
index c30e687fc8b..f64e47270c0 100644
--- a/nbd/server.c
+++ b/nbd/server.c
@@ -1150,8 +1150,8 @@ nbd_negotiate_meta_queries(NBDClient *client, Error **errp)
  * Return:
  * -errno  on error, errp is set
  * 0       on successful negotiation, errp is not set
- * 1       if client sent NBD_OPT_ABORT, i.e. on valid disconnect,
- *         errp is not set
+ * 1       if client sent NBD_OPT_ABORT (i.e. on valid disconnect) or never
+ *         wrote anything (i.e. port probe); errp is not set
  */
 static coroutine_fn int
 nbd_negotiate_options(NBDClient *client, Error **errp)
@@ -1175,8 +1175,13 @@ nbd_negotiate_options(NBDClient *client, Error **errp)
         ...           Rest of request
     */

-    if (nbd_read32(client->ioc, &flags, "flags", errp) < 0) {
-        return -EIO;
+    /*
+     * Intentionally ignore errors on this first read - we do not want
+     * to be noisy about a mere port probe, but only for clients that
+     * start talking the protocol and then quit abruptly.
+     */
+    if (nbd_read32(client->ioc, &flags, "flags", NULL) < 0) {
+        return 1;
     }
     client->mode = NBD_MODE_EXPORT_NAME;
     trace_nbd_negotiate_options_flags(flags);
@@ -1383,8 +1388,8 @@ nbd_negotiate_options(NBDClient *client, Error **errp)
  * Return:
  * -errno  on error, errp is set
  * 0       on successful negotiation, errp is not set
- * 1       if client sent NBD_OPT_ABORT, i.e. on valid disconnect,
- *         errp is not set
+ * 1       if client sent NBD_OPT_ABORT (i.e. on valid disconnect) or never
+ *         wrote anything (i.e. port probe); errp is not set
  */
 static coroutine_fn int nbd_negotiate(NBDClient *client, Error **errp)
 {
@@ -1415,9 +1420,12 @@ static coroutine_fn int nbd_negotiate(NBDClient *client, Error **errp)
     stq_be_p(buf + 8, NBD_OPTS_MAGIC);
     stw_be_p(buf + 16, NBD_FLAG_FIXED_NEWSTYLE | NBD_FLAG_NO_ZEROES);

-    if (nbd_write(client->ioc, buf, 18, errp) < 0) {
-        error_prepend(errp, "write failed: ");
-        return -EINVAL;
+    /*
+     * Be silent about failure to write our greeting: there is nothing
+     * wrong with a client testing if our port is alive.
+     */
+    if (nbd_write(client->ioc, buf, 18, NULL) < 0) {
+        return 1;
     }
     ret = nbd_negotiate_options(client, errp);
     if (ret != 0) {
-- 
2.47.0
Re: [PATCH] nbd-server: Silence server warnings on port probes
Posted by Eric Blake 4 days, 21 hours ago
On Fri, Nov 15, 2024 at 01:55:53PM -0600, Eric Blake wrote:
> While testing the use of qemu-nbd in a Pod of a Kubernetes cluster, I
> got LOTS of log messages of the forms:
> 
> qemu-nbd: option negotiation failed: Failed to read flags: Unexpected end-of-file before all data were read
> qemu-nbd: option negotiation failed: Failed to read flags: Unable to read from socket: Connection reset by peer
> 
> While it is nice to warn about clients that aren't following protocol
> (in case it helps diagnosing bugs in those clients), a mere port probe
> (where the client never write()s any bytes, and where we might even
> hit EPIPE in trying to send our greeting to the client) is NOT
> abnormal, but merely serves to pollute the log.  And Kubernetes
> _really_ likes to do port probes to determine whether a given Pod is
> up and running.
> 
> Easy ways to demonstrate the above port probes:
> $ qemu-nbd -r -f raw path/to/file &
> $ nc localhost 10809 </dev/null
> $ bash -c 'exec </dev/tcp/localhost/10809'
> $ kill $!
> 
> Silence the noise by not capturing errors until after our first
> successful read() from a client.
> 
> Signed-off-by: Eric Blake <eblake@redhat.com>
> ---
>  nbd/server.c | 26 +++++++++++++++++---------
>  1 file changed, 17 insertions(+), 9 deletions(-)

In testing this as a potential candidate for -rc1, I'm seeing iotests
failures in `./check 094 119 -nbd` both pre- and post-patch.
Bisecting now to see if I can find where those tests started
regressing (looks like a timing change; a "return" line is swapping
place with a SHUTDOWN event line in the QMP output).

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.
Virtualization:  qemu.org | libguestfs.org
Re: [PATCH] nbd-server: Silence server warnings on port probes
Posted by Eric Blake 4 days, 19 hours ago
On Mon, Nov 18, 2024 at 11:08:51AM -0600, Eric Blake wrote:
> On Fri, Nov 15, 2024 at 01:55:53PM -0600, Eric Blake wrote:
> > While testing the use of qemu-nbd in a Pod of a Kubernetes cluster, I
> > got LOTS of log messages of the forms:
> > 
> > qemu-nbd: option negotiation failed: Failed to read flags: Unexpected end-of-file before all data were read
> > qemu-nbd: option negotiation failed: Failed to read flags: Unable to read from socket: Connection reset by peer
> > 

> In testing this as a potential candidate for -rc1, I'm seeing iotests
> failures in `./check 094 119 -nbd` both pre- and post-patch.
> Bisecting now to see if I can find where those tests started
> regressing (looks like a timing change; a "return" line is swapping
> place with a SHUTDOWN event line in the QMP output).

Huh - I'm seeing those same two tests fail on a vanilla v0.9.0
checkout; therefore, this is probably a long-standing regression, and
certainly not something introduced by this patch.

-- 
Eric Blake, Principal Software Engineer
Red Hat, Inc.
Virtualization:  qemu.org | libguestfs.org
Re: [PATCH] nbd-server: Silence server warnings on port probes
Posted by Vladimir Sementsov-Ogievskiy 5 days, 7 hours ago
On 15.11.24 22:55, Eric Blake wrote:
> While testing the use of qemu-nbd in a Pod of a Kubernetes cluster, I
> got LOTS of log messages of the forms:
> 
> qemu-nbd: option negotiation failed: Failed to read flags: Unexpected end-of-file before all data were read
> qemu-nbd: option negotiation failed: Failed to read flags: Unable to read from socket: Connection reset by peer
> 
> While it is nice to warn about clients that aren't following protocol
> (in case it helps diagnosing bugs in those clients), a mere port probe
> (where the client never write()s any bytes, and where we might even
> hit EPIPE in trying to send our greeting to the client) is NOT
> abnormal, but merely serves to pollute the log.  And Kubernetes
> really  likes to do port probes to determine whether a given Pod is
> up and running.
> 
> Easy ways to demonstrate the above port probes:
> $ qemu-nbd -r -f raw path/to/file &
> $ nc localhost 10809 </dev/null
> $ bash -c 'exec </dev/tcp/localhost/10809'
> $ kill $!
> 
> Silence the noise by not capturing errors until after our first
> successful read() from a client.
> 
> Signed-off-by: Eric Blake<eblake@redhat.com>

Reviewed-by: Vladimir Sementsov-Ogievskiy <vsementsov@yandex-team.ru>

-- 
Best regards,
Vladimir