Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-08-26
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
21:45:06 fungi can anyone double-check for me that bug 1837252 was introduced in os-vif 1.12.0? sean-k-mooney said it "was introduced in stein" but there were multiple releases in master before it branched to stable/stein
21:45:07 openstack bug 1837252 in os-vif stein "IFLA_BR_AGEING_TIME of 0 causes flooding across bridges" [High,In progress] https://launchpad.net/bugs/1837252 - Assigned to sean mooney (sean-k-mooney)
21:45:48 fungi just want to be sure before i go sending this to mitre, so i don't have to update them with errata
21:45:51 sean-k-mooney i think the exact commit is in the bug somewhere but ya ill check
21:45:58 sean-k-mooney it was right at the end of the cycle
21:46:04 fungi oh, sorry if i overlooked it, checking
21:46:54 fungi 5027ce8
21:47:10 sean-k-mooney https://github.com/openstack/os-vif/commit/1f6fed6a69e9fd386e421f3cacae97c11cdd7c75
21:47:27 sean-k-mooney so 1.15.0
21:47:48 fungi aha, thanks
21:48:13 sean-k-mooney thats the commit where i swaped the linux bridge plugin to use the common code intoduced in the previous commit
21:48:44 fungi any chance you can skim the rest of the impact description in comment #17 there and see if it makes sense, aside from the affected versions obviously being an incorrect guess?
21:50:10 sean-k-mooney im not actully sure if it disable mac learning or if mac learning is still enabled but macs are never unlearnt
21:50:28 sean-k-mooney both would result in flooding in different situations
21:52:31 sean-k-mooney form the inital bug i woudl have suspected that former
21:52:54 sean-k-mooney sorry the latter
21:53:05 fungi hrm, yeah at first i thought it simply filled the mac table, but logan- suggested it disabled learning
21:53:09 sean-k-mooney the fdb does have macs
21:53:36 sean-k-mooney maybe ip route has some info
21:53:44 sean-k-mooney or ip tools
21:53:45 fungi hence the diff between the impact descriptions in comment #15 and #17
21:54:46 sean-k-mooney brctl setageing <brname> <time> sets the ethernet (MAC) address ageing time, in seconds. After <time> seconds of not having seen a frame coming from a certain address, the bridge
21:54:48 sean-k-mooney will time out (delete) that address from the Forwarding DataBase (fdb).
21:55:26 sean-k-mooney so i would think it never delete the macs
21:55:37 sean-k-mooney so it would only flood if the mac was learned on two ports

Earlier   Later