Bug 1422154
| Summary: | Second attempt to evacuate an instance fails | ||||||||||||||||||||||||||||||
|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|---|
| Product: | Red Hat OpenStack | Reporter: | John Williams <j_t_williams> | ||||||||||||||||||||||||||||
| Component: | openstack-nova | Assignee: | Sylvain Bauza <sbauza> | ||||||||||||||||||||||||||||
| Status: | CLOSED DUPLICATE | QA Contact: | Prasanth Anbalagan <panbalag> | ||||||||||||||||||||||||||||
| Severity: | high | Docs Contact: | |||||||||||||||||||||||||||||
| Priority: | unspecified | ||||||||||||||||||||||||||||||
| Version: | 10.0 (Newton) | CC: | arkady_kanevsky, berrange, cdevine, christopher_dearborn, dasmith, dcain, eglynn, jjoyce, John_walsh, j_t_williams, kchamart, kurt_hey, manisha_tripathy, mburns, morazi, mschuppe, randy_perryman, sbauza, sferdjao, sgordon, smerrow, sreichar, srevivo, stephenfin, vromanso | ||||||||||||||||||||||||||||
| Target Milestone: | z3 | Keywords: | Triaged, ZStream | ||||||||||||||||||||||||||||
| Target Release: | 10.0 (Newton) | ||||||||||||||||||||||||||||||
| Hardware: | x86_64 | ||||||||||||||||||||||||||||||
| OS: | Linux | ||||||||||||||||||||||||||||||
| Whiteboard: | |||||||||||||||||||||||||||||||
| Fixed In Version: | openstack-nova-14.0.6-1.el7ost | Doc Type: | If docs needed, set a value | ||||||||||||||||||||||||||||
| Doc Text: | Story Points: | --- | |||||||||||||||||||||||||||||
| Clone Of: | Environment: | ||||||||||||||||||||||||||||||
| Last Closed: | 2017-05-30 09:01:01 UTC | Type: | Bug | ||||||||||||||||||||||||||||
| Regression: | --- | Mount Type: | --- | ||||||||||||||||||||||||||||
| Documentation: | --- | CRM: | |||||||||||||||||||||||||||||
| Verified Versions: | Category: | --- | |||||||||||||||||||||||||||||
| oVirt Team: | --- | RHEL 7.3 requirements from Atomic Host: | |||||||||||||||||||||||||||||
| Cloudforms Team: | --- | Target Upstream Version: | |||||||||||||||||||||||||||||
| Embargoed: | |||||||||||||||||||||||||||||||
| Bug Depends On: | |||||||||||||||||||||||||||||||
| Bug Blocks: | 1356451 | ||||||||||||||||||||||||||||||
| Attachments: |
|
||||||||||||||||||||||||||||||
|
Description
John Williams
2017-02-14 15:36:02 UTC
Created attachment 1250286 [details]
Nova-compute 2 log file
This bugzilla has been removed from the release and needs to be reviewed and Triaged for another Target Release. Created attachment 1250294 [details]
sos report for compute 1
Created attachment 1250295 [details]
sos report for compute2
I have been investigating this issue and have been able to reproduce what appears to be the same ERROR state using nova commands such as nova migrate <server>, openstack server migrate <server> and nova host-servers-migrate <nodename>. The resulting conditions of running these commands are the same or similar to the IHA tests as they result in nova status state ERROR. This bugzilla has been removed from the release and needs to be reviewed and Triaged for another Target Release. John, The errors you see about missing compute nodes are expected on the first start of a compute service. From what I see in your logs, that's not a problem. Incidentally, we just changed this upstream to be a little less concerning for first-time runs. Looking through your compute-1 log, I see some things that would concern me and could explain any amount of strange behavior. Note this: 2017-02-13 18:49:32.542 5320 ERROR nova.compute.manager [instance: 7d95a678-bf2d-4bbb-8405-9f722d63d5a1] IOError: [Errno 13] Permission denied: '/var/lib/nova/instances/7d95a678-bf2d-4bbb-8405-9f722d63d5a1/console.log' It looks like maybe the instance started on compute-2 and moved to compute-1, is that right? The compute-2 logs show it was there, and running at some point: 2017-02-13 17:42:30.194 86872 INFO nova.virt.libvirt.driver [-] [instance: 7d95a678-bf2d-4bbb-8405-9f722d63d5a1] Instance spawned successfully. Perhaps resolving the permissions issue on compute-1 will resolve the evacuation problem as well? Dan, I'm in the middle of redeploying but will get back to this. I believe the scenario described above was the cirros_test instance was originally on r14-compute-1.r14.rcbd.lab and was evacuated to r14-compute-2.r14.rcbd.lab. It was successful and started fine. After which the second test to evacuate it from r14-compute-2.r14.rcbd.lab resulted in failure. I have confirmed this is not a permissions issue but a selinux policy issue. setting selinux to permissive on the compute nodes allows the nodes to relocate when IHA tries to evacuate the node. I will need help setting the selinux policies. FYI, I am still having the reports issue with instances with attached backend volumes (rbd_backend), even with selinx set to permissive. I am not seeing the issue with instances with no attached backends. s/reports/reported/ JT, since you still see the issue even with SELinux in permissive mode, when you see that failure, are you still seeing errors around permissions as pointed out by Dan? I am at the point where I can recreate the issue, so I would like to know if there are any specific logs, debug settings or information I should collect before attempting to recreate the issue.
[osp_admin@r14-director pilot]$ nova show bc46724d-9f0e-492a-a024-ea5034fbfc1b
| Property | Value |
| OS-DCF:diskConfig | MANUAL |
| OS-EXT-AZ:availability_zone | nova |
| OS-EXT-SRV-ATTR:host | r14-compute-1.oss.labs |
| OS-EXT-SRV-ATTR:hostname | cirros-test |
| OS-EXT-SRV-ATTR:hypervisor_hostname | r14-compute-1.oss.labs |
| OS-EXT-SRV-ATTR:instance_name | instance-00000002 |
| OS-EXT-SRV-ATTR:kernel_id | |
| OS-EXT-SRV-ATTR:launch_index | 0 |
| OS-EXT-SRV-ATTR:ramdisk_id | |
| OS-EXT-SRV-ATTR:reservation_id | r-61j0b50q |
| OS-EXT-SRV-ATTR:root_device_name | /dev/vda |
| OS-EXT-SRV-ATTR:user_data | - |
| OS-EXT-STS:power_state | 1 |
| OS-EXT-STS:task_state | - |
| OS-EXT-STS:vm_state | active |
| OS-SRV-USG:launched_at | 2017-03-02T21:26:08.000000 |
| OS-SRV-USG:terminated_at | - |
| accessIPv4 | |
| accessIPv6 | |
| config_drive | |
| created | 2017-03-02T21:25:57Z |
| description | - |
| flavor | m1.small (2) |
| hostId | 4726fa94a004cae0e94faa384557b6b89f6e495463abed226196fcb5 |
| host_status | UP |
| id | bc46724d-9f0e-492a-a024-ea5034fbfc1b |
| image | cirros (4b1fab05-7e06-49cd-8d82-4245881ed58e) |
| key_name | key_name |
| locked | False |
| metadata | {} |
| name | cirros_test |
| os-extended-volumes:volumes_attached | [{"id": "ff5e6eef-f664-4fa9-a7ec-a1d9f17242bf", "delete_on_termination": false}] |
| progress | 0 |
| security_groups | sanity_security_group |
| status | ACTIVE |
| tags | [] |
| tenant_id | 39fe5bd1e3854390a3725f75943e2fbd |
| tenant_net network | 192.168.201.6, 100.82.39.71 |
| updated | 2017-03-02T21:26:08Z |
| user_id | bad85718f51e47a1a2d4e0a3c182f46a |
[osp_admin@r14-director pilot]$ openstack volume show ff5e6eef-f664-4fa9-a7ec-a1d9f17242bf
| Field | Value |
| attachments | [{u'server_id': u'bc46724d-9f0e-492a-a024-ea5034fbfc1b', u'attachment_id': u'7e3d4c66-b29a-4759-99d0-579fb144dffd', u'attached_at': |
| | u'2017-03-02T21:27:03.000000', u'host_name': None, u'volume_id': u'ff5e6eef-f664-4fa9-a7ec-a1d9f17242bf', u'device': u'/dev/vdb', u'id': u'ff5e6eef-f664-4fa9 |
| | -a7ec-a1d9f17242bf'}] |
| availability_zone | nova |
| bootable | false |
| consistencygroup_id | None |
| created_at | 2017-03-02T21:26:50.000000 |
| description | None |
| encrypted | False |
| id | ff5e6eef-f664-4fa9-a7ec-a1d9f17242bf |
| migration_status | None |
| multiattach | False |
| name | volume_test |
| os-vol-host-attr:host | hostgroup@tripleo_ceph#tripleo_ceph |
| os-vol-mig-status-attr:migstat | None |
| os-vol-mig-status-attr:name_id | None |
| os-vol-tenant-attr:tenant_id | 39fe5bd1e3854390a3725f75943e2fbd |
| properties | attached_mode='rw', readonly='False' |
| replication_status | disabled |
| size | 1 |
| snapshot_id | None |
| source_volid | None |
| status | in-use |
| type | rbd_backend |
| updated_at | 2017-03-02T21:27:03.000000 |
| user_id | bad85718f51e47a1a2d4e0a3c182f46a
Yes, I am seeing the "[Errno 13] Permission denied:" error message in the compute log of the node where the instance was running (compute-1) before being relocated to compute-0 node. However, the error occurs on the second attempt when trying to evacuate the node off of compute-0. I ran stat on reported file as shown below: root@r14-compute-1 log]# stat /var/lib/nova/instances/bc46724d-9f0e-492a-a024-ea5034fbfc1b/console.log File: ‘/var/lib/nova/instances/bc46724d-9f0e-492a-a024-ea5034fbfc1b/console.log’ Size: 19749 Blocks: 40 IO Block: 4096 regular file Device: 802h/2050d Inode: 62914628 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 107/ qemu) Gid: ( 107/ qemu) Context: system_u:object_r:svirt_image_t:s0:c104,c589 Access: 2017-03-02 21:26:02.603672530 +0000 Modify: 2017-03-02 21:27:02.784935923 +0000 Change: 2017-03-02 21:27:02.784935923 +0000 Birth: - Stating the same file on compute-0 node shows the following: root@r14-compute-0 log]# stat /var/lib/nova/instances/bc46724d-9f0e-492a-a024-ea5034fbfc1b/console.log File: ‘/var/lib/nova/instances/bc46724d-9f0e-492a-a024-ea5034fbfc1b/console.log’ Size: 19190 Blocks: 40 IO Block: 4096 regular file Device: 802h/2050d Inode: 197132419 Links: 1 Access: (0644/-rw-r--r--) Uid: ( 107/ qemu) Gid: ( 107/ qemu) Context: system_u:object_r:svirt_image_t:s0:c562,c633 Access: 2017-03-03 15:13:00.535279429 +0000 Modify: 2017-03-03 15:13:05.202312303 +0000 Change: 2017-03-03 15:13:05.202312303 +0000 Birth: - I have concluded reproduction of this issue with selinux set to Enforcing, capturing sosreports prior to evacuating the instance, after the successful first attempt and after the second attempt that resulted in failure. In total that is 18 sosreports, 3 for each controller/compute node. Would it be better to upload them here or some other site? Created attachment 1259594 [details]
cntl1-before-iha
Created attachment 1259595 [details]
cntl1-iha-1st-success
Created attachment 1259596 [details]
cntl1-iha-2nd-err
Created attachment 1259597 [details]
nova0-before-iha
Created attachment 1259598 [details]
nova0-iha-1st-success
Created attachment 1259599 [details]
nova0-iha-2nd-err
Created attachment 1259601 [details]
nova1-before-iha
Created attachment 1259603 [details]
nova1-iha-1st-success
Created attachment 1259604 [details]
nova1-iha-2nd-err
I have uploaded the sosreports for the systems that I believe are involved with the issue. I have collected the reports for the other systems and can upload them is needed. biha is before attempting iha evacuation, 1st and 2nd attempts are the sosreports after attempting iha evacuation. I think I have found the root cause of the issue. When an instance (regardless of whether a volume is attached or not) is evacuated via IHA when a compute node goes down (via a simulated panic) and it leaves artifacts behind in the form of the instance directory and console.log. /var/lib/nova/instances<instanceID> /var/lib/nova/instances<instanceID>/compute.log These lingering artifacts become blockers to the instance being relocated back onto the compute node it previously was evacuated from and causes the "Error" condition. Removing the log file and directory prior to a second attempt of evacuation results in "Success". The fix is not as simple as removing the directory and log file for all instances when the node comes back online, because there may be instances that are not running under IHA control which will restart when the node comes up. I think a better solution would be to store the console.log file in a directory on the backend storage node so that it would live with the instance files. Hi Dan, Any thoughts on JT's findings? Thanks, Sean *** Bug 1434986 has been marked as a duplicate of this bug. *** This got assigned to sbauza earlier today based on the belief that this is resolved upstream. Please send me a pointer to the upstream patch where it has been resolved. Thanks Manisha (In reply to Mike Orazi from comment #30) > This got assigned to sbauza earlier today based on the belief > that this is resolved upstream. This isn't 100% in line with my recollection of the triage call where we discussed this, while there are reports of and fixes for issues with similar symptoms upstream I think there was still some investigation required to confirm a match. Sylvain, any update here? Still looking for an update. The issue has been identified upstream in https://bugs.launchpad.net/nova/+bug/1634282 Basically, libvirt makes ownership of the console.log file which prevents subsequent move operations that go back to the original host to work correctly. While the problem is pretty difficult to resolve because it would mean that we should discuss about how to clean-up libvirt permissions, there is a workaround that was provided in Pike and backported to Ocata : https://review.openstack.org/#/c/392643/ The workaround is about to accept permission issues when opening the console.log file. That change hasn't been backported to Newton (OSP10) but could possibly be done in our OSP product, given the upstream policy only accepts backports for the N-2 version (N being the master branch) if it's only a security fix or a very important bugfix. Just working now on providing that backport for OSP10. Downstream backport to OSP10 open for reviews : https://code.engineering.redhat.com/gerrit/#/c/102808/ Just a comment, I'm discussing with upstream stable maintainers to see whether https://review.openstack.org/#/c/392643/6 could directly be backported to the Newton branch. That would prevent us a downstream-only bugfix for OSP10 so please hold the approval of https://code.engineering.redhat.com/gerrit/#/c/102808/ until the upstream situation is clarified. https://review.openstack.org/#/c/454593/ is proposed as a Newton backport. Upstream backport https://review.openstack.org/#/c/454593/ has been approved, consequently abandoning https://code.engineering.redhat.com/gerrit/#/c/102808/ Next Newton stable release will include that change, and next rebase of OSP10 will include it. Mike B., when do you expect that to land in CDN? I patched the /usr/lib/python2.7/site-packages/nova/virt/libvirt/driver.py file on my compute nodes and it appears to work. Need more time on it, but initial results look good. Is this something we can expect to receive on CDN or something I should handle for our release? FWIW, the change has merged upstream in stable/newton. I'll discuss with the upstream Nova PTL to know when we'll provide a new Newton stable release but I think probably in the next 3 weeks. This is a duplicate of #1386420. The fix delivered for that bug was incomplete, however, we will continue to track work on a revised fix there. Closing this as such. *** This bug has been marked as a duplicate of bug 1386420 *** Dup -- QE will decide about automating the original |