Earlier  
Posted Nick Remark
#openstack-nova - 2017-10-06
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
19:00:29 ronlund well, 1 second apart, 3 times
19:00:46 ronlund all with the same request id
19:01:22 ronlund leakypipes: well that answers that i think ^
19:01:30 ronlund the 409 is probably because we already posted allocations for the same consumer
19:01:52 Jose____ Hi! i found this in nova placement api log: "Placement API returning an error response: JSON does not validate: 0 is less than the minimum of 1", can this be affecting with the image creation service?
19:02:02 ronlund Jose____: no
19:02:04 leakypipes ronlund: hmm, that's odd indeed.
19:03:11 cdent ronlund: is that request id the local one or the one passed up from nova-api
19:04:13 ronlund cdent: the api http://logs.openstack.org/18/507918/6/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/d4f175d/logs/screen-n-api.txt.gz#_Oct_04_18_30_21_221501
19:04:20 ronlund {"server": {"name": "test-alloc-conflict", "imageRef": "947823a9-8c15-420a-95d8-f35cd2f024b9", "flavorRef": "1", "max_count": 1000, "min_count": 1000, "networks": "none"}}
19:04:50 ronlund i see a successful allocation for the failed instance 2 seconds after the final 409 retry failure
19:04:51 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_34_13_854776
19:05:40 ronlund wth, why would we have 3 greenthreads?
19:08:16 openstackgerrit Jay Pipes proposed openstack/nova master: rp: de-ORM ResourceProvider.get_by_uuid() https://review.openstack.org/509025
19:08:17 openstackgerrit Jay Pipes proposed openstack/nova master: rp: Remove RP.get_traits() method https://review.openstack.org/509027
19:08:17 openstackgerrit Jay Pipes proposed openstack/nova master: rp: Move RP._get|set_aggregates() to module scope https://review.openstack.org/509026
19:08:18 openstackgerrit Jay Pipes proposed openstack/nova master: rp: remove CRUD operations on Inventory class https://review.openstack.org/509029
19:08:18 openstackgerrit Jay Pipes proposed openstack/nova master: rp: move RP._set_traits() to module scope https://review.openstack.org/509028
19:08:19 openstackgerrit Jay Pipes proposed openstack/nova master: rp: remove dead code in Allocation._create_in_db() https://review.openstack.org/509031
19:08:19 openstackgerrit Jay Pipes proposed openstack/nova master: rp: streamline InventoryList.get_all_by_rp_uuid() https://review.openstack.org/509030
19:08:20 openstackgerrit Jay Pipes proposed openstack/nova master: rp: remove ability to delete 1 allocation record https://review.openstack.org/509032

Earlier   Later