| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-08-26 | |||
| 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 | |
| 21:55:43 | mriedem | melwitt: dansmith: if either of you are around can we move this stein backport series through please? https://review.opendev.org/#/q/topic:bug/1839560+branch:stable/stein | |
| 21:55:53 | sean-k-mooney | that would only happen if the vm was migrated | |
| 21:56:02 | fungi | sean-k-mooney: or if the table filled i guess? | |
| 21:56:16 | sean-k-mooney | i dont think there is a limit on the table size | |
| 21:56:40 | fungi | there is bound to be some practical limit on table size, whether it is reachable or not is another matter ;) | |
| 21:56:46 | sean-k-mooney | maybe there is but there the docs on linux bridge are rather limited | |
| 21:57:59 | dansmith | mriedem: hit me tomorrow and I will, I gotta run | |
| 21:58:26 | fungi | not sure what sort of layer 2 filters are generally in place to prevent poisoning, but could an instance spoof frames from random macs to overrun the bridge table? or spoof specific macs for other victim instances so they show up on multiple ports? | |
| 21:58:27 | dansmith | nm, I'll just do it now | |
| 21:59:05 | sean-k-mooney | fungi: neutron adds iptbales rules to prevent mac spoofing and nova used to also | |
| 21:59:13 | melwitt | heh, dansmith wins | |
| 21:59:31 | fungi | sean-k-mooney: yeah, and i think that would be a more general concern beyond the scope of this particular bug anyway | |
| 22:00:17 | mriedem | dansmith: <3 | |