yahoo-eng-team team mailing list archive
-
yahoo-eng-team team
-
Mailing list archive
-
Message #54227
[Bug 1597644] Re: Quobyte: Permission denied on console.log during instance startup
Reviewed: https://review.openstack.org/337174
Committed: https://git.openstack.org/cgit/openstack/nova/commit/?id=d4e6bd8b2d0236b44baa9e20f301e88934e1450c
Submitter: Jenkins
Branch: master
commit d4e6bd8b2d0236b44baa9e20f301e88934e1450c
Author: Silvan Kaiser <silvan@xxxxxxxxxxx>
Date: Mon Jul 4 11:58:00 2016 +0000
Revert "Remove manual creation of console.log"
The change to be reverted in this change removed a manual
console.log creation that was thought unnecessary. However due
to libvirt behaviour permission issue arise if console.log is
created not by nova causing the Quobyte CI to fail.
Closes-Bug: #1597644
This reverts commit ea3904b168e4360b6c68464dbcd0585987b27e91.
Change-Id: I36d1faf90f9b97ae756b8bcda3beb47e66f9e587
** Changed in: nova
Status: In Progress => Fix Released
--
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/1597644
Title:
Quobyte: Permission denied on console.log during instance startup
Status in OpenStack Compute (nova):
Fix Released
Bug description:
A range of tempest volume tests fails when starting Quobyte volume
based instances. This issue might be hit by other filesystem based
volume drivers. The error shows the following trace in the nova-
compute log:
2016-06-30 07:01:42.770 1391 ERROR nova.virt.libvirt.guest [req-b128a930-5eaa-4c20-a26c-0bf5168f2232 tempest-AttachVolumeShelveTestJSON-88210136 tempest-AttachVolumeShelveTestJSON-88210136] Error launching a defined domain with XML: <domain type='kvm'>
<name>instance-00000001</name>
<uuid>5f1d3712-641e-4cbe-a801-b103d75f59e3</uuid>
<metadata>
<nova:instance xmlns:nova="http://openstack.org/xmlns/libvirt/nova/1.0";>
<nova:package version="14.0.0"/>
<nova:name>tempest.common.compute-instance-314522010</nova:name>
<nova:creationTime>2016-06-30 07:01:40</nova:creationTime>
<nova:flavor name="m1.nano">
<nova:memory>64</nova:memory>
<nova:disk>0</nova:disk>
<nova:swap>0</nova:swap>
<nova:ephemeral>0</nova:ephemeral>
<nova:vcpus>1</nova:vcpus>
</nova:flavor>
<nova:owner>
<nova:user uuid="1d590d924957414fa8703df521929a4b">tempest-AttachVolumeShelveTestJSON-88210136</nova:user>
<nova:project uuid="584fd090d35842919068946631985f59">tempest-AttachVolumeShelveTestJSON-88210136</nova:project>
</nova:owner>
<nova:root type="image" uuid="7a52389e-22fc-4ec4-9572-1b3a5f3cfd79"/>
</nova:instance>
</metadata>
<memory unit='KiB'>65536</memory>
<currentMemory unit='KiB'>65536</currentMemory>
<vcpu placement='static'>1</vcpu>
<cputune>
<shares>1024</shares>
</cputune>
<sysinfo type='smbios'>
<system>
<entry name='manufacturer'>OpenStack Foundation</entry>
<entry name='product'>OpenStack Nova</entry>
<entry name='version'>14.0.0</entry>
<entry name='serial'>32c3c45f-2605-40e5-8262-de1d16cd6181</entry>
<entry name='uuid'>5f1d3712-641e-4cbe-a801-b103d75f59e3</entry>
<entry name='family'>Virtual Machine</entry>
</system>
</sysinfo>
<os>
<type arch='x86_64' machine='pc-i440fx-trusty'>hvm</type>
<kernel>/opt/stack/data/nova/instances/5f1d3712-641e-4cbe-a801-b103d75f59e3/kernel</kernel>
<initrd>/opt/stack/data/nova/instances/5f1d3712-641e-4cbe-a801-b103d75f59e3/ramdisk</initrd>
<cmdline>root=/dev/vda console=tty0 console=ttyS0</cmdline>
<boot dev='hd'/>
<smbios mode='sysinfo'/>
</os>
<features>
<acpi/>
<apic/>
</features>
<cpu mode='host-model'>
<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/bin/kvm-spice</emulator>
<disk type='file' device='disk'>
<driver name='qemu' type='qcow2' cache='none'/>
<source file='/opt/stack/data/nova/instances/5f1d3712-641e-4cbe-a801-b103d75f59e3/disk'/>
<target dev='vda' bus='virtio'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x03' function='0x0'/>
</disk>
<disk type='file' device='cdrom'>
<driver name='qemu' type='raw' cache='none'/>
<source file='/opt/stack/data/nova/instances/5f1d3712-641e-4cbe-a801-b103d75f59e3/disk.config'/>
<target dev='hdd' bus='ide'/>
<readonly/>
<address type='drive' controller='0' bus='1' target='0' unit='1'/>
</disk>
<controller type='usb' index='0'>
<address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x2'/>
</controller>
<controller type='pci' index='0' model='pci-root'/>
<controller type='ide' index='0'>
<address type='pci' domain='0x0000' bus='0x00' slot='0x01' function='0x1'/>
</controller>
<interface type='bridge'>
<mac address='fa:16:3e:c7:44:5e'/>
<source bridge='br100'/>
<model type='virtio'/>
<address type='pci' domain='0x0000' bus='0x00' slot='0x02' function='0x0'/>
</interface>
<serial type='file'>
<source path='/opt/stack/data/nova/instances/5f1d3712-641e-4cbe-a801-b103d75f59e3/console.log'/>
<target port='0'/>
</serial>
<serial type='pty'>
<target port='1'/>
</serial>
<console type='file'>
<source path='/opt/stack/data/nova/instances/5f1d3712-641e-4cbe-a801-b103d75f59e3/console.log'/>
<target type='serial' port='0'/>
</console>
<memballoon model='virtio'>
<address type='pci' domain='0x0000' bus='0x00' slot='0x04' function='0x0'/>
<stats period='10'/>
</memballoon>
</devices>
</domain>
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [req-b128a930-5eaa-4c20-a26c-0bf5168f2232 tempest-AttachVolumeShelveTestJSON-88210136 tempest-AttachVolumeShelveTestJSON-88210136] [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] Instance failed to spawn
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] Traceback (most recent call last):
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/opt/stack/nova/nova/compute/manager.py", line 2063, in _build_resources
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] yield resources
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/opt/stack/nova/nova/compute/manager.py", line 1907, in _build_and_run_instance
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] block_device_info=block_device_info)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 2665, in spawn
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] post_xml_callback=gen_confdrive)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 4860, in _create_domain_and_network
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] post_xml_callback=post_xml_callback)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/opt/stack/nova/nova/virt/libvirt/driver.py", line 4789, in _create_domain
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] guest.launch(pause=pause)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/opt/stack/nova/nova/virt/libvirt/guest.py", line 142, in launch
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] self._encoded_xml, errors='ignore')
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 221, in __exit__
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] self.force_reraise()
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/usr/local/lib/python2.7/dist-packages/oslo_utils/excutils.py", line 197, in force_reraise
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] six.reraise(self.type_, self.value, self.tb)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/opt/stack/nova/nova/virt/libvirt/guest.py", line 137, in launch
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] return self._domain.createWithFlags(flags)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 186, in doit
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] result = proxy_call(self._autowrap, f, *args, **kwargs)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 144, in proxy_call
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] rv = execute(f, *args, **kwargs)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 125, in execute
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] six.reraise(c, e, tb)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 83, in tworker
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] rv = meth(*args, **kwargs)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] File "/usr/local/lib/python2.7/dist-packages/libvirt.py", line 900, in createWithFlags
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] if ret == -1: raise libvirtError ('virDomainCreateWithFlags() failed', dom=self)
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3] libvirtError: internal error: process exited while connecting to monitor: qemu-system-x86_64: -chardev file,id=charserial0,path=/opt/stack/data/nova/instances/5f1d3712-641e-4cbe-a801-b103d75f59e3/console.log: Could not open '/opt/stack/data/nova/instances/5f1d3712-641e-4cbe-a801-b103d75f59e3/console.log': Permission denied
2016-06-30 07:01:42.770 1391 ERROR nova.compute.manager [instance: 5f1d3712-641e-4cbe-a801-b103d75f59e3]
An example Quobyte CI run can be found at: http://osci4.ext/logs/refs-changes-30-260930-40/
This fail occurs continuously.
Cinder is using nas_secure_file_operations=true and nas_secure_file_permissions=true which means files are handled not with root but service ownership and permissions set to 660. Both Nova and Cinder run with common ownership to assure access to the instance files. However the console.log file has root ownership at this point causing the nova process to be unable to access the file. Libvirts qemu config is set to run with non-root ownership using the same owner as the nova service and dynamic_ownership off. So libvirt should not change the file ownership here.
The tempest tests are run in a clean devstack setup.
Expectation is that the console.log file has the same ownership as all the other instances files (nova service owner).
Actual result is that console.log has root:root 640 ownership.
To manage notifications about this bug go to:
https://bugs.launchpad.net/nova/+bug/1597644/+subscriptions
References
