yahoo-eng-team team mailing list archive

Thread
Date
[Bug 1309740] Re: nova compute instance deletion on NFS filesystem fails

To: yahoo-eng-team@xxxxxxxxxxxxxxxxxxx
From: Stefano Maffulli <1309740@xxxxxxxxxxxxxxxxxx>
Date: Sat, 19 Apr 2014 20:34:35 -0000
Reply-to: Bug 1309740 <1309740@xxxxxxxxxxxxxxxxxx>
Sender: bounces@xxxxxxxxxxxxx
** Also affects: nova
   Importance: Undecided
       Status: New

** No longer affects: openstack-community

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

Title:
  nova compute instance deletion on NFS filesystem fails

Status in OpenStack Compute (Nova):
  New

Bug description:
  Instance creation on NFS leave qemu-system process which locks
  Instance disk file on NFS cause deletion failure.

  The process locks the instance disk on NFS :
  qemu-system-x86_64 -machine accel=kvm:tcg -global virtio-blk-pci.scsi=off -drive file=/var/lib/nova/instances/f8f5481e-b5f2-4dfb-a299-245f9ad691b9/disk,cache=off,format=qcow2,if=virtio -nodefconfig -machine accel=kvm:tcg -nodefaults -nographic -m 500 -no-reboot -no-hpet -device virtio-serial -serial stdio -chardev socket,path=/tmp/libguestfsO9sbVq/guestfsd.sock,id=channel0 -device virtserialport,chardev=channel0,name=org.libguestfs.channel.0 -kernel /var/tmp/.guestfs-120/kernel.23462 -initrd /var/tmp/.guestfs-120/initrd.23462 -append panic=1 console=ttyS0 udevtimeout=300 no_timer_check acpi=off printk.time=1 cgroup_disable=memory selinux=0  TERM=linux  -drive file=/var/tmp/.guestfs-120/root.23462,snapshot=on,if=virtio,cache=unsafe

  When instance is deleted, the  following messages are logged:

  =================================
  2014-04-18 16:35:17.905 5731 INFO nova.compute.resource_tracker [-] Compute_service record updated for dmsosnovacomp6:dmsosnovacomp6.dmlabs.verizon.com
  2014-04-18 16:35:18.379 5731 INFO nova.ceilometer.notifier [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] processing compute.instance.delete.start
  2014-04-18 16:35:18.565 5731 INFO ceilometer.compute.pollsters.disk [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] DISKIO USAGE: <ceilometer.compute.nova_notifier.Instance object at 0x394d1d0> vda: read-requests=5183 read-bytes=77607936 write-requests=3796 write-bytes=344785920 errors=-1
  2014-04-18 16:35:18.595 5731 INFO ceilometer.compute.pollsters.net [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] checking instance 2190
  2014-04-18 16:35:18.620 5731 INFO ceilometer.compute.pollsters.net [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] NETWORK USAGE: instance-0000088e tapffb76b64-bc: read-bytes=18510 write-bytes=17101
  2014-04-18 16:35:18.623 5731 INFO ceilometer.compute.pollsters.net [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] checking instance 2190
  2014-04-18 16:35:18.623 5731 INFO ceilometer.compute.pollsters.net [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] NETWORK USAGE: instance-0000088e tapffb76b64-bc: read-bytes=18510 write-bytes=17101
  2014-04-18 16:35:18.624 5731 INFO ceilometer.compute.pollsters.net [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] checking instance 2190
  2014-04-18 16:35:18.625 5731 INFO ceilometer.compute.pollsters.net [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] NETWORK USAGE: instance-0000088e tapffb76b64-bc: read-bytes=18510 write-bytes=17101
  2014-04-18 16:35:18.626 5731 INFO ceilometer.compute.pollsters.net [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] checking instance 2190
  2014-04-18 16:35:18.627 5731 INFO ceilometer.compute.pollsters.net [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] NETWORK USAGE: instance-0000088e tapffb76b64-bc: read-bytes=18510 write-bytes=17101
  2014-04-18 16:35:18.628 5731 INFO ceilometer.compute.pollsters.cpu [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] checking instance 2190
  2014-04-18 16:35:18.651 5731 INFO ceilometer.compute.pollsters.cpu [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] CPUTIME USAGE: {'flavor_name': u'm1.small', 'vm_state': u'active', 'internal_id': None, 'availability_zone': u'nova', 'terminated_at': None, 'ephemeral_gb': 0, 'instance_type_id': 5, 'user_data': None, 'OS-EXT-SRV-ATTR:instance_name': u'instance-0000088e', 'cleaned': 0, 'vm_mode': None, 'deleted_at': None, 'reservation_id': u'r-tx9y20gm', 'id': 2190, 'security_groups': [{u'project_id': u'1129030a03974f5087edd212704d3a4c', u'user_id': u'1f631c561b634f31a31e207a999c70b3', u'name': u'default', u'deleted': 0, u'created_at': u'2014-03-14T16:47:30.000000', u'updated_at': None, u'rules': [], u'deleted_at': None, u'id': 3, u'description': u'default'}], 'disable_terminate': False, 'user_id': u'1f631c561b634f31a31e207a999c70b3', 'uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', 'default_swap_device': None, 'info_cache': {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 2190, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': u'2014-04-18T20:32:32.000000', u'network_info': u'[{"ovs_interfaceid": "ffb76b64-bc06-4493-9a3b-9a2aad74bb45", "network": {"bridge": "br-int", "subnets": [{"ips": [{"meta": {}, "version": 4, "type": "fixed", "floating_ips": [], "address": "10.5.5.3"}], "version": 4, "meta": {"dhcp_server": "10.5.5.2"}, "dns": [{"meta": {}, "version": 4, "type": "dns", "address": "152.190.136.8"}], "routes": [], "cidr": "10.5.5.0/24", "gateway": {"meta": {}, "version": 4, "type": "gateway", "address": "10.5.5.1"}}], "meta": {"injected": false, "tenant_id": "1129030a03974f5087edd212704d3a4c"}, "id": "2b41e5b5-d995-44a9-9d15-ad55765227f0", "label": "demo-net-1"}, "devname": "tapffb76b64-bc", "qbh_params": null, "meta": {}, "address": "fa:16:3e:9e:6a:66", "type": "ovs", "id": "ffb76b64-bc06-4493-9a3b-9a2aad74bb45", "qbg_params": null}]', u'deleted_at': u'2014-04-18T20:35:18.000000', u'id': 2190}, 'hostname': u'sreeni-test1', 'launched_on': u'dmsosnovacomp6', 'display_description': u'sreeni-test1', 'key_data': u'ssh-rsa AAAAB3NzaC1yc2EAAAADAQABAAABAQCizOGhx/xs+hU03hlmDA5rK33Sy+p8oGRp7AimL5mqMGjwurZMpG61gn4ak/Wps9ZwSwsTi0bIl9C+imnNzNJHcL4+kbbj0Mg1TpostgIvqsAMnRN9BjXMAEMzcoEh4Ob81i151oGvI8dgZvnQeJYPko/WcC9hNfNL6ZEujzQ9AihH4NOtXME+bb+D4GiduLIfy+akTB94t7UJD5I89lR9XP3tU0z3KULztuHu+xf+JIAwhMi2X+shP0JqRKYHfP9W6qhx+855vbvAA9bfhNYHgTWhSZIxF7bdiMxKDesRtiCnKmu62IOfd9msB91B6v35U5VpLI12RmcLxODXFV7R dmsos@dmsosadmin1\n', 'kernel_id': u'', 'power_state': 1, 'default_ephemeral_device': None, 'progress': 0, 'project_id': u'1129030a03974f5087edd212704d3a4c', 'launched_at': u'2014-04-18T20:33:33.000000', 'scheduled_at': u'2014-04-18T20:32:30.000000', 'node': u'dmsosnovacomp6.dmlabs.verizon.com', 'ramdisk_id': u'', 'access_ip_v6': None, 'access_ip_v4': None, 'deleted': 0, 'key_name': u'mar21demokey', 'updated_at': u'2014-04-18T20:35:18.000000', 'host': u'dmsosnovacomp6', 'architecture': u'x86_64', 'display_name': u'sreeni-test1', 'system_metadata': [{u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'ubuntu', u'key': u'image_os_distro', u'deleted_at': None, u'id': 36798}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'2048', u'key': u'instance_type_memory_mb', u'deleted_at': None, u'id': 36801}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'0', u'key': u'instance_type_swap', u'deleted_at': None, u'id': 36804}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': None, u'key': u'instance_type_vcpu_weight', u'deleted_at': None, u'id': 36807}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'20', u'key': u'instance_type_root_gb', u'deleted_at': None, u'id': 36810}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'5', u'key': u'instance_type_id', u'deleted_at': None, u'id': 36813}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'm1.small', u'key': u'instance_type_name', u'deleted_at': None, u'id': 36816}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'0', u'key': u'instance_type_ephemeral_gb', u'deleted_at': None, u'id': 36819}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'1', u'key': u'instance_type_rxtx_factor', u'deleted_at': None, u'id': 36822}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'raw', u'key': u'image_disk_format', u'deleted_at': None, u'id': 36825}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'x86_64', u'key': u'image_architecture', u'deleted_at': None, u'id': 36828}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'2', u'key': u'instance_type_flavorid', u'deleted_at': None, u'id': 36831}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'bare', u'key': u'image_container_format', u'deleted_at': None, u'id': 36834}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'1', u'key': u'instance_type_vcpus', u'deleted_at': None, u'id': 36837}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'0', u'key': u'image_min_ram', u'deleted_at': None, u'id': 36840}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'20', u'key': u'image_min_disk', u'deleted_at': None, u'id': 36843}, {u'instance_uuid': u'1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5', u'deleted': 0, u'created_at': u'2014-04-18T20:32:29.000000', u'updated_at': None, u'value': u'd947c1fa-6099-4a02-914e-0cc74f79bbce', u'key': u'image_base_image_ref', u'deleted_at': None, u'id': 36846}], 'task_state': u'deleting', 'shutdown_terminate': False, 'cell_name': None, 'root_gb': 20, 'locked': False, 'created_at': u'2014-04-18T20:32:29.000000', 'locked_by': None, 'launch_index': 0, 'metadata': {}, 'memory_mb': 2048, 'vcpus': 1, 'image_ref': u'd947c1fa-6099-4a02-914e-0cc74f79bbce', 'root_device_name': u'/dev/vda', 'auto_disk_config': False, 'os_type': None, 'config_drive': u''} 10900000000
  2014-04-18 16:35:18.663 5731 AUDIT nova.compute.manager [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] [instance: 1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5] Terminating instance
  2014-04-18 16:35:19.828 5731 INFO nova.compute.manager [-] Lifecycle event 1 on VM 1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5
  2014-04-18 16:35:19.835 5731 INFO nova.virt.libvirt.driver [-] [instance: 1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5] Instance destroyed successfully.
  2014-04-18 16:35:19.997 5731 INFO nova.compute.manager [-] [instance: 1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5] During sync_power_state the instance has a pending task. Skip.
  2014-04-18 16:35:20.022 5731 INFO nova.virt.libvirt.driver [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] [instance: 1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5] Deleting instance files /var/lib/nova/instances/1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5
  2014-04-18 16:35:20.029 5731 ERROR nova.virt.libvirt.driver [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] [instance: 1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5] Failed to cleanup directory /var/lib/nova/instances/1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5: [Errno 39] Directory not empty: '/var/lib/nova/instances/1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5'
  2014-04-18 16:35:20.030 5731 INFO nova.virt.libvirt.driver [req-aa9cc8e7-8fb8-4d11-960c-41fec0e1d2e7 1f631c561b634f31a31e207a999c70b3 1129030a03974f5087edd212704d3a4c] [instance: 1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5] Deletion of /var/lib/nova/instances/1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5 failed
  ================================
  the instance folder listing :

  drwxr-xr-x   2 nova nova      4096 Apr 18 16:35 .
  drwxrwxrwx 170 nova nova     20480 Apr 18 16:33 ..
  -rw-r--r--   1 root root 346488832 Apr 18 16:35 .nfs000000000b5e52a900000001
  ================================
  ~# fuser -vm /var/lib/nova/instances/1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5/
                       USER        PID ACCESS COMMAND
  /var/lib/nova/instances/1d82813e-c1ee-4d4d-b9b2-d532fc83c2c5:
                       root     kernel mount /var/lib/nova/instances
                       nova       1602 F.... qemu-system-x86
                       nova       1603 F.... nova-compute
  ================================

  restarting nova-compute service releases the nfs lock,

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