| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-10-06 | |||
| 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 | |
| 19:08:21 | openstackgerrit | Jay Pipes proposed openstack/nova master: rp: remove _HasAResourceProvider mixin https://review.openstack.org/509036 | |
| 19:08:21 | openstackgerrit | Jay Pipes proposed openstack/nova master: rp: rework AllocList.get_all_by_consumer_id() https://review.openstack.org/509035 | |
| 19:08:21 | openstackgerrit | Jay Pipes proposed openstack/nova master: rp: fix up AllocList.get_by_resource_provider_uuid https://review.openstack.org/509033 | |
| 19:08:22 | openstackgerrit | Jay Pipes proposed openstack/nova master: rp: break functions out of _set_traits() https://review.openstack.org/509908 | |
| 19:09:02 | ronlund | http://logs.openstack.org/18/507918/6/check/gate-tempest-dsvm-neutron-full-ubuntu-xenial/d4f175d/logs/screen-n-super-cond.txt.gz#_Oct_04_18_32_07_052398 | |
| 19:09:02 | ronlund | aha | |
| 19:09:21 | ronlund | select_destinations took too long, so oslo.messaging retried | |
| 19:09:53 | ronlund | well that explains that i think | |
| 19:09:58 | ronlund | i'm going to bump up the rpc timeout | |
| 19:10:18 | cdent | that doesn’t sound safe | |
| 19:10:47 | cdent | (dishwasher not done yet) | |
| 19:11:14 | ronlund | huh, given we don't rate limit min_count at all, | |
| 19:11:23 | ronlund | you could totally bork some stuff up with making a huge request | |
| 19:11:35 | ronlund | if the server's rpc timeout isn't configured high enough to handle it | |