testcloud

#51 Handle "libvirtError: Device or resource busy" when stopping instance
Closed Opened by kparal.

Closed
Reopen Issue

When the host is very busy, killing a process might take longer than libvirt timeout when stopping a VM. An example is here:

[testcloud.instance:instance.py:476] 2018-02-12 17:00:06 DEBUG   removing instance taskotron-caf07b2e-0eca-11e8-920b-525400ee7c53 from libvirt.
[testcloud.instance:instance.py:454] 2018-02-12 17:00:17 DEBUG   stopping instance taskotron-caf07b2e-0eca-11e8-920b-525400ee7c53.
libvirt:  error : Failed to terminate process 34561 with SIGKILL: Device or resource busy
[libtaskotron:logger.py:88] 2018-02-12 17:00:33 CRITICAL Traceback (most recent call last):
  File "/usr/bin/runtask", line 11, in <module>
    load_entry_point('libtaskotron==0.4.99.1', 'console_scripts', 'runtask')()
  File "/usr/lib/python2.7/site-packages/libtaskotron/main.py", line 195, in main
    finished = executor.execute()
  File "/usr/lib/python2.7/site-packages/libtaskotron/executor.py", line 303, in execute
    self.task_vm.teardown()
  File "/usr/lib/python2.7/site-packages/libtaskotron/ext/disposable/vm.py", line 177, in teardown
    tc_instance.remove(autostop=True)
  File "/usr/lib/python2.7/site-packages/testcloud/instance.py", line 484, in remove
    self.stop()
  File "/usr/lib/python2.7/site-packages/testcloud/instance.py", line 466, in stop
    self._get_domain().destroy()
  File "/usr/lib64/python2.7/site-packages/libvirt.py", line 1136, in destroy
    if ret == -1: raise libvirtError ('virDomainDestroy() failed', dom=self)
libvirtError: Failed to terminate process 34561 with SIGKILL: Device or resource busy

http://taskotron-dev.fedoraproject.org/taskmaster/builders/x86_64/builds/845698/steps/runtask/logs/stdio

There's some explanation about the issue here:
https://bugzilla.redhat.com/show_bug.cgi?id=1205647#c13

It would make sense for testcloud to repeat the stop request once or twice, if this exact error happens (libvirt errors are numbered). Or if it finds out the VM is already stopped before sending another stop request, it can behave like everything is in order. The code to wrap in try-except is in instance.Instance.stop() (probably the whole method).

The worst part here would be to simulate this behavior so that you can test the patch. My ideas are:
a) overload the host heavily, e.g. running out of RAM and swapping heavily?
b) run the VM over NFS and then disconnect the connection abruptly. That often causes I/O hangs in kernel, in my experience.
c) patch libvirt and lower the timeout, if it's reasonably easy to do

Please submit a PR.

@lbrabec, is this something you could look at? Thanks a lot.

Commit 91db0df9 fixes this issue

...
c) patch libvirt and lower the timeout, if it's reasonably easy to do
...

For future issues, patching libvirt is what I had to do to simulate behavior of busy host.

I commented out line with usleep(200 * 1000); in src/util/virprocess.c.

Unfortunately this doesn't work great:

[testcloud.instance:instance.py:494] 2018-02-23 10:00:03 DEBUG   removing instance taskotron-195bb648-1880-11e8-bb81-525400ee7c53 from libvirt.
[testcloud.instance:instance.py:455] 2018-02-23 10:00:03 DEBUG   stopping instance taskotron-195bb648-1880-11e8-bb81-525400ee7c53.
libvirt:  error : Failed to terminate process 2480 with SIGKILL: Device or resource busy
[testcloud.instance:instance.py:476] 2018-02-23 10:00:18 WARNING Host is busy, retrying to stop the instance taskotron-195bb648-1880-11e8-bb81-525400ee7c53
libvirt: QEMU Driver error : Requested operation is not valid: domain is not running
[libtaskotron:vm.py:179] 2018-02-23 10:00:25 ERROR   Error while tearing down instance taskotron-195bb648-1880-11e8-bb81-525400ee7c53
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/libtaskotron/ext/disposable/vm.py", line 177, in teardown
    tc_instance.remove(autostop=True)
  File "/usr/lib/python2.7/site-packages/testcloud/instance.py", line 502, in remove
    self.stop()
  File "/usr/lib/python2.7/site-packages/testcloud/instance.py", line 479, in stop
    .format(self.name, e))
TestcloudInstanceError: Error while stopping instance taskotron-195bb648-1880-11e8-bb81-525400ee7c53: Requested operation is not valid: domain is not running
[libtaskotron:logger.py:88] 2018-02-23 10:00:25 CRITICAL Traceback (most recent call last):
  File "/usr/bin/runtask", line 11, in <module>
    load_entry_point('libtaskotron==0.4.99.1', 'console_scripts', 'runtask')()
  File "/usr/lib/python2.7/site-packages/libtaskotron/main.py", line 195, in main
    finished = executor.execute()
  File "/usr/lib/python2.7/site-packages/libtaskotron/executor.py", line 308, in execute
    self.task_vm.teardown()
  File "/usr/lib/python2.7/site-packages/libtaskotron/ext/disposable/vm.py", line 180, in teardown
    raise exc.TaskotronRemoteError(e)
TaskotronRemoteError: Error while stopping instance taskotron-195bb648-1880-11e8-bb81-525400ee7c53: Requested operation is not valid: domain is not running

http://taskotron-dev.fedoraproject.org/taskmaster/builders/x86_64/builds/866042/steps/runtask/logs/stdio

As I feared, with certain timing another destroy operation doesn't make sense. It seems we first need to figure out whether the domain is running before destroying it again (but that itself is also prone to races), and/or ignore this particular "domain is not running" error.
Edited by kparal

Metadata Update from @kparal:
- Issue status updated to: Open (was: Closed)

Commit 1ff0aa9 fixes this issue

Metadata Update from @lbrabec:
- Issue status updated to: Closed (was: Open)
Metadata
None
None
None
Normal
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.