Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-09-20
17:44:02 mriedem yeah _nil_out_instance_obj_host_and_node should also null out launched_on
17:44:35 mriedem anyway, that doesn't explain why the instance is also in cell0
17:44:40 mnaser yeah that explains half the story i guess
17:44:45 mriedem mnaser: which copy of the instance has launched_on set?
17:44:46 mriedem cell1?
17:44:51 mnaser yeah
17:45:07 mriedem and that compute host that launched_on is set to, the host_mapping in the api db is pointing at cell1?
17:45:27 mnaser yeah the one is cell1 is correct
17:46:04 mnaser good question about host_mapping
17:46:11 mriedem does the name of the instance have an index-like suffix on it, i.e. was it part of a multi-create request?
17:46:27 mriedem e.g. my-vm-1, my-vm-2 etc
17:46:42 mnaser its not a multicreate request (afaik) but the title looks like it is
17:47:02 mnaser centos-7-large-tf-ci-0000006321
17:47:04 mnaser a zuul instance though
17:47:19 mriedem oh that's not the kind of index i'd be looking for
17:47:21 mriedem simple integers
17:47:31 mnaser yeah
17:47:41 mnaser i was just wondering in case nova had some logic to match <name>-<number>
17:47:45 mnaser but i didn't think we'd be that wild :)
17:48:32 mriedem i don't know how this could happen, unless some kind of weird rabbit thing where like we actually got 2 copies of the same build request message to conductor, one went to cell1 and one failed scheduling and went to cell0 or something
17:48:34 mnaser yeah host_mappings is the right one
17:49:07 mnaser yeah im pretty confused..
17:49:20 dansmith that sounds pretty fantastical
17:49:34 dansmith especially without other MAJOR problems showing up all over the place
17:49:43 mriedem btw the request_specs.num_instances field for the instance would tell you if it was a multi-create request
17:50:33 mriedem each instance in a multi-create request gets a unique id but i've seen some weird things with multi-create requests that blow up the scheduler and trigger automatic retries to the scheduler
17:50:37 mriedem we removed that in stein though i think
17:51:26 mriedem this thing https://github.com/openstack/nova/blob/stable/queens/nova/scheduler/utils.py#L807
17:51:54 mnaser i mean, given the instance failed to deploy because of a timeout
17:52:08 mnaser there may be other weird things happening
17:52:13 mriedem well the timeout was likely a failure on the ovs agent
17:52:21 mnaser i .. don't know how it can result in something like scheduling it twice though
17:52:21 mriedem causing vif plugging to fail
17:53:27 dansmith if the failure was vif plugging, we should be well-settled on the destination host and in the right cell
17:53:36 dansmith way way way away from anything that would re-create it in cell0
17:54:34 mnaser yeah thats why i think the only place it could have happened is scheduled twice
17:59:02 mriedem mnaser: do you see instance actions for that instance in both dbs?
17:59:09 mnaser oh good idea
17:59:12 mriedem and if so, are there any differences in the events?
17:59:18 mriedem the instance_action_events tables i mean
17:59:21 mriedem *table
18:00:04 mriedem i'm not sure we actually have instance action events until we have picked a cell though
18:00:29 mnaser theres no column for instance in instance_actions_events or am i losing it?
18:00:31 mriedem yeah we create the action once we've picked a cell https://github.com/openstack/nova/blob/stable/stein/nova/conductor/manager.py#L1483
18:00:42 mriedem mnaser: instance -> instance_actions -> instance_action_events
18:00:48 mnaser ohhhh okay
18:01:03 mriedem *instance_actions_events
18:01:35 mnaser create in cell1, nothing in cell0
18:01:58 mnaser compute__do_build_and_run_instance in actions
18:01:59 mriedem yeah i guess that's what i'd expect since bury in cell0 before creating the "create" action
18:02:26 mnaser so the only thing is somehow it got scheduled .. twice?
18:02:37 mnaser one said "nope" and the other said "yep"
18:02:46 mriedem idk how that could happen
18:02:49 mnaser probably because a db exception error for some constraint
18:02:54 mnaser i mean at this point i'm convinced it might be an infra thing
18:03:11 mnaser again the VM failed to provision because port plugging timed out so that does hint at things likely being weird
18:03:14 mriedem well that's why i brought up rabbit
18:03:45 mnaser and not an issue in galera, yeah, it would be rabbit issue surely
18:03:47 mriedem e.g. is it possible that rabbit thought the message to conductor (or scheduler) wasn't received and resent it?
18:04:08 mnaser i guess that is the most likely theory
18:04:14 dansmith I don't think so
18:04:17 mriedem pre-cells v2 we wouldn't have a problem b/c instances.uuid is unique per cell db
18:04:32 mnaser unless rabbit thought the cluster was split or something
18:04:50 dansmith I think that when you enqueue a message, it goes into a queue for a given receiver, if there is one waiting
18:04:55 mriedem do you have rabbit logs going back to when that instance was created?
18:04:56 dansmith but yeah, rabbit split brain could have done something I guess
18:05:27 dansmith mriedem: what if, in bury_in_cell0, we check last minute to see if there's already a host mapping and if so, we log and abort?
18:05:37 dansmith I mean, I would think that's where we fail in that routine anyway,
18:05:50 dansmith so there should be some log fallout from us failing to create the cell0 mapping anyway right?
18:06:03 mriedem is this one of the many reasons people say to not cluster rabbit?
18:06:07 mriedem beyond performance?
18:06:27 mnaser rabbitmq is the worlds biggest pita :(
18:07:55 mnaser ok so at least to clean things up i will update the instance_mappings to point that the right cell
18:08:01 mnaser and then at least the instance will be delete-able
18:08:12 mnaser and then the cell0 will just get archived and disappear
18:08:52 mriedem dansmith: i'm not sure what you mean by "already a host mapping" in bury_in_cell0
18:09:09 dansmith mriedem: when we bury in cell0, we also have to create a mapping for it to be there
18:09:22 dansmith mriedem: we should fail to do that if we're late to the party because we're a failed reschedule right?
18:09:37 mnaser hmm yeah, that's true, i guess the bury doesn't check if there's an existing one there
18:09:43 mriedem dansmith: so here https://github.com/openstack/nova/blob/stable/stein/nova/conductor/manager.py#L1282 ?
18:09:52 mriedem before doing that, double check that instance_mapping.cell_mapping is None, right?
18:11:03 mriedem i mean we'd want to check way before that though, before this https://github.com/openstack/nova/blob/stable/stein/nova/conductor/manager.py#L1260
18:11:41 mriedem i'm not opposed to adding a sanity check
18:11:48 mriedem worst case is it doesn't hurt anything,
18:11:58 mriedem best case is it avoids crazy rabbit clustering split brain weirdness
18:12:10 dansmith mriedem: well, I'm thinking more like direct hit the database to make sure
18:12:21 dansmith mriedem: but again, we should fail to create a duplicate mapping there
18:13:10 mnaser is this just a matter of `if inst_mapping.cell_mapping is not None:` before updating it?
18:14:22 dansmith no
18:19:52 dansmith mriedem: oh, hmm
18:20:02 dansmith mriedem: we look up the mapping and set it to cell0 there and then save, not a create
18:20:05 dansmith that's why no dupe
18:20:21 dansmith so maybe the cell0 save happens first and then the cell1 one comes in later?
18:20:31 dansmith so, mnaser maybe yes to your above question
18:20:44 dansmith I was forgetting how this worked, that we create the mapping early and then update it later
18:21:34 mriedem mnaser: yes that's what i was thinking
18:21:37 mriedem dansmith: the create happens in the api
18:21:45 mriedem atomically with the build request and request spec
18:21:55 mriedem yeah that (sorry was catching up)
18:22:36 mriedem mnaser: so i'd move the code that gets the instance mapping earlier before we create the instance record in cell0, check if instance_mapping.cell_mapping is not None and if not log an error or something and return

Earlier   Later