yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1746188] [NEW] Virtlogd recreates console.log file as root:root after live migration

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Daniel Russell <danielr@xxxxxxxxxxxxxxxx>
Date: Tue, 30 Jan 2018 08:09:25 -0000
Reply-to: Bug 1746188 <1746188@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
Public bug reported:

Hi,

Description / Steps to reproduce
================================

When instances are launched, they get the following console/serial
configuration :

    <serial type="pty">
      <log file="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log" append="off"/>
      <target type="isa-serial" port="0"/>
    </serial>
    <console type="pty">
      <log file="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log" append="off"/>
      <target type="serial" port="0"/>\n
    </console>

If I look at the permissions for the console.log I see :

[root@<snip> nova]# ls -l /var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log
-rw-------. 1 nova openstack 0 Jan 30 11:09 /var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log
[root@<snip> nova]#

If I then live migrate the instance to another host (or complete a
resize operation), virtlogd deletes the console.log and then recreates
it as root:root.

[root@<snip> nova]# ls -l /var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log
-rw-------. 1 root root 0 Jan 30 11:14 /var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log
[root@<snip> nova]#

This looks to be because when the instance is configured with
append="off", it ends up setting trunc to True in
https://github.com/libvirt/libvirt/blob/93575f345116fe1413f6fe3109227b8be2f416da/src/util/virrotatingfile.c#L260-L265
and deletes the console log before recreating.  As virtlogd is running
as root and it doesn't seem to chown anything, it becomes root:root.

The first migration completes successfully but subsequent ones fail due
to permissions errors trying to access the console.log.

If I change virt/libvirt/config.py to set append="on", the log isn't
recreated (but I know have a problem with an ever growing log file).

Expected result
===============
Console.log still have nova:openstack ownership

Actual result
=============
Console.log has root:root ownership

Environment
===========
This is a libvirt + KVM environment on CentOS 7.

nova - 16.0.3
libvirt - 3.2.0-14.el7_4.7
qemu - 2.9.0-16.el7_4.13.1

In /etc/libvirt/qemu.conf, I have the following configured :
user = "nova"
group = "openstack"
dynamic_ownership = 0

SElinux is enabled, and if I set it to permissive and make it error for
that folder, I get records like :

(virtlogd attempting delete)
time->Tue Jan 30 12:43:27 2018
type=PROCTITLE msg=audit(1517276607.013:90227): proctitle="/usr/sbin/virtlogd"
type=PATH msg=audit(1517276607.013:90227): item=1 name="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log" inode=1898807 dev=00:27 mode=0100600 ouid=162 ogid=1100 rdev=00:00 obj=system_u:object_r:nfs_t:s0 objtype=DELETE
type=PATH msg=audit(1517276607.013:90227): item=0 name="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/" inode=1898806 dev=00:27 mode=040755 ouid=162 ogid=1100 rdev=00:00 obj=system_u:object_r:nfs_t:s0 objtype=PARENT
type=CWD msg=audit(1517276607.013:90227):  cwd="/"
type=SYSCALL msg=audit(1517276607.013:90227): arch=c000003e syscall=87 success=yes exit=0 a0=7f406c000d30 a1=7f406c000cd9 a2=0 a3=6e6f632f36353935 items=2 ppid=1 pid=25859 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="virtlogd" exe="/usr/sbin/virtlogd" subj=system_u:system_r:virtlogd_t:s0-s0:c0.c1023
type=AVC msg=audit(1517276607.013:90227): avc:  denied  { unlink } for  pid=25859 comm="virtlogd" name="console.log" dev="0:39" ino=1898807 scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
type=AVC msg=audit(1517276607.013:90227): avc:  denied  { remove_name } for  pid=25859 comm="virtlogd" name="console.log" dev="0:39" ino=1898807 scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
type=AVC msg=audit(1517276607.013:90227): avc:  denied  { write } for  pid=25859 comm="virtlogd" name="e53cf7b4-e11a-445f-b4e3-006120e8d8006" dev="0:39" ino=1898806 scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir

(virtlogd attempting create)
time->Tue Jan 30 12:43:27 2018
type=PROCTITLE msg=audit(1517276607.018:90231): proctitle="/usr/sbin/virtlogd"
type=PATH msg=audit(1517276607.018:90231): item=1 name="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log" inode=1898807 dev=00:27 mode=0100600 ouid=0 ogid=99 rdev=00:00 obj=system_u:object_r:nfs_t:s0 objtype=NORMAL
type=PATH msg=audit(1517276607.018:90231): item=0 name="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/" inode=1898806 dev=00:27 mode=040755 ouid=162 ogid=1100 rdev=00:00 obj=system_u:object_r:nfs_t:s0 objtype=PARENT
type=CWD msg=audit(1517276607.018:90231):  cwd="/"
type=SYSCALL msg=audit(1517276607.018:90231): arch=c000003e syscall=2 success=yes exit=15 a0=7f406c000d30 a1=80441 a2=180 a3=7f406c000d90 items=2 ppid=1 pid=25859 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="virtlogd" exe="/usr/sbin/virtlogd" subj=system_u:system_r:virtlogd_t:s0-s0:c0.c1023
type=AVC msg=audit(1517276607.018:90231): avc:  denied  { create } for  pid=25859 comm="virtlogd" name="console.log" scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
type=AVC msg=audit(1517276607.018:90231): avc:  denied  { add_name } for  pid=25859 comm="virtlogd" name="console.log" scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir

** Affects: nova
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to OpenStack Compute (nova).
https://bugs.launchpad.net/bugs/1746188

Title:
  Virtlogd recreates console.log file as root:root after live migration

Status in OpenStack Compute (nova):
  New

Bug description:
  Hi,

  Description / Steps to reproduce
  ================================

  When instances are launched, they get the following console/serial
  configuration :

      <serial type="pty">
        <log file="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log" append="off"/>
        <target type="isa-serial" port="0"/>
      </serial>
      <console type="pty">
        <log file="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log" append="off"/>
        <target type="serial" port="0"/>\n
      </console>

  If I look at the permissions for the console.log I see :

  [root@<snip> nova]# ls -l /var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log
  -rw-------. 1 nova openstack 0 Jan 30 11:09 /var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log
  [root@<snip> nova]#

  If I then live migrate the instance to another host (or complete a
  resize operation), virtlogd deletes the console.log and then recreates
  it as root:root.

  [root@<snip> nova]# ls -l /var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log
  -rw-------. 1 root root 0 Jan 30 11:14 /var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log
  [root@<snip> nova]#

  This looks to be because when the instance is configured with
  append="off", it ends up setting trunc to True in
  https://github.com/libvirt/libvirt/blob/93575f345116fe1413f6fe3109227b8be2f416da/src/util/virrotatingfile.c#L260-L265
  and deletes the console log before recreating.  As virtlogd is running
  as root and it doesn't seem to chown anything, it becomes root:root.

  The first migration completes successfully but subsequent ones fail
  due to permissions errors trying to access the console.log.

  If I change virt/libvirt/config.py to set append="on", the log isn't
  recreated (but I know have a problem with an ever growing log file).

  Expected result
  ===============
  Console.log still have nova:openstack ownership

  Actual result
  =============
  Console.log has root:root ownership

  Environment
  ===========
  This is a libvirt + KVM environment on CentOS 7.

  nova - 16.0.3
  libvirt - 3.2.0-14.el7_4.7
  qemu - 2.9.0-16.el7_4.13.1

  In /etc/libvirt/qemu.conf, I have the following configured :
  user = "nova"
  group = "openstack"
  dynamic_ownership = 0

  SElinux is enabled, and if I set it to permissive and make it error
  for that folder, I get records like :

  (virtlogd attempting delete)
  time->Tue Jan 30 12:43:27 2018
  type=PROCTITLE msg=audit(1517276607.013:90227): proctitle="/usr/sbin/virtlogd"
  type=PATH msg=audit(1517276607.013:90227): item=1 name="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log" inode=1898807 dev=00:27 mode=0100600 ouid=162 ogid=1100 rdev=00:00 obj=system_u:object_r:nfs_t:s0 objtype=DELETE
  type=PATH msg=audit(1517276607.013:90227): item=0 name="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/" inode=1898806 dev=00:27 mode=040755 ouid=162 ogid=1100 rdev=00:00 obj=system_u:object_r:nfs_t:s0 objtype=PARENT
  type=CWD msg=audit(1517276607.013:90227):  cwd="/"
  type=SYSCALL msg=audit(1517276607.013:90227): arch=c000003e syscall=87 success=yes exit=0 a0=7f406c000d30 a1=7f406c000cd9 a2=0 a3=6e6f632f36353935 items=2 ppid=1 pid=25859 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="virtlogd" exe="/usr/sbin/virtlogd" subj=system_u:system_r:virtlogd_t:s0-s0:c0.c1023
  type=AVC msg=audit(1517276607.013:90227): avc:  denied  { unlink } for  pid=25859 comm="virtlogd" name="console.log" dev="0:39" ino=1898807 scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
  type=AVC msg=audit(1517276607.013:90227): avc:  denied  { remove_name } for  pid=25859 comm="virtlogd" name="console.log" dev="0:39" ino=1898807 scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir
  type=AVC msg=audit(1517276607.013:90227): avc:  denied  { write } for  pid=25859 comm="virtlogd" name="e53cf7b4-e11a-445f-b4e3-006120e8d8006" dev="0:39" ino=1898806 scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir

  (virtlogd attempting create)
  time->Tue Jan 30 12:43:27 2018
  type=PROCTITLE msg=audit(1517276607.018:90231): proctitle="/usr/sbin/virtlogd"
  type=PATH msg=audit(1517276607.018:90231): item=1 name="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/console.log" inode=1898807 dev=00:27 mode=0100600 ouid=0 ogid=99 rdev=00:00 obj=system_u:object_r:nfs_t:s0 objtype=NORMAL
  type=PATH msg=audit(1517276607.018:90231): item=0 name="/var/lib/nova/instances/e53cf7b4-e11a-445f-b4e3-006120e8d800/" inode=1898806 dev=00:27 mode=040755 ouid=162 ogid=1100 rdev=00:00 obj=system_u:object_r:nfs_t:s0 objtype=PARENT
  type=CWD msg=audit(1517276607.018:90231):  cwd="/"
  type=SYSCALL msg=audit(1517276607.018:90231): arch=c000003e syscall=2 success=yes exit=15 a0=7f406c000d30 a1=80441 a2=180 a3=7f406c000d90 items=2 ppid=1 pid=25859 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) ses=4294967295 comm="virtlogd" exe="/usr/sbin/virtlogd" subj=system_u:system_r:virtlogd_t:s0-s0:c0.c1023
  type=AVC msg=audit(1517276607.018:90231): avc:  denied  { create } for  pid=25859 comm="virtlogd" name="console.log" scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=file
  type=AVC msg=audit(1517276607.018:90231): avc:  denied  { add_name } for  pid=25859 comm="virtlogd" name="console.log" scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:nfs_t:s0 tclass=dir

To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1746188/+subscriptions
Follow ups

[Bug 1746188] Re: Virtlogd recreates console.log file as root:root after live migration
From: Sylvain Bauza, 2018-02-08