Earlier  
Posted Nick Remark
#openstack-nova - 2021-01-22
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 stephenfin I'll have to poke cdent or efried when they're about, to see if they have any suggestions
16:40:08 lbragstad downgrade gabbi
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
17:23:50 sean-k-mooney lyarwood: im basically done with it and it looks ready to merge IMO
17:24:04 kashyap melwitt: ... so we should see more fine-grained info. And I was hoping to hurl a useful bit at one of the US-based libvirt developers :D
17:24:05 sean-k-mooney lyarwood: but it need a second core to review
17:24:17 melwitt kashyap: ack
17:25:10 kashyap melwitt: Oh, wait ... I first didn't see this error is _actually_ libvirt error. Looks like it's not
17:25:43 sean-k-mooney lyarwood: specifclly i was refering to https://review.opendev.org/q/topic:%22bp%252Fsupport-interface-attach-with-qos-ports%22+(status:open%20OR%20status:merged) if you are still lookign for somethign easy to review
17:26:15 melwitt kashyap: yeah it's not emitting an error afaik. it's just that we keep checking the job status and it shows it one block from the end and it stays that way for about 4 minutes and then we give up

Earlier   Later