| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2018-08-30 | |||
| 20:18:20 | tzumainn | mriedem, I only have one, in any case | |
| 20:18:27 | tzumainn | mriedem, no worries, thanks for taking a look : ) | |
| 20:20:16 | mriedem | so uh, the xen ci passed this time with the debug patch https://review.openstack.org/#/c/597613/ | |
| 20:20:21 | mriedem | that's nice and consistent | |
| 20:23:46 | melwitt | great | |
| 20:26:28 | melwitt | keeping in the theme of Impossible Bug Week | |
| 20:26:29 | Sundar | melwitt: I am proposing a session for Cyborg/Nova to sort out os-acc. The main session could be in Cyborg time (Mon/Tue) and hopefully placement folks would attend. It may be helpful to get some time on Nova schedule as well to get everybody on board. What do you think? | |
| 20:26:52 | cdent | sorry mriedem, I'm sort of afk: if it was was that patch from back in queens, then the twisted narrow passageways are way twisted and have a lot of explaining to do to say why it's only showing up now | |
| 20:29:54 | melwitt | Sundar: do you think we need two sessions? we could just join the monday or tuesday session since nova doesn't start until wednesday | |
| 20:29:55 | cdent | mriedem: can you think of a way we could model the issue in a functional test? the feedback latency is hurting my head | |
| 20:30:50 | mriedem | cdent: given the xen ci is now passing, i don't really know | |
| 20:31:03 | mriedem | and why this isn't failing with the libvirt driver in master CI, again don't know | |
| 20:31:10 | cdent | fun fun | |
| 20:31:12 | mriedem | efried: we now have a new ERROR in the n-cpu logs on startup http://logs.openstack.org/98/584598/21/check/tempest-full/85acbda/controller/logs/screen-n-cpu.txt.gz?level=TRACE#_Aug_29_21_43_10_675029 | |
| 20:31:22 | mriedem | efried: b/c we hit ^ before the resource provider is created | |
| 20:31:50 | mriedem | new from https://review.openstack.org/#/c/584598/ | |
| 20:32:17 | dansmith | hmm, I got that disk not found one the other day locally | |
| 20:32:26 | dansmith | I thought it was residue from my old machine | |
| 20:33:04 | dansmith | is that because we're re-raising too? | |
| 20:34:18 | mriedem | https://bugs.launchpad.net/nova/+bug/1789998 | |
| 20:34:18 | openstack | Launchpad bug 1789998 in OpenStack Compute (nova) "ResourceProviderAllocationRetrievalFailed ERROR log message on fresh n-cpu startup" [Low,Triaged] | |
| 20:34:50 | mriedem | the DiskNotFound during periodic is usually b/c we're deleting an instance on that host at the same time | |
| 20:35:11 | mriedem | http://logs.openstack.org/98/584598/21/check/tempest-full/85acbda/controller/logs/screen-n-cpu.txt.gz#_Aug_29_21_51_13_055225 | |
| 20:35:14 | dansmith | okay this was on startup for me, which prevented it from every reporting initial inventory to placement | |
| 20:35:16 | mriedem | right before the DiskNotFound | |
| 20:35:25 | mriedem | Aug 29 21:51:13.055225 ubuntu-xenial-rax-iad-0001643010 nova-compute[16853]: INFO nova.virt.libvirt.driver [None req-af17b138-d942-4bbf-bf67-4d03b492ed3c tempest-ImagesTestJSON-1980657675 tempest-ImagesTestJSON-1980657675] [instance: 21227895-e216-463f-8e76-998fe637bab2] Deletion of /opt/stack/data/nova/instances/21227895-e216-463f-8e76-998fe637bab2_del complete | |
| 20:35:28 | dansmith | but I had what I think was a stale disk image in my instances directory | |
| 20:35:34 | mriedem | Aug 29 21:51:13.167422 ubuntu-xenial-rax-iad-0001643010 nova-compute[16853]: ERROR nova.compute.manager [None req-6f4285cc-ce12-4c29-b879-99fdaaae59be None None] Error updating resources for node ubuntu-xenial-rax-iad-0001643010.: DiskNotFound: No disk at /opt/stack/data/nova/instances/21227895-e216-463f-8e76-998fe637bab2/disk | |
| 20:35:42 | dansmith | nuking that fixed it, but I just had to do one more thing and then killed it all | |
| 20:35:46 | mriedem | yeah on startup would be a different weirdness | |
| 20:37:39 | Sundar | melwitt: If we can settle everything in one session, that would be great. Given the quantum of reviews, we want to make sure that there is enough convergence to close the spec https://review.openstack.org/#/c/577438 after the PTG. | |
| 20:38:02 | Sundar | Could we keep a 30-minute placeholder? | |
| 20:40:31 | mriedem | so on the 2nd go around in the RT.update_available_resource in this xen CI run, we see the RT say the tracked compute node has changed: | |
| 20:40:33 | mriedem | http://paste.openstack.org/show/729180/ | |
| 20:40:44 | mriedem | b/c of _copy_resources updating the *_allocation_ratio values to 0.0 | |
| 20:42:13 | mriedem | Aug 30 08:03:09.458344 dsvm-devstack-citrix-lon-nodepool-1379396 nova-compute[24292]: INFO nova.compute.resource_tracker [None req-9b1b9924-b89e-4a03-9a69-c9fff17594e3 None None] ComputeNode.cpu_allocation_ratio changed from 16.0 to 0.0 in _copy_resources. | |
| 20:44:50 | melwitt | Sundar: 30-minute placeholder for monday or tuesday? | |
| 20:46:05 | melwitt | Sundar: also, I think we should have the nova bits of the interaction proposed to nova-specs for review, that way we can more easily organize our review on that part | |
| 20:46:48 | Sundar | 30 min in Nova's schedule, anytime you want. Cyborg should allocate at least 1 hour on mon/tue. | |
| 20:47:27 | Sundar | The os-acc spec as a whole is Nova/Cyborg, so do we want another spec? | |
| 20:48:19 | melwitt | Sundar: okay, so you're saying you think we need two sessions. I can try to find a 30-minute slot on our schedule | |
| 20:48:51 | melwitt | Sundar: we need a nova spec for the proposed changes to the nova code, so the nova team can review those proposed changes | |
| 20:50:04 | Sundar | melwitt: Thanks a lot. OK, will propose a Nova spec too. BTW, I have been interacting a lot with efried and any Nova developer who gives feedback on os-acc spec. | |
| 20:50:08 | melwitt | nova meeting in 10 minutes | |
| 20:50:47 | melwitt | Sundar: thanks | |
| 20:52:57 | mriedem | cdent: just so you can rest easy tonight, i think we can safely confirm that we have some sort of weird multi-thread race with shared ProviderTree cache | |
| 20:52:59 | mriedem | https://bugs.launchpad.net/nova/+bug/1789654/comments/9 | |
| 20:52:59 | openstack | Launchpad bug 1789654 in OpenStack Compute (nova) "placement allocation_ratio initialized with 0.0" [High,In progress] - Assigned to Matt Riedemann (mriedem) | |
| 20:52:59 | melwitt | mriedem: so _copy_resources is bypassing the compute node normalization routine? | |
| 20:53:00 | mriedem | efried: ^ | |
| 20:53:32 | mriedem | melwitt: yes, and from my log digging in that comment it shows that if we hit this in the right order, we call ComputeNode.save() which will change the CN.cpu_allocation_ratio from 0.0 (from _copy_resources) back to 16.0 | |
| 20:53:43 | cdent | oh great, I love weird multi-thread races, especially when caches are involved | |
| 20:53:49 | mriedem | which goes to the RT._normalize_inventory_from_cn_obj method which puts 16.0 back into the inventory dict | |
| 20:54:02 | melwitt | mriedem: ah, ok. nice sleuthing | |
| 20:54:13 | mriedem | but there is clearly something else hitting ProviderTree.update_inventory at the same time that RT.update_available_resource is running | |
| 20:54:42 | mriedem | and i don't think it's coming from the RT | |
| 20:54:59 | mriedem | the only place in RT that we call ProviderTree.update_inventory is after driver.update_provider_tree, which isn't implemented for xen | |
| 20:55:09 | mriedem | so i think it's the SchedulerReportClient's provider tree cache | |
| 20:57:37 | cdent | I suspect (or at least hope) that efried will have some insight on the meanderings of the cache | |
| 20:58:06 | efried | I may, once I'm not trying to do several things at once. | |
| 20:59:00 | cdent | efried: this seems to be an unfortunately common problem | |
| 20:59:15 | cdent | let's all quit | |
| 20:59:22 | cdent | (that'll show em) | |
| 20:59:32 | mriedem | meeting in 1 min? | |
| 20:59:48 | melwitt | yes, I gave a 10 minute warning 9 minutes ago | |
| 21:05:13 | mriedem | far as i can tell the report client gets inventory like 500 times a second | |
| 21:05:25 | mriedem | it calls _refresh_and_get_inventory *a lot* | |
| 21:05:37 | mriedem | for every _ensure_resource_provider | |
| 21:05:49 | mriedem | where again, _ensure_resource_provider is less ensure and more "refresh the world" now | |
| 21:13:48 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Log the operation when updating generation in ProviderTree https://review.openstack.org/597553 | |
| 21:13:49 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Add debug logs for when provider inventory changes https://review.openstack.org/597560 | |
| 21:15:14 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Add debug logs for when provider inventory changes https://review.openstack.org/597560 | |
| 21:18:58 | openstackgerrit | Dan Smith proposed openstack/nova master: WIP: Move conductor wait_until_ready() delay before manager init https://review.openstack.org/598353 | |
| 21:19:10 | dansmith | mriedem: can we see if this helps? ^ | |
| 21:20:05 | mriedem | we sure can | |
| 21:21:58 | mriedem | i didn't know conductor_api.wait_until_ready existed | |
| 21:22:01 | mriedem | so see, i did need you | |
| 21:22:25 | dansmith | you need better grep skills, that's all | |
| 21:25:26 | mriedem | i even said in my patch after WPIing it something like "we should really wait until conductor is ready, but what makes it 'ready'" | |
| 21:25:31 | mriedem | i guess this | |
| 21:25:44 | melwitt | wait_until_ready, of course | |
| 21:25:50 | melwitt | (I didn't know about it either) | |
| 21:25:55 | mriedem | ConductorAPI.easy_button() | |
| 21:26:31 | mriedem | what i'd like to do, del nova.compute.resource_tracker | |
| 21:28:35 | melwitt | you and jaypipes and bauzas and everyone else | |
| 21:29:15 | dansmith | well, so far that patch is doing super awesome in the gate | |
| 21:30:40 | jaypipes | dansmith: which patch? | |
| 21:31:04 | jaypipes | damn it, I've got more reading back to do... | |
| 21:31:48 | dansmith | it's annoying that this didn't even capture some basic logs | |
| 21:32:47 | dansmith | unless something else just broke real bad | |
| 21:35:46 | dansmith | ...which is the case, woot. | |
| 21:42:09 | mriedem | jebus h c | |
| 21:42:41 | lbragstad | all the grep skillz you need is just one plugin away | |
| 21:43:13 | mriedem | ctrl+shift+f my man | |
| 21:47:50 | efried | how does a guy install a pycharm plugin? | |
| 21:51:05 | jaypipes | efried: sudo apt install vim? | |
| 21:51:40 | lbragstad | git clone https://github.com/$USER/dotfiles | |
| 21:53:33 | efried | found it. Thanks for nothing, snarks | |
| 21:54:16 | zigo | jaypipes: Real man use joe editor ... | |
| 21:59:39 | jaypipes | zigo: luckily, I'm not a real man. | |