** Changed in: nova
       Status: Incomplete => Invalid

** Changed in: os-brick
       Status: In Progress => Fix Released

** Changed in: cinder
       Status: New => Invalid

-- 
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/1495701

Title:
  Sometimes Cinder volumes fail to attach with error "The device is not
  writable: Permission denied"

Status in Cinder:
  Invalid
Status in OpenStack Compute (nova):
  Invalid
Status in os-brick:
  Fix Released

Bug description:
  This is happening on the latest master branch in CI systems. It
  happens very rarely in the gate:

  
http://logstash.openstack.org/#eyJzZWFyY2giOiJcImxpYnZpcnRFcnJvcjogb3BlcmF0aW9uIGZhaWxlZDogb3BlbiBkaXNrIGltYWdlIGZpbGUgZmFpbGVkXCIiLCJmaWVsZHMiOltdLCJvZmZzZXQiOjAsInRpbWVmcmFtZSI6IjYwNDgwMCIsImdyYXBobW9kZSI6ImNvdW50IiwidGltZSI6eyJ1c2VyX2ludGVydmFsIjowfSwic3RhbXAiOjE0NDIyNjY3MDU1NzZ9

  And on some third party CI systems (not included in the logstash
  results):

  http://ec2-52-8-200-217.us-
  west-1.compute.amazonaws.com/28/216728/5/check/PureFCDriver-tempest-
  dsvm-volume-
  multipath/bd3618d/logs/libvirt/libvirtd.txt.gz#_2015-09-14_09_00_44_829

  When the error occurs there is a stack trace in the n-cpu log like
  this:

  http://logs.openstack.org/22/222922/2/check/gate-tempest-dsvm-full-
  lio/550be5e/logs/screen-n-cpu.txt.gz?level=DEBUG#_2015-09-13_17_34_07_787

  2015-09-13 17:34:07.787 ERROR nova.virt.libvirt.driver 
[req-4ac04f97-f468-466a-9fb2-02d1df3a5633 
tempest-TestEncryptedCinderVolumes-1564844141 
tempest-TestEncryptedCinderVolumes-804461249] [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6] Failed to attach volume at mountpoint: 
/dev/vdb
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6] Traceback (most recent call last):
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]   File 
"/opt/stack/new/nova/nova/virt/libvirt/driver.py", line 1115, in attach_volume
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]     guest.attach_device(conf, 
persistent=True, live=live)
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]   File 
"/opt/stack/new/nova/nova/virt/libvirt/guest.py", line 233, in attach_device
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]     
self._domain.attachDeviceFlags(conf.to_xml(), flags=flags)
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]   File 
"/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 183, in doit
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]     result = proxy_call(self._autowrap, 
f, *args, **kwargs)
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]   File 
"/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 141, in 
proxy_call
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]     rv = execute(f, *args, **kwargs)
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]   File 
"/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 122, in execute
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]     six.reraise(c, e, tb)
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]   File 
"/usr/local/lib/python2.7/dist-packages/eventlet/tpool.py", line 80, in tworker
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]     rv = meth(*args, **kwargs)
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]   File 
"/usr/local/lib/python2.7/dist-packages/libvirt.py", line 517, in 
attachDeviceFlags
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]     if ret == -1: raise libvirtError 
('virDomainAttachDeviceFlags() failed', dom=self)
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6] libvirtError: operation failed: open disk 
image file failed
  2015-09-13 17:34:07.787 22300 ERROR nova.virt.libvirt.driver [instance: 
82f33247-d8be-49c7-9f89-f02602de5ef6]

  and a corresponding error in the libvirt log such as this:

  http://logs.openstack.org/22/222922/2/check/gate-tempest-dsvm-full-
  lio/550be5e/logs/libvirt/libvirtd.txt.gz#_2015-09-13_17_34_07_499

  2015-09-13 17:34:07.496+0000: 16871: debug : qemuMonitorJSONCommandWithFd:264 
: Send command 
'{"execute":"human-monitor-command","arguments":{"command-line":"drive_add 
dummy 
file=/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0,if=none,id=drive-virtio-disk1,format=raw,serial=561640e9-081a-430b-a7f8-9cadd63d2d00,cache=none"},"id":"libvirt-16"}'
 for write with FD -1
  2015-09-13 17:34:07.496+0000: 16871: debug : qemuMonitorSend:959 : 
QEMU_MONITOR_SEND_MSG: mon=0x7f50dc008db0 
msg={"execute":"human-monitor-command","arguments":{"command-line":"drive_add 
dummy 
file=/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0,if=none,id=drive-virtio-disk1,format=raw,serial=561640e9-081a-430b-a7f8-9cadd63d2d00,cache=none"},"id":"libvirt-16"}
   fd=-1
  2015-09-13 17:34:07.496+0000: 16868: debug : qemuMonitorIOWrite:504 : 
QEMU_MONITOR_IO_WRITE: mon=0x7f50dc008db0 
buf={"execute":"human-monitor-command","arguments":{"command-line":"drive_add 
dummy 
file=/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0,if=none,id=drive-virtio-disk1,format=raw,serial=561640e9-081a-430b-a7f8-9cadd63d2d00,cache=none"},"id":"libvirt-16"}
   len=325 ret=325 errno=22
  2015-09-13 17:34:07.499+0000: 16868: debug : qemuMonitorIOProcess:396 : 
QEMU_MONITOR_IO_PROCESS: mon=0x7f50dc008db0 buf={"return": "could not open disk 
image 
/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0:
 Could not open 
'/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0':
 Operation not permitted\r\n", "id": "libvirt-16"}
   len=352
  2015-09-13 17:34:07.499+0000: 16868: debug : qemuMonitorJSONIOProcessLine:157 
: Line [{"return": "could not open disk image 
/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0:
 Could not open 
'/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0':
 Operation not permitted\r\n", "id": "libvirt-16"}]
  2015-09-13 17:34:07.499+0000: 16868: debug : qemuMonitorJSONIOProcessLine:177 
: QEMU_MONITOR_RECV_REPLY: mon=0x7f50dc008db0 reply={"return": "could not open 
disk image 
/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0:
 Could not open 
'/dev/disk/by-path/ip-172.99.112.13:3260-iscsi-iqn.2010-10.org.openstack:volume-561640e9-081a-430b-a7f8-9cadd63d2d00-lun-0':
 Operation not permitted\r\n", "id": "libvirt-16"}
  2015-09-13 17:34:07.499+0000: 16868: debug : qemuMonitorJSONIOProcess:226 : 
Total used 352 bytes out of 352 available in buffer
  2015-09-13 17:34:07.499+0000: 16871: debug : qemuMonitorJSONCommandWithFd:269 
: Receive command reply ret=0 rxObject=0x7f511026bfc0
  2015-09-13 17:34:07.499+0000: 16871: error : qemuMonitorTextAddDrive:2611 : 
operation failed: open disk image file failed
  2015-09-13 17:34:07.499+0000: 16871: debug : 
qemuDomainObjExitMonitorInternal:1301 : Exited monitor (mon=0x7f50dc008db0 
vm=0x7f50f81661f0 name=instance-00000057)

  It is unclear yet what causes this to occur. It has reproduced in
  several different tempest tests.

To manage notifications about this bug go to:
https://bugs.launchpad.net/cinder/+bug/1495701/+subscriptions

-- 
Mailing list: https://launchpad.net/~yahoo-eng-team
Post to     : yahoo-eng-team@lists.launchpad.net
Unsubscribe : https://launchpad.net/~yahoo-eng-team
More help   : https://help.launchpad.net/ListHelp

Reply via email to