| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-11-22 | |||
| 18:30:33 | melwitt | yeah. I'm just saying it brought the action log to my attention as a thing to use more regularly | |
| 18:30:46 | sean-k-mooney | yep | |
| 18:30:58 | melwitt | because prior to that, the only time I've seen action log used is when you're like "who deleted this instance and on what date" | |
| 18:31:29 | sean-k-mooney | did that come up on the mailing list | |
| 18:31:45 | sean-k-mooney | the fact the userid was missing or somthing like that | |
| 18:31:46 | melwitt | and I know, some other clouds use it on a regular basis, just in yahoo when I was there, they didn't. so maybe other people don't | |
| 18:31:57 | gregwork | so there is an instance id in the python traceback of nova-compute.log | |
| 18:32:06 | gregwork | failed to attach xxx to for id | |
| 18:32:10 | gregwork | let me try that | |
| 18:34:40 | gregwork | im guessing the instance id in this line is not actually the instance uuid ? | |
| 18:34:44 | gregwork | 2019-11-22 12:26:56.077 8 ERROR nova.compute.manager [req-a25aba4e-952f-431e-bb85-1e2a45f62e3b d16f2bc26e91f8221042c91c61d0c4f7e7ae57a09507d54809f0279e3d6ee29e f4e6856a85b14ecc99b494159f28e425 - 424dfc884bcd46e7915e62495d6b569c 424dfc884bcd46e7915e62495d6b569c] [instance: 1e65006f-58ee-470d-9111-522d5c63094d] Failed to attach 176cca17-3f02-4fcd-884d-a4bd74ad5943 at /dev/vdb: ProcessExecutionError: Unexpected | |
| 18:34:45 | gregwork | error while running command. | |
| 18:34:56 | gregwork | doing an openstack server even list 1e65006f-58ee-470d-9111-522d5c63094d | |
| 18:34:59 | gregwork | says its unknown | |
| 18:35:15 | gregwork | *event | |
| 18:35:31 | sean-k-mooney | am you might need to pass a --deleted flag | |
| 18:35:35 | sean-k-mooney | if we support that | |
| 18:36:04 | gregwork | there is no --deleted flag | |
| 18:36:11 | gregwork | at least not in my osc | |
| 18:36:29 | sean-k-mooney | looking at the api i dont see one either | |
| 18:36:50 | gregwork | melwitt: seemed to think this was a thing, hence the "show when something was deleted" | |
| 18:37:34 | melwitt | yeah, I know it used to. that was the one use I saw in yahoo. let me take a quick look | |
| 18:37:53 | melwitt | ah ok | |
| 18:38:14 | melwitt | you have to do openstack --os-compute-api-version 2.21 openstack server event list | |
| 18:38:24 | sean-k-mooney | i assume if do an openstack server show with that uuid i assume it give you nothing | |
| 18:38:35 | melwitt | apparently ability to show deleted was added in 2.21 version of the api | |
| 18:38:56 | melwitt | https://docs.openstack.org/python-openstackclient/latest/cli/command-objects/server-event.html#server-event-list | |
| 18:39:12 | gregwork | is that api available in queens ? | |
| 18:39:29 | sean-k-mooney | oh yes that is mentioned in the api ref too | |
| 18:39:36 | melwitt | gregwork: yes https://docs.openstack.org/nova/latest/reference/api-microversion-history.html#id19 | |
| 18:39:48 | melwitt | added in mitaka | |
| 18:41:56 | gregwork | No server with a name or ID of '1e65006f-58ee-470d-9111-522d5c63094d' exists. | |
| 18:41:56 | gregwork | (openstack) server event list 1e65006f-58ee-470d-9111-522d5c63094d | |
| 18:41:56 | gregwork | $ openstack --os-compute-api-version 2.21 | |
| 18:42:15 | melwitt | sean-k-mooney: I dunno, I see userid when I do openstack server event list abd23967-2dd5-42ea-b96b-a226ee07ad44 --long | |
| 18:42:27 | melwitt | I'm gonna try on my devstack | |
| 18:42:42 | sean-k-mooney | melwitt: yes but it was added i think in stien or rocky | |
| 18:43:12 | sean-k-mooney | i think specificly for the how deleted my vm case you mentioned | |
| 18:43:21 | melwitt | sigh, wtf it's not working for me either | |
| 18:44:25 | melwitt | what am I missing here... | |
| 18:45:10 | sean-k-mooney | same "openstack --os-compute-api-version 2.21 --os-cloud openstack server event list cef12383-3f43-44cf-be52-218a4da30c0a" fails | |
| 18:45:43 | melwitt | gregwork: ok well the trusty legacy client works nova instance-action-list d7446288-688b-4a44-be78-008aa1ca524c | |
| 18:46:15 | melwitt | sean-k-mooney: I bet it's some underlying osc thing where it can't get deleted servers. I don't know. have to dig into what's going on there | |
| 18:46:49 | gregwork | | attach_volume | req-a25aba4e-952f-431e-bb85-1e2a45f62e3b | Error | 2019-11-22T17:26:54.000000 | 2019-11-22T17:26:56.000000 | | |
| 18:46:49 | gregwork | | create | req-b76ac906-148b-497a-8d87-72a65be367bd | - | 2019-11-22T17:26:28.000000 | 2019-11-22T17:26:52.000000 | | |
| 18:46:59 | melwitt | HALLELUJAH | |
| 18:47:17 | gregwork | so there is an error being observed but nothing seems to react to it | |
| 18:47:28 | gregwork | horizon/heat all just whistle by | |
| 18:47:59 | melwitt | yup. because the instance is still in a working state, it's not put into ERROR | |
| 18:47:59 | gregwork | "volume error? cool story bro" | |
| 18:48:06 | melwitt | lol | |
| 18:48:08 | melwitt | well, | |
| 18:48:39 | melwitt | as you have noticed there's no task/status api and if there are any they're not unified, | |
| 18:49:05 | melwitt | so our only way of communicating errors for asynchronous operations is basically ERROR state and 'server events' | |
| 18:49:11 | sean-k-mooney | ya i would guess heat did not check the responce | |
| 18:49:28 | sean-k-mooney | i think attach is blocking so it should have been return to heat | |
| 18:49:33 | melwitt | yeah, I mean, heat could probably do something. but I don't know that much about heat | |
| 18:50:07 | gregwork | the heat behavior is it sits there | |
| 18:50:20 | gregwork | no errors, just waiting | |
| 18:50:30 | gregwork | it eventually times out when its auth token expires | |
| 18:51:13 | melwitt | we don't put the instance into ERROR because it's in a perfectly healthy state, it's just the attach didn't work, which sucks, but it doesn't mean the instance is broken or unusable. so that's why we don't do ERROR state. other than that, the API is async so return code will be 202 ACCEPTED but it can obviously fail after that point after the request goes async | |
| 18:51:46 | sean-k-mooney | melwitt: which api is async? | |
| 18:52:04 | melwitt | sean-k-mooney: is attach not async? | |
| 18:52:32 | sean-k-mooney | its respocne code is listed as 200 | |
| 18:52:36 | melwitt | I assumed it must be based on the behavior. gregwork did you call volume attach or something else? | |
| 18:52:36 | sean-k-mooney | which would imply not | |
| 18:53:10 | sean-k-mooney | https://docs.openstack.org/api-ref/compute/?expanded=attach-a-volume-to-an-instance-detail#attach-a-volume-to-an-instance | |
| 18:53:12 | gregwork | i create a data volume with os::cinder::volume then attach it using ::volumeattach | |
| 18:53:33 | sean-k-mooney | gregwork: are you attaching via nova or cinder | |
| 18:53:38 | sean-k-mooney | oh heat | |
| 18:53:38 | gregwork | cinder | |
| 18:53:39 | melwitt | yeah it shows as a cast | |
| 18:53:41 | gregwork | via heat | |
| 18:53:51 | melwitt | attach_volume is a cast (async) | |
| 18:53:57 | gregwork | i mean i assume os::cinder::herpderp means its talking to cinder ? | |
| 18:54:14 | sean-k-mooney | the we are returning the wrong responce code it should be a 202 as you said | |
| 18:54:14 | gregwork | (heat that is) | |
| 18:54:21 | melwitt | fun | |
| 18:54:40 | gregwork | i try and bring only quality bugs to these channels :) | |
| 18:55:00 | melwitt | THANKS gregwork | |
| 18:55:39 | gregwork | heh np :P | |
| 18:55:43 | melwitt | sigh, yeah that sucks. I dunno why that's not a 202 | |
| 18:56:11 | melwitt | gregwork: I think probably it's (heat) creating the volume in cinder and then calls nova to attach | |
| 18:56:14 | sean-k-mooney | i guess its calling https://docs.openstack.org/api-ref/block-storage/v3/index.html?expanded=attach-volume-to-a-server-detail#attach-volume-to-a-server | |
| 18:56:28 | sean-k-mooney | that one does return a 202 | |
| 18:56:47 | melwitt | oh what? I didn't know that cinder had an api to attach to instance. it must just call us | |
| 18:57:04 | melwitt | I don't remember any of this stuff | |
| 18:57:14 | sean-k-mooney | all the proxy apis lol | |
| 18:57:28 | melwitt | can we achieve a full mesh proxy to one another | |
| 18:57:48 | sean-k-mooney | that is the dream | |
| 18:58:09 | sean-k-mooney | also i grab the curl command form osc via --debug | |
| 18:58:10 | sean-k-mooney | http://paste.openstack.org/show/786587/ | |
| 18:58:31 | sean-k-mooney | i adde a valid token and that is what we get form the nova api | |
| 18:59:08 | melwitt | yeah but you need to do that with the instance actions api | |
| 18:59:15 | melwitt | it works fine in the legacy client | |
| 18:59:28 | melwitt | so there's something buggy with how osc is calling instance actions api | |
| 18:59:42 | sean-k-mooney | right so osc is first hitting the /server endpoing for some reason | |
| 18:59:57 | melwitt | oh, yeah. that was my assumption that it does something like that across the board | |
| 19:00:19 | melwitt | which will break nova commands that are supposed to work on deleted things | |
| 19:00:22 | sean-k-mooney | right so its makeing an extra api call before trying to call the events api | |