| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-10-06 | |||
| 17:47:53 | ronlund | there is no generation id on the consumer allocation | |
| 17:47:56 | andreykurilin | superdan: as expected, your fix works :) | |
| 17:48:03 | jgwentworth | I'm guessing it has something to do with the newer ostestr being stestr underneath and somehow it's messing up the result gathering | |
| 17:48:13 | sean-k-mooney | ya that workflow is fine | |
| 17:48:20 | ronlund | sean-k-mooney: this https://developer.openstack.org/api-ref/placement/#update-allocations | |
| 17:48:25 | superdan | andreykurilin: okay it won't actually work with multiple cells, but I'm polishing off the full fix | |
| 17:48:31 | superdan | andreykurilin: will certainly want you to test that as well | |
| 17:49:41 | andreykurilin | superdan: I do not have multiple cells installation, so will able to test only on regular one | |
| 17:49:47 | superdan | andreykurilin: yep that's fine | |
| 17:50:16 | jgwentworth | .tox/py27/bin/testr last --subunit vs .tox/py27/bin/stestr last --subunit | |
| 17:52:50 | sean-k-mooney | jgwentworth: so on master the tox config for py27 is https://github.com/openstack/nova/blob/master/tox.ini#L33 with stestr and on newton we delegate to pretty tox script | |
| 17:53:26 | leakypipes | bauwser, superdan, ronlund: reading back... just got back in. | |
| 17:53:33 | sean-k-mooney | on pike we use ostestr | |
| 17:56:14 | jgwentworth | sean-k-mooney: yeah, I think we're gonna need mtreinish to look at this. especially now that we know it's not urgent, it's running all the tests, just showing the wrong results in the html page | |
| 17:57:48 | jgwentworth | and if the run fails the unit tests, the os profiler thing won't even run, so I think in a fail case it would show the fail results | |
| 17:57:58 | sean-k-mooney | jgwentworth: looking at stable ocata i think we are overriding the result because we do this https://github.com/openstack/nova/blob/c2aa30b102808882c85d3d3f53d531c4510218cd/tox.ini#L28-L32 | |
| 17:58:39 | leakypipes | bauwser, superdan: https://blueprints.launchpad.net/nova/+spec/de-orm-resource-providers | |
| 17:59:01 | sean-k-mooney | i think we are running all the test first then running the osprofiler tests | |
| 17:59:31 | jgwentworth | sean-k-mooney: yes, it's been like that for a long time. it's like that on master too. it's just I don't know how the results are picked out of that | |
| 17:59:51 | leakypipes | finucannot: we are indeed going to be transferring these objects over the wire in short order. Probably good to get the obj_make_compatible() stuff done sooner or later. | |
| 17:59:51 | jgwentworth | out of the fact that we have two separate runs I mean | |
| 18:00:12 | sean-k-mooney | yes but on master we are not using pretty tox anymore we are using stestr | |
| 18:01:27 | leakypipes | cdent: sorry, I had to leave before answering your question. yes, I'd like to add the nested resource providers series on to the end of that de-orm series because it makes handling superdan's request to make root_provider_uuid and parent_provider_uuid into root_provider_id and parent_provider_id. | |
| 18:01:47 | leakypipes | ronlund: ok, now looking into your issue | |
| 18:04:33 | leakypipes | ronlund: technically, any change to either inventory or traits of a resource provider would cause that concurrent update error. that said, I don't believe we are yet setting traits on a resource provider (other than in functional DB tests...) | |
| 18:04:50 | sean-k-mooney | jgwentworth: basically my assertion is that ostestr(pike) and python setup.py testr(ocata) probably overrite the results stestr(master) is appending? | |
| 18:06:18 | leakypipes | ronlund: grasping at straws, but maybe cdent's patch that reduced the number of times we update aggregates might be playing into this.. cdent, does updating aggs change the generation? /me goes to check | |
| 18:06:24 | jgwentworth | sean-k-mooney: maybe. I know almost nothing about how the unit test jobs work so I couldn't tell you :) | |
| 18:07:14 | sean-k-mooney | jgwentworth: https://github.com/openstack/nova/blob/353db2d1932965b6502e002b8be510440ff529c0/tox.ini#L33 yes just checked stestr docs thats what the --combine does http://stestr.readthedocs.io/en/latest/MANUAL.html#combining-test-results | |
| 18:08:03 | sean-k-mooney | jgwentworth: on newton we doe not run os profiler which is why that works | |
| 18:08:10 | jgwentworth | ahhh, nice sleuthing | |
| 18:09:59 | leakypipes | ronlund: that's a negative on the set aggregates changing the resource provider generation. | |
| 18:11:06 | openstackgerrit | Dan Smith proposed openstack/nova master: Always put 'uuid' into sort_keys for stable instance lists https://review.openstack.org/510140 | |
| 18:11:07 | openstackgerrit | Dan Smith proposed openstack/nova master: Fix instance_get_by_sort_filters() for multiple sort keys https://review.openstack.org/510203 | |
| 18:11:12 | superdan | ronlund: andreykurilin ^ | |
| 18:16:33 | sean-k-mooney | jgwentworth: we might be able to use the --partial flag for testr to get similar behavior ill propose a patch to stable/ocata to test it | |
| 18:17:04 | jgwentworth | sounds cool | |
| 18:19:08 | sean-k-mooney | the doc of what --partial actully does is kindof vagure but it mentioned that it was useed with --failing to make sure un run failures where not lost if interupted so im guessing it will prevent whiping the resuts of previous runs | |
| 18:37:29 | ronlund | leakypipes: note we aren't setting traits or doing aggregate anything in this recreate | |
| 18:37:37 | ronlund | RP inventory is only set once when the compute node is created | |
| 18:37:47 | leakypipes | ronlund: yeah, weird indeed. | |
| 18:38:00 | ronlund | the only thing we're doing is trying to create 1000 instances in a single request, so we're processing those instances in order and making the consumer allocation requests against the same RP | |
| 18:38:12 | ronlund | leakypipes: which i assume means the error comes from the amount consumed changing | |
| 18:38:19 | leakypipes | ronlund: yes. | |
| 18:38:21 | ronlund | which, fine, but it's happening in serial | |
| 18:38:54 | ronlund | unless that just means i'm hitting some limit, but then i'd expect a different error? | |
| 18:39:27 | ronlund | there were also 18 retries logged in that recreate until the failure, so something is giving the 409 and saying, retry, and it's working for some | |
| 18:39:29 | leakypipes | ronlund: it could be the periodic task on the compute node kicking in, noticing the generation has updated, and pulling inventory and generation info again. | |
| 18:39:32 | ronlund | so it's not a limit issue it seems | |
| 18:39:45 | ronlund | leakypipes: the inventory isn't getting updated though | |
| 18:39:46 | leakypipes | ronlund: but it shouldn't be setting inventory to a different set of values... :( | |
| 18:39:50 | ronlund | right | |
| 18:40:07 | ronlund | i see only 1 PUT /resource_providers/<uuid>/inventories in the placement api logs | |
| 18:40:32 | ronlund | mayhap i need a patch to dump a stacktrace when we hit the 409 in the placement api | |
| 18:40:36 | ronlund | to see where it's coming from | |
| 18:40:50 | cdent | if you get the inventory, update the local generation on the local node, will an inflight allocation rap out? | |
| 18:40:51 | ronlund | also, i like to say mayhap | |
| 18:41:01 | cdent | crap , not rap | |
| 18:41:09 | cdent | but who knows, allocations may like to rhyme | |
| 18:42:51 | ronlund | leakypipes: specless bp approved btw | |
| 18:43:00 | leakypipes | ronlund: donkey shane. | |
| 18:44:52 | cdent | ronlund: the 409 is being received in the scheduler? and the scheduler is definitely not eventlet-ing? | |
| 18:45:01 | cdent | (i believe you said that before, just confirming) | |
| 18:46:21 | ronlund | we don't have multiple scheduler workers | |
| 18:46:49 | cdent | ronlund: i know that, but if somehow eventlet is involved and socket is patched, things might go awry | |
| 18:48:12 | ronlund | well, there was something weird | |
| 18:48:15 | ronlund | sec | |
| 18:48:21 | openstackgerrit | Dan Smith proposed openstack/nova master: Always put 'uuid' into sort_keys for stable instance lists https://review.openstack.org/510140 | |
| 18:48:21 | openstackgerrit | Dan Smith proposed openstack/nova master: Fix instance_get_by_sort_filters() for multiple sort keys https://review.openstack.org/510203 | |
| 18:48:29 | ronlund | http://logs.openstack.org/18/507918/6/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/d4f175d/logs/screen-n-sch.txt.gz#_Oct_04_18_32_08_753794 | |
| 18:48:29 | ronlund | so the error in the scheduler is here | |
| 18:48:42 | ronlund | right before that, it says, | |
| 18:48:43 | ronlund | Attempting to claim resources in the placement API for instance af059052-6221-4685-8151-6f450e4dc97d {{(pid=29557) _claim_resources | |
| 18:48:55 | ronlund | but if you look at req-16b6ac82-6274-4300-bb65-cc94a26648fd in the placement logs, | |
| 18:49:04 | ronlund | http://logs.openstack.org/18/507918/6/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/d4f175d/logs/screen-placement-api.txt.gz#_Oct_04_18_32_08_696647 | |
| 18:49:24 | ronlund | PUT /placement/allocations/da3c3f24-227b-4b3a-8b1d-43a62c637e44 | |
| 18:49:27 | ronlund | that's a different consumer | |
| 18:50:40 | cdent | ronlund: since the scheduler is started via nova/cmd, the monkey patch in __init__.py is called, right? | |
| 18:51:19 | cdent | So any expectations of linear may be wrong, if a socket at some point decides to wait | |
| 18:51:43 | ronlund | nova/cmd/scheduler.py calls utils.monkey_patch() but i think that's a different thing | |
| 18:52:14 | cdent | yues | |
| 18:52:22 | ronlund | oh in nova/cmd/__init__ yes | |
| 18:52:23 | cdent | but if you are in nova/cmd, __init__ is run | |
| 18:53:36 | ronlund | oh nvm the logging thing | |
| 18:53:43 | ronlund | Unable to submit allocation for instance da3c3f24-227b-4b3a-8b1d-43a62c637e44 (409 {"errors": [{"status": 409, "request_id": "req-16b6ac82-6274-4300-bb65-cc94a26648fd", "detail": "There was a conflict when trying to complete your request.\n\n Inventory changed while attempting to allocate: Another thread concurrently updated the data. Please retry your update ", "title": "Conflict"}]}) | |
| 18:53:59 | ronlund | so da3c3f24-227b-4b3a-8b1d-43a62c637e44 was the instance it was requesting on | |
| 18:54:54 | ronlund | the "Attempting to claim resources in the placement API for instance af059052-6221-4685-8151-6f450e4dc97d" was a red herring, | |
| 18:55:03 | ronlund | if we log ^ but no error, it just means the claim was successful | |
| 18:55:06 | cdent | ronlund: I’m not sure that’s the case? | |
| 18:55:18 | ronlund | we don't log anything for a successful claim | |
| 18:55:59 | cdent | so in that case we have an attempt for instance X, then a fail for instance Y, where is the attempt for Y? | |
| 18:56:08 | ronlund | http://logs.openstack.org/18/507918/6/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/d4f175d/logs/screen-placement-api.txt.gz#_Oct_04_18_32_08_825897 is that other instance | |
| 18:56:48 | cdent | so why are we getting the warn about the failure after the debug about the other attempt | |
| 18:56:53 | cdent | they _are_ out of order | |
| 18:57:04 | cdent | which is what we would expect in a monkey patched eventlet scene | |
| 18:59:20 | cdent | bbs, gotta do the dishes | |
| 18:59:38 | ronlund | i'm seeing something f'ed in the scheduler code, | |
| 18:59:43 | ronlund | it's doing the same scheduling request 3 times | |
| 18:59:45 | ronlund | "Starting to schedule for" | |
| 19:00:22 | ronlund | 3 seconds apart | |