← Back to team overview

yahoo-eng-team team mailing list archive

  1. yahoo-eng-team team
  2. Mailing list archive
  3. Message #76391

[Bug 1809123] [NEW] OSError failure to read when creating multiple instances with NFS

  Thread Previous • Date Previous • • Thread Next 
Public bug reported:

There is a race condition in when launching multiple instances over NFS
simultaneously that can end up causing the os.utime function to fail
when updating the mtime for the image base:

2018-12-15 14:22:38.740 7 INFO nova.virt.libvirt.driver [req-d33edf35-733b-4591-831c-666cd159cee1 8965b22a11c44875a90fe88f50769a5a b9644067db0d44789e19d9d032287ada - default default] [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] Creating image
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [req-d33edf35-733b-4591-831c-666cd159cee1 8965b22a11c44875a90fe88f50769a5a b9644067db0d44789e19d9d032287ada - default default] [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] Instance failed to spawn: OSError: [Errno 13] Permission denied
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] Traceback (most recent call last):
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2252, in _build_resources
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     yield resources
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2032, in _build_and_run_instance
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     block_device_info=block_device_info)
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3091, in spawn
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     block_device_info=block_device_info)
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3469, in _create_image
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     fallback_from_host)
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3560, in _create_and_inject_local_root
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     instance, size, fallback_from_host)
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7634, in _try_fetch_image_cache
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     size=size)
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py", line 243, in cache
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     *args, **kwargs)
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py", line 601, in create_image
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     nova.privsep.path.utime(base)
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/oslo_privsep/priv_context.py", line 207, in _wrap
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     return self.channel.remote_call(name, args, kwargs)
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/oslo_privsep/daemon.py", line 202, in remote_call
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     raise exc_type(*result[2])
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] OSError: [Errno 13] Permission denied
2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] 


The NFS settings are correct:
[root@overcloud-novacompute-0 ~]# mount | grep nova
overcloud-controller-0.opnfvlf.org:/nova on /var/lib/nova/instances type nfs4 (rw,relatime,sync,context=system_u:object_r:nfs_t:s0,vers=4.1,rsize=1048576,wsize=1048576,namlen=255,hard,nosharecache,proto=tcp,timeo=600,retrans=2,sec=sys,clientaddr=192.0.2.44,local_lock=none,addr=192.0.2.40,_netdev)


[root@overcloud-novacompute-0 ~]# getenforce
Permissive

[root@overcloud-novacompute-0 ~]# ls -lrt /var/lib/nova/
total 0
drwxrwxrwx. 4 42436 42436 53 Dec 14 19:52 instances

[root@overcloud-novacompute-0 ~]# ls -lrt /var/lib/nova/instances/
total 4
drwxr-xr-x. 2 42436 42436 54 Dec 14 19:16 _base
drwxr-xr-x. 2 42436 42436 93 Dec 14 19:52 locks
-rw-r--r--. 1 42436 42436 58 Dec 14 20:33 compute_nodes

[root@overcloud-novacompute-0 ~]# ls -lrt /var/lib/nova/instances/_base/
total 13384
-rw-r--r--. 1 42427 42427 46137344 Dec 14 19:18 78c6ae575fd026484b1f46588b5c337b3fd53558

[root@overcloud-novacompute-0 ~]# docker exec -it bf4658c561e1 /bin/bash
()[nova@overcloud-novacompute-0 /]$ id -u nova
42436
()[nova@overcloud-novacompute-0 /]$ id -u qemu
42427

()[nova@overcloud-novacompute-0 /]$ ls -lrt /var/lib/nova/instances/
total 4
drwxr-xr-x. 2 nova nova 54 Dec 14 19:16 _base
drwxr-xr-x. 2 nova nova 93 Dec 14 19:52 locks
-rw-r--r--. 1 nova nova 58 Dec 14 20:33 compute_nodes
()[nova@overcloud-novacompute-0 /]$ ls -lrt /var/lib/nova/instances/_base/
total 13384
-rw-r--r--. 1 qemu qemu 46137344 Dec 14 19:18 78c6ae575fd026484b1f46588b5c337b3fd53558

** Affects: nova
     Importance: Undecided
     Assignee: Tim Rozet (trozet)
         Status: In Progress


** Tags: queens-backport-potential

** Changed in: nova
     Assignee: (unassigned) => Tim Rozet (trozet)

** Changed in: nova
       Status: New => In Progress

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

Title:
  OSError failure to read when creating multiple instances with NFS

Status in OpenStack Compute (nova):
  In Progress

Bug description:
  There is a race condition in when launching multiple instances over
  NFS simultaneously that can end up causing the os.utime function to
  fail when updating the mtime for the image base:

  2018-12-15 14:22:38.740 7 INFO nova.virt.libvirt.driver [req-d33edf35-733b-4591-831c-666cd159cee1 8965b22a11c44875a90fe88f50769a5a b9644067db0d44789e19d9d032287ada - default default] [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] Creating image
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [req-d33edf35-733b-4591-831c-666cd159cee1 8965b22a11c44875a90fe88f50769a5a b9644067db0d44789e19d9d032287ada - default default] [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] Instance failed to spawn: OSError: [Errno 13] Permission denied
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] Traceback (most recent call last):
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2252, in _build_resources
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     yield resources
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/compute/manager.py", line 2032, in _build_and_run_instance
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     block_device_info=block_device_info)
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3091, in spawn
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     block_device_info=block_device_info)
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3469, in _create_image
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     fallback_from_host)
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 3560, in _create_and_inject_local_root
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     instance, size, fallback_from_host)
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py", line 7634, in _try_fetch_image_cache
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     size=size)
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py", line 243, in cache
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     *args, **kwargs)
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/nova/virt/libvirt/imagebackend.py", line 601, in create_image
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     nova.privsep.path.utime(base)
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/oslo_privsep/priv_context.py", line 207, in _wrap
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     return self.channel.remote_call(name, args, kwargs)
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]   File "/usr/lib/python2.7/site-packages/oslo_privsep/daemon.py", line 202, in remote_call
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552]     raise exc_type(*result[2])
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] OSError: [Errno 13] Permission denied
  2018-12-15 14:22:38.747 7 ERROR nova.compute.manager [instance: 6fec5d88-09ab-4ecc-815d-c08c298fe552] 

  
  The NFS settings are correct:
  [root@overcloud-novacompute-0 ~]# mount | grep nova
  overcloud-controller-0.opnfvlf.org:/nova on /var/lib/nova/instances type nfs4 (rw,relatime,sync,context=system_u:object_r:nfs_t:s0,vers=4.1,rsize=1048576,wsize=1048576,namlen=255,hard,nosharecache,proto=tcp,timeo=600,retrans=2,sec=sys,clientaddr=192.0.2.44,local_lock=none,addr=192.0.2.40,_netdev)

  
  [root@overcloud-novacompute-0 ~]# getenforce
  Permissive

  [root@overcloud-novacompute-0 ~]# ls -lrt /var/lib/nova/
  total 0
  drwxrwxrwx. 4 42436 42436 53 Dec 14 19:52 instances

  [root@overcloud-novacompute-0 ~]# ls -lrt /var/lib/nova/instances/
  total 4
  drwxr-xr-x. 2 42436 42436 54 Dec 14 19:16 _base
  drwxr-xr-x. 2 42436 42436 93 Dec 14 19:52 locks
  -rw-r--r--. 1 42436 42436 58 Dec 14 20:33 compute_nodes

  [root@overcloud-novacompute-0 ~]# ls -lrt /var/lib/nova/instances/_base/
  total 13384
  -rw-r--r--. 1 42427 42427 46137344 Dec 14 19:18 78c6ae575fd026484b1f46588b5c337b3fd53558

  [root@overcloud-novacompute-0 ~]# docker exec -it bf4658c561e1 /bin/bash
  ()[nova@overcloud-novacompute-0 /]$ id -u nova
  42436
  ()[nova@overcloud-novacompute-0 /]$ id -u qemu
  42427

  ()[nova@overcloud-novacompute-0 /]$ ls -lrt /var/lib/nova/instances/
  total 4
  drwxr-xr-x. 2 nova nova 54 Dec 14 19:16 _base
  drwxr-xr-x. 2 nova nova 93 Dec 14 19:52 locks
  -rw-r--r--. 1 nova nova 58 Dec 14 20:33 compute_nodes
  ()[nova@overcloud-novacompute-0 /]$ ls -lrt /var/lib/nova/instances/_base/
  total 13384
  -rw-r--r--. 1 qemu qemu 46137344 Dec 14 19:18 78c6ae575fd026484b1f46588b5c337b3fd53558

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

Follow ups

  Thread Previous • Date Previous • • Thread Next