[Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Ed Swierk]

Recently I noticed that when I configure a virtio-scsi-pci device
using an iothread, as soon as the guest virtio-scsi driver loads, the
iothread spins at 100%:

  -object iothread,id=iothread1 -device virtio-scsi-pci,iothread=iothread1

This occurs whether or not a disk is attached, with either
poll-max-ns=0 or poll-max-ns=32768, and with Linux 3.13, 4.1 and 4.4
guests. The iothread stops spinning as soon as the guest driver is
unloaded.

I bisected the issue to commit 684e508c23d28af8d6ed2c62738a0f60447c8274:

  aio: add .io_poll_begin/end() callbacks

It doesn't seem to affect performance, but obviously consuming CPU
cycles when there's no disk attached is undesirable. Is this an
expected side effect of implementing iothread polling? Is there a way
to revert to the old non-polling behavior?

--Ed

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Ed Swierk]

On Wed, Feb 8, 2017 at 8:33 AM, Ed Swierk <eswierk@skyportsystems.com> wrote:
> Recently I noticed that when I configure a virtio-scsi-pci device
> using an iothread, as soon as the guest virtio-scsi driver loads, the
> iothread spins at 100%:
>
>   -object iothread,id=iothread1 -device virtio-scsi-pci,iothread=iothread1
>
> This occurs whether or not a disk is attached, with either
> poll-max-ns=0 or poll-max-ns=32768, and with Linux 3.13, 4.1 and 4.4
> guests. The iothread stops spinning as soon as the guest driver is
> unloaded.
>
> I bisected the issue to commit 684e508c23d28af8d6ed2c62738a0f60447c8274:
>
>   aio: add .io_poll_begin/end() callbacks
>
> It doesn't seem to affect performance, but obviously consuming CPU
> cycles when there's no disk attached is undesirable. Is this an
> expected side effect of implementing iothread polling? Is there a way
> to revert to the old non-polling behavior?

FWIW, changing

  return run_poll_handlers_once(ctx);

to

  return false;

in try_poll_mode() in aio-posix.c makes the iothread stop spinning,
but I don't know what damage this will cause.

--Ed

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Fam Zheng]

On Wed, 02/08 08:33, Ed Swierk wrote:
> Recently I noticed that when I configure a virtio-scsi-pci device
> using an iothread, as soon as the guest virtio-scsi driver loads, the
> iothread spins at 100%:
> 
>   -object iothread,id=iothread1 -device virtio-scsi-pci,iothread=iothread1
> 
> This occurs whether or not a disk is attached, with either
> poll-max-ns=0 or poll-max-ns=32768, and with Linux 3.13, 4.1 and 4.4
> guests. The iothread stops spinning as soon as the guest driver is
> unloaded.
> 
> I bisected the issue to commit 684e508c23d28af8d6ed2c62738a0f60447c8274:
> 
>   aio: add .io_poll_begin/end() callbacks
> 
> It doesn't seem to affect performance, but obviously consuming CPU
> cycles when there's no disk attached is undesirable. Is this an
> expected side effect of implementing iothread polling?

No, something is wrong. The polling shouldn't keep running when there is no I/O
activity.

Can you try "perf top" to see what poll handlers are spinning?

Fam

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Ed Swierk]

On Wed, Feb 8, 2017 at 5:47 PM, Fam Zheng <famz@redhat.com> wrote:
> No, something is wrong. The polling shouldn't keep running when there is no I/O
> activity.
>
> Can you try "perf top" to see what poll handlers are spinning?

Samples: 288K of event 'cycles', Event count (approx.): 57149970643
Overhead  Shared Object            Symbol
  16.96%  qemu-system-x86_64       [.] lduw_le_phys
  15.77%  [vdso]                   [.] __vdso_clock_gettime
   7.25%  qemu-system-x86_64       [.] qemu_lockcnt_cmpxchg_or_wait
   7.16%  qemu-system-x86_64       [.] aio_poll
   3.94%  qemu-system-x86_64       [.] address_space_translate
   3.69%  qemu-system-x86_64       [.] qemu_lockcnt_dec
   3.46%  qemu-system-x86_64       [.] virtio_queue_host_notifier_aio_poll
   3.32%  qemu-system-x86_64       [.] address_space_translate_internal
   2.54%  qemu-system-x86_64       [.] run_poll_handlers_once
   2.54%  libpthread-2.19.so       [.] pthread_mutex_lock
   2.53%  libpthread-2.19.so       [.] __pthread_mutex_unlock_usercnt
   2.53%  qemu-system-x86_64       [.] aio_notify_accept
   2.40%  qemu-system-x86_64       [.] timerlist_deadline_ns
   2.38%  qemu-system-x86_64       [.] address_space_lookup_region
   2.23%  qemu-system-x86_64       [.] timerlistgroup_deadline_ns
   2.21%  qemu-system-x86_64       [.] qemu_lockcnt_inc
   2.08%  qemu-system-x86_64       [.] qemu_clock_get_ns
   1.91%  qemu-system-x86_64       [.] object_dynamic_cast_assert
   1.54%  qemu-system-x86_64       [.] virtio_queue_notify_aio_vq.part.16
   1.21%  qemu-system-x86_64       [.] qemu_map_ram_ptr
   1.16%  libc-2.19.so             [.] __clock_gettime
   1.02%  qemu-system-x86_64       [.] event_notifier_poll
   1.02%  qemu-system-x86_64       [.] timerlistgroup_run_timers
   1.02%  qemu-system-x86_64       [.] virtio_queue_set_notification
   0.82%  qemu-system-x86_64       [.] aio_bh_poll
   0.81%  qemu-system-x86_64       [.] timerlist_run_timers
   0.70%  qemu-system-x86_64       [.] aio_dispatch
   0.66%  qemu-system-x86_64       [.] virtio_queue_empty.part.32
   0.62%  qemu-system-x86_64       [.] aio_compute_timeout
   0.50%  qemu-system-x86_64       [.] virtio_scsi_data_plane_handle_event
   0.32%  qemu-system-x86_64       [.] clock_gettime@plt
   0.26%  qemu-system-x86_64       [.] memory_region_is_ram_device
   0.21%  qemu-system-x86_64       [.] qemu_mutex_unlock
   0.12%  qemu-system-x86_64       [.] aio_context_acquire
   0.12%  qemu-system-x86_64       [.] iothread_run
   0.12%  qemu-system-x86_64       [.] qemu_lockcnt_count
   0.11%  qemu-system-x86_64       [.] pthread_mutex_lock@plt
   0.11%  qemu-system-x86_64       [.] qemu_mutex_lock
   0.11%  [kernel]                 [k] vmx_vcpu_run
   0.10%  libpthread-2.19.so       [.] pthread_mutex_unlock
   0.09%  qemu-system-x86_64       [.] aio_context_release
   0.09%  qemu-system-x86_64       [.] pthread_mutex_unlock@plt
   0.09%  [kernel]                 [k] native_write_msr_safe
   0.08%  [kernel]                 [k] ksm_do_scan
   0.07%  qemu-system-x86_64       [.] virtio_scsi_handle_event_vq

--Ed

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Fam Zheng]

On Wed, 02/08 18:11, Ed Swierk wrote:
> On Wed, Feb 8, 2017 at 5:47 PM, Fam Zheng <famz@redhat.com> wrote:
> > No, something is wrong. The polling shouldn't keep running when there is no I/O
> > activity.
> >
> > Can you try "perf top" to see what poll handlers are spinning?
> 
> Samples: 288K of event 'cycles', Event count (approx.): 57149970643
> Overhead  Shared Object            Symbol
>   16.96%  qemu-system-x86_64       [.] lduw_le_phys
>   15.77%  [vdso]                   [.] __vdso_clock_gettime
>    7.25%  qemu-system-x86_64       [.] qemu_lockcnt_cmpxchg_or_wait
>    7.16%  qemu-system-x86_64       [.] aio_poll
>    3.94%  qemu-system-x86_64       [.] address_space_translate
>    3.69%  qemu-system-x86_64       [.] qemu_lockcnt_dec
>    3.46%  qemu-system-x86_64       [.] virtio_queue_host_notifier_aio_poll
>    3.32%  qemu-system-x86_64       [.] address_space_translate_internal
>    2.54%  qemu-system-x86_64       [.] run_poll_handlers_once
>    2.54%  libpthread-2.19.so       [.] pthread_mutex_lock
>    2.53%  libpthread-2.19.so       [.] __pthread_mutex_unlock_usercnt
>    2.53%  qemu-system-x86_64       [.] aio_notify_accept
>    2.40%  qemu-system-x86_64       [.] timerlist_deadline_ns
>    2.38%  qemu-system-x86_64       [.] address_space_lookup_region
>    2.23%  qemu-system-x86_64       [.] timerlistgroup_deadline_ns
>    2.21%  qemu-system-x86_64       [.] qemu_lockcnt_inc
>    2.08%  qemu-system-x86_64       [.] qemu_clock_get_ns
>    1.91%  qemu-system-x86_64       [.] object_dynamic_cast_assert
>    1.54%  qemu-system-x86_64       [.] virtio_queue_notify_aio_vq.part.16
>    1.21%  qemu-system-x86_64       [.] qemu_map_ram_ptr
>    1.16%  libc-2.19.so             [.] __clock_gettime
>    1.02%  qemu-system-x86_64       [.] event_notifier_poll
>    1.02%  qemu-system-x86_64       [.] timerlistgroup_run_timers
>    1.02%  qemu-system-x86_64       [.] virtio_queue_set_notification
>    0.82%  qemu-system-x86_64       [.] aio_bh_poll
>    0.81%  qemu-system-x86_64       [.] timerlist_run_timers
>    0.70%  qemu-system-x86_64       [.] aio_dispatch
>    0.66%  qemu-system-x86_64       [.] virtio_queue_empty.part.32
>    0.62%  qemu-system-x86_64       [.] aio_compute_timeout
>    0.50%  qemu-system-x86_64       [.] virtio_scsi_data_plane_handle_event
>    0.32%  qemu-system-x86_64       [.] clock_gettime@plt
>    0.26%  qemu-system-x86_64       [.] memory_region_is_ram_device
>    0.21%  qemu-system-x86_64       [.] qemu_mutex_unlock
>    0.12%  qemu-system-x86_64       [.] aio_context_acquire
>    0.12%  qemu-system-x86_64       [.] iothread_run
>    0.12%  qemu-system-x86_64       [.] qemu_lockcnt_count
>    0.11%  qemu-system-x86_64       [.] pthread_mutex_lock@plt
>    0.11%  qemu-system-x86_64       [.] qemu_mutex_lock
>    0.11%  [kernel]                 [k] vmx_vcpu_run
>    0.10%  libpthread-2.19.so       [.] pthread_mutex_unlock
>    0.09%  qemu-system-x86_64       [.] aio_context_release
>    0.09%  qemu-system-x86_64       [.] pthread_mutex_unlock@plt
>    0.09%  [kernel]                 [k] native_write_msr_safe
>    0.08%  [kernel]                 [k] ksm_do_scan
>    0.07%  qemu-system-x86_64       [.] virtio_scsi_handle_event_vq

This means virtio-scsi event vq handler is returning true but actually no
progress is made. Can you try the following patch to see if it's because a
stalled cache of VQ index?

diff --git a/hw/virtio/virtio.c b/hw/virtio/virtio.c
index 6365706..7f7ab57 100644
--- a/hw/virtio/virtio.c
+++ b/hw/virtio/virtio.c
@@ -2126,7 +2126,7 @@ static bool virtio_queue_host_notifier_aio_poll(void *opaque)
     EventNotifier *n = opaque;
     VirtQueue *vq = container_of(n, VirtQueue, host_notifier);
 
-    if (virtio_queue_empty(vq)) {
+    if (vring_avail_idx(vq) == vq->last_avail_idx) {
         return false;
     }

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Ed Swierk]

On Wed, Feb 8, 2017 at 6:52 PM, Fam Zheng <famz@redhat.com> wrote:
> This means virtio-scsi event vq handler is returning true but actually no
> progress is made. Can you try the following patch to see if it's because a
> stalled cache of VQ index?
>
> diff --git a/hw/virtio/virtio.c b/hw/virtio/virtio.c
> index 6365706..7f7ab57 100644
> --- a/hw/virtio/virtio.c
> +++ b/hw/virtio/virtio.c
> @@ -2126,7 +2126,7 @@ static bool virtio_queue_host_notifier_aio_poll(void *opaque)
>      EventNotifier *n = opaque;
>      VirtQueue *vq = container_of(n, VirtQueue, host_notifier);
>
> -    if (virtio_queue_empty(vq)) {
> +    if (vring_avail_idx(vq) == vq->last_avail_idx) {
>          return false;
>      }

I tried this change but the behavior is the same, unfortunately.

--Ed

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Fam Zheng]

On Wed, 02/08 19:44, Ed Swierk wrote:
> On Wed, Feb 8, 2017 at 6:52 PM, Fam Zheng <famz@redhat.com> wrote:
> > This means virtio-scsi event vq handler is returning true but actually no
> > progress is made. Can you try the following patch to see if it's because a
> > stalled cache of VQ index?
> >
> > diff --git a/hw/virtio/virtio.c b/hw/virtio/virtio.c
> > index 6365706..7f7ab57 100644
> > --- a/hw/virtio/virtio.c
> > +++ b/hw/virtio/virtio.c
> > @@ -2126,7 +2126,7 @@ static bool virtio_queue_host_notifier_aio_poll(void *opaque)
> >      EventNotifier *n = opaque;
> >      VirtQueue *vq = container_of(n, VirtQueue, host_notifier);
> >
> > -    if (virtio_queue_empty(vq)) {
> > +    if (vring_avail_idx(vq) == vq->last_avail_idx) {
> >          return false;
> >      }
> 
> I tried this change but the behavior is the same, unfortunately.

Hmm, maybe I'm missing something. How about this:

diff --git a/hw/scsi/virtio-scsi.c b/hw/scsi/virtio-scsi.c
index ce19eff..8b23e80 100644
--- a/hw/scsi/virtio-scsi.c
+++ b/hw/scsi/virtio-scsi.c
@@ -754,9 +754,7 @@ out:
 
 void virtio_scsi_handle_event_vq(VirtIOSCSI *s, VirtQueue *vq)
 {
-    if (s->events_dropped) {
-        virtio_scsi_push_event(s, NULL, VIRTIO_SCSI_T_NO_EVENT, 0);
-    }
+    virtio_scsi_push_event(s, NULL, VIRTIO_SCSI_T_NO_EVENT, 0);
 }
 
 static void virtio_scsi_handle_event(VirtIODevice *vdev, VirtQueue *vq)

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Fam Zheng]

On Thu, 02/09 13:39, Fam Zheng wrote:
> On Wed, 02/08 19:44, Ed Swierk wrote:
> > On Wed, Feb 8, 2017 at 6:52 PM, Fam Zheng <famz@redhat.com> wrote:
> > > This means virtio-scsi event vq handler is returning true but actually no
> > > progress is made. Can you try the following patch to see if it's because a
> > > stalled cache of VQ index?
> > >
> > > diff --git a/hw/virtio/virtio.c b/hw/virtio/virtio.c
> > > index 6365706..7f7ab57 100644
> > > --- a/hw/virtio/virtio.c
> > > +++ b/hw/virtio/virtio.c
> > > @@ -2126,7 +2126,7 @@ static bool virtio_queue_host_notifier_aio_poll(void *opaque)
> > >      EventNotifier *n = opaque;
> > >      VirtQueue *vq = container_of(n, VirtQueue, host_notifier);
> > >
> > > -    if (virtio_queue_empty(vq)) {
> > > +    if (vring_avail_idx(vq) == vq->last_avail_idx) {
> > >          return false;
> > >      }
> > 
> > I tried this change but the behavior is the same, unfortunately.
> 
> Hmm, maybe I'm missing something. How about this:
> 
> diff --git a/hw/scsi/virtio-scsi.c b/hw/scsi/virtio-scsi.c
> index ce19eff..8b23e80 100644
> --- a/hw/scsi/virtio-scsi.c
> +++ b/hw/scsi/virtio-scsi.c
> @@ -754,9 +754,7 @@ out:
>  
>  void virtio_scsi_handle_event_vq(VirtIOSCSI *s, VirtQueue *vq)
>  {
> -    if (s->events_dropped) {
> -        virtio_scsi_push_event(s, NULL, VIRTIO_SCSI_T_NO_EVENT, 0);
> -    }
> +    virtio_scsi_push_event(s, NULL, VIRTIO_SCSI_T_NO_EVENT, 0);
>  }
>  
>  static void virtio_scsi_handle_event(VirtIODevice *vdev, VirtQueue *vq)
> 

Ignore this. It will break the "assert(event == VIRTIO_SCSI_T_EVENTS_MISSED)" in
the called function. 

Anyway I think the cause is virtio_queue_host_notifier_aio_poll() only checks if
there is an available req in the virtqueue, but in virtio-scsi, eventq actually
contain buffers that are only useful when an event needs to be pushed.

It is reproducible with ubuntu LTS 14.04.5. I'll see if I can sort out a proper
fix.

Fam

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Fam Zheng]

On Wed, 02/08 19:44, Ed Swierk wrote:
> On Wed, Feb 8, 2017 at 6:52 PM, Fam Zheng <famz@redhat.com> wrote:
> > This means virtio-scsi event vq handler is returning true but actually no
> > progress is made. Can you try the following patch to see if it's because a
> > stalled cache of VQ index?
> >
> > diff --git a/hw/virtio/virtio.c b/hw/virtio/virtio.c
> > index 6365706..7f7ab57 100644
> > --- a/hw/virtio/virtio.c
> > +++ b/hw/virtio/virtio.c
> > @@ -2126,7 +2126,7 @@ static bool virtio_queue_host_notifier_aio_poll(void *opaque)
> >      EventNotifier *n = opaque;
> >      VirtQueue *vq = container_of(n, VirtQueue, host_notifier);
> >
> > -    if (virtio_queue_empty(vq)) {
> > +    if (vring_avail_idx(vq) == vq->last_avail_idx) {
> >          return false;
> >      }
> 
> I tried this change but the behavior is the same, unfortunately.

This should fix it:

https://lists.gnu.org/archive/html/qemu-devel/2017-02/msg01874.html

It would be great if you could help test it.

Fam

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Ed Swierk]

On Thu, Feb 9, 2017 at 2:12 AM, Fam Zheng <famz@redhat.com> wrote:
> This should fix it:
>
> https://lists.gnu.org/archive/html/qemu-devel/2017-02/msg01874.html

I tested this patch and found it fixes the problem. Thanks for the
speedy response!

--Ed

Re: [Qemu-devel] virtio-scsi-pci iothread spins at 100%

[Fam Zheng]

On Thu, 02/09 05:52, Ed Swierk wrote:
> On Thu, Feb 9, 2017 at 2:12 AM, Fam Zheng <famz@redhat.com> wrote:
> > This should fix it:
> >
> > https://lists.gnu.org/archive/html/qemu-devel/2017-02/msg01874.html
> 
> I tested this patch and found it fixes the problem. Thanks for the
> speedy response!

Thanks for the testing! If you could reply to the patch with a "Tested-by:" line
that would be even better. :)

Fam