Earlier  
Posted Nick Remark
#openstack-nova - 2019-08-26
19:23:42 artom I think devstack bork
19:23:50 sean-k-mooney you need to rebase
19:23:59 sean-k-mooney this is fixed on master
19:24:38 artom ack
19:24:45 artom When I push the new func test
19:24:55 sean-k-mooney are you goint to do ^
19:24:56 artom I gotta run for a daughter school thing (yes, she's starting shool!)
19:25:10 artom sean-k-mooney, can't have different configs in func tests
19:25:19 sean-k-mooney yes you can
19:25:32 artom Nope, CONF is global
19:25:43 sean-k-mooney you need to chente the config flag and start the compute agent serially
19:26:11 sean-k-mooney it does not have to be with mocks and we read most of the values on start up
19:26:20 dansmith sean-k-mooney: that only works for a subset of cases
19:30:17 sean-k-mooney dansmith: yes but i think it will work in this case. i do not belview we parse the config on ever iteration of the perodic tasks.
19:31:03 sean-k-mooney if we do we should stop and cache it. we dont support change this config at runtime.
19:35:28 dansmith it's not just the periodic that matters of course
19:36:10 dansmith % fgrep 'CONF.' -r nova/virt/hardware.py | wc -l
19:36:11 dansmith 9
19:36:12 sean-k-mooney true but i think it would work in this case. the simple way would to test this would be just try it
19:37:46 sean-k-mooney at least 7 of those shoudl one be check at star up i think
19:38:19 dansmith I'm just saying, this stuff is spread everywhere
19:38:22 sean-k-mooney i think all of them are just used in init
19:38:27 sean-k-mooney ya it is
19:38:45 sean-k-mooney i just think/hope this is simpler to do then it first seams
19:39:23 sean-k-mooney if we test this simple with conf setting that would be better then create a complicate test setup
19:44:40 sean-k-mooney anyway i replied in https://review.opendev.org/#/c/635669/39/nova/compute/resource_tracker.py@304 not sure if that is what ye wanted.
19:45:06 sean-k-mooney ill redeploy with artoms code shortly and start testing it again.
20:02:36 TheJulia mriedem: remember that seemingly weird rebalance race on stable/stein that we spotted with ironic last week? I just spotted it on master branch testing https://d01b2e57f0a56cb7edf0-b6bc206936c08bb07a5f77cfa916a2d4.ssl.cf5.rackcdn.com/678298/4/check/ironic-tempest-ipa-wholedisk-direct-tinyipa-multinode/92c65ac/compute1/logs/screen-n-cpu.txt.gz <-- nova 19.1.0 :\
20:04:04 sean-k-mooney TheJulia: implying that backport the other fix may not resolve the issue
20:04:23 sean-k-mooney assuming on master it still had the db issue
20:05:23 TheJulia indeed :(
20:06:09 sean-k-mooney those errors seam to be indicating that the RP is not found
20:06:25 sean-k-mooney im not sing the db conclit on the compute node uuid
20:06:49 TheJulia seeing?
20:07:28 sean-k-mooney yes :)
20:07:55 sean-k-mooney i dropped the ee it seams
20:08:22 TheJulia no worries, my brain does similar things
20:08:39 TheJulia so without the conflict.... hmmmm
20:09:50 sean-k-mooney but it might be that the other compute node is not recreating the rp
20:10:07 sean-k-mooney or it is but we race
20:11:58 TheJulia I'll go with it is but we race
20:15:31 mriedem umm yeah doesn't look like the same issue, no db conflicts on restart of the service that i see
20:15:47 mriedem Aug 26 18:41:38.367990 ubuntu-bionic-rax-ord-0010443319 nova-compute[747]: INFO nova.compute.resource_tracker [None req-a894abee-a2f1-4423-8ede-2a1b9eef28a4 None None] ComputeNode eabf1567-cb9f-4a93-b77e-44a80ddd50b0 moving from ubuntu-bionic-rax-ord-0010443317 to ubuntu-bionic-rax-ord-0010443319
20:15:47 mriedem i see this:
20:16:10 mriedem Aug 26 18:41:38.818412 ubuntu-bionic-rax-ord-0010443319 nova-compute[747]: INFO nova.compute.resource_tracker [None req-a894abee-a2f1-4423-8ede-2a1b9eef28a4 None None] ComputeNode 61dbc9c7-828b-4c42-b19c-a3716037965f moving from ubuntu-bionic-rax-ord-0010443317 to ubuntu-bionic-rax-ord-0010443319
20:16:27 mriedem and then a bunch of errors about resource provider not found
20:17:08 mriedem he resource could not be found.\n\n No resource provider with uuid 61dbc9c7-828b-4c42-b19c-a3716037965f found: No resource provider with uuid 61dbc9c7-828b-4c42-b19c-a3716037965f found ", "title": "Not Found"}]}.
20:17:08 mriedem Aug 26 18:41:38.992017 ubuntu-bionic-rax-ord-0010443319 nova-compute[747]: ERROR nova.scheduler.client.report [None req-a894abee-a2f1-4423-8ede-2a1b9eef28a4 None None] [req-208b7275-abc4-4445-9551-8edbce49e0e1] Failed to retrieve traits from placement API for resource provider with UUID 61dbc9c7-828b-4c42-b19c-a3716037965f. Got 404: {"errors": [{"status": 404, "request_id": "req-208b7275-abc4-4445-9551-8edbce49e0e1", "detail"
20:17:42 sean-k-mooney it looks like the perodic taks the cleans up allocation ran before the compute node rp was recreated by the other compute service
20:18:21 mriedem the traceback hits get_provider_tree_and_ensure_root which should ensure the provider exists, so i'm not sure why it wouldn't,
20:18:30 mriedem unless it's only looking at it's local provider tree cache and that is stale or something
20:23:06 TheJulia that does seem to possibly be the case. just glancing at records for eabf1567-cb9f-4a93-b77e-44a80ddd50b0, it is all over both compute logs
20:24:36 TheJulia in the same time window it looks like...
20:29:35 openstackgerrit Merged openstack/nova master: Remove descriptions of nonexistent hacking rules https://review.opendev.org/678462
20:36:44 TheJulia hmmmmm.... I wonder
20:41:57 openstackgerrit Merged openstack/nova master: tests: Split NUMA object tests https://review.opendev.org/672336
20:47:18 TheJulia I'm starting to wonder, at least digging at it, if things did't moderately correct themselves at least resource tracker wise as time went on. Looks like everything changed to no longer reserved around 18:46, placement reports still one node reserved 3 minutes later
21:09:07 mriedem i think this is bogus
21:09:08 mriedem he resource could not be found.\n\n No resource provider with uuid 61dbc9c7-828b-4c42-b19c-a3716037965f found: No resource provider with uuid 61dbc9c7-828b-4c42-b19c-a3716037965f found ", "title": "Not Found"}]}.
21:09:08 mriedem Aug 26 18:41:38.992017 ubuntu-bionic-rax-ord-0010443319 nova-compute[747]: ERROR nova.scheduler.client.report [None req-a894abee-a2f1-4423-8ede-2a1b9eef28a4 None None] [req-208b7275-abc4-4445-9551-8edbce49e0e1] Failed to retrieve traits from placement API for resource provider with UUID 61dbc9c7-828b-4c42-b19c-a3716037965f. Got 404: {"errors": [{"status": 404, "request_id": "req-208b7275-abc4-4445-9551-8edbce49e0e1", "detail"
21:09:16 mriedem because right before that we get inventories and aggregates for the provider
21:09:28 mriedem Aug 26 18:41:38.881026 ubuntu-bionic-rax-ord-0010443319 nova-compute[747]: DEBUG nova.scheduler.client.report [None req-a894abee-a2f1-4423-8ede-2a1b9eef28a4 None None] Refreshing inventories for resource provider 61dbc9c7-828b-4c42-b19c-a3716037965f {{(pid=747) _refresh_associations /opt/stack/nova/nova/scheduler/client/report.py:761}}
21:09:35 mriedem Aug 26 18:41:38.953685 ubuntu-bionic-rax-ord-0010443319 nova-compute[747]: DEBUG nova.scheduler.client.report [None req-a894abee-a2f1-4423-8ede-2a1b9eef28a4 None None] Refreshing aggregate associations for resource provider 61dbc9c7-828b-4c42-b19c-a3716037965f, aggregates: None {{(pid=747) _refresh_associations /opt/stack/nova/nova/scheduler/client/report.py:770}}
21:12:03 mriedem unless at the same time, the other host is deleting the resource provider
21:12:09 mriedem because the driver no longer reports it there
21:12:56 sean-k-mooney well that could happen. we are not syncronising any of this
21:12:59 mriedem Aug 26 18:41:38.832749 ubuntu-bionic-rax-ord-0010443317 nova-compute[19290]: INFO nova.compute.manager [None req-d5a9c4b6-f197-4f6c-8b12-8f736bbdb11c None None] Deleting orphan compute node 6 hypervisor host is 61dbc9c7-828b-4c42-b19c-a3716037965f, nodes are set([u'1d23263a-31d4-49d9-ad68-be19219c3bae', u'be80f41d-73ed-46ad-b8e4-cefb0193de36', u'f3c6add0-3eda-47d9-9624-c1f73d488066', u'2c909342-b5dc-4203-b9cb-05a8f29c6c35', u
21:13:00 mriedem 1f5d8-8b39-4d03-8423-8e8404128ece']) Aug 26 18:41:38.962237 ubuntu-bionic-rax-ord-0010443317 nova-compute[19290]: INFO nova.scheduler.client.report [None req-d5a9c4b6-f197-4f6c-8b12-8f736bbdb11c None None] Deleted resource provider 61dbc9c7-828b-4c42-b19c-a3716037965f
21:13:07 mriedem ^ is the other host
21:13:26 mriedem yup, 18:41:38
21:14:02 mriedem so the new host starts refreshing it's RT, the old host deletes the provider, then the new host blows up in the RT, but eventually corrects itself on the next run
21:14:22 mriedem dId SoMeOnE sAy EtCd?!?!
21:14:57 sean-k-mooney ... and follow cinders lead
21:15:02 mriedem i'm joking
21:15:24 sean-k-mooney i know
21:16:25 sean-k-mooney a distribute lock could prevent this by deadlocking the sytem so we dont get there
21:17:26 sean-k-mooney we proably need to cacht the error and if it happens remove the compute node form whatever data structure we were iterating over and move on
21:18:39 mriedem i think the bug is that we stash the node on the new host in RT.compute_nodes, then hit the failure, and the next pass in the RT periodic task we see the node is already in the RT.compute_nodes and don't attempt to go through the _update and flush to placement flow, so the new host doesn't recreate the provider until inventory changes
21:18:56 mriedem so find the thing on the new host and store it here https://github.com/openstack/nova/blob/71478c3eedd95e2eeb219f47460603221ee249b9/nova/compute/resource_tracker.py#L513
21:19:01 mriedem blow up here https://github.com/openstack/nova/blob/71478c3eedd95e2eeb219f47460603221ee249b9/nova/compute/resource_tracker.py#L516
21:19:12 mriedem and on the next pass find the node here https://github.com/openstack/nova/blob/71478c3eedd95e2eeb219f47460603221ee249b9/nova/compute/resource_tracker.py#L546
21:19:16 mriedem but don't call _update
21:19:18 mriedem until inventory changes
21:19:23 mriedem hence the RP not showing up again for awhile
21:19:25 mriedem TheJulia: ^
21:19:49 mriedem a la https://review.opendev.org/#/q/I9fa1d509a3de405d6246fb8670612c65c10cc93b
21:22:40 mriedem oh actually,
21:22:56 mriedem because we put the provider back into the cache and then failed, we don't attempt to create it later in the new host either
21:23:08 mriedem so the provider tree cache is hiding the fact the provider doesn't actually exist anymore
21:24:28 mriedem efried: fun stuff ^
21:25:36 mriedem guess i'll just report a bug for now
21:27:17 efried mriedem: Under what circumstances do we put a provider into the cache and then fail?
21:28:05 efried is this during update_from_provider_tree somehow?
21:28:43 mriedem yeah, it will probably be more clear when i post the bug report
21:39:39 mriedem efried: TheJulia: https://bugs.launchpad.net/nova/+bug/1841481
21:39:40 openstack Launchpad bug 1841481 in OpenStack Compute (nova) "Race during ironic re-balance corrupts local RT ProviderTree and compute_nodes cache" [Medium,Triaged]
21:42:18 TheJulia funnn..... and by fun, I think I mean anti-fun
21:44:10 openstackgerrit sean mooney proposed openstack/nova master: Libvirt: report storage bus traits https://review.opendev.org/666914
21:44:11 openstackgerrit sean mooney proposed openstack/nova master: Add transform_image_metadata request filter https://review.opendev.org/665775
21:44:11 openstackgerrit sean mooney proposed openstack/nova master: libvirt: use domain capabilities to get supported device models https://review.opendev.org/666915

Earlier   Later