package libvirt-bin 1.3.1-1ubuntu10 failed to install/upgrade: subprocess installed post-installation script returned error exit status 1

[Nodøn]

upgrade 15.10 -> 16.04

ProblemType: Package
DistroRelease: Ubuntu 16.04
Package: libvirt-bin 1.3.1-1ubuntu10
ProcVersionSignature: Ubuntu 4.2.0-36.41-generic 4.2.8-ckt8
Uname: Linux 4.2.0-36-generic x86_64
ApportVersion: 2.20.1-0ubuntu2
Architecture: amd64
Date: Mon Apr 25 12:44:51 2016
ErrorMessage: subprocess installed post-installation script returned error exit status 1
InstallationDate: Installed on 2016-04-06 (19 days ago)
InstallationMedia: Ubuntu 15.10 "Wily Werewolf" - Release amd64 (20151021)
ProcCmdline: BOOT_IMAGE=/vmlinuz-4.2.0-36-generic root=/dev/mapper/ubuntu--vg-root ro quiet splash vt.handoff=7
SourcePackage: libvirt
Title: package libvirt-bin 1.3.1-1ubuntu10 failed to install/upgrade: subprocess installed post-installation script returned error exit status 1
UpgradeStatus: Upgraded to xenial on 2016-04-25 (0 days ago)
modified.conffile..etc.libvirt.qemu.networks.default.xml: [modified]
mtime.conffile..etc.libvirt.qemu.networks.default.xml: 2016-04-14T14:20:45.067249

[Serge Hallyn (serge-hallyn)]

Apr 25 12:44:52 hostname libvirtd[18673]: Failed to acquire pid file '/var/run/libvirtd.pid': Resource temporarily unavailable

[Serge Hallyn (serge-hallyn)]

Apr 25 12:38:11 hostname systemd[1]: libvirt-bin.service: Got notification message from PID 103
8, but reception only permitted for main PID 1003

[Serge Hallyn (serge-hallyn)]

Do we need to add NotifyAccess=all to the systemd job?

[Serge Hallyn (serge-hallyn)]

(After some googling I'm not sure whether this should be considered a bug in the libvirt-bin upstart job, or a bug in systemd. https://bugzilla.redhat.com/show_bug.cgi?id=1047304 suggests it may be a systemd bug. Subscribing systemd to get some professional help :)

[Nodøn (nod0n)]

If you need some more Informations from me, let me know. I'm happy to see such a fast reaction.

[Serge Hallyn (serge-hallyn)]

Thanks, but actually the systemd.service(5) manpage tells me what I needed.

The fix for you should be to edit your /lib/systemd/system/libvirt-bin.service file to read:

============================================
[Unit]
Description=Virtualization daemon
Before=libvirt-guests.service
After=network.target
After=dbus.service
After=iscsid.service
After=apparmor.service
After=local-fs.target
After=remote-fs.target
Documentation=man:libvirtd(8)
Documentation=http://libvirt.org

[Service]
Type=notify
EnvironmentFile=-/etc/default/libvirt-bin
ExecStart=/usr/sbin/libvirtd $libvirtd_opts
ExecReload=/bin/kill -HUP $MAINPID
KillMode=process
Restart=on-failure
LimitNOFILE=infinity
LimitNPROC=infinity
TasksMax=infinity
NotifyAccess=all

[Install]
WantedBy=multi-user.target
Also=virtlockd.socket
Also=virtlogd.socket
============================================

In other words, just add the
 NotifyAccess=all
line in the second section.

I'll push that to the 16.10 package and SRU the change to wily and xenial.

Thanks!

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[jean-christophe manciot (manciot-jeanchristophe)]

Adding NotifyAccess=all in /lib/systemd/system/libvirt-bin.service does not solve the issue:

sudo systemctl restart libvirt-bin
sudo systemctl -l status libvirt-bin
● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: inactive (dead) (Result: exit-code) since Mon 2016-04-25 19:42:23 CEST; 56s ago
     Docs: man:libvirtd(8)
           http://libvirt.org
  Process: 2319 ExecStart=/usr/sbin/libvirtd $libvirtd_opts (code=exited, status=1/FAILURE)
 Main PID: 2319 (code=exited, status=1/FAILURE)

Apr 25 19:42:22 samsung-ubuntu systemd[1]: libvirt-bin.service: Unit entered failed state.
Apr 25 19:42:22 samsung-ubuntu systemd[1]: libvirt-bin.service: Failed with result 'exit-code'.
Apr 25 19:42:23 samsung-ubuntu systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Apr 25 19:42:23 samsung-ubuntu systemd[1]: Stopped Virtualization daemon.
Apr 25 19:42:23 samsung-ubuntu systemd[1]: libvirt-bin.service: Start request repeated too quickly.
Apr 25 19:42:23 samsung-ubuntu systemd[1]: Failed to start Virtualization daemon.

Despite: cat /lib/systemd/system/libvirt-bin.service
[Unit]
Description=Virtualization daemon
Before=libvirt-guests.service
After=network.target
After=dbus.service
After=iscsid.service
After=apparmor.service
After=local-fs.target
After=remote-fs.target
Documentation=man:libvirtd(8)
Documentation=http://libvirt.org

[Service]
Type=notify
EnvironmentFile=-/etc/default/libvirt-bin
ExecStart=/usr/sbin/libvirtd $libvirtd_opts
ExecReload=/bin/kill -HUP $MAINPID
KillMode=process
Restart=on-failure
LimitNOFILE=infinity
LimitNPROC=infinity
TasksMax=infinity
NotifyAccess=all

[Install]
WantedBy=multi-user.target
Also=virtlockd.socket
Also=virtlogd.socket

[Serge Hallyn (serge-hallyn)]

Hi,

just to make sure, did you do a

sudo systemctl daemon-reload

before restarting?

Could you please show the result of:

ps -ef | grep libvirt

sudo systemctl stop libvirt-bin
sudo systemctl start libvirt-bin
sudo journalctl -xe
sudo journalctl -u libvirt-bin

sudo libvirtd

[jean-christophe manciot (manciot-jeanchristophe)]

Yes, I did. If you don't, you get a warning.

However, after thorough research, I noticed some leftovers from a previously installed libvirt 1.3.3 from sources over 1.3.1.
Uninstalling the latter did not uninstall everything, hence the mess.
After cleaning everything and reinstalling libvirt 1.3.1 without 1.3.3, I was even able to correctly start libvirt-bin without having to modify the service file.
I then modified it with NotifyAccess=all, systemctl daemon-reload & systemctl restart libvirt-bin: everything works fine so far:
systemctl status libvirt-bin
● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: active (running) since Tue 2016-04-26 10:03:09 CEST; 6s ago
     Docs: man:libvirtd(8)
           http://libvirt.org
 Main PID: 17108 (libvirtd)
    Tasks: 18
   Memory: 33.5M
      CPU: 666ms
   CGroup: /system.slice/libvirt-bin.service
           ├─14707 /usr/sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/lib/libvirt/libvirt_leaseshel
           ├─14708 /usr/sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/lib/libvirt/libvirt_leaseshel
           └─17108 /usr/sbin/libvirtd

Apr 26 10:03:09 samsung-ubuntu systemd[1]: Starting Virtualization daemon...
Apr 26 10:03:09 samsung-ubuntu systemd[1]: Started Virtualization daemon.
Apr 26 10:03:09 samsung-ubuntu dnsmasq[14707]: read /etc/hosts - 29 addresses
Apr 26 10:03:09 samsung-ubuntu dnsmasq[14707]: read /var/lib/libvirt/dnsmasq/default.addnhosts - 0 addresses
Apr 26 10:03:09 samsung-ubuntu dnsmasq-dhcp[14707]: read /var/lib/libvirt/dnsmasq/default.hostsfile

[Martin Pitt (pitti)]

For the record, https://cgit.freedesktop.org/systemd/systemd/commit/?id=da13d4d was fixed in 209 already, thus in ≥ vivid. NotifyAccess=all sounds like the right solution if child processes from the main process want to send "ready" signals indeed.

[Serge Hallyn (serge-hallyn)]

Quoting Martin Pitt (<email address hidden>):
> For the record,
> https://cgit.freedesktop.org/systemd/systemd/commit/?id=da13d4d was
> fixed in 209 already, thus in ≥ vivid. NotifyAccess=all sounds like the
> right solution if child processes from the main process want to send
> "ready" signals indeed.

Thanks Martin - though upstream (libvirt) says that children do not
do so, so I think I'll be removing that in the next upload.

[Launchpad Janitor (janitor)]

This bug was fixed in the package libvirt - 1.3.1-1ubuntu11

---------------
libvirt (1.3.1-1ubuntu11) yakkety; urgency=medium

  [ Stefan Bader ]
  * Add alias for libvirtd.service into libvirt-bin.service

  [ Serge Hallyn ]
  * d/p/u/libvirt-bin-service-set-notifyaccess.patch: Set NotifyAccess=all in
    libvirt-bin systemd service file. (LP: #1574566)

 -- Serge Hallyn <email address hidden> Mon, 18 Apr 2016 13:44:15 -0500

[Serge Hallyn (serge-hallyn)]

So given the upstream feedback i will remove the Notify line, and we'll see if we get any other separate reports. Given comment #11 I've marked this invallid.

[jean-christophe manciot (manciot-jeanchristophe)]

There is an issue, although it is not directly related to the title of this thread.

It used to be possible to install libvirt 1.3.3 over 1.2.16 on Ubuntu 15.10 ***without any issue.***
Now, on Ubuntu 16.10, trying to install libvirt 1.3.3 from the ***same sources*** triggers the error already depicted above:
systemctl status libvirt-bin
● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: inactive (dead) (Result: exit-code) since Thu 2016-04-28 19:10:19 CEST; 1min 3s ago
     Docs: man:libvirtd(8)
           http://libvirt.org
  Process: 11398 ExecStart=/usr/sbin/libvirtd $libvirtd_opts (code=exited, status=1/FAILURE)
 Main PID: 11398 (code=exited, status=1/FAILURE)

Apr 28 19:10:19 samsung-ubuntu systemd[1]: Failed to start Virtualization daemon.
Apr 28 19:10:19 samsung-ubuntu systemd[1]: libvirt-bin.service: Unit entered failed state.
Apr 28 19:10:19 samsung-ubuntu systemd[1]: libvirt-bin.service: Failed with result 'exit-code'.
Apr 28 19:10:19 samsung-ubuntu systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Apr 28 19:10:19 samsung-ubuntu systemd[1]: Stopped Virtualization daemon.
Apr 28 19:10:19 samsung-ubuntu systemd[1]: libvirt-bin.service: Start request repeated too quickly.
Apr 28 19:10:19 samsung-ubuntu systemd[1]: Failed to start Virtualization daemon.

What has changed?
I finally figured it out.
On Ubuntu 15.10, we had the shared libraries in /usr/lib as expected:
dpkg --contents libvirt0_1.2.16-2ubuntu11_amd64.deb | grep so
-rw-r--r-- root/root 3607776 2015-09-29 03:02 ./usr/lib/libvirt.so.0.1002.16
-rw-r--r-- root/root 10168 2015-09-29 03:02 ./usr/lib/libvirt-lxc.so.0.1002.16
-rw-r--r-- root/root 14264 2015-09-29 03:02 ./usr/lib/libvirt-qemu.so.0.1002.16
lrwxrwxrwx root/root 0 2015-09-29 03:02 ./usr/lib/libvirt-qemu.so.0 -> libvirt-qemu.so.0.1002.16
lrwxrwxrwx root/root 0 2015-09-29 03:02 ./usr/lib/libvirt.so.0 -> libvirt.so.0.1002.16
lrwxrwxrwx root/root 0 2015-09-29 03:02 ./usr/lib/libvirt-lxc.so.0 -> libvirt-lxc.so.0.1002.16

Since libvirt 1.3.3 installs its libraries over the previous ones in the same folder, everything worked fine:
dpkg --contents libvirt_1.3.3-14_amd64.deb | grep so
...
-rwxr-xr-x root/root 3718272 2016-04-28 19:09 ./usr/lib/libvirt.so.0.1003.3
-rwxr-xr-x root/root 34952 2016-04-28 19:09 ./usr/lib/libvirt-admin.so.0.1003.3
-rwxr-xr-x root/root 14272 2016-04-28 19:09 ./usr/lib/libvirt-qemu.so.0.1003.3
-rwxr-xr-x root/root 14272 2016-04-28 19:09 ./usr/lib/libvirt-lxc.so.0.1003.3
-rwxr-xr-x root/root 264496 2016-04-28 19:09 ./usr/lib/libnss_libvirt.so.2
lrwxrwxrwx root/root 0 2016-04-28 19:09 ./usr/lib/libvirt.so -> libvirt.so.0.1003.3
lrwxrwxrwx root/root 0 2016-04-28 19:09 ./usr/lib/libvirt-qemu.so.0 -> libvirt-qemu.so.0.1003.3
lrwxrwxrwx root/root 0 2016-04-28 19:09 ./usr/lib/libvirt-admin.so.0 -> libvirt-admin.so.0.1003.3
lrwxrwxrwx root/root 0 2016-04-28 19:09 ./usr/lib/libvirt-lxc.so.0 -> libvirt-lxc.so.0.1003.3
lrwxrwxrwx root/root 0 2016-04-28 19:09 ./usr/lib/libvirt.so.0 -> libvirt.so.0...

[jean-christophe manciot (manciot-jeanchristophe)]

Do I need to open a new "bug report"?

[jean-christophe manciot (manciot-jeanchristophe)]

as a POC with libvirt 1.3.3 installed:

sudo rm -v /usr/lib/x86_64-linux-gnu/libvirt*
removed '/usr/lib/x86_64-linux-gnu/libvirt-admin.so.0'
removed '/usr/lib/x86_64-linux-gnu/libvirt-admin.so.0.1003.1'
removed '/usr/lib/x86_64-linux-gnu/libvirt-lxc.so.0'
removed '/usr/lib/x86_64-linux-gnu/libvirt-lxc.so.0.1003.1'
removed '/usr/lib/x86_64-linux-gnu/libvirt-qemu.so.0'
removed '/usr/lib/x86_64-linux-gnu/libvirt-qemu.so.0.1003.1'
removed '/usr/lib/x86_64-linux-gnu/libvirt.so.0'
removed '/usr/lib/x86_64-linux-gnu/libvirt.so.0.1003.1'

sudo ldconfig
sudo systemctl stop libvirt-bin
sudo systemctl start libvirt-bin
sudo systemctl status libvirt-bin
● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2016-04-28 20:00:40 CEST; 5s ago
     Docs: man:libvirtd(8)
           http://libvirt.org
 Main PID: 15862 (libvirtd)
    Tasks: 16
   Memory: 8.8M
      CPU: 426ms
   CGroup: /system.slice/libvirt-bin.service
           └─15862 /usr/sbin/libvirtd

sudo libvirtd version
libvirtd (libvirt) 1.3.3

[Serge Hallyn (serge-hallyn)]

Quoting jean-christophe manciot (<email address hidden>):
> Alas! Someone in Canonical decided to change that and now the libraries have moved to a different folder:
> dpkg --contents libvirt0_1.3.1-1ubuntu10_amd64.deb | grep so
> -rw-r--r-- root/root 10168 2016-04-15 09:15 ./usr/lib/x86_64-linux-gnu/libvirt-lxc.so.0.1003.1

Please see https://wiki.debian.org/Multiarch/Implementation

[jean-christophe manciot (manciot-jeanchristophe)]

I don't get your point... at all. Are you suggesting th
Debian has not changed the path for the libraries: File list of package libvirt0 1.3.3 in sid of architecture amd64

/usr/lib/libvirt-admin.so.0
/usr/lib/libvirt-admin.so.0.1003.3
/usr/lib/libvirt-lxc.so.0
/usr/lib/libvirt-lxc.so.0.1003.3
/usr/lib/libvirt-qemu.so.0
/usr/lib/libvirt-qemu.so.0.1003.3
/usr/lib/libvirt.so.0
/usr/lib/libvirt.so.0.1003.3
/usr/share/doc/libvirt0/changelog.Debian.gz
/usr/share/doc/libvirt0/changelog.gz
/usr/share/doc/libvirt0/copyright

[jean-christophe manciot (manciot-jeanchristophe)]

Are you suggesting that the change was motivated to make libvirt support multiple architectures?
You can check that debian has the same path for the libvirt libraries across multiple architectures at the bottom of this page: https://packages.debian.org/sid/libvirt0.

[Serge Hallyn (serge-hallyn)]

Yes, Debian has not yet made this change for libvirt. It was done
in 1.3.1-1ubuntu1 . We've not yet submitted a patch to Debian, but
I'll be doing so soon as I'm working on syncing the packaging.

[Fabian Zimmermann (dev-faz)]

Hi,

back to the topic of this bugreport. I'm getting the same error:

--
root@compute1:~# systemctl status libvirt-bin
● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Thu 2016-07-28 09:09:57 CEST; 6s ago
     Docs: man:libvirtd(8)
           http://libvirt.org
  Process: 5456 ExecStart=/usr/sbin/libvirtd $libvirtd_opts (code=exited, status=0/SUCCESS)
 Main PID: 5456 (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/libvirt-bin.service
           ├─5459 /usr/sbin/libvirtd -d -l
           ├─5519 /usr/sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/lib/libvirt/libvirt_leaseshelper
           └─5520 /usr/sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/lib/libvirt/libvirt_leaseshelper

Jul 28 09:09:57 compute1 systemd[1]: Starting Virtualization daemon...
Jul 28 09:09:57 compute1 systemd[1]: libvirt-bin.service: Got notification message from PID 5459, but reception only permitted for main PID 5456
Jul 28 09:09:57 compute1 systemd[1]: Started Virtualization daemon.
--

it's a fresh installed 16.04 so no old version is laying around and doing something unusual.

systemd is also newer than above commit:

--
Package: systemd
Priority: required
Section: admin
Installed-Size: 18776
Maintainer: Ubuntu Developers <email address hidden>
Original-Maintainer: Debian systemd Maintainers <email address hidden>
Architecture: amd64
Version: 229-4ubuntu4
--

even after adding "NotifyAccess=all" the service isn't handled correctly.

--
root@compute1:~# systemctl status libvirt-bin
● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Thu 2016-07-28 09:23:32 CEST; 747ms ago
     Docs: man:libvirtd(8)
           http://libvirt.org
  Process: 5361 ExecStart=/usr/sbin/libvirtd $libvirtd_opts (code=exited, status=0/SUCCESS)
 Main PID: 5361 (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/libvirt-bin.service
           ├─5364 /usr/sbin/libvirtd -d -l
           ├─5424 /usr/sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/lib/libvirt/libvirt_leaseshelper
           └─5425 /usr/sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/lib/libvirt/libvirt_leaseshelper

Jul 28 09:23:32 compute1 systemd[1]: Starting Virtualization daemon...
Jul 28 09:23:32 compute1 systemd[1]: Started Virtualization daemon.
--

I'm unable to stop/restart the service - only killing the processes manually will allow further usage of "systemctl stop/start.."

If I remove the "-d" in OPTS of /etc/default/libvirt-bin, systemd is able to detect the running libvirtd.

--
root@compute1:~# systemctl status libvirt-bin
● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2016-07-28 09:25:37 CEST; 2s a...

[Fabian Zimmermann (dev-faz)]

Just replaced my /etc/default/libvirt-bin with the original packaged one and did a diff:

--
root@compute1:/etc/default# diff -u libvirt-bin.bck libvirt-bin
--- libvirt-bin.bck 2016-07-28 09:31:34.649296000 +0200
+++ libvirt-bin 2016-01-13 08:36:30.000000000 +0100
@@ -5,7 +5,7 @@
 start_libvirtd="yes"

 # options passed to libvirtd, add "-l" to listen on tcp
-libvirtd_opts="-d -l"
+#libvirtd_opts=""

 # pass in location of kerberos keytab
 #export KRB5_KTNAME=/etc/libvirt/libvirt.keytab
--

so, "-d" is not set by default.

Let me summarize, just in case someone else finds this bugreport while debugging the situation:

* You should not set "-d" in OPTS
* You don't need "NotifyAccess=all"

But still the dnsmasq-processes are not terminated on stop.

 Fabian

[Serge Hallyn (serge-hallyn)]

Indeed, that (-d) is a difference in how the upstart and systemctl
jobs expect to function. The upstart job was 'expect daemon' and
specifies -d in the upstart job itself (not in
/etc/default/libvirt-bin)

Assuming Ubuntu doesn't drop the upstart job altogether (which would
be a problem for me) it might be good, during yakkety, to switch the
upstart job to also not daemonizing libvirt.

[Martin Pitt (pitti)]

In an ideal world the -d would get moved out of the /etc/default file and into the sysvinit/upstart job. The "-d" is *not* a thing that users can configure, it's an intrinsic property how the corresponding init script wants/expects the daemon to start. It should never have been in the default file in the first place.

But as that is a conffile and thus ugly to change, the next best thing would be to specify it again in SysV/upstart (just to make sure it's there) and sed it away in the unit. Or alternatively keep it in the background, add Type=forking, and live with the much less useful logging.