vms shutting down on libvirt upgrade

[Henk Jan Agteresch]

Server running ubuntu wily, kvm and a few virtual machines

Today installed security updates which contained a libvirt update. After finishing the updates i found al my virtual machines were shutdown. Previous libvirt updates did not shutdown running virtual machines.

SRU TEST CASE:
 - sudo apt-get install libvirt-bin
 - Run "sudo journalctl -f /lib/systemd/systemd" in a separate terminal to watch which services get stopped/started during upgrade.
 - sudo apt-get install --reinstall libvirt-bin
 - When upgrading from the broken version (1.2.16-2ubuntu11.15.10.2 or below) you will see "Stopped Stop Active Libvirt Guests." and later a corresponding "Started" in the log. When upgrading from the fixed version (1.2.16-2ubuntu11.15.10.3), this will not be restarted.
 - Ensure that purging libvirt-bin still does "Stopped Stop Active Libvirt Guests".

[Henk Jan Agteresch (hjagteresch)]

2016-01-13 10:59:11 startup archives unpack
2016-01-13 10:59:11 install linux-image-4.2.0-23-generic:amd64 <none> 4.2.0-23.28
2016-01-13 10:59:11 status half-installed linux-image-4.2.0-23-generic:amd64 4.2.0-23.28
2016-01-13 10:59:15 status unpacked linux-image-4.2.0-23-generic:amd64 4.2.0-23.28
2016-01-13 10:59:15 status unpacked linux-image-4.2.0-23-generic:amd64 4.2.0-23.28
2016-01-13 10:59:15 upgrade libpng12-0:amd64 1.2.51-0ubuntu3.15.10.1 1.2.51-0ubuntu3.15.10.2
2016-01-13 10:59:15 status half-configured libpng12-0:amd64 1.2.51-0ubuntu3.15.10.1
2016-01-13 10:59:15 status unpacked libpng12-0:amd64 1.2.51-0ubuntu3.15.10.1
2016-01-13 10:59:15 status half-installed libpng12-0:amd64 1.2.51-0ubuntu3.15.10.1
2016-01-13 10:59:15 status half-installed libpng12-0:amd64 1.2.51-0ubuntu3.15.10.1
2016-01-13 10:59:15 status unpacked libpng12-0:amd64 1.2.51-0ubuntu3.15.10.2
2016-01-13 10:59:15 status unpacked libpng12-0:amd64 1.2.51-0ubuntu3.15.10.2
2016-01-13 10:59:15 upgrade grub-pc:amd64 2.02~beta2-29ubuntu0.2 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 status half-configured grub-pc:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status unpacked grub-pc:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status half-installed grub-pc:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status triggers-pending man-db:amd64 2.7.4-1
2016-01-13 10:59:15 status half-installed grub-pc:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status unpacked grub-pc:amd64 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 status unpacked grub-pc:amd64 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 upgrade grub-pc-bin:amd64 2.02~beta2-29ubuntu0.2 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 status half-configured grub-pc-bin:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status unpacked grub-pc-bin:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status half-installed grub-pc-bin:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status half-installed grub-pc-bin:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status unpacked grub-pc-bin:amd64 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 status unpacked grub-pc-bin:amd64 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 upgrade grub2-common:amd64 2.02~beta2-29ubuntu0.2 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 status half-configured grub2-common:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status unpacked grub2-common:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status half-installed grub2-common:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status triggers-pending install-info:amd64 6.0.0.dfsg.1-3
2016-01-13 10:59:15 status half-installed grub2-common:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:15 status unpacked grub2-common:amd64 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 status unpacked grub2-common:amd64 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 upgrade grub-common:amd64 2.02~beta2-29ubuntu0.2 2.02~beta2-29ubuntu0.3
2016-01-13 10:59:15 status half-configured grub-common:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:16 status unpacked grub-common:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:16 status half-installed grub-common:amd64 2.02~beta2-29ubuntu0.2
2016-01-13 10:59:17 status triggers-pending systemd:amd64 225-1ubunt...

[Henk Jan Agteresch (hjagteresch)]

root@kvm:/var/log# grep libvirt syslog
Jan 13 10:59:17 kvm libvirt: libvirt-bin: starting wait_on_vms at Wed Jan 13 10:59:17 UTC 2016
Jan 13 10:59:18 kvm libvirt: libvirt-bin: attempting clean shutdown of qemu:///system:fw58 at Wed Jan 13 10:59:18 UTC 2016
Jan 13 10:59:18 kvm libvirt: libvirt-bin: attempting clean shutdown of qemu:///system:pbx at Wed Jan 13 10:59:18 UTC 2016
Jan 13 10:59:18 kvm libvirt: libvirt-bin: attempting clean shutdown of qemu:///system:sterling at Wed Jan 13 10:59:18 UTC 2016
Jan 13 10:59:18 kvm libvirt: libvirt-bin: attempting clean shutdown of qemu:///system:lb3 at Wed Jan 13 10:59:18 UTC 2016
Jan 13 10:59:18 kvm libvirt: libvirt-bin: attempting clean shutdown of qemu:///system:services at Wed Jan 13 10:59:18 UTC 2016
Jan 13 10:59:18 kvm libvirt: libvirt-bin: attempting clean shutdown of qemu:///system:kivistik at Wed Jan 13 10:59:18 UTC 2016
Jan 13 10:59:18 kvm libvirtd[1355]: internal error: libxenlight state driver is not active
Jan 13 10:59:18 kvm libvirtd[1355]: End of file while reading data: Input/output error
Jan 13 10:59:23 kvm libvirtd[1355]: internal error: End of file from monitor
Jan 13 10:59:24 kvm kernel: [1283873.470106] audit: type=1400 audit(1452682764.469:50): apparmor="STATUS" operation="profile_remove" profile="unconfined" name="libvirt-6b155522-a61e-74f9-7eb4-ca1de2497e4b" pid=31605 comm="apparmor_parser"
Jan 13 10:59:25 kvm libvirtd[1355]: internal error: End of file from monitor
Jan 13 10:59:25 kvm kernel: [1283874.647066] audit: type=1400 audit(1452682765.645:51): apparmor="STATUS" operation="profile_remove" profile="unconfined" name="libvirt-8b403fa3-b33c-8db5-a255-c06c8858f32f" pid=31614 comm="apparmor_parser"
Jan 13 10:59:32 kvm libvirtd[1355]: stream aborted at client request
Jan 13 10:59:32 kvm libvirtd[1355]: internal error: End of file from monitor
Jan 13 10:59:33 kvm kernel: [1283882.356646] audit: type=1400 audit(1452682773.353:52): apparmor="STATUS" operation="profile_remove" profile="unconfined" name="libvirt-95b62769-a060-4606-9ce7-695b883fac94" pid=31663 comm="apparmor_parser"
Jan 13 10:59:36 kvm libvirtd[1355]: internal error: End of file from monitor
Jan 13 10:59:36 kvm kernel: [1283885.983999] audit: type=1400 audit(1452682776.977:53): apparmor="STATUS" operation="profile_remove" profile="unconfined" name="libvirt-afc518f2-d08c-5a4f-a60f-1e47d0f5ea12" pid=31686 comm="apparmor_parser"
Jan 13 10:59:40 kvm libvirtd[1355]: internal error: End of file from monitor
Jan 13 10:59:40 kvm kernel: [1283889.849819] audit: type=1400 audit(1452682780.845:54): apparmor="STATUS" operation="profile_remove" profile="unconfined" name="libvirt-76771fa1-4c01-80e1-d6ad-97bca6838fce" pid=31711 comm="apparmor_parser"
Jan 13 10:59:49 kvm libvirt: destroying qemu:///system:sterling
Jan 13 10:59:50 kvm kernel: [1283899.152225] audit: type=1400 audit(1452682790.150:55): apparmor="STATUS" operation="profile_remove" profile="unconfined" name="libvirt-5b4e09e9-aa2a-c501-4862-b878bc8c8c6c" pid=31768 comm="apparmor_parser"
Jan 13 10:59:50 kvm libvirtd[1355]: internal error: libxenlight state driver is not active
Jan 13 10:59:50 kvm libvirtd[1355]: End of file while reading data: Input/output error
Jan 13 10:...

[Serge Hallyn (serge-hallyn)]

Thanks for submitting this bug.

Reproduce here.

[Serge Hallyn (serge-hallyn)]

prior versions are doing it for me to.

[Serge Hallyn (serge-hallyn)]

lv2 login: systemd-journald.service: Got notification message from PID 318 (WATCHDOG=1)
Accepted new private connection.
Got message type=method_call sender=n/a destination=org.freedesktop.systemd1 object=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=StopUnit cookie=1 reply_cookie=0 error=n/a
libvirt-guests.service: Trying to enqueue job libvirt-guests.service/stop/replace
libvirt-guests.service: Installed new job libvirt-guests.service/stop as 343
libvirt-guests.service: Enqueued job libvirt-guests.service/stop as 343
Sent message type=method_return sender=n/a destination=n/a object=n/a interface=n/a member=n/a cookie=1 reply_cookie=1 error=n/a
Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=2 reply_cookie=0 error=n/a
Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=JobNew cookie=249 reply_cookie=0 error=n/a
Got message type=method_call sender=n/a destination=org.freedesktop.systemd1 object=/org/freedesktop/systemd1 interface=org.freedesktop.systemd1.Manager member=GetUnit cookie=2 reply_cookie=0 error=n/a
Sent message type=method_return sender=n/a destination=n/a object=n/a interface=n/a member=n/a cookie=3 reply_cookie=2 error=n/a
libvirt-guests.service: About to execute: /usr/lib/libvirt/libvirt-stop-guests
libvirt-guests.service: Forked /usr/lib/libvirt/libvirt-stop-guests as 1264
libvirt-guests.service: Changed exited -> stop[ 88.071982] libvirt-stop-guests[1264]: libvirt-guests.service: Executing: /usr/lib/libvirt/libvirt-stop-guests

Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1/unit/libvirt_2dguests_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=4 reply_cookie=0 error=n/a
Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1/unit/libvirt_2dguests_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=5 reply_cookie=0 error=n/a
Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1/unit/libvirt_2dguests_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=250 reply_cookie=0 error=n/a
Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1/unit/libvirt_2dguests_2eservice interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=251 reply_cookie=0 error=n/a
Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1/job/343 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=6 reply_cookie=0 error=n/a
Sent message type=signal sender=n/a destination=n/a object=/org/freedesktop/systemd1/job/343 interface=org.freedesktop.DBus.Properties member=PropertiesChanged cookie=252 reply_cookie=0 error=n/a
systemd-logind.service: Got notification message from PID 721 (WATCHDOG=1)
Got message type=method_call sender=n/a destination=org.freedesktop.systemd1 object=/org/freedesktop/systemd1/unit/libvirt_2dguests_2eservice interface=org.freedesktop.DBus.P...

[Serge Hallyn (serge-hallyn)]

libvirt-bin.service has

Before=libvirt-guests.service

and libvirt-guests.service has

After=network.target libvirt-bin.service time-sync.target systemd-machined.target

Does that sabotage the --no-restart-on-upgrade?

[Martin Pitt (pitti)]

This easily reproduces in a VM with

  sudo apt-get install libvirt-bin
  sudo apt-get install --reinstall libvirt-bin

During the second operation you can see this in the journal:

Jan 15 12:39:43 autopkgtest systemd[1]: Stopped Stop Active Libvirt Guests.

/var/lib/dpkg/info/libvirt-bin.prerm has

# Automatically added by dh_systemd_start
if [ -d /run/systemd/system ]; then
        deb-systemd-invoke stop libvirt-guests.service >/dev/null
fi
[...]
# Automatically added by dh_systemd_start
if [ -d /run/systemd/system ] && [ "$1" = remove ]; then
        deb-systemd-invoke stop libvirt-guests.service >/dev/null
fi
# End automatically added section
# Automatically added by dh_installinit
if ([ -x "/etc/init.d/libvirt-guests" ] || [ -e "/etc/init/libvirt-guests.conf" ]) && \
   [ "$1" = remove ]; then
        invoke-rc.d libvirt-guests stop || exit $?
fi

which is unconditionally run regardless of the operation. So this explains why libvirt-guests get stopped. So the prerm needs to be fixed. This sounds like a bug in dh_systemd_start --no-restart-on-upgrade.

[Serge Hallyn (serge-hallyn)]

Indeed, the following debdiff to init-system-helpers fixes it for me (with the exception that I used quilt and it's a native package, so don't use the debdiff verbatim) :

diff -Nru init-system-helpers-1.24ubuntu2/debian/changelog init-system-helpers-1.24ubuntu2x1/debian/changelog
--- init-system-helpers-1.24ubuntu2/debian/changelog 2015-11-18 12:27:05.000000000 +0000
+++ init-system-helpers-1.24ubuntu2x1/debian/changelog 2016-01-16 00:43:32.000000000 +0000
@@ -1,3 +1,9 @@
+init-system-helpers (1.24ubuntu2x1) xenial; urgency=medium
+
+ * fix inverted use of -r flag to dh_systemd_start
+
+ -- Serge Hallyn <email address hidden> Sat, 16 Jan 2016 00:42:51 +0000
+
 init-system-helpers (1.24ubuntu2) xenial; urgency=medium

   * Add Breaks/Replaces on upstart to cover move of
diff -Nru init-system-helpers-1.24ubuntu2/patches/fix-systemd-restart-on-upgrade.patch init-system-helpers-1.24ubuntu2x1/patches/fix-systemd-restart-on-upgrade.patch
--- init-system-helpers-1.24ubuntu2/patches/fix-systemd-restart-on-upgrade.patch 1970-01-01 00:00:00.000000000 +0000
+++ init-system-helpers-1.24ubuntu2x1/patches/fix-systemd-restart-on-upgrade.patch 2016-01-16 00:42:50.000000000 +0000
@@ -0,0 +1,13 @@
+Index: init-system-helpers-1.24ubuntu2/script/dh_systemd_start
+===================================================================
+--- init-system-helpers-1.24ubuntu2.orig/script/dh_systemd_start
++++ init-system-helpers-1.24ubuntu2/script/dh_systemd_start
+@@ -205,7 +205,7 @@ foreach my $package (@{$dh{DOPACKAGES}})
+
+ $sd_autoscript->("postrm", "postrm-systemd-reload-only");
+
+- if ($dh{R_FLAG} || $dh{RESTART_AFTER_UPGRADE}) {
++ if (!$dh{R_FLAG} || $dh{RESTART_AFTER_UPGRADE}) {
+ # stop service only on remove
+ $sd_autoscript->("prerm", "prerm-systemd-restart");
+ } elsif (!$dh{NO_START}) {
diff -Nru init-system-helpers-1.24ubuntu2/patches/series init-system-helpers-1.24ubuntu2x1/patches/series
--- init-system-helpers-1.24ubuntu2/patches/series 1970-01-01 00:00:00.000000000 +0000
+++ init-system-helpers-1.24ubuntu2x1/patches/series 2016-01-16 00:42:06.000000000 +0000
@@ -0,0 +1 @@
+fix-systemd-restart-on-upgrade.patch

[Martin Pitt (pitti)]

The original dh_systemd_start code is correct:

  if ($dh{R_FLAG} || $dh{RESTART_AFTER_UPGRADE}) {

in this case it installs "prerm-systemd-restart" which *only* stops the service in the prerm if $1 == "remove". The problem is a bit more subtle: As you can see in the prerm, there are *two* stanzas for "stop libvirt-guests.service". The first one is wrong, the second one is correct (if $1 == "remove") and comes from the explicit

   dh_systemd_start -p libvirt-bin --no-restart-on-upgrade libvirt-guests.service

call in debian/rules. However, the first one gets synthesized by cdbs' debhelper.mk, and unfortunately cdbs does not have a way to override the options per-service:

   $(if $(wildcard /usr/bin/dh_systemd_start),dh_systemd_start -p$(cdbs_curpkg) $(call cdbs_expand_curvar,DEB_DH_SYSTEMD_START_ARGS))

this can also be seen in the build log:

dh_installinit -p libvirt-bin --name=libvirt-guests --no-restart-on-upgrade -- defaults 29 71
dh_systemd_enable
dh_systemd_start -p libvirt-bin --restart-after-upgrade libvirt-bin.service
dh_systemd_start -p libvirt-bin --no-restart-on-upgrade libvirt-guests.service
[... the above is from the explicit debian/rules code ...]
dh_install -plibvirt-bin⎵⎵
dh_systemd_enable -plibvirt-bin⎵
dh_systemd_start -plibvirt-bin⎵
[... the above is from the implicit cdbs debhelper rules ...]

As debian/rules already has explicit calls for libvirt-bin's dh_systemd_start, I think the easiest fix is to completely disable the implicicly generated rules:

# we have explicit calls with different options per .service, disable
# autogenerated calls
DEB_DH_SYSTEMD_START_ARGS_libvirt-bin = --no-act

[Martin Pitt (pitti)]

Xenial fix uploaded. Note that guests will still be stopped on upgrades from the current 1.2.21-2ubuntu8 or earlier, as we cannot retroactively fix the old prerm. But from now on, upgrades will behave correctly.

[Martin Pitt (pitti)]

Wily fix uploaded to SRU review queue, test case added to description.

[Launchpad Janitor (janitor)]

This bug was fixed in the package libvirt - 1.2.21-2ubuntu9

---------------
libvirt (1.2.21-2ubuntu9) xenial; urgency=medium

  * debian/rules: Disable cdbs' implicitly generated dh_systemd_start calls.
    We already call it explicitly with the right options, calling it again
    with the default options stops libvirt-guests during upgrades.
    (LP: #1533839)

 -- Martin Pitt <email address hidden> Mon, 18 Jan 2016 09:10:21 +0100

[Brian Murray (brian-murray)]

Hello Henk, or anyone else affected,

Accepted libvirt into wily-proposed. The package will build now and be available at https://launchpad.net/ubuntu/+source/libvirt/1.2.16-2ubuntu11.15.10.3 in a few hours, and then in the -proposed repository.

Please help us by testing this new package. See https://wiki.ubuntu.com/Testing/EnableProposed for documentation how to enable and use -proposed. Your feedback will aid us getting this update out to other Ubuntu users.

If this package fixes the bug for you, please add a comment to this bug, mentioning the version of the package you tested, and change the tag from verification-needed to verification-done. If it does not fix the bug for you, please add a comment stating that, and change the tag to verification-failed. In either case, details of your testing will help us make a better decision.

Further information regarding the verification process can be found at https://wiki.ubuntu.com/QATeam/PerformingSRUVerification . Thank you in advance!

[Robert Dinse (nanook)]

     I have installed 1.2.16-2ubuntu11.15.10.3 and confirmed that the guest machines no longer reboot when libvirt-bin is restarted. Thanks much for the fix!

[Launchpad Janitor (janitor)]

This bug was fixed in the package libvirt - 1.2.16-2ubuntu11.15.10.3

---------------
libvirt (1.2.16-2ubuntu11.15.10.3) wily-proposed; urgency=medium

  * debian/rules: Disable cdbs' implicitly generated dh_systemd_start calls.
    We already call it explicitly with the right options, calling it again
    with the default options stops libvirt-guests during upgrades.
    (LP: #1533839)

 -- Martin Pitt <email address hidden> Mon, 18 Jan 2016 09:25:17 +0100

[Chris J Arges (arges)]

The verification of the Stable Release Update for libvirt has completed successfully and the package has now been released to -updates. Subsequently, the Ubuntu Stable Release Updates Team is being unsubscribed and will not receive messages about this bug report. In the event that you encounter a regression using the package from -updates please report a new bug using ubuntu-bug and tag the bug report regression-update so we can easily find any regressions.