| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-02-02 | |||
| 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 | mriedem | so i'll throw that into the debug patch | |
| 19:14:20 | dansmith | melwitt: which is a get all | |
| 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 | mriedem | but, we should see it in the logs somewhere, | |
| 19:14:49 | dansmith | melwitt: I know, but they've done at least one get_all by that point right? | |
| 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 | dansmith | but we create the instance map early | |
| 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:12 | melwitt | uh oh, looks tha tway | |
| 19:25:16 | dansmith | lemme look | |
| 19:25:28 | mriedem | we create the instance mapping after the instance is created, but before the build request is deleted | |
| 19:25:43 | dansmith | no | |
| 19:25:45 | dansmith | we update it | |
| 19:25:53 | dansmith | we create the instance mapping at almost the same time as the buildreq | |
| 19:26:01 | dansmith | although the buildreq is first by a few python cycles | |
| 19:26:11 | dansmith | this would be nanoseconds of a window | |
| 19:26:15 | mriedem | https://github.com/openstack/nova/blob/master/nova/compute/api.py#L997 | |
| 19:26:15 | mriedem | oh right | |
| 19:26:21 | mriedem | https://github.com/openstack/nova/blob/master/nova/compute/api.py#L1010 | |
| 19:26:27 | dansmith | picoseconds even | |
| 19:26:33 | dansmith | yeah | |
| 19:26:52 | mriedem | i thought you just started making up small time units now | |
| 19:26:59 | mriedem | danoseconds | |
| 19:27:00 | dansmith | femtoseconds | |
| 19:27:12 | melwitt | smithoseconds | |
| 19:27:19 | mriedem | only Vek can say femto-anything | |
| 19:27:21 | dansmith | mriedem: so I can swap the order of those in a test patch to run experimental on, but I'm highly dubious | |
| 19:27:35 | dansmith | mriedem: Vek gave me the femtotorch | |
| 19:27:49 | mriedem | ha | |
| 19:27:57 | dansmith | it was a small and quick handoff | |
| 19:28:06 | mriedem | how appropriate | |
| 19:28:07 | melwitt | /facepalm | |
| 19:28:19 | mriedem | rimshot? | |
| 19:30:03 | openstackgerrit | Dan Smith proposed openstack/nova master: DNM: Reorder two electrons to see if it fixes a race https://review.openstack.org/428385 | |
| 19:30:24 | melwitt | haha, like that commit message | |
| 19:30:31 | dansmith | so this probably comes from the logic in get_instance needing to be defensive against pre-cellsv2 data, so we could also just rearrange that and probably simplify | |
| 19:54:32 | amoralej | mriedem, dansmith, i've been debugging by printing value of service_version right before https://github.com/openstack/nova/blob/master/nova/compute/api.py#L2268 | |
| 19:54:38 | amoralej | and i'm getting allways 0 | |
| 19:55:06 | amoralej | in fact if y remove the "service_version < 15" part of the if, tempest test passes | |
| 19:55:24 | amoralej | how can i see the versions of each service? | |
| 19:55:37 | amoralej | EmilienM ^ | |
| 19:55:40 | dansmith | amoralej: orly | |
| 19:56:04 | dansmith | amoralej: maybe we're grabbing a cached version of zero before we start computes | |
| 19:56:24 | dansmith | not sure what would have changed around that specific thing recently though | |