| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2019-11-22 | |||
| 18:18:44 | sean-k-mooney | then it sound like its doing the right thing | |
| 18:18:52 | gregwork | its like you didnt do anything at all | |
| 18:19:06 | sean-k-mooney | yes because it tried to attach and failed | |
| 18:19:07 | melwitt | did you check the instance actions api? :P | |
| 18:19:17 | sean-k-mooney | i was just going to mention that | |
| 18:19:28 | melwitt | I won! | |
| 18:19:33 | melwitt | jk | |
| 18:19:37 | sean-k-mooney | that is where the error if it was going to be reported would likely end up | |
| 18:19:47 | gregwork | in cinder or nova ? | |
| 18:19:51 | melwitt | nova | |
| 18:20:39 | melwitt | I don't know how it looks on horizon, but it's like 'openstack server event list' on the openstackclient | |
| 18:21:40 | gregwork | so i cant openstack server event list <that instance> because we fixed it just now (configuring multipathd) and redeployed the stack | |
| 18:21:40 | sean-k-mooney | in horizon there is the action log for the instace | |
| 18:21:47 | gregwork | where would it be in the infra | |
| 18:21:51 | sean-k-mooney | when you click into it | |
| 18:21:52 | gregwork | compute or control plane | |
| 18:22:04 | gregwork | the logs you are looking for | |
| 18:22:42 | sean-k-mooney | gregwork: if you have not deleted the instnace it would still be in the instance event log | |
| 18:22:54 | melwitt | by redeployed do you mean wiped the database? yeah, what sean-k-mooney said | |
| 18:22:57 | gregwork | it was deleted when the stack was cleaned up | |
| 18:23:07 | gregwork | so all i have are the overcloud logs on the various nodes | |
| 18:23:18 | melwitt | I thought you could still see for deleted no? because one of the actions will be 'deleted' | |
| 18:23:29 | melwitt | that's how you can check who deleted an instance and what time, for example | |
| 18:23:42 | sean-k-mooney | if you have not done a db archive/purge it should still be there | |
| 18:23:53 | gregwork | id need the uuid of the instance wouldnt i ? the instances were redployed from a templated name | |
| 18:23:59 | gregwork | or is there a list all events | |
| 18:24:19 | sean-k-mooney | yes you would | |
| 18:25:03 | melwitt | you need uuid | |
| 18:25:30 | sean-k-mooney | you would be hitting this api endpoint https://docs.openstack.org/api-ref/compute/?&expanded=list-actions-for-server-detail#list-actions-for-server | |
| 18:26:31 | sean-k-mooney | speaking of which is the volume attachmet api call blocking or async https://docs.openstack.org/api-ref/compute/?&expanded=attach-a-volume-to-an-instance-detail#attach-a-volume-to-an-instance | |
| 18:27:11 | sean-k-mooney | it returns a 200 so i assume its blocking but i expected it to be async | |
| 18:27:36 | melwitt | gregwork: ok, well, just fyi the "action log" 'openstack server event list' is a place to see failed actions that did not actually touch the instance. and there's a new change proposed to add more detail to errors that go in there, to aid in communication to the user https://review.opendev.org/694428 | |
| 18:28:14 | efried | melwitt or mriedem or dansmith: Could I please get +A on three simple test-only tech debt reductions (johnthetubaguy just +2ed 'em so they're freshhhh): https://review.opendev.org/#/q/topic:use-base-test-code+(status:open+OR+status:merged) | |
| 18:28:30 | efried | johnthetubaguy: thanks for that btw | |
| 18:28:30 | melwitt | gregwork: this came up recently with a change in behavior in the resize and migration APIs too http://lists.openstack.org/pipermail/openstack-discuss/2019-November/011040.html | |
| 18:29:57 | sean-k-mooney | melwitt: ya although in that context that is because we changed it to async so you have to check the action log going forward | |
| 18:30:22 | sean-k-mooney | melwitt: if attach is currently blocking the we woudl expect the error to be returned there | |
| 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:33 | sean-k-mooney | if its async then it would only be in the action log | |
| 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 | $ openstack --os-compute-api-version 2.21 | |
| 18:41:56 | gregwork | (openstack) server event list 1e65006f-58ee-470d-9111-522d5c63094d | |
| 18:41:56 | gregwork | No server with a name or ID of '1e65006f-58ee-470d-9111-522d5c63094d' exists. | |
| 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 | | create | req-b76ac906-148b-497a-8d87-72a65be367bd | - | 2019-11-22T17:26:28.000000 | 2019-11-22T17:26:52.000000 | | |
| 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: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 | gregwork | "volume error? cool story bro" | |
| 18:47:59 | melwitt | yup. because the instance is still in a working state, it's not put into ERROR | |
| 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? | |