[Qemu-devel] [PATCH v2 0/2] libqos: use microseconds instead of iterations for virtio timeout

[Qemu-devel] [PATCH v2 0/2] libqos: use microseconds instead of iterations for virtio timeout

[Stefan Hajnoczi]

v2:
 * Implement "no interrupt" test properly, added Patch 1 [Peter]

Fix the race condition that leads to Travis "make check" failures.

Stefan Hajnoczi (2):
  libqos: improve event_index test with timeout
  libqos: use microseconds instead of iterations for virtio timeout

 tests/libqos/virtio.c   | 50 ++++++++++++++++++++++++++++++++------------
 tests/libqos/virtio.h   | 13 ++++++++----
 tests/virtio-blk-test.c | 55 +++++++++++++++++++++++--------------------------
 3 files changed, 72 insertions(+), 46 deletions(-)

-- 
1.9.3

[Qemu-devel] [PATCH v2 1/2] libqos: improve event_index test with timeout

[Stefan Hajnoczi]

The virtio event_index feature lets the device driver tell the device
how many requests to process before raising the next interrupt.
virtio-blk-test.c tries to verify that the device does not raise an
interrupt unnecessarily.

Unfortunately the test has a race condition.  It spins checking for an
interrupt up to 100 times and then assumes the request has finished.  On
a slow host the I/O request could still be in flight and the test would
fail.

This patch waits for the request to complete, or until a 30-second
timeout is reached.  If an interrupt is raised while waiting the test
fails since the device was not supposed to raise interrupts.

Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 tests/libqos/virtio.c   | 22 ++++++++++++++++++++++
 tests/libqos/virtio.h   |  5 +++++
 tests/virtio-blk-test.c |  8 ++++----
 3 files changed, 31 insertions(+), 4 deletions(-)

diff --git a/tests/libqos/virtio.c b/tests/libqos/virtio.c
index 9b6de2c..009325d 100644
--- a/tests/libqos/virtio.c
+++ b/tests/libqos/virtio.c
@@ -91,6 +91,28 @@ bool qvirtio_wait_queue_isr(const QVirtioBus *bus, QVirtioDevice *d,
     return timeout != 0;
 }
 
+/* Wait for the status byte at given guest memory address to be set
+ *
+ * The virtqueue interrupt must not be raised, making this useful for testing
+ * event_index functionality.
+ */
+uint8_t qvirtio_wait_status_byte_no_isr(const QVirtioBus *bus,
+                                        QVirtioDevice *d,
+                                        QVirtQueue *vq,
+                                        uint64_t addr,
+                                        gint64 timeout_us)
+{
+    gint64 start_time = g_get_monotonic_time();
+    uint8_t val;
+
+    while ((val = readb(addr)) == 0xff) {
+        clock_step(100);
+        g_assert(!bus->get_queue_isr_status(d, vq));
+        g_assert(g_get_monotonic_time() - start_time <= timeout_us);
+    }
+    return val;
+}
+
 bool qvirtio_wait_config_isr(const QVirtioBus *bus, QVirtioDevice *d,
                                                             uint64_t timeout)
 {
diff --git a/tests/libqos/virtio.h b/tests/libqos/virtio.h
index 70b3376..bc7518e 100644
--- a/tests/libqos/virtio.h
+++ b/tests/libqos/virtio.h
@@ -162,6 +162,11 @@ void qvirtio_set_driver_ok(const QVirtioBus *bus, QVirtioDevice *d);
 
 bool qvirtio_wait_queue_isr(const QVirtioBus *bus, QVirtioDevice *d,
                                             QVirtQueue *vq, uint64_t timeout);
+uint8_t qvirtio_wait_status_byte_no_isr(const QVirtioBus *bus,
+                                        QVirtioDevice *d,
+                                        QVirtQueue *vq,
+                                        uint64_t addr,
+                                        gint64 timeout_us);
 bool qvirtio_wait_config_isr(const QVirtioBus *bus, QVirtioDevice *d,
                                                             uint64_t timeout);
 QVirtQueue *qvirtqueue_setup(const QVirtioBus *bus, QVirtioDevice *d,
diff --git a/tests/virtio-blk-test.c b/tests/virtio-blk-test.c
index 588666c..0e3bfa7 100644
--- a/tests/virtio-blk-test.c
+++ b/tests/virtio-blk-test.c
@@ -42,6 +42,7 @@
 
 #define TEST_IMAGE_SIZE         (64 * 1024 * 1024)
 #define QVIRTIO_BLK_TIMEOUT     100
+#define QVIRTIO_BLK_TIMEOUT_US  (30 * 1000 * 1000)
 #define PCI_SLOT                0x04
 #define PCI_FN                  0x00
 
@@ -595,10 +596,9 @@ static void pci_idx(void)
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
     /* No notification expected */
-    g_assert(!qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
-
-    status = readb(req_addr + 528);
+    status = qvirtio_wait_status_byte_no_isr(&qvirtio_pci, &dev->vdev,
+                                             &vqpci->vq, req_addr + 528,
+                                             QVIRTIO_BLK_TIMEOUT_US);
     g_assert_cmpint(status, ==, 0);
 
     guest_free(alloc, req_addr);
-- 
1.9.3

[Qemu-devel] [PATCH v2 2/2] libqos: use microseconds instead of iterations for virtio timeout

[Stefan Hajnoczi]

Some hosts are slow or overloaded so test execution takes a long time.
Test cases use timeouts to protect against an infinite loop stalling the
test forever (especially important in automated test setups).

Commit 6cd14054b67774cc58a51fca6660cfa1d3c08059 ("libqos virtio:
Increase ISR timeout") increased the clock_step() value in an attempt to
lengthen the virtio interrupt wait timeout, but timeout failures are
still occuring on the Travis automated testing platform.

This is because clock_step() only affects the guest's virtual time.
Virtio requests can be bottlenecked on host disk I/O latency - which
cannot be improved by stepping the clock, so the fix was ineffective.

This patch changes the qvirtio_wait_queue_isr() and
qvirtio_wait_config_isr() timeout mechanism from loop iterations to
microseconds.  This way the test case can specify an absolute 30 second
timeout.  Number of loop iterations is not a reliable timeout mechanism
since the speed depends on many factors including host performance.

Tests should no longer timeout on overloaded Travis instances.

Cc: Marc Marí <marc.mari.barcelo@gmail.com>
Reported-by: Peter Maydell <peter.maydell@linaro.org>
Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 tests/libqos/virtio.c   | 30 ++++++++++++++++--------------
 tests/libqos/virtio.h   |  8 ++++----
 tests/virtio-blk-test.c | 47 ++++++++++++++++++++++-------------------------
 3 files changed, 42 insertions(+), 43 deletions(-)

diff --git a/tests/libqos/virtio.c b/tests/libqos/virtio.c
index 009325d..a061289 100644
--- a/tests/libqos/virtio.c
+++ b/tests/libqos/virtio.c
@@ -78,17 +78,18 @@ void qvirtio_set_driver_ok(const QVirtioBus *bus, QVirtioDevice *d)
                 QVIRTIO_DRIVER_OK | QVIRTIO_DRIVER | QVIRTIO_ACKNOWLEDGE);
 }
 
-bool qvirtio_wait_queue_isr(const QVirtioBus *bus, QVirtioDevice *d,
-                                            QVirtQueue *vq, uint64_t timeout)
+void qvirtio_wait_queue_isr(const QVirtioBus *bus, QVirtioDevice *d,
+                            QVirtQueue *vq, gint64 timeout_us)
 {
-    do {
+    gint64 start_time = g_get_monotonic_time();
+
+    for (;;) {
         clock_step(100);
         if (bus->get_queue_isr_status(d, vq)) {
-            break; /* It has ended */
+            return;
         }
-    } while (--timeout);
-
-    return timeout != 0;
+        g_assert(g_get_monotonic_time() - start_time <= timeout_us);
+    }
 }
 
 /* Wait for the status byte at given guest memory address to be set
@@ -113,17 +114,18 @@ uint8_t qvirtio_wait_status_byte_no_isr(const QVirtioBus *bus,
     return val;
 }
 
-bool qvirtio_wait_config_isr(const QVirtioBus *bus, QVirtioDevice *d,
-                                                            uint64_t timeout)
+void qvirtio_wait_config_isr(const QVirtioBus *bus, QVirtioDevice *d,
+                             gint64 timeout_us)
 {
-    do {
+    gint64 start_time = g_get_monotonic_time();
+
+    for (;;) {
         clock_step(100);
         if (bus->get_config_isr_status(d)) {
-            break; /* It has ended */
+            return;
         }
-    } while (--timeout);
-
-    return timeout != 0;
+        g_assert(g_get_monotonic_time() - start_time <= timeout_us);
+    }
 }
 
 void qvring_init(const QGuestAllocator *alloc, QVirtQueue *vq, uint64_t addr)
diff --git a/tests/libqos/virtio.h b/tests/libqos/virtio.h
index bc7518e..29fbacb 100644
--- a/tests/libqos/virtio.h
+++ b/tests/libqos/virtio.h
@@ -160,15 +160,15 @@ void qvirtio_set_acknowledge(const QVirtioBus *bus, QVirtioDevice *d);
 void qvirtio_set_driver(const QVirtioBus *bus, QVirtioDevice *d);
 void qvirtio_set_driver_ok(const QVirtioBus *bus, QVirtioDevice *d);
 
-bool qvirtio_wait_queue_isr(const QVirtioBus *bus, QVirtioDevice *d,
-                                            QVirtQueue *vq, uint64_t timeout);
+void qvirtio_wait_queue_isr(const QVirtioBus *bus, QVirtioDevice *d,
+                            QVirtQueue *vq, gint64 timeout_us);
 uint8_t qvirtio_wait_status_byte_no_isr(const QVirtioBus *bus,
                                         QVirtioDevice *d,
                                         QVirtQueue *vq,
                                         uint64_t addr,
                                         gint64 timeout_us);
-bool qvirtio_wait_config_isr(const QVirtioBus *bus, QVirtioDevice *d,
-                                                            uint64_t timeout);
+void qvirtio_wait_config_isr(const QVirtioBus *bus, QVirtioDevice *d,
+                             gint64 timeout_us);
 QVirtQueue *qvirtqueue_setup(const QVirtioBus *bus, QVirtioDevice *d,
                                         QGuestAllocator *alloc, uint16_t index);
 
diff --git a/tests/virtio-blk-test.c b/tests/virtio-blk-test.c
index 0e3bfa7..5ce6e79 100644
--- a/tests/virtio-blk-test.c
+++ b/tests/virtio-blk-test.c
@@ -41,7 +41,6 @@
 #define QVIRTIO_BLK_T_GET_ID        8
 
 #define TEST_IMAGE_SIZE         (64 * 1024 * 1024)
-#define QVIRTIO_BLK_TIMEOUT     100
 #define QVIRTIO_BLK_TIMEOUT_US  (30 * 1000 * 1000)
 #define PCI_SLOT                0x04
 #define PCI_FN                  0x00
@@ -184,8 +183,8 @@ static void pci_basic(void)
     qvirtqueue_add(&vqpci->vq, req_addr + 528, 1, true, false);
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
 
@@ -206,8 +205,8 @@ static void pci_basic(void)
 
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
 
@@ -234,8 +233,8 @@ static void pci_basic(void)
 
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
 
@@ -257,8 +256,8 @@ static void pci_basic(void)
 
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
 
@@ -330,8 +329,8 @@ static void pci_indirect(void)
     free_head = qvirtqueue_add_indirect(&vqpci->vq, indirect);
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
 
@@ -355,8 +354,8 @@ static void pci_indirect(void)
     free_head = qvirtqueue_add_indirect(&vqpci->vq, indirect);
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
 
@@ -397,8 +396,7 @@ static void pci_config(void)
 
     qmp("{ 'execute': 'block_resize', 'arguments': { 'device': 'drive0', "
                                                     " 'size': %d } }", n_size);
-    g_assert(qvirtio_wait_config_isr(&qvirtio_pci, &dev->vdev,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_config_isr(&qvirtio_pci, &dev->vdev, QVIRTIO_BLK_TIMEOUT_US);
 
     capacity = qvirtio_config_readq(&qvirtio_pci, &dev->vdev, addr);
     g_assert_cmpint(capacity, ==, n_size / 512);
@@ -453,8 +451,7 @@ static void pci_msix(void)
     qmp("{ 'execute': 'block_resize', 'arguments': { 'device': 'drive0', "
                                                     " 'size': %d } }", n_size);
 
-    g_assert(qvirtio_wait_config_isr(&qvirtio_pci, &dev->vdev,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_config_isr(&qvirtio_pci, &dev->vdev, QVIRTIO_BLK_TIMEOUT_US);
 
     capacity = qvirtio_config_readq(&qvirtio_pci, &dev->vdev, addr);
     g_assert_cmpint(capacity, ==, n_size / 512);
@@ -474,8 +471,8 @@ static void pci_msix(void)
     qvirtqueue_add(&vqpci->vq, req_addr + 528, 1, true, false);
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
 
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
@@ -498,8 +495,8 @@ static void pci_msix(void)
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
 
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
@@ -575,8 +572,8 @@ static void pci_idx(void)
     qvirtqueue_add(&vqpci->vq, req_addr + 528, 1, true, false);
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
 
     /* Write request */
     req.type = QVIRTIO_BLK_T_OUT;
@@ -619,8 +616,8 @@ static void pci_idx(void)
     qvirtqueue_kick(&qvirtio_pci, &dev->vdev, &vqpci->vq, free_head);
 
 
-    g_assert(qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
-                                                        QVIRTIO_BLK_TIMEOUT));
+    qvirtio_wait_queue_isr(&qvirtio_pci, &dev->vdev, &vqpci->vq,
+                           QVIRTIO_BLK_TIMEOUT_US);
 
     status = readb(req_addr + 528);
     g_assert_cmpint(status, ==, 0);
-- 
1.9.3

Re: [Qemu-devel] [PATCH v2 0/2] libqos: use microseconds instead of iterations for virtio timeout

[Paolo Bonzini]

Il 29/09/2014 17:40, Stefan Hajnoczi ha scritto:
> v2:
>  * Implement "no interrupt" test properly, added Patch 1 [Peter]
> 
> Fix the race condition that leads to Travis "make check" failures.
> 
> Stefan Hajnoczi (2):
>   libqos: improve event_index test with timeout
>   libqos: use microseconds instead of iterations for virtio timeout
> 
>  tests/libqos/virtio.c   | 50 ++++++++++++++++++++++++++++++++------------
>  tests/libqos/virtio.h   | 13 ++++++++----
>  tests/virtio-blk-test.c | 55 +++++++++++++++++++++++--------------------------
>  3 files changed, 72 insertions(+), 46 deletions(-)
> 

Reviewed-by: Paolo Bonzini <pbonzini@redhat.com>

Re: [Qemu-devel] [PATCH v2 0/2] libqos: use microseconds instead of iterations for virtio timeout

[Peter Maydell]

On 29 September 2014 16:40, Stefan Hajnoczi <stefanha@redhat.com> wrote:
> v2:
>  * Implement "no interrupt" test properly, added Patch 1 [Peter]
>
> Fix the race condition that leads to Travis "make check" failures.
>
> Stefan Hajnoczi (2):
>   libqos: improve event_index test with timeout
>   libqos: use microseconds instead of iterations for virtio timeout
>
>  tests/libqos/virtio.c   | 50 ++++++++++++++++++++++++++++++++------------
>  tests/libqos/virtio.h   | 13 ++++++++----
>  tests/virtio-blk-test.c | 55 +++++++++++++++++++++++--------------------------
>  3 files changed, 72 insertions(+), 46 deletions(-)

Applied, thanks.

-- PMM

Re: [Qemu-devel] [PATCH v2 1/2] libqos: improve event_index test with timeout

[Peter Maydell]

On 29 September 2014 16:40, Stefan Hajnoczi <stefanha@redhat.com> wrote:
> The virtio event_index feature lets the device driver tell the device
> how many requests to process before raising the next interrupt.
> virtio-blk-test.c tries to verify that the device does not raise an
> interrupt unnecessarily.
>
> Unfortunately the test has a race condition.  It spins checking for an
> interrupt up to 100 times and then assumes the request has finished.  On
> a slow host the I/O request could still be in flight and the test would
> fail.
>
> This patch waits for the request to complete, or until a 30-second
> timeout is reached.  If an interrupt is raised while waiting the test
> fails since the device was not supposed to raise interrupts.
>
> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>

Hi; just noticed this breaks 'make check' build on MacOSX:

/Users/pm215/src/qemu/tests/libqos/virtio.c:84:25: warning: implicit
declaration of function
      'g_get_monotonic_time' is invalid in C99 [-Wimplicit-function-declaration]
    gint64 start_time = g_get_monotonic_time();
                        ^
(and subsequent linker error).

g_get_monotonic_time() only appeared in glib 2.28, and our
minimum is 2.12.

thanks
-- PMM

Re: [Qemu-devel] [PATCH v2 1/2] libqos: improve event_index test with timeout

[Peter Maydell]

On 11 October 2014 12:43, Peter Maydell <peter.maydell@linaro.org> wrote:
> Hi; just noticed this breaks 'make check' build on MacOSX:
>
> /Users/pm215/src/qemu/tests/libqos/virtio.c:84:25: warning: implicit
> declaration of function
>       'g_get_monotonic_time' is invalid in C99 [-Wimplicit-function-declaration]
>     gint64 start_time = g_get_monotonic_time();
>                         ^
> (and subsequent linker error).
>
> g_get_monotonic_time() only appeared in glib 2.28, and our
> minimum is 2.12.

vhost-user-test.c has a helper function that has a fallback
for not having g_get_monotonic_time(); we probably want to
put that somewhere more generally accessible.

-- PMM