| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2021-01-22 | |||
| 16:33:06 | stephenfin | lbragstad: oh, the project_id was different /o\ | |
| 16:33:38 | stephenfin | I even wrote a quick unit test that proved it worked, but I figured the unit test was wrong because the functional test was obviously correct /o\ | |
| 16:33:55 | lbragstad | stephenfin right - so the tenancy check was doing what it should | |
| 16:34:07 | lbragstad | but i found something else that's concerning and i'm not sure how it's working now | |
| 16:34:33 | lbragstad | stephenfin https://review.opendev.org/c/openstack/placement/+/772061/1/placement/tests/functional/gabbits/usage-secure-rbac.yaml | |
| 16:35:04 | lbragstad | i added negative tests to ensure project users from anther project can't fetch usage information for projects they don't have authorization on | |
| 16:35:52 | stephenfin | Oh, I noticed that when I was debugging the rule | |
| 16:35:59 | lbragstad | and the project admin persona test fails consistently because the rule:admin_api rule is appended to the new default, regardless of what we're setting up in fixture | |
| 16:36:53 | lbragstad | i went splunking through the enforce_new_default configuration behavior and it appears to be working as expected | |
| 16:37:28 | stephenfin | Hmm, I'm guessing misconfiguration _somewhere_. We have a lot of examples of project reader policies in nova and I'm pretty sure we have unit tests for them all that prove that other project admins can't access $RESOURCE | |
| 16:37:34 | lbragstad | but that deprecated rule check get appended to the default rule magically | |
| 16:38:08 | lbragstad | yeah... i started looking at the placement fixture structure to see if it was doing something unexpected (not cleaning things up properly)? | |
| 16:38:16 | stephenfin | gibi: There's the BP https://blueprints.launchpad.net/nova/+spec/configurable-instance-hostnames | |
| 16:38:35 | gibi | stephenfin: on it | |
| 16:38:58 | lbragstad | but i couldn't find anything that stuck out - and i'm not that knowledgeable about gabbi/placement tests | |
| 16:39:31 | lbragstad | so - i pushed what i have based on your patch... but if you pull that down you should be able to recreate the issue, it'll fail the check gate | |
| 16:39:43 | stephenfin | Neither am I. They're tough to debug. I can't figure out how to even get logs from the placement server | |
| 16:40:08 | lbragstad | downgrade gabbi | |
| 16:40:08 | stephenfin | I'll have to poke cdent or efried when they're about, to see if they have any suggestions | |
| 16:41:05 | efried | Howdy. TLDR or should I read scrollback? | |
| 16:41:35 | lbragstad | if you're using gabbi > 2.0.0 the output logging is broken | |
| 16:41:37 | lbragstad | https://github.com/cdent/gabbi/issues/287 | |
| 16:41:54 | stephenfin | lbragstad++ Well that makes my life much easier | |
| 16:42:02 | zigo | gibi: I just looked, Eventlet claims compat with ... python 3.7 ! :/ | |
| 16:42:17 | lbragstad | stephenfin downgrading to 1.49.0 works for me | |
| 16:42:33 | lbragstad | in the sense that you can actually capture stdout in tests | |
| 16:42:48 | gibi | zigo: based on that we cannot even release OpenStack :/ | |
| 16:43:01 | zigo | Yeah... | |
| 16:43:10 | zigo | Or I stay forever on Buster... | |
| 16:43:11 | stephenfin | efried: We're seeing some unusual policy behavior in placement as part of the RBAC work, and I was looking for a way to get more info from the placement server to debug. Sounds like it's just a downgrade of gabbi that's needed ^ | |
| 16:43:30 | efried | cool | |
| 16:45:43 | openstackgerrit | Stephen Finucane proposed openstack/nova-specs master: Update spec for configurable-instance-hostnames https://review.opendev.org/c/openstack/nova-specs/+/772065 | |
| 16:46:03 | stephenfin | gibi: And there's the spec amendment ^ | |
| 16:46:13 | stephenfin | bauzas, lyarwood, artom also ^ | |
| 16:47:52 | gibi | stephenfin: thanks | |
| 16:50:05 | zigo | Great, tests.patcher_test.test_fork_after_monkey_patch fails in Py 3.9 ... :/ | |
| 16:53:48 | melwitt | lyarwood: I wanted to ask you about a failure in test_volume_swap I saw yesterday in the gate, have you seen a thing where it doesn't finish the copy and emits "COPY block job progress, current cursor: 1073741823 final cursor: 1073741824" a lot of times, showing that the cursor is only 1 from the end? | |
| 16:54:45 | melwitt | https://zuul.opendev.org/t/openstack/build/a078a17aa9924517b329cafc3f54fed4/log/controller/logs/screen-n-cpu.txt#11115 | |
| 16:57:44 | lyarwood | melwitt: I've not seen it 1 block (!?) away and not finish no | |
| 16:58:16 | lyarwood | melwitt: it's typically much greater than that, did it get there pretty quickly and then stall? | |
| 16:58:17 | melwitt | ack | |
| 16:58:37 | melwitt | erm.. let me check. | |
| 16:59:33 | melwitt | lyarwood: yeah looks like it actually. got there and then stuck on the last block for 4 minutes | |
| 17:00:12 | melwitt | do you suppose this could be similar to problems with live migration where we've needed post copy/auto converge? | |
| 17:00:20 | melwitt | seems weird | |
| 17:00:48 | lyarwood | yeah it might be but I can't think that the cirros image would be writing that much to the volume if at all | |
| 17:00:58 | lyarwood | I think we write timestamps during the test and that's it | |
| 17:01:18 | melwitt | hm ok | |
| 17:06:12 | lyarwood | melwitt: we could write this up as a Ubuntu QEMU bug again and see if upstream can help debug this further | |
| 17:06:37 | lyarwood | melwitt: assuming there's something we can log that would help them | |
| 17:08:08 | melwitt | lyarwood: good idea, let me go through and collect more data (if there is more) and I'll open one if I can find more to go on | |
| 17:08:20 | kashyap | melwitt: So ... just reading the scrollback; that "current" and "final" cursors differing means: the copy (i.e. migration w/ storage) hasn't finished succesfully | |
| 17:08:46 | kashyap | In the past we've hit that, and debugged on list; and I recall filing a libvirt RFE to fix that ... let me check | |
| 17:09:18 | melwitt | kashyap: yeah, I think I understood that but the weird thing is it quickly gets to the last block and then stays stuck there for 4 minutes until the test wait in tempest times out and kills it | |
| 17:09:37 | kashyap | Hmm | |
| 17:09:44 | kashyap | melwitt: Yeah, this definitely looks ome something new | |
| 17:10:17 | kashyap | Because in that old behaviour, libvirt was just making "educated guess" when the syncing has finished | |
| 17:10:41 | melwitt | I see | |
| 17:10:42 | kashyap | Especially the "current cursor" terminology looks new to me. I haven't seen the word "cursor" in this error's context before | |
| 17:11:05 | lyarwood | this is blockCopy and not blockRebase btw kashyap | |
| 17:11:09 | kashyap | melwitt: I don't want to bore you with a long bug, but for the record, here it is: https://bugzilla.redhat.com/show_bug.cgi?id=1382165 | |
| 17:11:11 | openstack | bugzilla.redhat.com bug 1382165 in libvirt "virDomainGetBlockJobInfo: Adjust job reporting based on QEMU stats & the "ready" field of `query-block-jobs`" [Unspecified,Closed: nextrelease] - Assigned to pkrempa | |
| 17:11:22 | kashyap | lyarwood: I see; nod | |
| 17:11:24 | lyarwood | I think we dropped that workaround a while ago | |
| 17:11:43 | kashyap | Yep | |
| 17:11:49 | kashyap | But just for clarity, blockCopy() is a _superset_ of blockRebase() | |
| 17:11:55 | melwitt | kashyap: any data/background helps :) | |
| 17:12:07 | kashyap | (So whatever worked, or failed w/ Rebase(), will also fails equal w/ Copy()) | |
| 17:12:29 | lyarwood | yeah https://review.opendev.org/c/openstack/nova/+/729596 removed it | |
| 17:12:38 | kashyap | melwitt: But yeah; filing an upstream Ubuntu QEMU bug would be cool to start with | |
| 17:13:01 | melwitt | k, I'll collect data points and write something up. thanks for the hints both | |
| 17:13:05 | kashyap | lyarwood: Yep, recall it as much, it just reminded me of it. | |
| 17:14:50 | lyarwood | if anyone has anything they'd like me review please let me know | |
| 17:14:51 | kashyap | melwitt: The libvirtd log might have some interesting stuff in there. /me tries to fish it out | |
| 17:14:53 | lyarwood | PLEASE :| | |
| 17:15:07 | kashyap | LOL | |
| 17:15:12 | melwitt | I feel for you. clicky clicky clicky | |
| 17:15:18 | melwitt | click all the things | |
| 17:15:29 | kashyap | lyarwood: I finished it the next day it came; I'm a free man! | |
| 17:15:44 | stephenfin | kashyap: no one likes a show off | |
| 17:15:48 | kashyap | stephenfin: LOL | |
| 17:15:51 | lyarwood | ./ban kashyap | |
| 17:15:57 | lyarwood | ^_^ | |
| 17:16:05 | kashyap | stephenfin: I know; the secret pleasure of doing the right thing goes away if one brags | |
| 17:18:19 | kashyap | melwitt: I'm looking at the log file here: https://storage.gra.cloud.ovh.net/v1/AUTH_dcaab5e32b234d56b626f72581e3644c/zuul_opendev_logs_a07/771749/1/check/nova-next/a078a17/controller/logs/libvirt/index.html | |
| 17:18:25 | kashyap | Hope that's the correct log tree | |
| 17:20:39 | melwitt | kashyap: yes that's right | |
| 17:21:02 | kashyap | melwitt: Unrelated: I know that the "controller" directory has the compute logs, but why is it named "controller"? | |
| 17:21:27 | kashyap | (Because there's also the "compute" top-level directory, which has its own QEMU/libvirt logs. It's always tripping me up | |
| 17:21:37 | melwitt | kashyap: in the case of multi-node job, to identify the "main" node vs one of the additional compute nodes | |
| 17:21:53 | kashyap | I see | |
| 17:22:04 | melwitt | in this case you're in the right place bc the swap volume got stuck on the main node | |
| 17:22:33 | melwitt | if it had happened on the other compute node, you'd want to look in the compute1 dir | |
| 17:22:47 | kashyap | melwitt: It looks like so; because I don't see the failure in this libvirtd log | |
| 17:22:58 | kashyap | And these copy failures are logged to libvirtd. So let me look in the other one | |
| 17:23:10 | sean-k-mooney | lyarwood: you should review gibis qos attach | |
| 17:23:16 | sean-k-mooney | series | |
| 17:23:20 | melwitt | kashyap: would there be a failure though? there was no error. it's just that the cursor never moved from the last block | |
| 17:23:41 | kashyap | melwitt: Not a failure per-se; but in Gate, we have libvirt log filters enabled | |
| 17:23:49 | melwitt | and the test timed out at the tempest level as a result of never seeing the 'available' status for the volume | |