Deleting instance files sometimes fails on NFS
Affects | Status | Importance | Assigned to | Milestone | |
---|---|---|---|---|---|
OpenStack Compute (nova) |
Fix Released
|
Medium
|
Michael Still |
Bug Description
Sometimes on Instance deletion the following error is logged:
2012-08-22 11:16:10 AUDIT nova.compute.
instance: 9ea4c222-
2012-08-22 11:16:14 WARNING nova.virt.
0211856] [instance: 9ea4c222-
e connection driver: virDomainHasMan
2012-08-22 11:16:14 INFO nova.virt.
1856] [instance: 9ea4c222-
2012-08-22 11:16:14 ERROR nova.rpc.amqp [req-ba764e1d-
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/
2012-08-22 11:16:14 TRACE nova.rpc.amqp rval = node_func(
2012-08-22 11:16:14 TRACE nova.rpc.amqp File "/usr/lib64/
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/
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/
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/
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/
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/
2012-08-22 11:16:14 TRACE nova.rpc.amqp do_terminate_
2012-08-22 11:16:14 TRACE nova.rpc.amqp File "/usr/lib64/
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/
2012-08-22 11:16:14 TRACE nova.rpc.amqp self._delete_
2012-08-22 11:16:14 TRACE nova.rpc.amqp File "/usr/lib64/
2012-08-22 11:16:14 TRACE nova.rpc.amqp self._shutdown_
2012-08-22 11:16:14 TRACE nova.rpc.amqp File "/usr/lib64/
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/
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/
2012-08-22 11:16:14 TRACE nova.rpc.amqp self._cleanup(
2012-08-22 11:16:14 TRACE nova.rpc.amqp File "/usr/lib64/
2012-08-22 11:16:14 TRACE nova.rpc.amqp shutil.
2012-08-22 11:16:14 TRACE nova.rpc.amqp File "/usr/lib64/
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/
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/
00c'
2012-08-22 11:16:14 TRACE nova.rpc.amqp
2012-08-22 11:16:15 INFO nova.virt.
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 .nfs00000000000
-rw-r--r-- 1 root root 34359738368 Aug 21 10:44 .nfs00000000000
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 .nfs00000000000
-rw-r--r-- 1 root root 34359738368 Aug 21 10:44 .nfs00000000000
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 .nfs00000000000
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 .nfs00000000000
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
Changed in nova: | |
milestone: | none → havana-1 |
tags: | added: ops |
Changed in nova: | |
milestone: | havana-1 → havana-2 |
Changed in nova: | |
milestone: | havana-2 → havana-3 |
Changed in nova: | |
status: | Fix Committed → Fix Released |
Changed in nova: | |
milestone: | havana-3 → 2013.2 |
These .nfs files are apparently created when you delete a file on NFS that is still held open by a process:
http:// librelist. com/browser/ /libgit2/ 2012/4/ 3/file- locking- in-libgit2/ #7a19b8c37c5235 ddfd60ff8a137c9 4ef
So, we need to figure out why the file is still open.
This is interesting:
Error from libvirt during saved instance removal. Code=3 Error=this function is not supported by the connection driver: virDomainHasMan agedSaveImage
and could indicate another problem
What exact versions of OpenStack components are you using? What version of libvirt and what distro?
Could you enable debugging (debug=true in nova.conf) and attach the full compute log?