Earlier  
Later
New Search
Posted Nick Remark
#openstack-nova - 2019-01-14
20:39:49 ade_lee we're waiting to see if the volume is "in-use",
20:40:08 ade_lee but thats checking if cinder thinks the volume is in use
20:40:23 ade_lee and not if the instance thinks the volume is attached ..
20:40:44 ade_lee so how/what do I wait on instead?
20:41:19 ade_lee mriedem, the specific gate job that is failing is here -- http://logs.openstack.org/67/628667/13/check/grenade-devstack-barbican/613998f/
20:41:22 mriedem that should be sufficient,
20:41:31 mriedem nova tells cinder when the local connection happens for the guest vm,
20:41:38 mriedem and that's what should change the volume status to in-use
20:41:40 smcginnis Yeah, I didn't think we marked it as in-use until things were ready.
20:42:26 ade_lee mriedem, smcginnis interesting -- any idea whats going on in the above test then?
20:42:28 smcginnis Could it be that the local device is getting set wrong for some reason? http://logs.openstack.org/67/628667/13/check/grenade-devstack-barbican/613998f/job-output.txt.gz#_2019-01-14_15_22_54_281033
20:43:49 ade_lee note - the code we are executing is here -- https://github.com/openstack/barbican-tempest-plugin/blob/master/barbican_tempest_plugin/tests/scenario/manager.py line 326
20:45:12 mriedem is something specifically waiting on /dev/vdb ?
20:45:28 mriedem because nova, or at least the libvirt driver, totally ignores the user-requested device name for the attach
20:45:35 mriedem so https://github.com/openstack/barbican-tempest-plugin/blob/master/barbican_tempest_plugin/tests/scenario/manager.py#L328 is kind of pointless to pass the device kwarg
20:46:00 mriedem https://github.com/openstack/barbican-tempest-plugin/blob/master/barbican_tempest_plugin/tests/scenario/manager.py#L346
20:46:03 mriedem looks like it probably is
20:46:05 ade_lee mriedem, well - that fails when we actually try to write to the device ..
20:46:32 smcginnis There's only a /dev/vda
20:46:56 mriedem this is the POST to attach the volume it looks like http://logs.openstack.org/67/628667/13/check/grenade-devstack-barbican/613998f/job-output.txt.gz#_2019-01-14_15_21_32_860642
20:47:01 ade_lee mriedem, so this is the test -- https://github.com/openstack/barbican-tempest-plugin/blob/master/barbican_tempest_plugin/tests/scenario/test_volume_encryption.py line 101
20:47:41 mriedem wtf this is nice http://logs.openstack.org/67/628667/13/check/grenade-devstack-barbican/613998f/logs/screen-n-cpu.txt.gz#_Jan_14_15_14_46_115508
20:47:43 mriedem unrelated though
20:48:36 mriedem http://logs.openstack.org/67/628667/13/check/grenade-devstack-barbican/613998f/logs/screen-n-cpu.txt.gz#_Jan_14_15_20_47_770302
20:48:40 mriedem Jan 14 15:20:47.770302 ubuntu-xenial-rax-ord-0001683696 nova-compute[343]: INFO nova.virt.libvirt.driver [None req-c127b555-17c3-4ce7-9c75-b3df8b653f76 tempest-VolumeEncryptionTest-1809383190 tempest-VolumeEncryptionTest-1809383190] [instance: 1f45a2d6-3811-4b85-a13b-68c3eb605dea] Ignoring supplied device name: /dev/vdb
20:49:00 mriedem http://logs.openstack.org/67/628667/13/check/grenade-devstack-barbican/613998f/logs/screen-n-cpu.txt.gz#_Jan_14_15_20_48_012939
20:49:00 mriedem says it's attaching it to /dev/vdb though
20:49:05 mriedem Jan 14 15:20:48.012939 ubuntu-xenial-rax-ord-0001683696 nova-compute[343]: INFO nova.compute.manager [None req-c127b555-17c3-4ce7-9c75-b3df8b653f76 tempest-VolumeEncryptionTest-1809383190 tempest-VolumeEncryptionTest-1809383190] [instance: 1f45a2d6-3811-4b85-a13b-68c3eb605dea] Attaching volume ed7fc802-ba1c-4639-8723-47ed02bd11de to /dev/vdb
20:51:11 lyarwood ade_lee: are you only seeing this with the _cryptsetup test?
20:51:13 mriedem hmm, i wonder if it's connected at sda
20:51:14 mriedem http://logs.openstack.org/67/628667/13/check/grenade-devstack-barbican/613998f/logs/screen-n-cpu.txt.gz#_Jan_14_15_20_51_033570
20:51:38 ade_lee lyarwood, seems so
20:53:22 mriedem something sure enjoys calling the barbican secrets API a lot during this attach flow
20:54:08 lyarwood ade_lee: if the _luks version of the test is passing I'd put money on there being an issue with how os-brick is wiring up the encrypted volume on the underlying host
20:54:22 mriedem Jan 14 15:20:51.786765 ubuntu-xenial-rax-ord-0001683696 nova-compute[343]: DEBUG os_brick.encryptors.cryptsetup [None req-c127b555-17c3-4ce7-9c75-b3df8b653f76 tempest-VolumeEncryptionTest-1809383190 tempest-VolumeEncryptionTest-1809383190] opening encrypted volume /dev/sda {{(pid=343) _open_volume /usr/local/lib/python2.7/dist-packages/os_brick/encryptors/cryptsetup.py:109}}
20:54:29 mriedem it's on sda but the test is looking for dev/vdb
20:54:48 lyarwood that's on the compute host itself
20:54:50 mriedem http://logs.openstack.org/67/628667/13/check/grenade-devstack-barbican/613998f/logs/screen-n-cpu.txt.gz#_Jan_14_15_20_51_786765
20:55:03 mriedem <target bus="virtio" dev="vdb"/>
20:56:09 ade_lee mriedem, not sure if I understand what that means -- does that mean we asked for it to be on vdb and it put it on sda instead?
20:57:09 mriedem maybe not, tempest is sshi'ing into the guest looking for it at vdb
20:57:14 mriedem if the sda thing is host only, then ignore me
20:57:24 mriedem lyarwood seems to know something about cryptsetup
20:57:37 mriedem i remember something about that coming up in berlin too
20:58:09 lyarwood unfortunately, yeah I'd like to drop support for it tbh
20:58:16 mriedem L22 https://etherpad.openstack.org/p/BER-volume-encryption-forum
20:59:03 lyarwood ade_lee: so os-brick currently hacks the device paths on the host to point the instance at the decrypted volume using the original encrypted device path.
21:01:21 ade_lee lyarwood, so os-brick is setting it up sda instead of vdb -- and luks is setting it up on vdb?
21:02:58 smcginnis I don't think so. /dev/vda should be the boot volume.
21:05:08 lyarwood ade_lee: os-brick points /dev/disk/by-id/scsi-360000000000000000e00000000010001 to the decrypted device on the host, for some reason I can't see the actual commands in the logs anymore.
21:13:03 ade_lee lyarwood, sorry - did you find anything? I'm looking at a couple runs -- one where it worked and one where it didn't - but not sure how to make heads or tails of it
21:13:40 lyarwood ade_lee: yeah sorry I can't see anything obvious on the host / os-brick side of things tbh
21:14:16 lyarwood ade_lee: /dev/disk/by-id/scsi-360000000000000000e00000000010001 should point to the decrypted device that in turn points to encrypted /dev/sda
21:15:09 ade_lee lyarwood, well sdb right?
21:18:31 lyarwood ade_lee: nope, this is on the host sorry
21:19:03 lyarwood ade_lee: like I said there's a load of hacks with this legacy encryptor to decrypt the volume on the host itself
21:19:35 ade_lee lyarwood, it seems to work intermittently .. so not sure whats going on
21:21:54 lyarwood ade_lee: hard to say but if we can't read/write to the device once it's connected within the instance then I'd start by looking at the devicemapper layer on the compute host itself.
21:23:16 lyarwood ade_lee: if it's intermittent it might be a race between os-brick connecting another device while also setting up the decrypt devices for this volume.
21:24:54 ade_lee lyarwood, would that show up in the logs somehow?
21:25:31 efried mriedem: Doesn't deleting the compute service remove its node provider(s) from placement?
21:27:43 lyarwood ade_lee: yeah, os-brick keeps reporting the device path as /dev/disk/by-id/scsi-360000000000000000e00000000010001 once each volume is connected on the host.
21:28:17 lyarwood ade_lee: we use `scsi-360000000000000000e00000000010001` as part of the device name when using cryptsetup to decrypt
21:31:27 lyarwood ade_lee: I need to head offline now but it does look like we are overloading the /dev/disk/by-id/scsi-360000000000000000e00000000010001 path during these tests somehow
21:31:42 lyarwood ade_lee: do you have an env to hand btw?
21:32:06 lyarwood ade_lee: I'd be interested to see what `qemu-img info /dev/vdb` has to say within the instance
21:32:10 ade_lee lyarwood, no - I've just been trying to run in the gate ..
21:32:57 lyarwood ade_lee: kk, I can take another look at this during the morning in EMEA if it ends up in a bug somewhere.
21:33:36 ade_lee lyarwood, thanks - I'll send you an email and/or open a bug
21:34:21 ade_lee lyarwood, oh -- this is interesting ..
21:34:43 ade_lee Jan 14 15:21:51.361579 ubuntu-xenial-rax-ord-0001683696 nova-compute[343]: : ProcessExecutionError: Unexpected error while running command.
21:34:43 ade_lee Jan 14 15:21:51.361319 ubuntu-xenial-rax-ord-0001683696 nova-compute[343]: Command failed with code 22: Device /dev/disk/by-id/scsi-360000000000000000e00000000010001 is not a valid LUKS device.
21:34:43 ade_lee Jan 14 15:21:51.361034 ubuntu-xenial-rax-ord-0001683696 nova-compute[343]: WARNING os_brick.encryptors.luks [None req-b8bc15a0-3faf-41ee-bda7-65ede3c3e432 tempest-VolumeEncryptionTest-1809383190 tempest-VolumeEncryptionTest-1809383190] isLuks exited abnormally (status 1): Device /dev/disk/by-id/scsi-360000000000000000e00000000010001 is not a valid LUKS device.
21:35:22 lyarwood ade_lee: as horrid as that is it's expected the first time we connect to an empty encrypted volume
21:35:43 ade_lee lyarwood, ok :)
21:35:44 lyarwood ade_lee: as c-vol hasn't had to write and thus encrypt any data to the volume
21:35:45 mriedem efried: should
21:35:49 mriedem efried: are you on master?
21:35:56 mriedem and is the api configured to talk to placement?
21:36:05 lyarwood ade_lee: so n-cpu comes along and ensures the LUKs / crypt headers are written to the volume before we use it
21:36:18 efried mriedem: I found the code. It looks like for ironic deployments, it'll only delete the "first" compute node (whatever that means in practice).
21:36:46 efried mriedem: cf https://github.com/openstack/nova/blob/da98f4ba4554139b3901103aa0d26876b11e1d9a/nova/api/openstack/compute/services.py#L244-L247 and https://github.com/openstack/nova/blob/da98f4ba4554139b3901103aa0d26876b11e1d9a/nova/objects/service.py#L308-L311
21:37:35 mriedem efried: sure enough
21:37:39 mriedem bugify it
21:38:40 efried mriedem: Well, a) I can't prove it (not having an ironic setup); but b) as jaypipes points out here, we might actually not want to do that: https://review.openstack.org/#/c/615677/17//COMMIT_MSG@30
21:39:12 efried but I can open a bug anyway :)
21:40:26 mriedem efried: well, the "has instances on them" is caught here https://github.com/openstack/nova/blob/da98f4ba4554139b3901103aa0d26876b11e1d9a/nova/api/openstack/compute/services.py#L232
21:41:34 efried mriedem: Yeah, I didn't see that pre-check, but knew placement would bounce the delete in any case if we got that far.
21:41:57 mriedem yeah that's also a relatively recent validation
21:42:02 efried mriedem: But do we really want to delete "potentially thousands" of compute node records from placement, assuming they're non-spawned?
21:42:42 mriedem ironic is special since we use the ironic node uuid to set the compute node uuid
21:42:45 mriedem so we can actually link those
21:42:48 mriedem which is also relatively recent...
21:42:50 mriedem rocky or queens
21:43:17 mriedem otherwise if you delete the service record and the compute_nodes records, the providers in placement would be orphaned if you restart the compute service which creates new compute nodes records with new uuids
21:43:34 efried mriedem: I saw code elsewhere to delete those orphans.
21:43:36 mriedem or just simply forget to stop the nova-compute service...
21:43:43 efried seems like a bass-ackwards way off doing it.
21:43:53 efried s/ff/f/
21:44:12 mriedem says the guy that +2d the change https://review.openstack.org/#/c/554920/

Earlier   Later