Re: [PATCH v6] Work around vhost-user-blk-test hang

[Raphael Norwitz <raphael.norwitz@nutanix.com>]

On Mon, Oct 18, 2021 at 05:50:41PM -0400, Michael S. Tsirkin wrote:
> On Thu, Oct 14, 2021 at 04:32:23AM +0000, Raphael Norwitz wrote:
> > The vhost-user-blk-test qtest has been hanging intermittently for a
> > while. The root cause is not yet fully understood, but the hang is
> > impacting enough users that it is important to merge a workaround for
> > it.
> > 
> > The race which causes the hang occurs early on in vhost-user setup,
> > where a vhost-user message is never received by the backend. Forcing
> > QEMU to wait until the storage-daemon has had some time to initialize
> > prevents the hang. Thus the existing storage-daemon pidfile option can
> > be used to implement a workaround cleanly and effectively, since it
> > creates a file only once the storage-daemon initialization is complete.
> > 
> > This change implements a workaround for the vhost-user-blk-test hang by
> > making QEMU wait until the storage-daemon has written out a pidfile
> > before attempting to connect and send messages over the vhost-user
> > socket.
> > 
> > Some relevent mailing list discussions:
> > 
> > [1] https://urldefense.proofpoint.com/v2/url?u=https-3A__lore.kernel.org_qemu-2Ddevel_CAFEAcA8kYpz9LiPNxnWJAPSjc-3Dnv532bEdyfynaBeMeohqBp3A-40mail.gmail.com_&d=DwIBAg&c=s883GpUCOChKOHiocYtGcg&r=In4gmR1pGzKB8G5p6LUrWqkSMec2L5EtXZow_FZNJZk&m=eDRDFhe3H61BSSpDvy3PKzwQIa2grX5hNMhigtjMCJ8&s=c6OKIl0NMsDqP0-ZNnVjHhDq2psXIVszz-uBKw_8pEo&e= 
> > [2] https://urldefense.proofpoint.com/v2/url?u=https-3A__lore.kernel.org_qemu-2Ddevel_YWaky-252FKVbS-252FKZjlV-40stefanha-2Dx1.localdomain_&d=DwIBAg&c=s883GpUCOChKOHiocYtGcg&r=In4gmR1pGzKB8G5p6LUrWqkSMec2L5EtXZow_FZNJZk&m=eDRDFhe3H61BSSpDvy3PKzwQIa2grX5hNMhigtjMCJ8&s=B4EM_0f7TXqsh18YEKOg-cFHabUjsVA5Ie1riDXaB7A&e= 
> > 
> > Signed-off-by: Raphael Norwitz <raphael.norwitz@nutanix.com>
> > Reviewed-by: Eric Blake <eblake@redhat.com>
> 
> 
> Um. Does not seem to make things better for me:
> 
> **
> ERROR:../tests/qtest/vhost-user-blk-test.c:950:start_vhost_user_blk: assertion failed (retries < PIDFILE_RETRIES): (5 < 5)
> ERROR qtest-x86_64/qos-test - Bail out! ERROR:../tests/qtest/vhost-user-blk-test.c:950:start_vhost_user_blk: assertion failed (retries < PIDFILE_RETRIES): (5 < 5)
> 
> At this point I just disabled the test in meson. No need to make
> everyone suffer.

Makes sense. Do you still want to persue the workaround?

If so, can you share some details on how you're running the test?

I've gone through 1000+ iterations using the script I posted here:
https://lore.kernel.org/qemu-devel/20210827165253.GA14291@raphael-debian-dev/
without hitting a failure.

>
> 
> > ---
> >  tests/qtest/vhost-user-blk-test.c | 29 ++++++++++++++++++++++++++++-
> >  1 file changed, 28 insertions(+), 1 deletion(-)
> > 
> > diff --git a/tests/qtest/vhost-user-blk-test.c b/tests/qtest/vhost-user-blk-test.c
> > index 6f108a1b62..c6626a286b 100644
> > --- a/tests/qtest/vhost-user-blk-test.c
> > +++ b/tests/qtest/vhost-user-blk-test.c
> > @@ -24,6 +24,7 @@
> >  #define TEST_IMAGE_SIZE         (64 * 1024 * 1024)
> >  #define QVIRTIO_BLK_TIMEOUT_US  (30 * 1000 * 1000)
> >  #define PCI_SLOT_HP             0x06
> > +#define PIDFILE_RETRIES         5
> >  
> >  typedef struct {
> >      pid_t pid;
> 
> 
> Don't like the arbitrary retries counter.
> 
> Let's warn maybe, but on a busy machine we might not complete this
> in time ...

So you would like it to warn and keep trying forever? Or would you
rather set a much more lenient deadline? (1 min? 5 min?)

> 
> 
> > @@ -885,7 +886,8 @@ static void start_vhost_user_blk(GString *cmd_line, int vus_instances,
> >                                   int num_queues)
> >  {
> >      const char *vhost_user_blk_bin = qtest_qemu_storage_daemon_binary();
> > -    int i;
> > +    int i, retries;
> > +    char *daemon_pidfile_path;
> >      gchar *img_path;
> >      GString *storage_daemon_command = g_string_new(NULL);
> >      QemuStorageDaemonState *qsd;
> > @@ -898,6 +900,8 @@ static void start_vhost_user_blk(GString *cmd_line, int vus_instances,
> >              " -object memory-backend-memfd,id=mem,size=256M,share=on "
> >              " -M memory-backend=mem -m 256M ");
> >  
> > +    daemon_pidfile_path = g_strdup_printf("/tmp/daemon-%d", getpid());
> > +
> 
> Ugh. Predictable paths directly in /tmp are problematic .. mktemp?
> 

Ack

> >      for (i = 0; i < vus_instances; i++) {
> >          int fd;
> >          char *sock_path = create_listen_socket(&fd);
> > @@ -914,6 +918,9 @@ static void start_vhost_user_blk(GString *cmd_line, int vus_instances,
> >                                 i + 1, sock_path);
> >      }
> >  
> > +    g_string_append_printf(storage_daemon_command, "--pidfile %s ",
> > +                           daemon_pidfile_path);
> > +
> >      g_test_message("starting vhost-user backend: %s",
> >                     storage_daemon_command->str);
> >      pid_t pid = fork();
> > @@ -930,7 +937,27 @@ static void start_vhost_user_blk(GString *cmd_line, int vus_instances,
> >          execlp("/bin/sh", "sh", "-c", storage_daemon_command->str, NULL);
> >          exit(1);
> >      }
> > +
> > +    /*
> > +     * FIXME: The loop here ensures the storage-daemon has come up properly
> > +     *        before allowing the test to proceed. This is a workaround for
> > +     *        a race which used to cause the vhost-user-blk-test to hang. It
> > +     *        should be deleted once the root cause is fully understood and
> > +     *        fixed.
> > +     */
> > +    retries = 0;
> > +    while (access(daemon_pidfile_path, F_OK) != 0) {
> > +        g_assert_cmpint(retries, <, PIDFILE_RETRIES);
> > +
> > +        retries++;
> > +        g_usleep(1000);
> > +    }
> > +
> >      g_string_free(storage_daemon_command, true);
> > +    if (access(daemon_pidfile_path, F_OK) == 0) {
> > +        unlink(daemon_pidfile_path);
> > +    }
> > +    g_free(daemon_pidfile_path);
> >  
> >      qsd = g_new(QemuStorageDaemonState, 1);
> >      qsd->pid = pid;
> > -- 
> > 2.20.1
>