And here is how we can force recreate the bug:

[root@overcloud-compute-0 ~]# chcon -t svirt_image_t /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log
[root@overcloud-compute-0 ~]# ls -alZ /var/lib/nova/instances/*/console.log-rw-------. root root system_u:object_r:svirt_image_t:s0 /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log
[root@overcloud-compute-0 ~]# tail -f /var/log/nova/nova-compute.log
(...)
At this point, run `nova start <domain UUID>`
(...) 
2017-10-09 21:41:40.732 2878 TRACE oslo_messaging.rpc.dispatcher 
2017-10-09 21:41:40.732 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/db/sqlalchemy/api.py", line 2530, in _instance_update
2017-10-09 21:41:40.732 2878 TRACE oslo_messaging.rpc.dispatcher     actual=actual_state, expected=expected)
2017-10-09 21:41:40.732 2878 TRACE oslo_messaging.rpc.dispatcher 
2017-10-09 21:41:40.732 2878 TRACE oslo_messaging.rpc.dispatcher UnexpectedTaskStateError: Unexpected task state: expecting (u'powering-on',) but the actual state is None
2017-10-09 21:41:40.732 2878 TRACE oslo_messaging.rpc.dispatcher 
2017-10-09 21:41:40.732 2878 TRACE oslo_messaging.rpc.dispatcher 
2017-10-09 21:41:40.780 2878 WARNING nova.compute.manager [req-1f8dea84-6bcc-40cd-aabe-84cddda1f69a - - - - -] [instance: 8b3f8add-9029-4b37-9e67-fe3f82624c2b] Instance is not stopped. Calling the stop API. Current vm_state: stopped, current task_state: None, original DB power_state: 0, current VM power_state: 1
2017-10-09 21:43:06.037 2878 WARNING nova.compute.manager [req-cd431a57-d462-4525-abe4-5f471a073987 - - - - -] [instance: 8b3f8add-9029-4b37-9e67-fe3f82624c2b] Instance shutdown by itself. Calling the stop API. Current vm_state: active, current task_state: None, original DB power_state: 1, current VM power_state: 4
2017-10-09 21:43:25.522 2878 WARNING nova.compute.manager [req-1f8dea84-6bcc-40cd-aabe-84cddda1f69a - - - - -] [instance: 8b3f8add-9029-4b37-9e67-fe3f82624c2b] Instance is not stopped. Calling the stop API. Current vm_state: stopped, current task_state: None, original DB power_state: 4, current VM power_state: 1
2017-10-09 21:46:12.174 2878 ERROR nova.virt.libvirt.driver [req-a4c08cf2-0635-4a12-b948-36623ca1cd96 8ef7fc2a147f42af9dde53f623287b59 c98ba68d96b24ed3827189e17314ecb7 - - -] Error launching a defined domain with XML: <domain type='kvm'>
  <name>instance-00000001</name>
  <uuid>8b3f8add-9029-4b37-9e67-fe3f82624c2b</uuid>
  <metadata>
    <nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0">
      <nova:package version="2015.1.4-44.el7ost"/>
      <nova:name>cirros-test1</nova:name>
      <nova:creationTime>2017-10-09 21:46:11</nova:creationTime>
      <nova:flavor name="m1.tiny">
        <nova:memory>512</nova:memory>
        <nova:disk>1</nova:disk>
        <nova:swap>0</nova:swap>
        <nova:ephemeral>0</nova:ephemeral>
        <nova:vcpus>1</nova:vcpus>
      </nova:flavor>
      <nova:owner>
        <nova:user uuid="8ef7fc2a147f42af9dde53f623287b59">admin</nova:user>
        <nova:project uuid="c98ba68d96b24ed3827189e17314ecb7">admin</nova:project>
      </nova:owner>
      <nova:root type="image" uuid="b077edf2-1701-44de-b913-fa90967fc092"/>
    </nova:instance>
  </metadata>
  <memory unit='KiB'>524288</memory>
  <currentMemory unit='KiB'>524288</currentMemory>
  <vcpu placement='static'>1</vcpu>
  <cputune>
    <shares>1024</shares>
  </cputune>
  <sysinfo type='smbios'>
    <system>
      <entry name='manufacturer'>Red Hat</entry>
      <entry name='product'>OpenStack Compute</entry>
      <entry name='version'>2015.1.4-44.el7ost</entry>
      <entry name='serial'>b5d933d2-ec02-4284-98fc-10d70ea0fc86</entry>
      <entry name='uuid'>8b3f8add-9029-4b37-9e67-fe3f82624c2b</entry>
    </system>
  </sysinfo>
  <os>
    <type arch='x86_64' machine='pc-i440fx-rhel7.4.0'>hvm</type>
    <boot dev='hd'/>
    <smbios mode='sysinfo'/>
  </os>
  <features>
    <acpi/>
    <apic/>
  </features>
  <cpu mode='host-model' check='partial'>
    <model fallback='allow'/>
    <topology sockets='1' cores='1' threads='1'/>
  </cpu>
  <clock offset='utc'>
    <timer name='pit' tickpolicy='delay'/>
    <timer name='rtc' tickpolicy='catchup'/>
    <timer name='hpet' present='no'/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <devices>
    <emulator>/usr/libexec/qemu-kvm</emulator>
    <disk type='file' device='disk'>
      <driver name='qemu' type='qcow2' cache='none'/>
      <source file='/var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/disk'/>
      <target dev='vda' bus='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
    </disk>
    <controller type='usb' index='0' model='piix3-uhci'>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
    </controller>
    <controller type='pci' index='0' model='pci-root'/>
    <interface type='bridge'>
      <mac address='fa:16:3e:98:1f:46'/>
      <source bridge='qbrc17a559c-ff'/>
      <target dev='tapc17a559c-ff'/>
      <model type='virtio'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
    </interface>
    <serial type='file'>
      <source path='/var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log'/>
      <target port='0'/>
    </serial>
    <serial type='pty'>
      <target port='1'/>
    </serial>
    <console type='file'>
      <source path='/var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log'/>
      <target type='serial' port='0'/>
    </console>
    <input type='tablet' bus='usb'>
      <address type='usb' bus='0' port='1'/>
    </input>
    <input type='mouse' bus='ps2'/>
    <input type='keyboard' bus='ps2'/>
    <graphics type='vnc' port='-1' autoport='yes' listen='0.0.0.0' keymap='en-us'>
      <listen type='address' address='0.0.0.0'/>
    </graphics>
    <video>
      <model type='cirrus' vram='16384' heads='1' primary='yes'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
    </video>
    <memballoon model='virtio'>
      <stats period='10'/>
      <address type='pci' domain='0x0000' bus='0x00' slot='0x05' function='0x0'/>
    </memballoon>
  </devices>
</domain>

2017-10-09 21:46:12.175 2878 ERROR nova.virt.libvirt.driver [req-a4c08cf2-0635-4a12-b948-36623ca1cd96 8ef7fc2a147f42af9dde53f623287b59 c98ba68d96b24ed3827189e17314ecb7 - - -] [instance: 8b3f8add-9029-4b37-9e67-fe3f82624c2b] Failed to start libvirt guest
2017-10-09 21:46:13.099 2878 ERROR oslo_messaging.rpc.dispatcher [req-a4c08cf2-0635-4a12-b948-36623ca1cd96 8ef7fc2a147f42af9dde53f623287b59 c98ba68d96b24ed3827189e17314ecb7 - - -] Exception during message handling: Unable to delete file /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log: Permission denied
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     executor_callback))
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     executor_callback)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 130, in _do_dispatch
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     result = func(ctxt, **new_args)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 7070, in start_instance
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     return self.manager.start_instance(ctxt, instance)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 88, in wrapped
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     payload)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/exception.py", line 71, in wrapped
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     return f(self, context, *args, **kw)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 341, in decorated_function
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     LOG.warning(msg, e, instance_uuid=instance_uuid)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 312, in decorated_function
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 391, in decorated_function
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 369, in decorated_function
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     kwargs['instance'], e, sys.exc_info())
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 357, in decorated_function
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     return function(self, context, *args, **kwargs)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2917, in start_instance
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     self._power_on(context, instance)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2890, in _power_on
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     block_device_info)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2469, in power_on
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     self._hard_reboot(context, instance, network_info, block_device_info)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2358, in _hard_reboot
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     vifs_already_plugged=True)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4741, in _create_domain_and_network
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     destroy_disks_on_failure)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4714, in _create_domain_and_network
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     power_on=power_on)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4634, in _create_domain
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     LOG.error(err)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 85, in __exit__
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     six.reraise(self.type_, self.value, self.tb)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4624, in _create_domain
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     domain.createWithFlags(launch_flags)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 183, in doit
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     result = proxy_call(self._autowrap, f, *args, **kwargs)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 141, in proxy_call
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     rv = execute(f, *args, **kwargs)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 122, in execute
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     six.reraise(c, e, tb)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 80, in tworker
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     rv = meth(*args, **kwargs)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher   File "/usr/lib64/python2.7/site-packages/libvirt.py", line 1069, in createWithFlags
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher libvirtError: Unable to delete file /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log: Permission denied
2017-10-09 21:46:13.099 2878 TRACE oslo_messaging.rpc.dispatcher 
~~~

And 
~~~
[root@overcloud-compute-0 ~]# grep console.log /var/log/audit/audit.log  | grep denied 
type=AVC msg=audit(1507585572.134:272): avc:  denied  { unlink } for  pid=6260 comm="virtlogd" name="console.log" dev="vda2" ino=188743815 scontext=system_u:system_r:virtlogd_t:s0-s0:c0.c1023 tcontext=system_u:object_r:svirt_image_t:s0 tclass=file
~~~

And
~~~
[root@overcloud-compute-0 ~]# ls -alZ /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log-rw-------. root root system_u:object_r:svirt_image_t:s0 /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log
[root@overcloud-compute-0 ~]# restorecon -RF /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log
[root@overcloud-compute-0 ~]# ls -alZ /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log
-rw-------. root root system_u:object_r:nova_var_lib_t:s0 /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log
~~~

So I think we can pretty certainly say that this is due to an unclean shutdown of the domain --- the context was not correctly reset to nova_var_lib_t, and `restorecon` reset the context to nova_var_lib_t, which allowed virtlogd to access the console.log again.

This looks like a duplicate of bug 1499800

Hi Andreas,

I tried reproducing this on RHEL 7.3 and 7.4 by booting a nova instance in a packstack allinone VM, then killing the VM to simulate the ungraceful shutdown. When the packstack VM came back up, the instance was running again, and its selinux extended attributes were unchanged.

> [root@overcloud-compute-0 ~]# chcon -t svirt_image_t
> /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log
> [root@overcloud-compute-0 ~]# ls -alZ /var/lib/nova/instances/*/console.log
> -rw-------. root root system_u:object_r:svirt_image_t:s0
> /var/lib/nova/instances/8b3f8add-9029-4b37-9e67-fe3f82624c2b/console.log

Isn't that sort of like doing 'chmod 000 /' and then complaining that nothing works? Could we get steps to reproduce that don't involve manually changing the file's extended attributes?

Cheers!

Hi Artom,

Can you try with an OSP 10 deployment with latest RPMs, spawn a VM, then pull the power plug on the compute node, then reboot the compute node, then try to start the VM again? This is the sequence which caused this for me to happen. Let me retry.

- Andreas

> Can you try with an OSP 10 deployment with latest RPMs, spawn a VM, then
> pull the power plug on the compute node, then reboot the compute node, then
> try to start the VM again?

That's basically what I did. I used packstack to deploy an OSP10 allinone deployment in a VM, booted an instance, killed the VM running the deployment (equivalent to pulling the plug on the compute node), started it again, and found that my instance was still ACTIVE.

If you're able to reproduce it (without the chcon trick), would it be possible to ls -lZ console.log at the following moments in an instance's and compute node's life:

1. When the instance is normally started
2. When the instance is shutoff (through the nova-api)
3. With the instance running, libvirtd is gracefully stopped
4. Libvirtd is started again
5. With the instance running, nova-compute is stopped
6. nova-compute is started again
7. With the instance running, crash the compute node and recover, but do not start the instance.

Hi it again:
~~~
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server [req-3c5314ff-837a-49ba-9b99-bf4740bda6cd 6309eec4457b466599faa9fa343d7a01 02c65e958ea24d7ea947a018dcd5a66a - - -] Exception during message handling
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server Traceback (most recent call last):
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/server.py", line 133, in _process_incoming
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     res = self.dispatcher.dispatch(message)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 150, in dispatch
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     return self._do_dispatch(endpoint, method, ctxt, args)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/dispatcher.py", line 121, in _do_dispatch
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     result = func(ctxt, **new_args)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 75, in wrapped
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     function_name, call_dict, binary)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     self.force_reraise()
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/exception_wrapper.py", line 66, in wrapped
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     return f(self, context, *args, **kw)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 188, in decorated_function
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     LOG.warning(msg, e, instance=instance)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     self.force_reraise()
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 157, in decorated_function
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/utils.py", line 613, in decorated_function
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 216, in decorated_function
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     kwargs['instance'], e, sys.exc_info())
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     self.force_reraise()
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 204, in decorated_function
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     return function(self, context, *args, **kwargs)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2480, in start_instance
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     self._power_on(context, instance)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2450, in _power_on
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     block_device_info)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2479, in power_on
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     self._hard_reboot(context, instance, network_info, block_device_info)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 2368, in _hard_reboot
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     vifs_already_plugged=True)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4969, in _create_domain_and_network
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     destroy_disks_on_failure)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     self.force_reraise()
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4941, in _create_domain_and_network
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     post_xml_callback=post_xml_callback)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 4859, in _create_domain
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     guest.launch(pause=pause)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/guest.py", line 144, in launch
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     self._encoded_xml, errors='ignore')
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     self.force_reraise()
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     six.reraise(self.type_, self.value, self.tb)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/guest.py", line 139, in launch
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     return self._domain.createWithFlags(flags)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 186, in doit
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     result = proxy_call(self._autowrap, f, *args, **kwargs)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 144, in proxy_call
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     rv = execute(f, *args, **kwargs)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 125, in execute
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     six.reraise(c, e, tb)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib/python2.7/site-packages/eventlet/tpool.py", line 83, in tworker
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     rv = meth(*args, **kwargs)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server   File "/usr/lib64/python2.7/site-packages/libvirt.py", line 1069, in createWithFlags
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server     if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server libvirtError: Unable to delete file /var/lib/nova/instances/cc531a41-131b-4c6b-944d-55e73933ed5c/console.log: Permission denied
2017-10-30 15:24:26.076 2435 ERROR oslo_messaging.rpc.server 
^C


[root@overcloud-compute-0 network-scripts]# ls -lZ /var/lib/nova/instances/cc531a41-131b-4c6b-944d-55e73933ed5c/console.log
-rw-------. qemu qemu system_u:object_r:svirt_image_t:s0:c420,c994 /var/lib/nova/instances/cc531a41-131b-4c6b-944d-55e73933ed5c/console.log
~~~

Created attachment 1345518 [details]
var lib nova

Created attachment 1345521 [details]
var log nova

Created attachment 1345537 [details]
sosreport part aa

Created attachment 1345538 [details]
sosreport part ab

Created attachment 1345540 [details]
sosreport part ac

This is the same bug as 1483466. I'm not sure that 1483466 is going to go anywhere, so I'm going to retarget this bug to the openstack-selinux component in order to make the change described in [1] and [2]. Also, my comment in [3] may be relevant, since currently the selinux policy is set in /etc/selinux/targeted/contexts/files/file_contexts from the selinux-policy-targeted package - so we may end up retargeting to that instead.

[1] https://bugzilla.redhat.com/show_bug.cgi?id=1483466#c6
[2] https://bugzilla.redhat.com/show_bug.cgi?id=1483466#c7
[3] https://bugzilla.redhat.com/show_bug.cgi?id=1483466#c14

Resolved in upstream / 0.8.11

*** This bug has been marked as a duplicate of bug 1499800 ***