| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-07-23 | |||
| 20:31:46 | dansmith | if we do that, | |
| 20:31:47 | dansmith | we should also delete the instance in the cell db if we race with the conversion from BR to instance | |
| 20:31:52 | dansmith | but maybe we're slipping through those cracks | |
| 20:32:05 | dansmith | here: https://github.com/openstack/nova/blob/master/nova/conductor/manager.py#L1184 | |
| 20:32:53 | dansmith | not really sure how that could be wrong tbh | |
| 20:33:12 | dansmith | either we fail to delete it "during booting" and then fall through to regular delete, | |
| 20:33:23 | mriedem | mnaser: so you have any old nova-osapi_compute services? https://github.com/openstack/nova/blob/master/nova/compute/api.py#L1803 | |
| 20:33:23 | dansmith | or we succeed, conductor tries/fails to delete the BR, and destroys the instance | |
| 20:33:30 | mriedem | *do you have | |
| 20:33:36 | dansmith | or old service records | |
| 20:33:42 | mnaser | let me check the db rather than service-list | |
| 20:33:55 | mriedem | service list doesn't show api servies | |
| 20:33:58 | mriedem | so yeah you have to check the db | |
| 20:34:22 | mriedem | you could have some api services with version 0 from running with wsgi before we fixed that? | |
| 20:34:57 | mnaser | there are some stale records but i see 16/22/30 | |
| 20:35:05 | mnaser | can i safely delete those older ones in the db | |
| 20:35:11 | mnaser | (no 0's though) | |
| 20:35:33 | mnaser | haha | |
| 20:35:41 | mriedem | it's checking for version < 15 so those shouldn't be a problem for this issue | |
| 20:35:43 | mnaser | truncate table services; | |
| 20:35:46 | mnaser | "it'll autopopulate" | |
| 20:36:45 | mriedem | dansmith: umm, couldn't we have an instance mapping with no cell mapping if we hit this? https://github.com/openstack/nova/blob/master/nova/conductor/manager.py#L1244 | |
| 20:37:03 | mriedem | api deletes the build request, we catch it and just continue | |
| 20:37:33 | dansmith | instance mapping with no cell is not a problem if the instance is deleted from the cell | |
| 20:37:48 | mriedem | in ^ the instance wouldn't be created in a cell | |
| 20:38:04 | mnaser | this instance was created in cell0 though (i checked via the db) | |
| 20:38:12 | dansmith | mriedem: then it wouldn't fit his problem | |
| 20:38:59 | mnaser | is _bury_in_cell0 the only codebase that puts things into cell0? | |
| 20:39:04 | dansmith | yeah | |
| 20:39:30 | mnaser | so we know it got at least to here - https://github.com/openstack/nova/blob/master/nova/conductor/manager.py#L1155 | |
| 20:39:34 | mnaser | let me check if it created bdms | |
| 20:40:08 | dansmith | should have, | |
| 20:40:11 | dansmith | nothing to stop it there I think | |
| 20:40:35 | dansmith | it must not have hit 1183 because if so, the instance would be deleted | |
| 20:40:53 | mnaser | are bdms created when one is given? | |
| 20:41:18 | mnaser | cause: select * from block_device_mapping where instance_uuid='f5ce0c5f-0484-496f-a497-6d1a1fb370d3'; => nada | |
| 20:41:41 | dansmith | when one is _not_ given? | |
| 20:41:47 | dansmith | I think we can have no BDMs here | |
| 20:42:01 | mnaser | yes sorry, when one is not given | |
| 20:42:23 | mriedem | when you're not booting from volume, | |
| 20:42:24 | mnaser | hmm | |
| 20:42:30 | mriedem | i want to say we create a bdm record for the local image | |
| 20:42:33 | mnaser | the status should be ERROR but the status in cell0 is not error | |
| 20:43:07 | mnaser | state in cell0 is building/scheduling | |
| 20:43:12 | mnaser | which it should not be? | |
| 20:43:27 | mriedem | _set_vm_state_and_notify probably failed then | |
| 20:43:29 | dansmith | I'm not sure where/when it goes to error | |
| 20:43:36 | mriedem | https://github.com/openstack/nova/blob/master/nova/conductor/manager.py#L1166 | |
| 20:43:42 | mriedem | updates = {'vm_state': vm_states.ERROR, 'task_state': None} | |
| 20:43:43 | dansmith | maybe it failed on a task_state conflict? | |
| 20:43:59 | mriedem | scheduler_utils.set_vm_state_and_notify does a few things... | |
| 20:44:15 | mnaser | this should all be in the conductor right? | |
| 20:44:20 | dansmith | yeah | |
| 20:44:24 | mnaser | just to look at logs | |
| 20:44:41 | dansmith | oh | |
| 20:44:45 | dansmith | that could be the rabbit connection | |
| 20:44:49 | dansmith | trying to send the notify | |
| 20:44:58 | dansmith | amirite? | |
| 20:45:09 | mriedem | we send the notification last, | |
| 20:45:13 | mriedem | and save the instance changes before that | |
| 20:45:17 | dansmith | ah | |
| 20:45:30 | mriedem | https://github.com/openstack/nova/blob/master/nova/scheduler/utils.py#L600 | |
| 20:45:46 | dansmith | does get_notifier() fail if we can't talk to rabbit? | |
| 20:46:25 | mriedem | no idea | |
| 20:46:48 | mriedem | need to know if this is in the conductor logs for the instance in question https://github.com/openstack/nova/blob/master/nova/scheduler/utils.py#L581 | |
| 20:47:09 | melwitt | mnaser: this is a similar bug jroll opened https://bugs.launchpad.net/nova/+bug/1775934 instance was in cell0 db but the instance mapping had cell_id = NULL | |
| 20:47:10 | openstack | Launchpad bug 1775934 in OpenStack Compute (nova) "Cannot run "openstack server list" with instance stuck in scheduling state" [Undecided,New] | |
| 20:47:27 | mriedem | melwitt: yeah see https://github.com/openstack/nova/blob/bcbc1f9aeddb060513768489450c429bf53e1e46/nova/conductor/manager.py#L1244 | |
| 20:47:31 | mriedem | we don't bury in cell0 there | |
| 20:47:37 | mriedem | so that might be what jroll hit | |
| 20:48:35 | melwitt | I don't think so bc his instance was buried in cell0 but the instance mapping did not reflect cell0, it was still pointing at NULL for cell_id | |
| 20:48:57 | mriedem | that's what mnaser is seeing as well | |
| 20:50:29 | melwitt | okay, yeah so that's what dansmith was saying if the notify failed (or if nova-conductor somehow was restarted at the exact moment) we'd create in cell0 and not update the instance mapping | |
| 20:53:43 | mnaser | yeah | |
| 20:53:49 | mnaser | rabbit was having a field day at that point in time | |
| 20:54:06 | dansmith | but the task/vm states should be updated, as mriedem was saying | |
| 20:54:08 | dansmith | and they're not | |
| 20:54:16 | mnaser | Unexpected error during heartbeart thread processing, retrying...: error: [Errno 104] ECONNRESET | |
| 20:54:40 | mriedem | mnaser: do you see this in the logs for that instance? https://github.com/openstack/nova/blob/master/nova/scheduler/utils.py#L581 | |
| 20:54:58 | mnaser | in conductor right? | |
| 20:55:00 | mriedem | yeah | |
| 20:55:06 | mriedem | dansmith: oh btw, instance.save() sends it's own notification | |
| 20:55:11 | mriedem | i always forget about that | |
| 20:55:16 | dansmith | true story | |
| 20:55:19 | mriedem | should be after the db update | |
| 20:56:23 | mnaser | not a single reference to that instance id in the logs | |
| 20:56:24 | mnaser | :\ | |
| 20:56:34 | mnaser | in that range of time at least | |
| 20:56:41 | mnaser | unless zgrep is failing me but i dont think so | |
| 20:56:49 | dansmith | well, that's good | |
| 20:57:03 | dansmith | mnaser: whatabout https://github.com/openstack/nova/blob/master/nova/scheduler/utils.py#L567 | |
| 20:57:15 | mnaser | i see other references to it but this instance odes not have one | |
| 20:57:59 | mriedem | Failed to compute_task_build_instances | |
| 20:58:16 | mnaser | let me get the tenant id of this vm | |
| 20:58:55 | mnaser | just no valid hosts | |
| 20:59:06 | openstackgerrit | Jim Rollenhagen proposed openstack/nova master: ironic: add instance_uuid before any other spawn activity https://review.openstack.org/563722 | |
| 20:59:06 | dansmith | and this if you have debug on: https://github.com/openstack/nova/blob/master/nova/conductor/manager.py#L1098 | |
| 20:59:10 | mnaser | hmm | |
| 20:59:19 | mnaser | "Failed to get aggregates for resource provider with UUID 04ae18f3-7226-4d0f-81f3-74a73eb1722a" | |
| 20:59:25 | mnaser | for some failures in the similar timeline | |