| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-07-27 | |||
| 22:06:37 | mriedem | "locally" deleting the instance will automatically delete the tags and bdms along with the instance from the cell | |
| 22:06:39 | melwitt | I'm trying to think, why didn't we move the instance mapping update earlier last time? | |
| 22:07:01 | melwitt | yeah, that's what I'm getting from it too, merge the loops and check quota at the end | |
| 22:07:52 | mriedem | idk, my guess is tunnel vision on the fix at hand | |
| 22:10:05 | melwitt | wait, that change (last year) *did* move the inst mapping update earlier to right after the instance.create(). looking to see what happened to that | |
| 22:14:36 | mriedem | but only if the quota check failed | |
| 22:14:46 | mriedem | b/c we exit after that | |
| 22:15:07 | mriedem | we don't bury in cell0 if quota check fails because the instances are already created in cells at that point | |
| 22:16:03 | melwitt | I mean this, this is showing an update of the instance mapping right after we create the instance record https://review.openstack.org/#/c/501408/2/nova/conductor/manager.py@1003 | |
| 22:17:01 | mriedem | oh right yewah | |
| 22:17:03 | mriedem | *yeah | |
| 22:17:05 | melwitt | but in the current version of the code, the instance mapping update isn't right after the instance create anymore | |
| 22:17:19 | melwitt | and I can't find how that changed, looking at git blame and failing | |
| 22:17:27 | mriedem | _populate_instance_mapping was only ever used in the cellsv1 path | |
| 22:17:30 | mriedem | the build_instances method | |
| 22:17:33 | mriedem | i'm pretty sure | |
| 22:17:48 | melwitt | but in that old patch, it's in schedule_and_build_instances | |
| 22:19:16 | mriedem | because mnaser was re-using it | |
| 22:19:43 | mriedem | you mean why did we talk him out of that? | |
| 22:20:42 | melwitt | no I mean, as of that patch, the instance mapping update was right after instance create, but the current code has the mapping update much later, and I was wondering why that was moved. I assume it was to fix some other bug or something | |
| 22:21:01 | mriedem | looks like it was changed as a result of the irc convo | |
| 22:21:31 | melwitt | oh gaaaahhh, I didn't realize I was looking at an earlier PS | |
| 22:24:39 | melwitt | okay so the final version only added a mapping update to the cleanup method, like you said earlier I think. so the normal path for updating the mapping was always later on | |
| 22:25:35 | melwitt | ok | |
| 22:27:31 | mriedem | yup. alright gotta run. o/ | |
| 22:27:36 | melwitt | o/ | |
| 23:27:02 | openstackgerrit | Merged openstack/nova master: Use source vifs when unplugging on source during post live migrate https://review.openstack.org/586402 | |
| 23:27:09 | openstackgerrit | Merged openstack/nova master: Pass source vifs to driver.cleanup in _post_live_migration https://review.openstack.org/586568 | |
| 23:27:18 | openstackgerrit | Merged openstack/nova master: Update queued-for-delete from the ComputeAPI during deletion/restoration https://review.openstack.org/566813 | |
| 23:30:18 | melwitt | finally \o/ | |
| 23:49:23 | mnaser | well i know its late | |
| 23:49:29 | mnaser | but now even another whole interesting failure | |
| 23:49:39 | mnaser | no record in nova_api but one in the cell | |
| 23:49:40 | mnaser | lol | |
| 23:54:59 | melwitt | mnaser: no build request or instance mapping? | |
| 23:55:30 | mnaser | melwitt: build request, no instance mapping | |
| 23:55:53 | mnaser | wait sorry | |
| 23:55:57 | mnaser | it doesnt exist in the cell, sorry | |
| 23:56:00 | melwitt | build request, instance in cell, no instance mapping | |
| 23:56:02 | melwitt | build request only? | |
| 23:56:04 | mnaser | yes | |
| 23:56:08 | mnaser | build request only | |
| 23:56:14 | melwitt | that's the exact same thing rdo cloud ran into | |
| 23:56:30 | mnaser | so shows up in list but not deletable etc | |
| 23:56:34 | melwitt | right | |
| 23:56:45 | mnaser | i guess i can just delete the build request and have it disappear? | |
| 23:56:50 | melwitt | do you have several or just a few? like does it happen a lot? | |
| 23:57:01 | melwitt | yes, that's what I told rdo cloud to do too | |
| 23:57:11 | mnaser | i mean after running my fixup script, i still had a few instances that were stuck BUILD/scheduling | |
| 23:57:38 | melwitt | I dug around in the code and didn't see a way it can happen other than nova-api going down at the precise moment between the build_request.create() and the instance_mapping.create() or the instance_mapping.create() somehow failing | |
| 23:57:58 | mnaser | so for context it is possible that rpc and/or db both had issues at the time | |
| 23:58:05 | mnaser | does the build request and instance_mapping get created at the same time or? | |
| 23:58:08 | melwitt | which seems it would be crazy rare ... so maybe we're missing some other way it could happen | |
| 23:58:15 | melwitt | pretty much yeah. let me grab a link | |
| 23:58:49 | melwitt | https://github.com/openstack/nova/blob/3e0b17b1e138615b66293976ca5b55c291957844/nova/compute/api.py#L930-L942 | |
| 23:59:15 | melwitt | yeah, soon you can come fix all these bugs | |
| 23:59:18 | mnaser | ok that's interesting | |
| 23:59:18 | mnaser | haha | |
| 23:59:59 | mnaser | so build request was created, instance mapping was *not* created. unless there was an attempt to delete the instance while it was still in build request | |
| #openstack-nova - 2018-07-28 | |||
| 00:00:05 | melwitt | yeah so, just wonder if there's some bizarre way a delete could miss the build request, similar to what mriedem was saying earlier for the bug we discussed earlier | |
| 00:00:34 | mnaser | i might be like 5 steps behind your discussion so i might just be echoing stuff y'all already discusssed :p | |
| 00:00:48 | melwitt | nah | |
| 00:01:14 | melwitt | it's more likely that somehow a delete was partial | |
| 00:01:31 | melwitt | but I didn't find how last time I went spelunking in the code | |
| 00:02:17 | melwitt | (the nah was, no, you're not echoing) | |
| 00:02:22 | mnaser | :p | |
| 00:02:42 | mnaser | im looking in nova/conductor/manager.py on how ending up with a build request but without instance_mapping | |
| 00:08:16 | melwitt | build request is deleted once scheduled, so that means it had to be during the create process somewhere. ignore what I was saying about delete (unless it's a delete while booting? but I didn't see a way there either) | |
| 00:12:43 | mnaser | melwitt: does instance.delete() get rid of the mapping? | |
| 00:12:46 | mnaser | or does the mapping stay forever | |
| 00:13:06 | melwitt | mapping stays until you 'nova-manage db archive_deleted_rows' | |
| 00:13:20 | mnaser | and we dont do that | |
| 00:13:20 | mnaser | hmm | |
| 00:13:23 | melwitt | as of rocky, I believe | |
| 00:13:40 | mnaser | cause i went through the code and i couldn't find any instances where the instance mapping doesnt get deleted *after* the build request | |
| 00:13:49 | mnaser | in nova/compute/api.py and nova/conductor/manager.py | |
| 00:13:53 | mnaser | not sure if there is any other places to look | |
| 00:13:53 | melwitt | yeah, same | |
| 00:17:07 | mnaser | it would be good to know if the InstanceMapping was created and deleted or just never created in the first place | |
| 00:17:11 | mnaser | dont think there is an easy way to know that | |
| 00:17:14 | mnaser | let me try to look at logs | |
| 00:25:39 | mnaser | melwitt: looks like a db server issue just a few seconds after the build request was created | |
| 00:26:04 | melwitt | interesting. so possible that the instance mapping INSERT failed? | |
| 00:26:20 | mnaser | let me look at the stack traces of the failures | |
| 00:26:21 | melwitt | I mean, if it's really a few seconds, that would be too long after | |
| 00:26:26 | mnaser | hopefully it shows where | |
| 00:27:59 | mnaser | melwitt: AHA | |
| 00:28:06 | mnaser | stacktrace in db fail | |
| 00:28:06 | mnaser | inst_mapping.create() | |
| 00:28:12 | melwitt | holy crap | |
| 00:28:24 | mnaser | and looks like in the exception handling | |
| 00:28:27 | mnaser | it does self._cleanup_build_artifacts(None, instances_to_build) | |
| 00:28:58 | mnaser | so if a create failed, we do _cleanup_build_artifacts but maybe we need to make sure that we assume things don't exist in _cleanup_build_artifacts | |
| 00:29:02 | melwitt | and that *didn't* delete the build request? another db trace? | |
| 00:29:07 | melwitt | we do | |
| 00:29:17 | mnaser | well i assume the exception handling failed too | |
| 00:29:21 | mnaser | because the db was out | |
| 00:29:26 | melwitt | oh, yeah ok | |
| 00:29:28 | mnaser | let me share the stack trace | |
| 00:30:08 | mnaser | http://paste.openstack.org/show/726772/ | |