yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1040110] Re: Deleting instance files sometimes fails on NFS

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Thierry Carrez <thierry.carrez+lp@xxxxxxxxx>
Date: Thu, 05 Sep 2013 15:40:36 -0000
Reply-to: Bug 1040110 <1040110@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Changed in: nova
       Status: Fix Committed => 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/1040110

Title:
  Deleting instance files sometimes fails on NFS

Status in OpenStack Compute (Nova):
  Fix Released

Bug description:
  Sometimes on Instance deletion the following error is logged:

  2012-08-22 11:16:10 AUDIT nova.compute.manager [req-ba764e1d-36e0-4479-988e-7dc15fe47c29 bdb0bf5eb88b47f7a8fa8de5123e48ee d4bf9021295a4573aa10ca4900211856] [
  instance: 9ea4c222-e36d-468a-85b3-4aafd24eff9a] Terminating instance
  2012-08-22 11:16:14 WARNING nova.virt.libvirt.connection [req-ba764e1d-36e0-4479-988e-7dc15fe47c29 bdb0bf5eb88b47f7a8fa8de5123e48ee d4bf9021295a4573aa10ca490
  0211856] [instance: 9ea4c222-e36d-468a-85b3-4aafd24eff9a] Error from libvirt during saved instance removal. Code=3 Error=this function is not supported by th
  e connection driver: virDomainHasManagedSaveImage
  2012-08-22 11:16:14 INFO nova.virt.libvirt.connection [req-ba764e1d-36e0-4479-988e-7dc15fe47c29 bdb0bf5eb88b47f7a8fa8de5123e48ee d4bf9021295a4573aa10ca490021
  1856] [instance: 9ea4c222-e36d-468a-85b3-4aafd24eff9a] Deleting instance files /var/lib/nova/instances/f9226d17-1bfe-4819-b440-939e7635ed50/instance-0000000c
  2012-08-22 11:16:14 ERROR nova.rpc.amqp [req-ba764e1d-36e0-4479-988e-7dc15fe47c29 bdb0bf5eb88b47f7a8fa8de5123e48ee d4bf9021295a4573aa10ca4900211856] Exceptio
  n during message handling
  2012-08-22 11:16:14 TRACE nova.rpc.amqp Traceback (most recent call last):
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/rpc/amqp.py", line 253, in _process_data
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     rval = node_func(context=ctxt, **node_args)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/exception.py", line 114, in wrapped
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     return f(*args, **kw)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/compute/manager.py", line 162, in decorated_function
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     function(self, context, instance_uuid, *args, **kwargs)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/compute/manager.py", line 186, in decorated_function
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     sys.exc_info())
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/contextlib.py", line 23, in __exit__
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     self.gen.next()
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/compute/manager.py", line 180, in decorated_function
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     return function(self, context, instance_uuid, *args, **kwargs)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/compute/manager.py", line 769, in terminate_instance
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     do_terminate_instance()
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/utils.py", line 945, in inner
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     retval = f(*args, **kwargs)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/compute/manager.py", line 762, in do_terminate_instance
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     self._delete_instance(context, instance)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/compute/manager.py", line 740, in _delete_instance
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     self._shutdown_instance(context, instance, 'Terminating')
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/compute/manager.py", line 709, in _shutdown_instance
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     block_device_info)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/virt/libvirt/connection.py", line 515, in destroy
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     cleanup=True)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/virt/libvirt/connection.py", line 509, in _destroy
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     self._cleanup(instance)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/site-packages/nova/virt/libvirt/connection.py", line 524, in _cleanup
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     shutil.rmtree(target)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/shutil.py", line 221, in rmtree
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     onerror(os.rmdir, path, sys.exc_info())
  2012-08-22 11:16:14 TRACE nova.rpc.amqp   File "/usr/lib64/python2.6/shutil.py", line 219, in rmtree
  2012-08-22 11:16:14 TRACE nova.rpc.amqp     os.rmdir(path)
  2012-08-22 11:16:14 TRACE nova.rpc.amqp OSError: [Errno 39] Directory not empty: '/var/lib/nova/instances/f9226d17-1bfe-4819-b440-939e7635ed50/instance-00000
  00c'
  2012-08-22 11:16:14 TRACE nova.rpc.amqp
  2012-08-22 11:16:15 INFO nova.virt.libvirt.connection [-] [instance: 9ea4c222-e36d-468a-85b3-4aafd24eff9a] Instance destroyed successfully.

  The instance stays in the "deleting" task_state and another api call
  then deletes it successfully. We store instance files on a NFS mount,
  and shutil.rmtree has a known (as in: google is full of it) problem on
  NFS when the files that are to be deleted are still opened by someone.
  The nfs-client renames the open file to .nfs0000... and will
  automatically delete it once it is no longer open. Since there are
  indeed .nfs000... files in the directory rmdir fails.

  The following is shortened output of a repeating directory listing,
  where you can see how the image files are first renamed and then
  disappear.

  drwxr-xr-x   2 root root        4096 Aug 21 10:44 .
  drwxr-xr-x 167 root root       28672 Aug 22 10:35 ..
  -rw-rw----   1 root root           0 Aug 21 10:43 console.log
  -rw-r--r--   1 root root 23622320128 Aug 22 11:16 disk
  -rw-r--r--   1 root root 34359738368 Aug 21 10:44 disk.swap
  -rw-r--r--   1 root root        1689 Aug 21 10:43 libvirt.xml
  total 6074632
  drwxr-xr-x   2 root root        4096 Aug 21 10:44 .
  drwxr-xr-x 167 root root       28672 Aug 22 10:35 ..
  -rw-rw----   1 root root           0 Aug 21 10:43 console.log
  -rw-r--r--   1 root root 23622320128 Aug 22 11:16 disk
  -rw-r--r--   1 root root 34359738368 Aug 21 10:44 disk.swap
  -rw-r--r--   1 root root        1689 Aug 21 10:43 libvirt.xml
  total 6074628
  drwxr-xr-x   2 root root        4096 Aug 22 11:16 .
  drwxr-xr-x 167 root root       28672 Aug 22 10:35 ..
  -rw-r--r--   1 root root 23622320128 Aug 22 11:16 .nfs0000000000004f8400000001
  -rw-r--r--   1 root root 34359738368 Aug 21 10:44 .nfs0000000000004f8600000002
  total 6074628
  drwxr-xr-x   2 root root        4096 Aug 22 11:16 .
  drwxr-xr-x 167 root root       28672 Aug 22 10:35 ..
  -rw-r--r--   1 root root 23622320128 Aug 22 11:16 .nfs0000000000004f8400000001
  -rw-r--r--   1 root root 34359738368 Aug 21 10:44 .nfs0000000000004f8600000002
  total 6074628
  drwxr-xr-x   2 root root        4096 Aug 22 11:16 .
  drwxr-xr-x 167 root root       28672 Aug 22 10:35 ..
  -rw-r--r--   1 root root 34359738368 Aug 21 10:44 .nfs0000000000004f8600000002
  total 52
  drwxr-xr-x   2 root root        4096 Aug 22 11:16 .
  drwxr-xr-x 167 root root       28672 Aug 22 10:35 ..
  -rw-r--r--   1 root root 34359738368 Aug 21 10:44 .nfs0000000000004f8600000002
  total 52
  drwxr-xr-x   2 root root  4096 Aug 22 11:16 .
  drwxr-xr-x 167 root root 28672 Aug 22 10:35 ..
  total 36
  drwxr-xr-x   2 root root  4096 Aug 22 11:16 .
  drwxr-xr-x 167 root root 28672 Aug 22 10:35 ..
  total 36

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