Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2017-02-02
18:57:03 mriedem in a bunch of the tempest tests
18:57:47 mriedem it looks like it's waiting for the server to be active, it's gone
18:58:01 amoralej EmilienM, dansmith, reported in https://bugs.launchpad.net/nova/+bug/1661360
18:58:01 openstack Launchpad bug 1661360 in OpenStack Compute (nova) "tempest test fails with "Instance not found" error" [Undecided,New]
18:58:04 jroll johnthetubaguy: there's an experimental job for resource class stuff, so I was going to abandon https://review.openstack.org/#/c/426296/
18:58:11 jroll johnthetubaguy: but can keep it around if you rather
18:58:42 mriedem EmilienM: i can put up a debug patch if you guys can depend on it
18:58:48 amoralej mriedem, i've reproduced locally, nova server returns "instance not found" but it's found in "nova list" command
18:59:04 mriedem amoralej: that's probably a race between when we have a build request and the actual instance,
18:59:07 mriedem the api returns either
18:59:15 mriedem since they both represent a server at different stages of the lifecycle
18:59:22 EmilienM mriedem: yes I can
18:59:29 EmilienM mriedem: you can run check experimental
19:00:48 dansmith mriedem: what race?
19:01:02 melwitt mriedem: isn't that issue fixed by https://review.openstack.org/#/c/427775 this morning?
19:01:22 dansmith melwitt: there's no delete going on here, which is what ^ is for right?
19:01:31 melwitt oh. yeah the above is for delete
19:04:08 openstackgerrit Matt Riedemann proposed openstack/nova master: WIP: debugging for instance not found in tripleo https://review.openstack.org/428360
19:04:09 mriedem EmilienM: amoralej: ^
19:04:42 cdent edleafe: do you recall if this allocation checking is happening anywhere else because this seems important but is stuck behind something else: https://review.openstack.org/#/c/416752/
19:05:07 mriedem melwitt: dansmith: even with my fix,
19:05:31 mriedem couldn't we have a window of time where the build request exists, the instance exists, but the instance mapping doesn't?
19:05:44 dansmith mriedem: sure, but then we return the buildrequest, that's the point
19:05:53 dansmith mriedem: in their logs, I do not see "Found 1 cells"
19:05:54 edleafe cdent: it's not really "stuck"; just hasn't gotten core attention
19:06:35 dansmith mriedem: I wonder if it's the change from melwitt that skips looking in all cells -- maybe incorrectly following that path?
19:06:39 cdent edleafe: what I meant was that fix is +W and something we ought to release, but the other thing less so
19:06:41 mriedem dansmith: so maybe it hits a window when the api code sees there is no instance mapping, but then by the time it pulls the build request, that's gone
19:06:44 edleafe but yeah, it's not technically dependent on the one below it
19:06:56 mriedem that would be tight
19:07:01 dansmith mriedem: the api isn't even looking at the cells, though
19:07:17 melwitt that's only if CONF.cells.enable is True though
19:07:19 edleafe cdent: the other thing is as important
19:07:24 dansmith melwitt: I know, but
19:07:31 edleafe the create() method allows all sorts of bad stuff in
19:07:34 EmilienM mriedem: "check experimental" and we'll see what happens
19:07:46 amoralej I'm testing locally
19:07:49 dansmith melwitt: where is this in their log? https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2518
19:08:40 cdent edleafe: but it's not wired into the api is it? that's what I'm trying to get at. the patch above prevents the api being used badly, the patch below removes something that was never exposed
19:08:48 dansmith cells.enable=False in their startup dump
19:09:18 melwitt hm
19:09:29 dansmith melwitt: see what I mean though?
19:09:36 melwitt yeah
19:10:05 dansmith compare to a devstack run: http://logs.openstack.org/03/427903/1/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/fb34df9/logs/screen-n-api.txt.gz#_2017-02-01_21_00_47_552
19:10:24 edleafe cdent: true
19:10:36 edleafe cdent: but rebasing on master will lose the +W
19:10:49 dansmith now it's possible that they have never had it right, and removing those pre-cellsv2 short circuits are why they're failing now, but that's exactly why those have to be gone
19:10:50 melwitt dansmith: I'm also wondering about your change that changed the fallbacks into raises of InstanceNotFound
19:10:51 cdent edleafe: so the question is: how much of a bug is it that it is possible to write negative allocations?
19:11:11 dansmith melwitt: right, that's what I just mentioned, but we *have* to remove those else we'll paper over not having things
19:11:21 melwitt yeah
19:11:29 edleafe cdent: negative not so much. Zero allocations was the issue
19:11:36 cdent edleafe: by "tries it", I mean "will they get all the way through"
19:12:37 cdent if they get through, that seems a fair risk
19:13:57 mriedem dansmith: i'll throw this into the get instance flow in my debug patch https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2515-L2522
19:14:06 melwitt dansmith: the 'Found cells' message is only for the get_all so that's why we're not seeing it I think. they're seeing a fail on a get of a single instance and said they see it in the list of all instances if they do a 'nova list'
19:14:16 mriedem right
19:14:20 dansmith melwitt: which is a get all
19:14:20 mriedem so i'll throw that into the debug patch
19:14:32 mriedem the test is failing on a single GET
19:14:33 mriedem not list
19:14:34 melwitt dansmith: yeah, it shows up in get_all but not in get
19:14:40 mriedem that's why we don't see it
19:14:44 melwitt is the problem they described
19:14:47 melwitt yeah
19:14:49 dansmith melwitt: I know, but they've done at least one get_all by that point right?
19:14:49 mriedem but, we should see it in the logs somewhere,
19:14:53 mriedem because tempest will list instances at some point
19:14:56 dansmith right
19:15:09 melwitt hm
19:16:30 melwitt it's possible it didn't yet, but let me see if I can locate a list all in the log
19:17:00 dansmith am I missing where our requests are logged in n-api log?
19:17:49 melwitt I'm not seeing it them yet. this doesn't look usual to me
19:18:06 dansmith melwitt: http://logs.openstack.org/15/424915/8/check/gate-puppet-openstack-integration-4-scenario001-tempest-centos-7/b29f35b/logs/tempest.txt.gz#_2017-02-02_12_53_52_735
19:18:13 dansmith melwitt: yeah, something seems wrong about it
19:18:21 dansmith melwitt: but the above should have triggered a list all right?
19:18:29 jaypipes johnthetubaguy: +2
19:18:55 melwitt dansmith: no, I think that's a create. it will return the one instance, or the first instance if it's a multi create
19:19:08 melwitt that's a POST
19:19:13 dansmith oh you're right
19:19:56 openstackgerrit Ed Leafe proposed openstack/nova master: Delete a compute node's resource provider when node is deleted https://review.openstack.org/428375
19:20:03 edleafe jaypipes: cdent: ^^ please review
19:20:16 cdent edleafe: yessir
19:20:24 mriedem there is no "200 GET https://[::1]:8774/v2.1/servers" in that log
19:20:49 dansmith how is that possible
19:21:08 melwitt this is very odd
19:22:32 dansmith mriedem: so your race...
19:22:48 dansmith mriedem: we look up the map, if we fail, we look up the buildreq, if that fails we re-check for the map
19:23:25 dansmith by the time we've deleted the buildreq, we've finished up the instance map and saved it
19:23:31 dansmith so I don't see that there is any window there
19:23:33 openstackgerrit Matt Riedemann proposed openstack/nova master: WIP: debugging for instance not found in tripleo https://review.openstack.org/428360
19:23:54 dansmith are you thinking of a different place?
19:23:55 mriedem dansmith: i was thinking it's like this
19:24:03 mriedem 1. https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2271 we don't have an instance mappingyet
19:24:23 mriedem well, shit that's it
19:24:46 mriedem if there is no instance mapping, that doesn't lookup the build req
19:24:48 mriedem at all, right?
19:25:09 mriedem the conditionals in there are only caring if there is an instance mapping AND it has a cell mapping
19:25:09 dansmith but we create the instance map early
19:25:12 melwitt uh oh, looks tha tway

Earlier   Later