Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2017-09-20
17:12:59 edleafe cdent: yes, that's the one
17:13:04 cdent thanks
17:13:33 openstackgerrit Merged openstack/nova master: [placement] Unregister the ResourceProviderList object https://review.openstack.org/502162
17:14:04 openstackgerrit Merged openstack/nova master: [placement] Unregister the ResourceProvider object https://review.openstack.org/502163
17:16:50 openstackgerrit Merged openstack/nova master: [placement] Removing versioning from resource_provider objects https://review.openstack.org/502164
17:19:32 tasker mriedem: the only entry in the nova-conductor is a reply from the scheduler saying "no valid host was found". the scheduler shows "host [u'compute-2'] fails" but doesn't explain _why_ it failed. and the computes have no record or log of the request because it never gets past the scheduler.
17:21:23 mriedem tasker: the scheduler will dump the filter it failed on
17:21:30 mriedem i'd have to see if that's logged at info or debug
17:21:40 melwitt tasker: was the target host removed by a scheduler filter or are you saying the request was sent to the target compute host and then failed there?
17:22:30 melwitt if the former, the debug logs should show which filter removed the host from consideration. if the latter, the nova-compute logs should contain some message about why the request failed
17:22:43 mriedem tasker: you should see something like this at INFO level
17:22:44 mriedem LOG.info(_LI("Filter %s returned 0 hosts"), cls_name)
17:22:52 mriedem so for that request, figure out which filter kicked it out
17:23:52 mriedem you should also see something like, "Filtering removed all hosts for the request with"
17:24:00 mriedem if you have INFO level logging enabled
17:24:07 tasker Filter results: ['RetryFilter: (start: 1, end: 0)']
17:24:30 tasker ok .. after your explanation, that line makes sense.
17:25:14 melwitt it sounds like the request landed on a compute host and then failed and came back to the scheduler to retry a different host, and then it failed with NoValidHost
17:25:41 mriedem i don't think live migration actually does a retry from the compute
17:25:49 mriedem conductor will retry if the pre-migration checks on the chosen target host fail
17:26:05 mriedem we only retry from compute -> conductor for (1) initial create and (2) cold migrate/resize
17:26:56 mriedem this is where conductor is asking the scheduler for a host during live migrate https://github.com/openstack/nova/blob/master/nova/conductor/tasks/live_migrate.py#L274
17:27:01 tasker other migrations succeed.
17:27:04 tasker just not this one.
17:28:12 melwitt there should be some message about the request in the compute log. if filtering didn't remove the target host, then it must have gone to the host and then failed
17:28:17 tasker on a successful migrtion, RetryFilter returns 1 host.
17:29:15 mriedem tasker: how many hosts do you have? does the instance have anything special about it, like pci requests or numa affinity?
17:29:36 tasker on the instance that fails to live-migrate there is no log on the target host. filtering removes _all_ targets regardless of which host I send it to.
17:29:52 melwitt RetryFilter removes previously tried hosts from consideration. so if it removes anything, that means it already tried to run it on the host it selected last time
17:29:54 tasker 3; no. it and all other instances were built to the same requirements.
17:30:33 tasker melwitt: does that have a memory? or is each migration request independent of the previous?
17:30:43 melwitt each request is independent
17:31:30 tasker the only thing different is that this instance was built while the cluster was at M. now my cluster is at N.
17:32:06 melwitt I would grep for the request-id of the failing live migration request in nova-conductor and nova-compute logs and see if there's anything about it
17:32:31 tasker I am live watching all the logs.
17:32:46 tasker conductor says "no valid host" because that's what scheduler says.
17:32:53 mriedem i'm wondering if the retry filter shouldn't be ignored here...
17:33:16 tasker if i send another instance to the same target, retryfilter passes the host.
17:33:42 melwitt RetryFilter removing a host implies that it tried to run the pre-migration on a host already
17:34:01 melwitt so something is weird here
17:34:21 tasker nothing logged at the compute at INFO or lower.
17:34:25 mriedem i'm wondering if the original instance request spec has retries set on it, and that's goofing up the retry filter during live migration
17:34:55 tasker something I could see in the database?
17:35:30 mriedem yeah, you should be able to pull the serialized json request spec out of the db
17:36:04 mriedem select spec from nova_api.request_specs where instance_uuid=xyz;
17:36:34 mriedem melwitt: this is where we get the request spec during live migration https://github.com/openstack/nova/blob/master/nova/conductor/tasks/live_migrate.py#L227
17:36:40 mriedem we don't set a retry attribute on the request spec
17:37:16 mriedem we pass it along from the api if we are able to look it up https://github.com/openstack/nova/blob/master/nova/compute/api.py#L3860
17:37:36 mriedem which would be the original request spec from when we built the instance, which would have retry stuff set on it
17:38:03 mriedem if that wasn't set, we'd ignore it here https://github.com/openstack/nova/blob/master/nova/scheduler/filters/retry_filter.py#L31
17:38:42 mriedem which, this is all kinds of weird because the conductor task is handling it's own retry logic https://github.com/openstack/nova/blob/master/nova/conductor/tasks/live_migrate.py#L344
17:38:53 mriedem which tells me, when doing a live migration, we don't want to even ask the RetryFilter
17:39:01 mriedem bauzas: are you around?
17:39:44 mriedem tasker: if you can get that request spec json blob out of the db, that should tell us if the retry attribute is set and what hosts and how many times it's been retried during the initial build
17:41:43 tasker mriedem: yes, "retry" is set and is populated with both hypervisors that I'm trying to send it to.
17:42:16 tasker would you like to see it?
17:42:43 mriedem sure, throw it in a paste
17:46:32 mriedem i think this would actually fix the problem http://paste.openstack.org/show/621556/
17:46:40 melwitt mriedem: so the first time you build an instance, if it fails host X, it will save that to the RequestSpec so host X will never be tried again ever? I didn't know it persisted something like that
17:46:47 mriedem oops one issue there
17:47:00 tasker http://paste.openstack.org/show/621557/
17:47:09 mriedem melwitt: yeah
17:48:54 mriedem melwitt: i think this https://github.com/openstack/nova/blob/master/nova/conductor/manager.py#L583
17:49:05 mriedem conductor build_instances is called from compute on a reschedule
17:49:14 melwitt well, I learned a thing. I had thought retries were a locally tracked thing per request
17:49:14 mriedem and will put the chosen host in the retry object's list of hosts it's tried
17:49:28 mriedem request spec is the persisted object that keeps on giving
17:49:32 mriedem even when you don't want the gift
17:49:59 mriedem so i think this is the fix http://paste.openstack.org/show/621558/
17:50:16 melwitt yeah. I wouldn't have chosen to track retries _forever_. I thought RequestSpec would only contain the original request requirements so they could be honored in the future
17:50:17 mriedem just like how we don't want the original forced host/node during live migration, we don't want the original retry hosts either probably
17:51:45 tasker mriedem: I'm going to try your patch out.
17:52:01 mriedem tasker: yeah so the request spec had 2 original attempts, on compute-3.openstack.local and compute-2.openstack.local
17:52:11 tasker both targets I'm trying to send it to.
17:52:16 mriedem ok
17:52:30 mriedem and that's why this fails https://github.com/openstack/nova/blob/master/nova/scheduler/filters/retry_filter.py#L44
17:52:36 tasker which part of nova would I apply that to? compute, conductor, or scheduler?
17:52:50 mriedem conductor, but note, that diff is against master branch code
17:53:20 tasker let me see if I can adapt to the branch that I'm using.
17:54:09 mriedem http://paste.openstack.org/show/621559/ is latest stable/newton
17:55:12 tasker cool, thanks. I'm going to step out for some "fresh air" and then apply this.
17:55:19 mriedem it does stand to reason that if this instance failed to build originally on those 2 hosts, that live migrating it there might fail too...but we don't know why it originally failed, could have been a resource claim issue at the time
17:55:36 tasker that's a fair observation.
17:57:56 melwitt yeah, often it's a failed claim. and also what if that compute host is eventually replaced over the lifetime of the cluster, making it a fresh candidate for several instances that might still avoid it because they once failed to build there back when it was a different machine
18:06:45 tasker live migration successful
18:08:17 tasker mriedem and melwitt -- thank you so much for helping to figure out what was wrong.
18:11:01 mriedem nice
18:11:07 mriedem tasker: want to open a bug? i have a fix with the test locally
18:11:40 tasker sure. let me collect my notes.
18:12:31 cdent dansmith: responded to some of your comments on https://review.openstack.org/#/c/500410/ . you semi-accidentally identified a separate problem. The nullable thing I’m not quite sure how to proceed, depending on what we want to do.
18:14:56 mriedem cdent: congratulations, you have the first complete blueprint in queens https://blueprints.launchpad.net/nova/+spec/placement-deregister-objects
18:15:35 dansmith cdent: replied, I don't think there's an issue.. just make those not nullable and (separately) always set them and I think we're good
18:24:25 cdent dansmith: except that they are only ever used on input, never output, so why bother reading them?
18:25:01 tasker mriedem: https://bugs.launchpad.net/nova/+bug/1718512
18:25:02 openstack Launchpad bug 1718512 in OpenStack Compute (nova) "migration fails if instance build failed on destination host" [Undecided,New]
18:25:07 mriedem thanks
18:25:19 dansmith cdent: because it's (effectively) free, it makes the object consistent
18:25:26 tasker I hope that summary / description is clear enough.
18:28:40 cdent dansmith: okay, I’m happy to do that. I’m not sure why consistency matters _now_ but if we’d like it as a general rule, that’s fine.
18:29:48 dansmith cdent: clearly it doesn't have a user now, but we're an abstract model on top of the data store and unless there is a reason not to, we should do that thing, IMHO

Earlier   Later