| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-06-08 | |||
| 20:24:19 | melwitt | it's trying to lazy-load the flavor from the database, first thing it does while doing that is the lookup the instance, and that is not found because it's looking in the wrong database | |
| 20:24:29 | jroll | exactly | |
| 20:24:32 | melwitt | this sounds so familiar, just not finding a bug that matches yet | |
| 20:24:41 | temka | melwitt, yep, same here | |
| 20:24:46 | temka | I swear I've seen this | |
| 20:25:40 | jroll | melwitt: in the meantime, we can manually delete it from cell0.instances and nova_api.instance_mappings, trigger a quota reset... will all the other tables get cleaned up on delete? | |
| 20:28:10 | melwitt | I will say that ocata is particularly fraught with problems because the way we were doing cell targeting back then had some fundamental problems which we changed in pike, but was a huge change that backporting would involve backporting a ton of disjointed things in pike, so we abandoned it | |
| 20:28:57 | jroll | mmm | |
| 20:28:59 | melwitt | (assuming that things are okay-enough in ocata. if they're not, then we have to find another way to solve it) | |
| 20:29:53 | melwitt | jroll: yeah, I think that would do it as a manual cleanup. are you seeing this on/during an upgrade or on already-upgraded-and-been-running clusters? | |
| 20:30:24 | jroll | melwitt: already upgraded | |
| 20:30:39 | jroll | we shut down the API for this upgrade | |
| 20:30:42 | melwitt | jroll: okay, so any new instance that fails to schedule gets in this un-listable state | |
| 20:31:02 | jroll | trying to verify that now | |
| 20:31:10 | jroll | this instance is still in BUILD, rather than ERROR | |
| 20:31:19 | jroll | and is the only thing in instance_mappings with cell_id=NULL | |
| 20:31:44 | melwitt | oh, that's interesting. but yet it's in cell0, in BUILD state but not ERROR | |
| 20:32:17 | jroll | yep | |
| 20:32:22 | jroll | and built > 16 hours ago | |
| 20:32:28 | melwitt | cell_id=NULL is a problem. that should be cell0 if it's in cell0 | |
| 20:32:32 | melwitt | hmm | |
| 20:32:40 | jroll | task_state=scheduling | |
| 20:32:51 | jroll | so it's like it got dropped by rabbit or something? idk | |
| 20:33:53 | melwitt | yeah, I dunno. we have also heard from CERN folks of some instance_mappings ending up with cell_id=NULL but I've not understood the conditions under which it happened | |
| 20:35:21 | melwitt | while instances are in the middle of scheduling, they are supposed to be listed/shown using their build_requests in the nova_api database, IIRC | |
| 20:36:07 | jroll | hm, can't run server show on other instances in cell0 either | |
| 20:36:12 | jroll | so maybe that's unrelated | |
| 20:36:21 | jroll | though that 404s instead of 500s | |
| 20:37:58 | jroll | cell_id=1 doesn't break server list either, but doesn't show up in the response | |
| 20:38:24 | melwitt | okay, first check the db connection string for cell0 in nova_api.cell_mappings and make sure it's right, then look in nova_api.instance_mappings and check if cell_id is cell0, then check if the instance is in nova_cell0.instances. that's how it's all connected | |
| 20:39:35 | jroll | yeah, that's all correct | |
| 20:39:44 | melwitt | it will go instance_mappings.cell_id => db connect to cell_mappings.cell_id database_connection string => <cell database>.instances (if the instance has completed scheduling, either via success or error) | |
| 20:40:17 | melwitt | if it did not complete scheduling, it will live in build_requests only and have cell_id=NULL, I believe | |
| 20:40:42 | jroll | nod | |
| 20:40:50 | melwitt | :/ okay, if that's all correct I don't understand how it could _not_ be able to 'nova show' it | |
| 20:41:04 | melwitt | does that still fail with the flavor lazy-load thing? | |
| 20:41:13 | jroll | digging logs now for the 404 | |
| 20:41:45 | melwitt | meaning, the instance that checks out as far as all the things connected properly, fails on the flavor lazy-load? | |
| 20:44:20 | jroll | right, so the one that is properly mapped to cell0 | |
| 20:44:53 | jroll | is throwing a 404 | |
| 20:45:20 | jroll | HTTP exception thrown: Instance 75e193c5-6700-4d67-be44-7020fb4129ed could not be found. | |
| 20:45:34 | melwitt | okay | |
| 20:46:28 | melwitt | still trying to parse whether that lazy-load read_deleted bug you linked earlier is this or not | |
| 20:46:48 | melwitt | the bug seems light on details | |
| 20:46:58 | jroll | yeah, ditto | |
| 20:48:48 | melwitt | okay, so this is about deleted instances not being found when trying to lazy-load other instance properties. that seems kinda chicken and egg. (how did you get the deleted instance to lazy-load from in the first place?) | |
| 20:49:15 | melwitt | but your instances have not been deleted, so I think it's probably not the same bug | |
| 20:51:37 | melwitt | jroll: what's your service version for the nova-osapi_compute service? | |
| 20:52:09 | melwitt | probably in nova_cell0.services | |
| 20:52:49 | jroll | right, not deleted | |
| 20:54:10 | jroll | debug logs gave me jack | |
| 20:54:17 | jroll | no records in nova_cell0.services O_o | |
| 20:54:34 | melwitt | must be in a different db then, I don't know where to expect it | |
| 20:55:13 | melwitt | oh, maybe just nova? | |
| 20:55:20 | jroll | 16 in nova yeah | |
| 20:55:25 | melwitt | the non-compute service records are all together. okay | |
| 20:55:56 | jroll | bah, dogs need to go out, bbiab | |
| 20:56:02 | melwitt | k | |
| 20:56:39 | melwitt | so you should be in here https://github.com/openstack/nova/blob/stable/ocata/nova/compute/api.py#L2322-L2347 | |
| 21:00:25 | melwitt | oh, wait, it never even gets there. uuugggh | |
| 21:00:56 | melwitt | this is trying to look up the instance long before instance mappings are even begun to be examined | |
| 21:03:55 | jroll | the "bad" one does get that far | |
| 21:04:31 | jroll | but can't tell on the "good" one since there's no traceback or anything on the 404 | |
| 21:05:28 | jroll | I need to take off shortly, can write up something in launchpad for now? | |
| 21:05:34 | jroll | almost seems like two separate bugs | |
| 21:06:02 | melwitt | yes, that would be helpful. thanks. I'll comment there on the bug | |
| 21:06:39 | jroll | ok, I'll make two reports | |
| 21:09:27 | jroll | oh I'm an idiot, that "good" one is deleted, I'm sorry | |
| 21:09:39 | melwitt | oh, heh. that's okay | |
| 21:10:56 | melwitt | the one I'm looking at is the one in your original paste. tracing through to get straight what is happening on that one | |
| 21:11:16 | jroll | ok :) | |
| 21:11:27 | jroll | I'm just going to reopen https://bugs.launchpad.net/nova/+bug/1749167, looks to be the same | |
| 21:11:28 | openstack | Launchpad bug 1749167 in OpenStack Compute (nova) "nova show can not get an instance information, and this instance can be queried from nova list." [Undecided,Expired] | |
| 21:12:51 | melwitt | is it? this bug says they can see the instance with 'nova list' but can't delete it | |
| 21:13:05 | melwitt | your paste shows a failure to 'nova list' at all | |
| 21:16:18 | jroll | oh, good point | |
| 21:16:24 | jroll | ok, I'll open anew | |
| 21:19:56 | melwitt | if the 'nova list' involves deleted instances too, then the bug you linked earlier about lazy-load read_deleted="yes" may well fix your problem | |
| 21:20:39 | melwitt | I guess that would only make sense if you did 'nova list --deleted' | |
| 21:21:01 | jroll | https://bugs.launchpad.net/nova/+bug/1775934 | |
| 21:21:02 | openstack | Launchpad bug 1775934 in OpenStack Compute (nova) "Cannot run "openstack server list" with instance stuck in scheduling state" [Undecided,New] | |
| 21:21:05 | jroll | yeah, this isn't with deleted | |
| 21:21:31 | jroll | writing that I now understand why bauzus was trying to figure out how it got in that state | |
| 21:21:31 | melwitt | k, thanks | |
| 21:21:42 | jroll | I guess we probably don't expect it to work with an invalid cell mapping | |
| 21:22:07 | melwitt | well, if there's an invalid cell_mapping, it's supposed to use the data from nova_api.build_requests | |
| 21:23:04 | melwitt | rather, if InstanceMapping.cell_id=NULL it should be using nova_api.build_requests and using that to list and not failing | |
| 21:23:17 | jroll | well, that's an empty table :/ | |
| 21:23:39 | melwitt | build_requests is empty? | |
| 21:23:57 | jroll | yep | |
| 21:24:17 | melwitt | huh. that is weird | |
| 21:24:23 | jroll | indeed | |
| 21:24:38 | mriedem | pretty sure it doesn't work that way | |
| 21:24:46 | mriedem | this is the same thing surya was talking about on wednesday | |
| 21:24:56 | mriedem | we look for a build request and if not there, we look for an instance mapping with a cell | |
| 21:25:17 | mriedem | if the build request is gone, the instance mapping should have a cell mapping because we delete the build request after updating the instance mapping | |
| 21:25:36 | melwitt | this shows if mapped, we look in the cell db, else we look at build requests https://github.com/openstack/nova/blob/stable/ocata/nova/compute/api.py#L2322-L2347 | |
| 21:25:40 | mriedem | https://bugs.launchpad.net/nova/+bug/1773945 | |
| 21:25:41 | openstack | Launchpad bug 1773945 in OpenStack Compute (nova) "nova client servers.list crashes with bad marker" [Medium,Triaged] - Assigned to Surya Seetharaman (tssurya) | |
| 21:26:12 | mriedem | ok, but could be hitting ^ | |