Failed to upgrade to libvirt-bin 1.3.1-1ubuntu10.1 on Ubuntu 16.04 64-bit

Bug #1594902 reported by John Edwards
112
This bug affects 22 people
Affects Status Importance Assigned to Milestone
apparmor (Ubuntu)
Confirmed
Undecided
Unassigned
libvirt (Ubuntu)
Confirmed
Undecided
Unassigned

Bug Description

Output from 'apt-get upgrade':
Setting up libvirt-bin (1.3.1-1ubuntu10.1) ...
initctl: Unable to connect to Upstart: Failed to connect to socket /com/ubuntu/upstart: Connection refused
insserv: warning: script 'screen-cleanup' missing LSB tags and overrides
insserv: Default-Start undefined, assuming empty start runlevel(s) for script `screen-cleanup'
insserv: Default-Stop undefined, assuming empty stop runlevel(s) for script `screen-cleanup'
initctl: Unable to connect to Upstart: Failed to connect to socket /com/ubuntu/upstart: Connection refused
insserv: warning: script 'binfmt-support' missing LSB tags and overrides
insserv: Default-Start undefined, assuming empty start runlevel(s) for script `binfmt-support'
insserv: Default-Stop undefined, assuming empty stop runlevel(s) for script `binfmt-support'
initctl: Unable to connect to Upstart: Failed to connect to socket /com/ubuntu/upstart: Connection refused
insserv: warning: script 'screen-cleanup' missing LSB tags and overrides
insserv: Default-Start undefined, assuming empty start runlevel(s) for script `screen-cleanup'
insserv: Default-Stop undefined, assuming empty stop runlevel(s) for script `screen-cleanup'
initctl: Unable to connect to Upstart: Failed to connect to socket /com/ubuntu/upstart: Connection refused
insserv: warning: script 'binfmt-support' missing LSB tags and overrides
insserv: Default-Start undefined, assuming empty start runlevel(s) for script `binfmt-support'
insserv: Default-Stop undefined, assuming empty stop runlevel(s) for script `binfmt-support'
initctl: Unable to connect to Upstart: Failed to connect to socket /com/ubuntu/upstart: Connection refused
insserv: warning: script 'screen-cleanup' missing LSB tags and overrides
insserv: Default-Start undefined, assuming empty start runlevel(s) for script `screen-cleanup'
insserv: Default-Stop undefined, assuming empty stop runlevel(s) for script `screen-cleanup'
initctl: Unable to connect to Upstart: Failed to connect to socket /com/ubuntu/upstart: Connection refused
insserv: warning: script 'binfmt-support' missing LSB tags and overrides
insserv: Default-Start undefined, assuming empty start runlevel(s) for script `binfmt-support'
insserv: Default-Stop undefined, assuming empty stop runlevel(s) for script `binfmt-support'
Job for libvirt-bin.service failed because the control process exited with error code. See "systemctl status libvirt-bin.service" and "journalctl -xe" for details.
invoke-rc.d: initscript libvirt-bin, action "restart" failed.
dpkg: error processing package libvirt-bin (--configure):
 subprocess installed post-installation script returned error exit status 1
E: Sub-process /usr/bin/dpkg returned an error code (1)

Output from 'systemctl status libvirt-bin.service':
● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: inactive (dead) (Result: exit-code) since Tue 2016-06-21 17:55:16 BST; 4min 52s ago
     Docs: man:libvirtd(8)
           http://libvirt.org
  Process: 2984 ExecStart=/usr/sbin/libvirtd $libvirtd_opts (code=exited, status=6)
 Main PID: 2984 (code=exited, status=6)

Jun 21 17:55:15 lydia systemd[1]: Failed to start Virtualization daemon.
Jun 21 17:55:15 lydia systemd[1]: libvirt-bin.service: Unit entered failed state.
Jun 21 17:55:15 lydia systemd[1]: libvirt-bin.service: Failed with result 'exit-code'.
Jun 21 17:55:16 lydia systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Jun 21 17:55:16 lydia systemd[1]: Stopped Virtualization daemon.
Jun 21 17:55:16 lydia systemd[1]: libvirt-bin.service: Start request repeated too quickly.
Jun 21 17:55:16 lydia systemd[1]: Failed to start Virtualization daemon.

Tags: triage
Revision history for this message
Launchpad Janitor (janitor) wrote :

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

Changed in libvirt (Ubuntu):
status: New → Confirmed
Revision history for this message
John Edwards (john-cornerstonelinux) wrote :

Remove 'binfmt-support' package and tried upgrade again. Slightly different error message from 'systemctl status libvirt-bin.service' this time with addition of a 'NOTCONFIGURED' message:

Jun 27 22:57:22 lydia systemd[1]: libvirt-bin.service: Main process exited, code=exited, status=6/NOTCONFIGURED
Jun 27 22:57:22 lydia systemd[1]: Failed to start Virtualization daemon.
Jun 27 22:57:22 lydia systemd[1]: libvirt-bin.service: Unit entered failed state.
Jun 27 22:57:22 lydia systemd[1]: libvirt-bin.service: Failed with result 'exit-code'.
Jun 27 22:57:22 lydia systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Jun 27 22:57:22 lydia systemd[1]: Stopped Virtualization daemon.
Jun 27 22:57:22 lydia systemd[1]: libvirt-bin.service: Start request repeated too quickly.
Jun 27 22:57:22 lydia systemd[1]: Failed to start Virtualization daemon.

nijiwar (mkoleshev)
Changed in libvirt (Ubuntu):
assignee: nobody → bylXa_KoCMaTa (mkoleshev)
assignee: bylXa_KoCMaTa (mkoleshev) → nobody
Revision history for this message
Thomas Dreibholz (dreibh) wrote :

The bug is still there, in Ubuntu 16.04.1 with the following libvirt versions:
libvirt-bin:amd64/xenial-updates 1.3.1-1ubuntu10.1 uptodate
libvirt0:amd64/xenial-updates 1.3.1-1ubuntu10.1 uptodate

nornetpp@blanksjoe:~$ sudo service libvirt-bin start
Job for libvirt-bin.service failed because the control process exited with error code. See "systemctl status libvirt-bin.service" and "journalctl -xe" for details.
nornetpp@blanksjoe:~$ systemctl status libvirt-bin.service
● 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-08-08 14:22:28 CEST; 720ms ago
     Docs: man:libvirtd(8)
           http://libvirt.org
  Process: 15013 ExecStart=/usr/sbin/libvirtd $libvirtd_opts (code=exited, status=6)
 Main PID: 15013 (code=exited, status=6)

Aug 08 14:22:28 blanksjoe.simula.nornet systemd[1]: Failed to start Virtualization daemon.
Aug 08 14:22:28 blanksjoe.simula.nornet systemd[1]: libvirt-bin.service: Unit entered failed state.
Aug 08 14:22:28 blanksjoe.simula.nornet systemd[1]: libvirt-bin.service: Failed with result 'exit-code'.
Aug 08 14:22:28 blanksjoe.simula.nornet systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Aug 08 14:22:28 blanksjoe.simula.nornet systemd[1]: Stopped Virtualization daemon.
Aug 08 14:22:28 blanksjoe.simula.nornet systemd[1]: libvirt-bin.service: Start request repeated too quickly.
Aug 08 14:22:28 blanksjoe.simula.nornet systemd[1]: Failed to start Virtualization daemon.

I tried to purge all libvirt stuff (sudo apt-get purge 'libvirt.*') and reinstalling libvirt-bin again => no change.

Revision history for this message
Thomas Dreibholz (dreibh) wrote :

May be the problem is "apparmor". I noticed the following lines in /var/log/syslog:

Aug 8 14:37:34 blanksjoe systemd[1]: Starting Virtualization daemon...
Aug 8 14:37:34 blanksjoe libvirtd[15585]: libvirt version: 1.3.1, package: 1ubuntu10.1 (dann frazier <email address hidden> Fri, 03 Jun 2016 14:41:21 -0600)
Aug 8 14:37:34 blanksjoe libvirtd[15585]: hostname: blanksjoe.simula.nornet
Aug 8 14:37:34 blanksjoe libvirtd[15585]: Unable to initialize audit layer: Permission denied
Aug 8 14:37:34 blanksjoe kernel: [ 2198.315498] audit: type=1400 audit(1470659854.970:167): apparmor="DENIED" operation="create" profile="/usr/sbin/libvirtd" pid=15585 comm="libvirtd" family="netlink" sock_type="raw" protocol=9 requested_mask="create" denied_mask="create"
Aug 8 14:37:35 blanksjoe libvirtd[15585]: cannot connect to netlink socket with protocol 0: Permission denied
Aug 8 14:37:35 blanksjoe kernel: [ 2198.357952] audit: type=1400 audit(1470659855.014:168): apparmor="DENIED" operation="create" profile="/usr/sbin/libvirtd" pid=15585 comm="libvirtd" family="netlink" sock_type="raw" protocol=0 requested_mask="create" denied_mask="create"
Aug 8 14:37:35 blanksjoe systemd[1]: libvirt-bin.service: Main process exited, code=exited, status=6/NOTCONFIGURED
Aug 8 14:37:35 blanksjoe systemd[1]: Failed to start Virtualization daemon.
Aug 8 14:37:35 blanksjoe systemd[1]: libvirt-bin.service: Unit entered failed state.
Aug 8 14:37:35 blanksjoe systemd[1]: libvirt-bin.service: Failed with result 'exit-code'.
Aug 8 14:37:35 blanksjoe systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Aug 8 14:37:35 blanksjoe systemd[1]: Stopped Virtualization daemon.
Aug 8 14:37:35 blanksjoe systemd[1]: libvirt-bin.service: Start request repeated too quickly.
Aug 8 14:37:35 blanksjoe systemd[1]: Failed to start Virtualization daemon.

Revision history for this message
Thomas Dreibholz (dreibh) wrote :

Removing apparmor and libvirt-bin, running "apt-get auto-remove", purging all deleted packages, and reinstalling libvirt-bin, apparmor, apparmor-profiles and apparmor-profiles-extra seemed to have solved the problem. At least, my machine is working now.

I am not 100% sure whether the steps actually solved the problem, or some other side effects of the package removal and installation. I will soon try to upgrade another machine from 14.04 to 16.04. Then, I may be able to provide further information.

Revision history for this message
Thomas Dreibholz (dreibh) wrote :
Revision history for this message
Thomas Dreibholz (dreibh) wrote :

An update from another Ubuntu 14.04 -> Ubuntu 16.04 machine upgrade:

The following two steps seemed to fix the libvirt-bin service start problem here:

sudo apt-get purge 'libvirt.*' apparmor apparmor-profiles apparmor-profiles-extra
sudo apt-get install libvirt-bin apparmor apparmor-profiles

Revision history for this message
Thomas C. (thw-th) wrote :

It seems that there is problem with the systemd script. Systemd fails to monitor the processes accordingly. It starts fine and runs without problems, but systemd marks this service as incomplete (dead):

● libvirt-bin.service - Virtualization daemon
   Loaded: loaded (/lib/systemd/system/libvirt-bin.service; enabled; vendor preset: enabled)
   Active: inactive (dead) since Fri 2016-08-12 14:40:45 CEST; 24min ago
     Docs: man:libvirtd(8)
           http://libvirt.org
  Process: 6518 ExecStart=/usr/sbin/libvirtd $libvirtd_opts (code=exited, status=0/SUCCESS)
 Main PID: 6518 (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/libvirt-bin.service
           ├─6538 /usr/sbin/libvirtd -d
           ├─7170 /usr/sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/lib/libvirt/libvirt_leaseshelper
           └─7171 /usr/sbin/dnsmasq --conf-file=/var/lib/libvirt/dnsmasq/default.conf --leasefile-ro --dhcp-script=/usr/lib/libvirt/libvirt_leaseshelper

Restarting is not possible, because it start libvirtd a second time, which of course fails. This is reason why the package can be updated. After killing all libvirtd processes the package can be configured fine. So we should concentrate on the libvirt-bin.service.

Revision history for this message
John Edwards (john-cornerstonelinux) wrote :

Tried 'apt-get upgrade' again. Same result with the addition of the previous mentioned apparmor error (which was not present before). Contents of /etc/apparmor.d/usr.sbin.libvirtd on this system is attached.

Syslog of restart:
Aug 13 09:59:31 lydia systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Aug 13 09:59:31 lydia systemd[1]: Stopped Virtualization daemon.
Aug 13 09:59:31 lydia systemd[1]: Starting Virtualization daemon...
Aug 13 09:59:31 lydia libvirtd[8449]: libvirt version: 1.3.1, package: 1ubuntu10.1 (dann frazier <email address hidden> Fri, 03 Jun 2016 14:41:21 -0600)
Aug 13 09:59:31 lydia libvirtd[8449]: hostname: lydia.local.cornerstonelinux.co.uk
Aug 13 09:59:31 lydia libvirtd[8449]: Unable to initialise audit layer: Permission denied
Aug 13 09:59:31 lydia kernel: [ 1098.685954] audit: type=1400 audit(1471078771.194:128): apparmor="DENIED" operation="create" profile="/usr/sbin/libvirtd" pid=8449 comm="libvirtd" family="netlink" sock_type="raw" protocol=9 requested_mask="create" denied_mask="create"
Aug 13 09:59:31 lydia libvirtd[8449]: cannot connect to netlink socket with protocol 0: Permission denied
Aug 13 09:59:31 lydia kernel: [ 1098.748718] audit: type=1400 audit(1471078771.258:129): apparmor="DENIED" operation="create" profile="/usr/sbin/libvirtd" pid=8449 comm="libvirtd" family="netlink" sock_type="raw" protocol=0 requested_mask="create" denied_mask="create"
Aug 13 09:59:31 lydia systemd[1]: libvirt-bin.service: Main process exited, code=exited, status=6/NOTCONFIGURED
Aug 13 09:59:31 lydia systemd[1]: Failed to start Virtualization daemon.
Aug 13 09:59:31 lydia systemd[1]: libvirt-bin.service: Unit entered failed state.
Aug 13 09:59:31 lydia systemd[1]: libvirt-bin.service: Failed with result 'exit-code'.
Aug 13 09:59:31 lydia systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Aug 13 09:59:31 lydia systemd[1]: Stopped Virtualization daemon.
Aug 13 09:59:31 lydia systemd[1]: libvirt-bin.service: Start request repeated too quickly.
Aug 13 09:59:31 lydia systemd[1]: Failed to start Virtualization daemon.

Revision history for this message
Thomas C. (thw-th) wrote :

For my systems I found the reason: libvirtd_opts in /etc/default/libvirt-bin was set to "-d", which instructs libvirtd to fork into background. But the systemd service did not expect a fork (type=notify). This was the reason that systemd fails to restart the service. I believe it was the default in older systems. I did not verify that.

Check you /etc/default/libvirt-bin, remove the -d and libvirtd acts fine with systemd.

Revision history for this message
John Edwards (john-cornerstonelinux) wrote :

My /etc/default/libvirt-bin does not contain the -d option, but the /etc/init.d/libvirt-bin init script does.

Example:
  start-stop-daemon --start --quiet --pidfile $PIDFILE \
   --exec $DAEMON -- -d $libvirtd_opts

Revision history for this message
John Edwards (john-cornerstonelinux) wrote :

Contents of /etc/default/libvirt-bin:

# Defaults for libvirtd initscript (/etc/init.d/libvirtd)
# This is a POSIX shell fragment

# Start libvirtd to handle qemu/kvm:
start_libvirtd="yes"

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

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

# Whether to mount a systemd like cgroup layout (only
# useful when not running systemd)
#mount_cgroups=yes
# Which cgroups to mount
#cgroups="memory devices"

Revision history for this message
John Edwards (john-cornerstonelinux) wrote :

Contents of /etc/init.d/libvirt-bin attached.

Revision history for this message
John Edwards (john-cornerstonelinux) wrote :

Contents of /etc/init/libvirt-bin.conf attached.

Revision history for this message
Markus Neubauer (mn-ubuntu) wrote :

Can somebody confirm that this workaround is the same:

# kill `cat /var/run/libvirtd.pid`
# apt-get -f install

Revision history for this message
Harry de Vries (h-vries50) wrote : Re: [Bug 1594902] Re: Failed to upgrade to libvirt-bin 1.3.1-1ubuntu10.1 on Ubuntu 16.04 64-bit

Hallo Markus, is this also the workaround for my system ?

Op 05-10-16 om 10:05 schreef Markus Neubauer:
> Can somebody confirm that this workaround is the same:
>
> # kill `cat /var/run/libvirtd.pid`
> # apt-get -f install
>

Revision history for this message
Markus Neubauer (mn-ubuntu) wrote :

Hi Harry, you need to give it a try…

On 3 different busy hosts (while running kvm's) it worked for me. I did not need to reboot nor restart kvm.

Revision history for this message
Markus Neubauer (mn-ubuntu) wrote :

Sorry, it looks like I have overseen something. #1629634 is not a duplicate of this here.

Revision history for this message
peterdv (peter-dahl-vestergaard) wrote :

Redirected here from bug 1574566,

In my case, similar to comment 4 above, I found the culpit in /var/log/syslog:

Oct 15 10:38:00 coop33695 systemd[1]: Starting Virtualization daemon...
Oct 15 10:38:00 coop33695 libvirtd[4704]: libvirt version: 1.3.1, package: 1ubuntu10.3 (Christian Ehrhar

Oct 15 10:38:00 coop33695 systemd[1]: Starting Virtualization daemon...
Oct 15 10:38:00 coop33695 libvirtd[4704]: libvirt version: 1.3.1, package: 1ubuntu10.3 (Christian Ehrhardt <email address hidden> Wed, 21 Sep 2016 13:46:44 +0200)
Oct 15 10:38:00 coop33695 libvirtd[4704]: hostname: coop33695
Oct 15 10:38:00 coop33695 libvirtd[4704]: Unable to initialize audit layer: Permission denied
Oct 15 10:38:00 coop33695 kernel: [ 1136.505334] audit: type=1400 audit(1476520680.441:81): apparmor="DENIED" operation="create" profile="/usr/sbin/libvirtd" pid=4704 comm="libvirtd" family="netlink" s
ock_type="raw" protocol=9 requested_mask="create" denied_mask="create"
Oct 15 10:38:00 coop33695 kernel: [ 1136.506987] audit: type=1400 audit(1476520680.445:82): apparmor="DENIED" operation="create" profile="/usr/sbin/libvirtd" pid=4704 comm="libvirtd" family="netlink" s
ock_type="raw" protocol=0 requested_mask="create" denied_mask="create"
Oct 15 10:38:00 coop33695 libvirtd[4704]: cannot connect to netlink socket with protocol 0: Permission denied
Oct 15 10:38:00 coop33695 systemd[1]: libvirt-bin.service: Main process exited, code=exited, status=6/NOTCONFIGURED
Oct 15 10:38:00 coop33695 systemd[1]: Failed to start Virtualization daemon.
Oct 15 10:38:00 coop33695 systemd[1]: libvirt-bin.service: Unit entered failed state.
Oct 15 10:38:00 coop33695 systemd[1]: libvirt-bin.service: Failed with result 'exit-code'.
Oct 15 10:38:00 coop33695 systemd[1]: libvirt-bin.service: Service hold-off time over, scheduling restart.
Oct 15 10:38:00 coop33695 systemd[1]: Stopped Virtualization daemon.

The suggested solution found at https://appuals.com/unable-to-initialize-audit-layer-permission-denied/ :

# sudo apparmor_parser –purge-cache
# sudo apparmor_parser -R /etc/apparmor.d/usr.sbin.libvirtd
# sudo apparmor_parser -r /etc/apparmor.d/usr.sbin.libvirtd
# sudo systemctl restart libvirt-bin
# sudo apt-get -f install

fixed my problem

Revision history for this message
Hans Deragon (deragon) wrote :

None of the following suggestions below worked for me. The odd thing is that this problem appeared to me in 2017-01-18, while it appeared to others much earlier. Why hasn't the problem occurred to everyone at the same time?

Solutions that failed for me:

Thomas Dreibholz (dreibh)
sudo apt-get purge 'libvirt.*' apparmor apparmor-profiles apparmor-profiles-extra
sudo apt-get install libvirt-bin apparmor apparmor-profiles

peterdv (peter-dahl-vestergaard)
sudo apparmor_parser –purge-cache
sudo apparmor_parser -R /etc/apparmor.d/usr.sbin.libvirtd
sudo apparmor_parser -r /etc/apparmor.d/usr.sbin.libvirtd
sudo systemctl restart libvirt-bin
sudo apt-get -f install

Harry de Vries (h-vries50)
sudo kill `cat /var/run/libvirtd.pid`
sudo apt-get -f install

Revision history for this message
Seth Arnold (seth-arnold) wrote :

Hans, how odd. The people in this report who included dmesg often had AppArmor DENIED messages about netlink raw sockets in their logs.

Does your /etc/apparmor.d/usr.sbin.libvirtd include the following?

  network netlink,

Thanks

Revision history for this message
Hans Deragon (deragon) wrote :

Seth, yes, I have 'network netlink,' in /etc/apparmor.d/usr.sbin.libvirtd.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

So Hanns,
do you have other related apparmor Denies in your dmesg?

Also if possible could you attach a copy of your upgrade related logs?
You should be able to use this after your failed upgrade to do so:
  $ apport-bug 1594902

Revision history for this message
Ben Stanley (ben-stanley) wrote :

I observed the same messages in /var/log/syslog.
Reconfiguring apparmor as shown in #19 solved the problem for me.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Some very similar bugs also reported to get around it with:
$ /etc/init.d/apparmor restart
$ service libvirt-bin start
Which seems less than the force reload of the profile itself to me - might need a statement from the security Team here. But to test confirm this and others we need to get a recipe to reproduce.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

I once more tried to reproduce and check a few more logs.
Please do mind that bug 1386465 seems related or even the same - and occorring every now and then since 14.04->14.10 - but always ended similar with "unable to reproduce" or open questions :-/

I happened to find that Serge had no success reproducing so far on the older bug and expected to be no different, but always worth a try.
TODO - what I did

The upgrade then effectively was from 1.2.2-0ubuntu13.1.17 to TODO with a running guest.
The upgrade itself ran fine until it asked me to reboot, I checked status before and after that reboot,

$ service libvirt-bin status
libvirt-bin start/running, process 13840
$ virsh list | grep running
 2 testguest running
$ uvt-kvm ssh --insecure testguest "date; uptime"
Mon Feb 13 07:55:53 UTC 2017
 07:55:53 up 32 min, 0 users, load average: 0.00, 0.00, 0.00
$ dmesg | grep -i deni
<nothing>

Then after the restart I got:
- A correctly running service (now systemd output, but clealer not as in comment #9)
- Guest that starts just fine
- No Denies by apparmor

But - I had switched apparmor to audit mode for libvirt and did not see the netlink message at all.
You had:
  apparmor="DENIED" operation="create" profile="/usr/sbin/libvirtd" pid=15585 comm="libvirtd" family="netlink" sock_type="raw" protocol=9 requested_mask="create" denied_mask="create"
I'm fine not having the DENIED, but not seeing it at all, indicates to me that you have some sort of setup that triggers this.
This "bit of setup" might be what we look out for to be able to reproduce.

I'll look into that config a bit if I can easily find it, but would ask all of you if you know what of your config it might be.

I'll also duplicate a few more similar reports onto this, to hope we can find that missing config-bit together.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Upgrades were 1.2.2-0ubuntu13.1.17 to 1.3.1-1ubuntu10.7 - but from the history on this I assume tha absolute version numbers are unimportant.

Repro so far:
1. Trusty KVM Guest
2. Install libvirt / kvm
3. Create a 2nd level guest
4. Check logs and config
5. Upgrade to Xenial
6. Check status, logs and so on

As I said - so far this does not reproduce the issue, but I hope together we can find how to reproduce it.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

I was playing around with the options that were mentioned before in this or similar bugs.
/etc/default/libvirt-bin
libvirtd_opts="-d -l"

/etc/libvirt/libvirtd.conf
listen_tls = [0|1]
listen_tcp = [0|1]

But I realized after a while that the netlink messages show up in the default config without tweaking any. What I had to do to get them like:
  Feb 13 12:58:15 test-trusty-xenial-libvirt-upgrade audit[1242]: AVC apparmor="AUDIT" operation="recvmsg" profile="/usr/sbin/libvirtd" pid=1242 comm="libvirtd" family="netlink" sock_type="raw" protocol=15 requested_mask="receive"

Was actually starting/stopping guests.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

As mentioned I was able to get the netlink messages
But as I said before - no denies, all working just fine.

I was trying to connect the breadcrumbs I had I was retrying with a libvirt listening to tcp and having guest autostart set before upgrade.

That means the repro as in comment #27 + extra:
- set guest to autostart (virsh autostart testguest)
- configure libvirt to accept tcp

Those changes are not helping to recreate the issue, so for now I'd consider them not needed.
If one can help to get this to a working repro please let me know.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

I read into an mysql dh_apparmor case (bug 1435368) that was mentioned that it might be related.

There as well a postinst call has issues due to not yet reloaded apparmor profiles.

But the libvirt postinst already has:
    for p in usr.sbin.libvirtd usr.lib.libvirt.virt-aa-helper ; do
        profile="/etc/apparmor.d/$p"
        if [ -f "$profile" ] && aa-status --enabled 2>/dev/null; then
            apparmor_parser -r "$profile" || true
        fi
    done

While that lacks the --remove and the --purge-cache of the workaround it should still update the profile.
Yet there is a '|| true', so one might have failed to reload and then trigger.

Also the libvirt postinst seems to intentionally carry all restarting code AFTER the #DEBHELPER# section.
So the dh_apparmor code would run there I think and later code in the postinst should only face the reloaded profiles.

I wonder how/where/which-log could confirmed that these reloads (the explicit one from postinst and the apparmor one) failed ...? The service is restarted automatically
Maybe if one can reproduce the case he could debug that.

So please:
1. if one can modify my steps-to-repro in a way that they trigger please let us know
2. If one runs into this, before applying the workaround please check which profiles are loaded.
   Unfortunately I don't know a good way to check if the loaded one (assumed to be old) matches the on disk profile (new after update).

Revision history for this message
Launchpad Janitor (janitor) wrote :

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

Changed in systemd (Ubuntu):
status: New → Confirmed
affects: systemd → systemd (Ubuntu)
no longer affects: systemd (Ubuntu)
Changed in qemu (Ubuntu):
status: New → Confirmed
affects: libvirt → qemu (Ubuntu)
no longer affects: qemu (Ubuntu)
Changed in qemu (Ubuntu):
status: New → Confirmed
Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

I was cleaning up bug tasks, due to many being tasked against various upstreams that needed a few transitions to be cleaned.

Now it is correct IMHO - libvirt (showing the issues) and apparmor as (maybe being related in not properly refreshing)

affects: apparmor → qemu (Ubuntu)
no longer affects: qemu (Ubuntu)
Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Thanks to tyhicks from the security Team here some guidance how to go for step 2 of comment #30.
If anybody is hitting this issue again, please help to verify this before applying any of the workarounds summarized by Hans in comment #20.

To do so follow this:

# There are several moving parts involved:
#
# 1. The human readable profile
# 2. The binary cache file
# 3. The policy loaded into the kernel

# Save off the binary cache file
$ sudo mv /etc/apparmor.d/cache/usr.sbin.libvirtd /tmp/usr.sbin.libvirtd.oldcache

# Create a new binary cache file from the human readable profile (but do not load it) and save it off
$ sudo apparmor_parser -TWQ /etc/apparmor.d/usr.sbin.libvirtd
$ sudo mv /etc/apparmor.d/cache/usr.sbin.libvirtd /tmp/usr.sbin.libvirtd.newcache

# Verify that the old and new binary cache file matches the policy in the kernel
#
# Note: The in kernel path has an integer is appended to the end of the profile
# name and I can't tell you what the integer will be ahead of time, so use wildcard
$ sudo sha1sum /sys/kernel/security/apparmor/policy/profiles/usr.sbin.libvirtd.*/raw_data /tmp/usr.sbin.libvirtd.*
bbdf01649dd59ab1bd3d3696788aa0be9f6f6b03 /sys/kernel/security/apparmor/policy/profiles/usr.sbin.libvirtd.18/raw_data
bbdf01649dd59ab1bd3d3696788aa0be9f6f6b03 /tmp/usr.sbin.libvirtd.newcache
bbdf01649dd59ab1bd3d3696788aa0be9f6f6b03 /tmp/usr.sbin.libvirtd.oldcache

# If all hashes match, then it means that the profile, binary cache, and
# in-kernel policy are all in sync

But if in the error case all hashes would match it would make no sense that reloading the profiles helps as reported multiple times. So lets hope we can confirm this once somebody hits it again.

Revision history for this message
John Johansen (jjohansen) wrote :

There is a 3rd level of check that can be applied if those sha1sums don't match.

sys/kernel/security/apparmor/policy/profiles/usr.sbin.libvirtd.*/raw_hash

should be the same as the sha1sum for raw_data
i.e
$ cat sys/kernel/security/apparmor/policy/profiles/usr.sbin.libvirtd.*/raw_hash
bbdf01649dd59ab1bd3d3696788aa0be9f6f6b03

$ sha1sum /sys/kernel/security/apparmor/policy/profiles/usr.sbin.libvirtd.*/raw_data
bbdf01649dd59ab1bd3d3696788aa0be9f6f6b03 /sys/kernel/security/apparmor/policy/profiles/usr.sbin.libvirtd.18/raw_data

The raw_hash sum is taken at load time, and can be used to verify the sum of what was loaded and policy is applying. The raw_hash and sha1sum raw_data should always match unless there is memory corruption, or a bug in reading out the raw_data file.

Revision history for this message
Launchpad Janitor (janitor) wrote :

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

Changed in apparmor (Ubuntu):
status: New → Confirmed
Revision history for this message
Wei Zhou (ustcweizhou) wrote :

FYI

We fixed it by making the following change:

'''
--- /lib/systemd/system/libvirt-bin.service.bak 2017-05-15 10:21:10.832503252 +0000
+++ /lib/systemd/system/libvirt-bin.service 2017-05-15 10:22:24.631689012 +0000
@@ -20,6 +20,8 @@
 LimitNOFILE=infinity
 LimitNPROC=infinity
 TasksMax=infinity
+Type=forking
+PIDFile=/var/run/libvirtd.pid

 [Install]
 Alias=libvirtd.service
'''

pkill libvirtd
systemctl daemon-reload
service libvirtd restart

Revision history for this message
Hans Deragon (deragon) wrote :

ChristianEhrhardt (paelzer) and John Johansen (jjohansen), I tried your sha1sum checks and all looks good, but the problem still persists. Nothing suggested in this bug reports works for me. Luckily, on my system where it fails, I do not make use of libvirt; this issue is just an annoying error message when I upgrade my system. My server does not suffer from this problem; wonder why only some system suffer from this problem suddenly.

tags: added: triage
Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

@ustcweizhou - very interesting approach to fix this. The type is usually "notify".
There is a drawback that you change implies follow up units might start as soon as the daemonizing of libvirt is complete which might be too early. The notification would usually signal that it is completely ready and follow on units can be started. But lets ignore that for now and consider how it could affect the application of the netlink apparmor rule.

Related to comment #10 and comment #11 ff.
If there is an old manual config that will set -d in /etc/default/libvirt-bin /etc/default/libvirt-bin then your change of the service file would make it match the behavior.
There should be a non-default connection as the service file /lib/systemd/system/libvirt-bin.service starts libvirt "directly" and not via /etc/default/libvirt-bin - so the -d in that old files (if you are on SystemV/Upstart) should not matter.

For all still affected by this could you check:
1. if your libvirt is run with "-d" option (which it should not be anymore)
2. if #1 was yes, then where this config comes from
3. once you debugged #2, decide if you either want to become closer to the supported content by changing back OR try a fix like suggested in comment #38 (which is not generally applicable)

For everyone passing step #2 I'd be interested how in your personal system setup the "-d" gets applied, as with the systemd setup it should not be used anymore.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

Note - I don't see why/how that would affect the apparmor issue, but since there are multiple reports related to the -d demonizing we should go on to understand this.

Revision history for this message
Christian Ehrhardt  (paelzer) wrote :

We think we finally found the issue behind this and in hindsight the explanation why this was so bad to reproduce is that it seems to depend on apparmor profile caching.
Dupping on the bug that will SRU a fix.

Revision history for this message
keshara Dorakumbura (krs4keshara) wrote :

I just got into this same issue. My system is;

NAME="Ubuntu"
VERSION="16.04.1 LTS (Xenial Xerus)"

So, before i install the libvirt-bin, I remember I just messed up my locale settings. I didn't notice that and then I tried to setup virtualization. But it kept failed and finally fond this bug tread. Even any of the work around didn't solve the issue.

So accidentally I checked my locate settings by $ localectl. It was like this.

   System Locale: TIME=en_US
       VC Keymap: n/a
      X11 Layout: us
       X11 Model: pc105

I then changed it to as below.

   System Locale: LANG=en_US.UTF-8
       VC Keymap: n/a
      X11 Layout: us
       X11 Model: pc105

great, problem solved. Hope this may help.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.