| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-01-14 | |||
| 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/ | |
| 21:46:15 | mriedem | so let's say we delete a compute service hosting no instances and we delete 1000 ironic compute nodes records and related resource providers, | |
| 21:46:42 | mriedem | the next time you restart that compute service (or update_available_resources runs), nova-compute will just create 1000 new compute nodes records with uuids that match the ironic nodes that service is hosting, | |
| 21:46:50 | mriedem | and create 1000 new resource providers with those same uuids | |
| 21:47:19 | mriedem | if we don't delete the resource providers, the compute_nodes records are gone either way i think | |
| 21:47:24 | mriedem | when the services table record is deleted | |
| 21:48:02 | mriedem | because of this https://github.com/openstack/nova/blob/da98f4ba4554139b3901103aa0d26876b11e1d9a/nova/db/sqlalchemy/api.py#L406 | |
| 21:48:21 | efried | If I'm following, you're saying that deleting the service is going to cause deletion-and-recreation of all the ironic nodes even today? Just with different-than-optimal timing? | |
| 21:48:45 | mriedem | now if for some reason that service is only hosting 800 of those ironic nodes, n-cpu will create 800 compute_nodes records and you'll have orphaned 200 resource providers in placement | |
| 21:49:03 | mriedem | it will delete all of the compute_nodes table records for that service, yes | |
| 21:49:09 | mriedem | and always did | |
| 21:49:35 | mriedem | if some other compute service starts managing that other 200 nodes, then cool - their providers are already in placement | |
| 21:49:46 | mriedem | but if not, you're reporting things to the scheduler that might not be managed anywhere | |
| 21:50:25 | mriedem | the scheduler should filter those out but you could get NoValidHost if you're like CERN and have a real low config for how many placement allocation candidates you want to get back | |
| 21:51:37 | efried | I will try to express this in the bug report. | |
| 21:52:03 | mriedem | i could be wrong of course, i don't have a multinode ironic deployment to play with | |
| 21:52:14 | mriedem | but we could easily simulate this in functional tests | |
| 21:52:43 | mriedem | i guess the bug is, in the case of ironic, we should either delete 0 or all providers in placement for the related compute nodes | |
| 21:53:26 | mriedem | sure is fun needing nova to mirror everything to placement isn't it o-) | |
| 21:58:37 | efried | mriedem: https://bugs.launchpad.net/nova/+bug/1811726 -- please see if I expressed this correctly, kthx | |
| 21:58:38 | openstack | Launchpad bug 1811726 in OpenStack Compute (nova) "Deleting compute service only deletes "first" ironic node from placement" [Undecided,New] | |
| 22:03:22 | mriedem | commented | |
| 22:03:34 | mriedem | but i don't think that cleanup orphan code you pointed out is going to clean up orphans | |
| 22:04:17 | mriedem | that code in update_available_resource is for nodes that the driver no longer reports (user deleted the ironic node in the ironic api) but nova was still tracking it | |