| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-05-24 | |||
| 18:00:48 | openstackgerrit | Lars Kellogg-Stedman proposed openstack/nova master: provide interface-scoped nameserver information https://review.openstack.org/467699 | |
| 18:00:50 | mriedem | and through the magic of driver.get_block_device_info(instance, bdms) converst that list to a list of DriverBlockDevice objects | |
| 18:00:57 | mriedem | which are wrappers around a BlockDeviceMapping objec | |
| 18:00:58 | mriedem | *object | |
| 18:22:44 | tidwellr | I'm probably grasping at straws, but is there a chance anyone here can make sense of this error http://paste.openstack.org/show/610594 seen on stable/mitaka? | |
| 18:23:12 | mriedem | gmann: weren't you talking about something with hide addresses earlier today? ^ | |
| 18:25:02 | mriedem | tidwellr: the instance isn't in the req cache for some reason https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/compute/hide_server_addresses.py#L62 | |
| 18:25:34 | tidwellr | mriedem: that's what it looks like to me, the question is why | |
| 18:25:53 | mriedem | it should be cached here https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/compute/servers.py#L443 | |
| 18:25:55 | mriedem | so not sure | |
| 18:26:14 | mriedem | unless the extension's show() method is processed before the instance is cached? | |
| 18:26:21 | mriedem | sdague: ^ any idea how that craziness works? | |
| 18:26:28 | tidwellr | what's weird is the user that reported this can run operations from the CLI just fine, but has an app that invokes the API directly and that is where we see this | |
| 18:27:17 | tidwellr | I'm wondering if it is related to auth/domains somehow, again I'm grasping at straws here | |
| 18:28:43 | sdague | mriedem: I need you to summarize the question | |
| 18:28:49 | mriedem | sdague: heh, | |
| 18:28:58 | mriedem | how do extensions work in the api :) | |
| 18:29:07 | artom | mriedem, what I'm seeing is that the instance is obtained here: https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/compute/hide_server_addresses.py#L62 | |
| 18:29:24 | mriedem | artom: it has to be None | |
| 18:29:26 | artom | Is that from cache? Or is it missing from the bd | |
| 18:29:32 | mriedem | it's not in the cache | |
| 18:29:39 | mriedem | AttributeError: 'NoneType' object has no attribute 'get' | |
| 18:30:01 | mriedem | sdague: do the servers extensions for show() happen after the actual servers controller is called? | |
| 18:30:22 | sdague | yes, iirc. This is mitaka? | |
| 18:30:23 | mriedem | sdague: i.e. we do GET /servers/{server_id} and store the instance in the request cache here https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/compute/servers.py#L443 | |
| 18:30:26 | mriedem | yeah | |
| 18:30:33 | sdague | that's my recollection | |
| 18:30:43 | sdague | tidwellr: what was going on before the stack trace? | |
| 18:31:23 | mriedem | i see other server extensions like for security groups handle this differently | |
| 18:32:54 | mriedem | every other extension does something like https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/compute/servers.py#L443 | |
| 18:32:56 | mriedem | oops | |
| 18:33:01 | mriedem | req.get_db_instance(server['id']) | |
| 18:33:10 | mriedem | they don't use the id parameter in the 'show' method | |
| 18:33:10 | tidwellr | sdague: I've got a user who is making calls to v2.1/<project ID>/servers/<server ID> | |
| 18:33:25 | tidwellr | in this case, it's a GET | |
| 18:33:27 | sdague | tidwellr: what kind of calls? GET calls? | |
| 18:33:38 | sdague | tidwellr: is it immediately after a POST? | |
| 18:35:07 | tidwellr | sdague: no, we're troublshooting this call against an instance that's been running for a while | |
| 18:35:29 | sdague | tidwellr: do you have any local custom extensions? | |
| 18:35:42 | tidwellr | sdague: no, we don't | |
| 18:35:47 | sdague | hmmm | |
| 18:36:10 | mriedem | https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/wsgi.py#L619 | |
| 18:36:15 | mriedem | what are **action_args here? | |
| 18:37:18 | sdague | that's basically the peek of the actions dict iirc | |
| 18:37:33 | mriedem | but if this is a GET | |
| 18:37:40 | sdague | so it should be nothing | |
| 18:37:46 | mriedem | ok, so that would be the issue | |
| 18:37:55 | sdague | it really shouldn't be | |
| 18:38:13 | mriedem | if id passed to the show() method is None https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/compute/hide_server_addresses.py#L62 | |
| 18:38:42 | mriedem | note that every other show() extension gets the instance from the cache doing something like this https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/compute/config_drive.py#L52 | |
| 18:38:44 | mriedem | from the response object | |
| 18:38:55 | mriedem | resp_obj.obj['servers']['id'] | |
| 18:40:27 | sdague | mriedem: no, that's different | |
| 18:40:45 | sdague | https://github.com/openstack/nova/blob/d3297e2e73a2578ffc2987facf5b894667056f97/nova/api/openstack/compute/config_drive.py#L32 | |
| 18:41:35 | sdague | get_db_instance goes into the request instance cache | |
| 18:41:52 | sdague | that other thing is where it's munging the resp obj before it comes back | |
| 18:42:14 | sdague | tidwellr: is there anything notable before that part of the log? | |
| 18:42:56 | tidwellr | sdague: let me take another look, not that I recall | |
| 18:43:00 | tidwellr | just a sec | |
| 18:43:33 | openstackgerrit | Matt Riedemann proposed openstack/nova master: Provide original fault message when BFV fails https://review.openstack.org/467715 | |
| 18:46:03 | tidwellr | sdague: my logs are pretty quiet leading up this | |
| 18:46:33 | tidwellr | sdague: it only shows up when the tenant makes the call to show the instance | |
| 18:46:51 | mriedem | i don't know what would be different between CLI and a direct curl request to the api | |
| 18:47:16 | sdague | tidwellr: ..... why is the instance UUID uppercased? | |
| 18:47:19 | sdague | 5100C340-8967-4DB1-97F7-BFA1C155F250 | |
| 18:47:20 | tidwellr | the difference I'm thinking is the way the user is getting a token | |
| 18:48:07 | sdague | because, you know, that could actually totally cause this problem if that id is not case matched to the db id | |
| 18:48:12 | melwitt | mriedem: I was thinking I'm gonna just write a functional test that tests the counting across cells for server group members, without trying to do anything more complicated with scheduling. I'm thinking to try to set up two cell databases, put an instance in each that is associated with the same group, and see if the counting function returns the right thing | |
| 18:48:26 | sdague | because... mysql | |
| 18:49:02 | mriedem | melwitt: that's probably a good idea | |
| 18:49:18 | melwitt | cool | |
| 18:49:50 | dansmith | melwitt: not that you asked me, but I agree too :) | |
| 18:50:09 | tidwellr | sdague: that makes sense, I hadn't noticed that :) | |
| 18:50:26 | mriedem | ah... | |
| 18:50:31 | melwitt | dansmith: votes of confidence always good :) | |
| 18:50:31 | sdague | tidwellr: yeh, I was just looking for things that seemed odd | |
| 18:50:33 | mriedem | and because this extension is using the id from the request, | |
| 18:50:37 | mriedem | and not what's in the resp_obj | |
| 18:50:42 | mriedem | which could be different case | |
| 18:50:48 | sdague | tidwellr: no, it's like a legit nova bug | |
| 18:51:09 | sdague | it's just not an edge I've seen people cross | |
| 18:51:12 | dansmith | sdague: not a legit bug, just *like* a legit bug, yes? | |
| 18:51:39 | mriedem | tidwellr: can you report a bug? | |
| 18:51:51 | sdague | tidwellr: could you figure out if the user works if they use the lower case version of the uuid? | |
| 18:51:58 | tidwellr | sdague: sure, I can do that | |
| 18:52:00 | mriedem | there is a simple fix i can think of, which is make that extension behave like the rest, | |
| 18:52:11 | sdague | mriedem: it is behaving like the rest | |
| 18:52:23 | sdague | mriedem: I'm trying to understand why you think it isn't :) | |
| 18:52:43 | mriedem | https://github.com/openstack/nova/blob/stable/mitaka/nova/api/openstack/compute/hide_server_addresses.py#L62 is looking up the instance in the cache using the id parameter to the show() method | |
| 18:52:52 | mriedem | which is passed in via the wsgi extension processing code, right? | |
| 18:52:56 | melwitt | mysql is case-insensitive by default, right? it's the request instance cache in the REST API that is case-sensitive (python) | |
| 18:53:05 | mriedem | and i'm assuming is what came in on the request, the {server_id} part that is upper case | |
| 18:53:19 | sdague | mriedem: sure | |
| 18:53:40 | mriedem | sdague: if you look at all of the other extensions, they do something like resp_obj.obj['server']['id'] | |
| 18:53:49 | sdague | oh, right | |
| 18:53:53 | mriedem | which is presumably the id for the server obj that's coming out of the db | |
| 18:53:56 | mriedem | which is why it matches | |
| 18:54:02 | sdague | right, makes sense | |
| 18:54:13 | mriedem | please state that i'm correct for the record | |
| 18:54:17 | mriedem | let the record show | |