Bug 1661190 - Delete VM fails: Servers show task_state=deleting and status=ACTIVE
Summary: Delete VM fails: Servers show task_state=deleting and status=ACTIVE
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Red Hat OpenStack
Classification: Red Hat
Component: openstack-nova
Version: 14.0 (Rocky)
Hardware: Unspecified
OS: Unspecified
unspecified
medium
Target Milestone: ---
: ---
Assignee: nova-maint
QA Contact: nova-maint
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2018-12-20 10:50 UTC by Noam Manos
Modified: 2019-09-09 13:59 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
Environment:
Last Closed: 2018-12-21 16:02:59 UTC
Target Upstream Version:

Attachments (Terms of Use)
Add an attachment (proposed patch, testcase, etc.)

Description Noam Manos 2018-12-20 10:50:05 UTC 
Description of problem:
Creating VM and Deleting it multiple times, sometimes gets stuck on task_state=deleting and status=ACTIVE, and VM is not removed from server list.

nova-api.log shows:
Policy check for os_compute_api:os-hide-server-addresses failed with credentials

Version-Release number of selected component (if applicable):
OSP14 2018-12-17.1

How reproducible:
Sometimes

Steps to Reproduce:
1. Deploy OSP14
2. Create VMs
3. Delete those VMs
4. Repeat steps 2-3 few times, when using same VM name and configuration

Actual results:
---------------

(overcloud) [stack@undercloud-0 ~]$ openstack server list --all
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
| ID                                   | Name            | Status | Networks                                                     | Image  | Flavor      |
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
| ea436de1-51e2-40cb-9eef-d720b53cc240 | rhel75_vm1_net2 | ACTIVE | net_ipv64_2=10.0.2.6, 2002::f816:3eff:fe23:2eed, 10.0.0.232  | rhel75 | rhel_flavor |
| 08f439be-85e0-4086-94f2-131001a7f140 | rhel75_vm1_net1 | ACTIVE | net_ipv64_1=2001::f816:3eff:fe29:d5f9, 10.0.1.10, 10.0.0.220 | rhel75 | rhel_flavor |
| d28beb70-2331-4a53-ae77-a673edd2f6f5 | rhel75_vm1_net1 | ACTIVE |                                                              |        |             |
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+

(overcloud) [stack@undercloud-0 ~]$ openstack server delete d28beb70-2331-4a53-ae77-a673edd2f6f5

(overcloud) [stack@undercloud-0 ~]$ openstack server show d28beb70-2331-4a53-ae77-a673edd2f6f5
+-------------------------------------+----------------------------------------------------------+
| Field                               | Value                                                    |
+-------------------------------------+----------------------------------------------------------+
| OS-DCF:diskConfig                   | MANUAL                                                   |
| OS-EXT-AZ:availability_zone         | nova                                                     |
| OS-EXT-SRV-ATTR:host                | compute-1.localdomain                                    |
| OS-EXT-SRV-ATTR:hypervisor_hostname | compute-1.localdomain                                    |
| OS-EXT-SRV-ATTR:instance_name       | instance-00000003                                        |
| OS-EXT-STS:power_state              | Running                                                  |
| OS-EXT-STS:task_state               | deleting                                                 |
| OS-EXT-STS:vm_state                 | active                                                   |
| OS-SRV-USG:launched_at              | 2018-12-18T09:36:42.000000                               |
| OS-SRV-USG:terminated_at            | None                                                     |
| accessIPv4                          |                                                          |
| accessIPv6                          |                                                          |
| addresses                           |                                                          |
| config_drive                        |                                                          |
| created                             | 2018-12-18T09:35:45Z                                     |
| flavor                              | 665abd1f-c5eb-4445-b0f4-697c0df99646                     |
| hostId                              | 5667ed1c935eb41dd426738651204106b16bb077d17e3f560772b358 |
| id                                  | d28beb70-2331-4a53-ae77-a673edd2f6f5                     |
| image                               | 4c54fcf0-6a2a-4c4b-85c9-3cc5b4756b71                     |
| key_name                            | tester-key                                               |
| name                                | rhel75_vm1_net1                                          |
| progress                            | 0                                                        |
| project_id                          | 6966714861e2463fa97baf8962d82501                         |
| properties                          |                                                          |
| status                              | ACTIVE                                                   |
| updated                             | 2018-12-20T10:09:31Z                                     |
| user_id                             | 07ee5873f0f7463ea94afd434e282bc0                         |
| volumes_attached                    |                                                          |
+-------------------------------------+----------------------------------------------------------+

(overcloud) [stack@undercloud-0 ~]$ openstack server list --all
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
| ID                                   | Name            | Status | Networks                                                     | Image  | Flavor      |
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
| ea436de1-51e2-40cb-9eef-d720b53cc240 | rhel75_vm1_net2 | ACTIVE | net_ipv64_2=10.0.2.6, 2002::f816:3eff:fe23:2eed, 10.0.0.232  | rhel75 | rhel_flavor |
| 08f439be-85e0-4086-94f2-131001a7f140 | rhel75_vm1_net1 | ACTIVE | net_ipv64_1=2001::f816:3eff:fe29:d5f9, 10.0.1.10, 10.0.0.220 | rhel75 | rhel_flavor |
| d28beb70-2331-4a53-ae77-a673edd2f6f5 | rhel75_vm1_net1 | ACTIVE |                                                              |        |             |
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+


*** controller-1: /var/log/containers/nova/nova-api.log ***

--
2018-12-20 10:07:11.798 21 INFO nova.api.openstack.requestlog [req-a201260e-72ba-481c-a01e-caf1078a01dc fc2ad698314a45e0b159d6dd16792409 ca39859f0adf4030b04f873e9f10a98d - default default] 172.17.1.24 "OPTIONS /" status: 200 len: 411 microversion: - time: 0.001502
2018-12-20 10:07:13.171 18 INFO nova.api.openstack.requestlog [req-4631cf35-1d12-48d1-9638-9290c1d800f1 82172e7afa8e49618026f50182faf690 a94c0dad1808425e8d028c7b851dee26 - default default] 172.17.1.39 "GET /v2.1/servers/d28beb70-2331-4a53-ae77-a673edd2f6f5" status: 200 len: 1489 microversion: 2.1 time: 3.755484
2018-12-20 10:07:10.285 21 INFO nova.api.openstack.requestlog [req-a201260e-72ba-481c-a01e-caf1078a01dc fc2ad698314a45e0b159d6dd16792409 ca39859f0adf4030b04f873e9f10a98d - default default] 172.17.1.39 "OPTIONS /" status: 200 len: 411 microversion: - time: 0.001384
2018-12-20 10:07:10.743 19 INFO nova.api.openstack.requestlog [req-0c2c5fa9-1484-434c-a535-dc7e70d172d5 fc2ad698314a45e0b159d6dd16792409 ca39859f0adf4030b04f873e9f10a98d - default default] 172.17.1.40 "OPTIONS /" status: 200 len: 411 microversion: - time: 0.001402
2018-12-20 10:07:10.284 21 DEBUG nova.api.openstack.wsgi [req-a201260e-72ba-481c-a01e-caf1078a01dc fc2ad698314a45e0b159d6dd16792409 ca39859f0adf4030b04f873e9f10a98d - default default] Calling method '<bound method Versions.index of <nova.api.openstack.compute.versions.Versions object at 0x7f5ce924b510>>' _process_stack /usr/lib/python2.7/site-packages/nova/api/openstack/wsgi.py:618
2018-12-20 10:07:10.830 18 DEBUG nova.compute.api [req-4631cf35-1d12-48d1-9638-9290c1d800f1 82172e7afa8e49618026f50182faf690 a94c0dad1808425e8d028c7b851dee26 - default default] [instance: d28beb70-2331-4a53-ae77-a673edd2f6f5] Fetching instance by UUID get /usr/lib/python2.7/site-packages/nova/compute/api.py:2402
2018-12-20 10:07:10.867 18 DEBUG oslo_concurrency.lockutils [req-4631cf35-1d12-48d1-9638-9290c1d800f1 82172e7afa8e49618026f50182faf690 a94c0dad1808425e8d028c7b851dee26 - default default] Lock "c5c21019-9fb1-4b50-9b55-3035ef8754f3" acquired by "nova.context.get_or_set_cached_cell_and_set_connections" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273
2018-12-20 10:07:10.956 18 DEBUG nova.policy [req-4631cf35-1d12-48d1-9638-9290c1d800f1 82172e7afa8e49618026f50182faf690 a94c0dad1808425e8d028c7b851dee26 - default default] Policy check for os_compute_api:os-hide-server-addresses failed with credentials {'service_roles': [], 'user_id': u'82172e7afa8e49618026f50182faf690', 'roles': [u'member', u'_member_', u'reader', u'admin'], 'system_scope': None, 'service_project_id': None, 'service_user_id': None, 'service_user_domain_id': None, 'service_project_domain_id': None, 'is_admin_project': True, 'is_admin': True, 'user_domain_id': u'default', 'project_id': u'a94c0dad1808425e8d028c7b851dee26', 'project_domain_id': u'default'} authorize /usr/lib/python2.7/site-packages/nova/policy.py:168



Expected results:
VM should be removed from server list

Additional info:
Adding sos reports.
Comment 1 Noam Manos 2018-12-20 12:46:48 UTC 
SOS-Reports:
http://rhos-release.virt.bos.redhat.com/log/bz1661190
Comment 2 Noam Manos 2018-12-20 12:59:08 UTC 
After several attempts to delete the VM I got error 400: Networking client is experiencing an unauthorized exception.
Then another attempt to delete has succeeded.


(undercloud) [stack@undercloud-0 ~]$ openstack server list --all
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
| ID                                   | Name            | Status | Networks                                                     | Image  | Flavor      |
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
| ea436de1-51e2-40cb-9eef-d720b53cc240 | rhel75_vm1_net2 | ACTIVE | net_ipv64_2=10.0.2.6, 2002::f816:3eff:fe23:2eed, 10.0.0.232  | rhel75 | rhel_flavor |
| 08f439be-85e0-4086-94f2-131001a7f140 | rhel75_vm1_net1 | ACTIVE | net_ipv64_1=2001::f816:3eff:fe29:d5f9, 10.0.1.10, 10.0.0.220 | rhel75 | rhel_flavor |
| d28beb70-2331-4a53-ae77-a673edd2f6f5 | rhel75_vm1_net1 | ERROR  |                                                              |        |             |
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+

(overcloud) [stack@undercloud-0 ~]$ openstack server show d28beb70-2331-4a53-ae77-a673edd2f6f5
+-------------------------------------+----------------------------------------------------------------------------------------------------------------------------------+
| Field                               | Value                                                                                                                            |
+-------------------------------------+----------------------------------------------------------------------------------------------------------------------------------+
| OS-DCF:diskConfig                   | MANUAL                                                                                                                           |
| OS-EXT-AZ:availability_zone         | nova                                                                                                                             |
| OS-EXT-SRV-ATTR:host                | compute-1.localdomain                                                                                                            |
| OS-EXT-SRV-ATTR:hypervisor_hostname | compute-1.localdomain                                                                                                            |
| OS-EXT-SRV-ATTR:instance_name       | instance-00000003                                                                                                                |
| OS-EXT-STS:power_state              | NOSTATE                                                                                                                          |
| OS-EXT-STS:task_state               | None                                                                                                                             |
| OS-EXT-STS:vm_state                 | error                                                                                                                            |
| OS-SRV-USG:launched_at              | 2018-12-18T09:36:42.000000                                                                                                       |
| OS-SRV-USG:terminated_at            | None                                                                                                                             |
| accessIPv4                          |                                                                                                                                  |
| accessIPv6                          |                                                                                                                                  |
| addresses                           |                                                                                                                                  |
| config_drive                        |                                                                                                                                  |
| created                             | 2018-12-18T09:35:45Z                                                                                                             |
| fault                               | {u'message': u'Networking client is experiencing an unauthorized exception.', u'code': 400, u'created': u'2018-12-20T12:33:05Z'} |
| flavor                              | 665abd1f-c5eb-4445-b0f4-697c0df99646                                                                                             |
| hostId                              | 5667ed1c935eb41dd426738651204106b16bb077d17e3f560772b358                                                                         |
| id                                  | d28beb70-2331-4a53-ae77-a673edd2f6f5                                                                                             |
| image                               | 4c54fcf0-6a2a-4c4b-85c9-3cc5b4756b71                                                                                             |
| key_name                            | tester-key                                                                                                                       |
| name                                | rhel75_vm1_net1                                                                                                                  |
| project_id                          | 6966714861e2463fa97baf8962d82501                                                                                                 |
| properties                          |                                                                                                                                  |
| status                              | ERROR                                                                                                                            |
| updated                             | 2018-12-20T12:33:11Z                                                                                                             |
| user_id                             | 07ee5873f0f7463ea94afd434e282bc0                                                                                                 |
| volumes_attached                    |                                                                                                                                  |
+-------------------------------------+----------------------------------------------------------------------------------------------------------------------------------+

(overcloud) [stack@undercloud-0 ~]$ openstack server delete d28beb70-2331-4a53-ae77-a673edd2f6f5
(overcloud) [stack@undercloud-0 ~]$ 
(overcloud) [stack@undercloud-0 ~]$ 
(overcloud) [stack@undercloud-0 ~]$ openstack server list --all
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
| ID                                   | Name            | Status | Networks                                                     | Image  | Flavor      |
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
| ea436de1-51e2-40cb-9eef-d720b53cc240 | rhel75_vm1_net2 | ACTIVE | net_ipv64_2=10.0.2.6, 2002::f816:3eff:fe23:2eed, 10.0.0.232  | rhel75 | rhel_flavor |
| 08f439be-85e0-4086-94f2-131001a7f140 | rhel75_vm1_net1 | ACTIVE | net_ipv64_1=2001::f816:3eff:fe29:d5f9, 10.0.1.10, 10.0.0.220 | rhel75 | rhel_flavor |
+--------------------------------------+-----------------+--------+--------------------------------------------------------------+--------+-------------+
Comment 3 Noam Manos 2018-12-20 13:01:26 UTC 
Seems like same symptoms of Bug 1446752, but might be different cause.
Note You need to log in before you can comment on or make changes to this bug.