| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-03-21 | |||
| 20:55:35 | efried | but I guess you'll find out :) | |
| 20:55:51 | sean-k-mooney | i was trying not to say that out loud but yes | |
| 20:57:20 | sean-k-mooney | i should proably file a bug for this. ya the next issue is the zvm sdk | |
| 20:57:57 | sean-k-mooney | i think i fixed this error actully it complingin about the python version support | |
| 20:58:45 | sean-k-mooney | i shoudl proably file a bug for this. shoudl this be a RC2 thing | |
| 21:00:57 | openstackgerrit | Merged openstack/nova-specs master: Re-propose count quota usage from placement https://review.openstack.org/645302 | |
| 21:04:36 | mnaser | im struggling to trace the path of failure but i have a fix for this :\ | |
| 21:07:02 | openstackgerrit | Mohammed Naser proposed openstack/nova master: wip: bdm: store empty object as connection_info by default https://review.openstack.org/645352 | |
| 21:07:27 | mnaser | if someone has a few cycles to spare, i'm going to keep digging but i don't know the code that well to know why it's being saved with 'null' | |
| 21:08:23 | sean-k-mooney | mnaser: if the value is ever set to None it will be serialised to 'null' | |
| 21:08:55 | sean-k-mooney | i can try and take a look at it in a bit but i also dont know the bdm code that well | |
| 21:08:56 | mnaser | sean-k-mooney: yeah.. but i am trying to figure out why it would either be a) set to None or b) .get('connection_info') fails and returns None | |
| 21:09:30 | mnaser | oh interesting | |
| 21:09:34 | sean-k-mooney | if its trying to delete it before the block device mappings are constructed then that might be the issue | |
| 21:10:03 | mnaser | https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/virt/block_device.py#L284-L288 | |
| 21:10:14 | mnaser | by default, the connection_info field defaults to 'NULL' | |
| 21:10:23 | mnaser | so that means self['connection_info'] = None .. | |
| 21:10:40 | mriedem | isn't the instance.host set before that though? | |
| 21:10:46 | mriedem | the instance_claim sets the instance.host | |
| 21:10:47 | sean-k-mooney | ya which just porpagates that default | |
| 21:10:51 | mriedem | so you shouldn't get a local delete flow in the API | |
| 21:11:09 | mnaser | mriedem: this is a case where instance.host = None so i think what happens is that the build aborts a few times on the compute host | |
| 21:11:17 | mnaser | and then when it fails to build it, instance.host goes to None | |
| 21:11:31 | mnaser | because cinder blows up when it tries to create a volume and you're out of quota | |
| 21:11:57 | mnaser | this isnt a case of instance.host = None because we're in cell0, it's because we failed to build the instance N times and gave up | |
| 21:12:12 | mriedem | anything failing in _prep_block_device automatically aborts the build | |
| 21:12:14 | mriedem | there is no reschedule | |
| 21:12:38 | mriedem | https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/compute/manager.py#L2317 | |
| 21:12:43 | mriedem | especially if you hit overquota | |
| 21:12:52 | mnaser | yeah im def hitting overquota because of the error logs | |
| 21:13:01 | mnaser | "Failed to create block device for instance due to exceeding volume related resource quota. Error: VolumeSizeExceedsAvailableQuota: Requested volume or snapshot exceeds allowed gigabytes quota. Requested 80G, quota is 6144G and 6080G has been consumed.: OverQuota: VolumeSizeExceedsAvailableQuota: Requested volume or snapshot exceeds allowed gigabytes quota. Requested 80G, quota is 6144G and 6080G has been consumed." | |
| 21:13:23 | mriedem | that should reset the instance.host to None here https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/compute/manager.py#L2018 | |
| 21:13:23 | mnaser | so that code is getting exercised | |
| 21:13:45 | mriedem | this is booting a volume from an image yeah? | |
| 21:13:46 | mnaser | which means a follow up delete will result in a local delete path? | |
| 21:13:47 | mnaser | yeah | |
| 21:14:02 | mriedem | so it blows here https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/virt/block_device.py#L741 | |
| 21:14:27 | mnaser | yup, and the block device connection_info is set to null at this point | |
| 21:15:02 | mnaser | note if i quickly hit the db, i see it flap from NULL (actual SQL null, when a new record is created) to null (json-ified null, when the save happens, with a missing connection_info) | |
| 21:15:43 | mriedem | probably b/c of this https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/virt/block_device.py#L681 | |
| 21:15:53 | mriedem | if connection_info_string != self._bdm_obj.connection_info: | |
| 21:15:56 | mriedem | if '' != None: | |
| 21:16:24 | mnaser | mriedem: more accurately if 'null' != None afaik | |
| 21:16:30 | mriedem | oh right yeah | |
| 21:16:42 | mnaser | hence i think this will fix it https://review.openstack.org/#/c/645352/ | |
| 21:16:44 | mriedem | ok and then this blows up right? https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/compute/utils.py#L1096 | |
| 21:16:50 | mriedem | i mean, that is true, | |
| 21:16:54 | mriedem | then jsonutils.loads(bdm.connection_info).get('connector') | |
| 21:16:55 | mriedem | blows up | |
| 21:17:02 | mnaser | yeah | |
| 21:17:40 | mnaser | that's as far as i got, but i don't know what triggers a save() which pushes the json stuff in the db in the failing path | |
| 21:18:14 | mriedem | that code is rife with tricky decorators that save changes on methods | |
| 21:18:16 | mriedem | so could be one of those | |
| 21:18:20 | mnaser | https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/virt/block_device.py#L645 | |
| 21:18:27 | mnaser | so if `refresh_connection_info` is called at any given moment | |
| 21:18:37 | mnaser | https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/virt/block_device.py#L648-L650 | |
| 21:18:40 | mnaser | will return | |
| 21:18:44 | mnaser | and then it will call the decorator to save | |
| 21:19:09 | mnaser | self['connection_info'] by default is None | |
| 21:19:24 | mriedem | i don't think refresh_connection_info would be getting called during spawn | |
| 21:19:40 | mnaser | the only place i noticed calls it is refresh_conn_infos | |
| 21:19:43 | mriedem | but yeah that update_db decorator is what could be doing it | |
| 21:20:18 | sean-k-mooney | efried: .. we pin our lower constating for warlock to one explcitly blacklisted by python-glance client... | |
| 21:20:22 | mnaser | ah | |
| 21:20:23 | sean-k-mooney | the fun continues | |
| 21:20:31 | mriedem | mnaser: i think that's only called here https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/compute/manager.py#L1779 | |
| 21:20:33 | mriedem | on like move ops and such | |
| 21:20:44 | mnaser | indeed thats the only reference to it that i find | |
| 21:21:23 | efried | sean-k-mooney: Presumably it doesn't hurt to elevate the warlock l-c to... whatever glanclient is using | |
| 21:21:41 | sean-k-mooney | it is useing an older version and there is no newer version | |
| 21:21:57 | mnaser | ah shit | |
| 21:21:59 | sean-k-mooney | we pin to 1.3.0 which was relwased in 2016 | |
| 21:22:11 | sean-k-mooney | they use 1.2.0 | |
| 21:22:16 | mriedem | mnaser: which release is this? | |
| 21:22:21 | mnaser | rocky | |
| 21:23:02 | mriedem | it could be somewhere in here that the changes to connection_info get saved https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/compute/manager.py#L2554 | |
| 21:23:26 | sean-k-mooney | efried: im goint to try lowerering it | |
| 21:23:42 | sean-k-mooney | the constratin we have is from when we intoduced lower-constratits | |
| 21:23:56 | sean-k-mooney | so im not sure its actully the min version we need | |
| 21:24:12 | mnaser | terminate_instance seems to get bdms | |
| 21:24:39 | mriedem | mnaser: you wouldn't get there when the server is deleted, | |
| 21:24:42 | mriedem | because the instance.host is None | |
| 21:24:44 | mnaser | yeah | |
| 21:24:49 | sean-k-mooney | efried: actully looking at requirements.txt we dont actully depend on it directly | |
| 21:25:45 | efried | Not surprising. | |
| 21:28:23 | mriedem | mnaser: anyway, it's probably not worth trying to figure out where in that pile of spaghetting the bdm.save is getting called, | |
| 21:28:32 | mriedem | we shouldn't save 'null' in the connection_info | |
| 21:28:48 | mriedem | so your change is probably sane on it's own | |
| 21:29:00 | mnaser | mriedem: yeah.. i was just trying to find a way to have some sort of tests but yeah | |
| 21:29:10 | mnaser | also i just realized that wouldn't even fix it | |
| 21:29:12 | mriedem | get_stashed_volume_connector is very old so i'm kind of surprised someone is just hitting this now | |
| 21:29:40 | mnaser | https://github.com/openstack/nova/blob/67ac57b3258d4d7476fa544b3dfef7296e220ad2/nova/virt/block_device.py#L284-L288 | |
| 21:30:16 | mnaser | where i thought we were getting 'None' because .get("connection_info") was returning an empty field, it was actually set, but to 'null'.. so yeah | |
| 21:30:19 | mriedem | i'm not sure what that has to do with it - that's code that runs before things blow up | |
| 21:30:46 | mnaser | the assumption in my fix that self['connection_info'] doesn't exist and the fact we get None is because there is no 'connection_info' key | |
| 21:31:04 | mriedem | _transform is called to convert the BlockDeviceMapping object into a DriverVolImageBlockDevice object before the compute manager calls attach() on it | |
| 21:31:08 | mriedem | from _prep_block_device | |
| 21:31:11 | mriedem | it's extremely confusing | |
| 21:31:21 | mnaser | but it seems that 'connection_info' key always exists, but it can be set to None. so the 'None' value comes from the fact that it's *actually* equal to 'None' | |
| 21:31:54 | mriedem | loads(None) should raise the TypeError though | |