| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-07-23 | |||
| 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 | |
| 20:59:37 | dansmith | mnaser: and I guess you've looked for any stack traces in this instance's build time window yeah? | |
| 21:00:06 | mnaser | if an instance tries scheduling several times and fails does it end up in cell0 as well? | |
| 21:00:07 | jroll | melwitt: jaypipes: you were both +2 on https://review.openstack.org/#/c/563722/10, had a trivial rebase conflict | |
| 21:00:13 | dansmith | mnaser: yeah | |
| 21:00:23 | dansmith | novalidhost -> cell0 | |
| 21:00:27 | mriedem | tries scheduling several times? | |
| 21:00:34 | mnaser | well as in | |
| 21:00:38 | mnaser | retrying build on another host | |
| 21:00:38 | mriedem | reschedules? | |
| 21:00:45 | mnaser | i guess thats the term | |
| 21:00:49 | mriedem | not in this case | |
| 21:00:55 | mriedem | reschedules happen within a cell | |
| 21:01:07 | mriedem | cell0 is when you don't get a host to start with | |
| 21:01:17 | dansmith | oh I guess that's right, once you've picked your first host, you're stuck in there | |
| 21:01:25 | mnaser | oh | |
| 21:01:26 | mnaser | uhoh | |
| 21:01:38 | mnaser | y'all are never gonna listen to me again | |
| 21:01:38 | dansmith | I was writing off a lot of that given that he's flat, but I guess that ain't right | |
| 21:01:41 | melwitt | jroll: +W | |
| 21:01:46 | mnaser | i just noticed a failure with | |
| 21:01:47 | mnaser | "WSREP has not yet prepared node for application use" | |
| 21:01:54 | jroll | melwitt: thanks | |
| 21:02:29 | mnaser | that is quite possibly the cause why | |
| 21:02:40 | dansmith | I don't know what that menas | |
| 21:02:41 | mnaser | it might have happened exactly in between the update for cells? | |
| 21:02:54 | mnaser | that message comes up if something happens with the galera cluster and it refuses to accept mysql requests | |
| 21:03:04 | mnaser | aka "i am bootstrapping and syncing up with other masters, leave me alone till im ready" | |