[RFC] [Wok] Issue 141 - Track asynchronous tasks in user request log
User Request Log needs to be improved to track some special requests of Kimchi, Ginger and Gingerbase which, when successful, generate an asynchronous task to do the actual job. Examples are cloning vms, upgrading software and creating volumes. Currently those requests are always logged as successful, even when the generated asynchronous task fails for some reason. My proposal to solve this issue is to: 1 - Change the wording of all existing user log messages for requests that generate asynchronous task. i.e.: change "Clone vm 'name'" to "Start to clone vm 'name'" 2 - Log a couple of additional entries in AsyncTask for each task executed: - "Started Kimchi task ID 100: /plugins/kimchi/vms/name/clone" when async task is started successfully - "Successfully completed Kimchi task ID 100: /plugins/kimchi/vms/name/clone" when async task works fine *or* "Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to clone vm 'name')" when async task fails 3 - Backend/UI work to recognize the new type of entry: { "time": "11:49:55", "date": "2016-08-12" "zone": "BRT", timezone continues the same "req": "TASK", use a specific "request" type for differentiation, i.e. TASK "user": "", "ip": "", user and ip will be blank, since we are out of scope of the request "status": 1002, create 3 new status codes, say 1000 for "task started", 1001 for "task completed successfully", 1002 for "task failed" "app": "kimchi", app will be informed by each plugin (backend change) "msgCode": "WOKASYNC0002L", async task log message Id, based on status "detCode": "KCHVM00001E", failed task details: original exception }
{"target_uri": "/plugins/kimchi/vms/name/clone", "task_id": 100} msgCode params
{"vm": "name"} detCode params (optional)
Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to blah blah) English log message
A corresponding log entry in text file for this example would be: [2016-08-12 11:49:55 BRT] TASK 1002 kimchi Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to clone vm 'name') With this implementation it will be possible for an admin to see: * how much time a task took/is taking to run * which other requests were done between task start and finish Thanks, -- Lucio Correia Software Engineer IBM LTC Brazil
Go for it. Daniel On 08/12/2016 04:45 PM, Lucio Correia wrote:
User Request Log needs to be improved to track some special requests of Kimchi, Ginger and Gingerbase which, when successful, generate an asynchronous task to do the actual job. Examples are cloning vms, upgrading software and creating volumes.
Currently those requests are always logged as successful, even when the generated asynchronous task fails for some reason.
My proposal to solve this issue is to:
1 - Change the wording of all existing user log messages for requests that generate asynchronous task. i.e.: change "Clone vm 'name'" to "Start to clone vm 'name'"
2 - Log a couple of additional entries in AsyncTask for each task executed: - "Started Kimchi task ID 100: /plugins/kimchi/vms/name/clone" when async task is started successfully - "Successfully completed Kimchi task ID 100: /plugins/kimchi/vms/name/clone" when async task works fine *or* "Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to clone vm 'name')" when async task fails
3 - Backend/UI work to recognize the new type of entry: { "time": "11:49:55", "date": "2016-08-12" "zone": "BRT", timezone continues the same
"req": "TASK", use a specific "request" type for differentiation, i.e. TASK
"user": "", "ip": "", user and ip will be blank, since we are out of scope of the request
"status": 1002, create 3 new status codes, say 1000 for "task started", 1001 for "task completed successfully", 1002 for "task failed"
"app": "kimchi", app will be informed by each plugin (backend change)
"msgCode": "WOKASYNC0002L", async task log message Id, based on status
"detCode": "KCHVM00001E", failed task details: original exception }
{"target_uri": "/plugins/kimchi/vms/name/clone", "task_id": 100} msgCode params
{"vm": "name"} detCode params (optional)
Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to blah blah) English log message
A corresponding log entry in text file for this example would be: [2016-08-12 11:49:55 BRT] TASK 1002 kimchi Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to clone vm 'name')
With this implementation it will be possible for an admin to see: * how much time a task took/is taking to run * which other requests were done between task start and finish
Thanks,
Hi Lucio, Task is an internal mechanism to Wok and its plugins execute long time processing. So that is not part of user knowledge. Adding a log record as Task will make the user confused IMO. So my proposal is: when the Task is started in the backend, add a log record and set its status as 'pending' Once the Task is completed (with success or not), change the log record to success or failure according to what happened there. To do that you will need to find a way to query a log entry in the JSON file and edit/replace it to the updated entry. What do you think about it? Regards, Aline Manera On 08/12/2016 04:45 PM, Lucio Correia wrote:
User Request Log needs to be improved to track some special requests of Kimchi, Ginger and Gingerbase which, when successful, generate an asynchronous task to do the actual job. Examples are cloning vms, upgrading software and creating volumes.
Currently those requests are always logged as successful, even when the generated asynchronous task fails for some reason.
My proposal to solve this issue is to:
1 - Change the wording of all existing user log messages for requests that generate asynchronous task. i.e.: change "Clone vm 'name'" to "Start to clone vm 'name'"
2 - Log a couple of additional entries in AsyncTask for each task executed: - "Started Kimchi task ID 100: /plugins/kimchi/vms/name/clone" when async task is started successfully - "Successfully completed Kimchi task ID 100: /plugins/kimchi/vms/name/clone" when async task works fine *or* "Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to clone vm 'name')" when async task fails
3 - Backend/UI work to recognize the new type of entry: { "time": "11:49:55", "date": "2016-08-12" "zone": "BRT", timezone continues the same
"req": "TASK", use a specific "request" type for differentiation, i.e. TASK
"user": "", "ip": "", user and ip will be blank, since we are out of scope of the request
"status": 1002, create 3 new status codes, say 1000 for "task started", 1001 for "task completed successfully", 1002 for "task failed"
"app": "kimchi", app will be informed by each plugin (backend change)
"msgCode": "WOKASYNC0002L", async task log message Id, based on status
"detCode": "KCHVM00001E", failed task details: original exception }
{"target_uri": "/plugins/kimchi/vms/name/clone", "task_id": 100} msgCode params
{"vm": "name"} detCode params (optional)
Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to blah blah) English log message
A corresponding log entry in text file for this example would be: [2016-08-12 11:49:55 BRT] TASK 1002 kimchi Failure on Kimchi task ID 100: /plugins/kimchi/vms/name/clone (KCHVM0001E failed to clone vm 'name')
With this implementation it will be possible for an admin to see: * how much time a task took/is taking to run * which other requests were done between task start and finish
Thanks,
On 22-08-2016 13:52, Aline Manera wrote:
Hi Lucio,
Hi,
Task is an internal mechanism to Wok and its plugins execute long time processing. So that is not part of user knowledge.
User log functionality is for admins, not regular users, right?
Adding a log record as Task will make the user confused IMO.
I don't think so, have you seen my patches running? I've changed the UI too. It's pretty clear IMHO.
So my proposal is: when the Task is started in the backend, add a log record and set its status as 'pending' Once the Task is completed (with success or not), change the log record to success or failure according to what happened there.
To do that you will need to find a way to query a log entry in the JSON file and edit/replace it to the updated entry.
What do you think about it?
To do that we will also need to differentiate in wok/control/base.py the type of request (if it generates task or not) and I tried to avoid that with my design. Also, I believe the way I proposed to do it makes it more clear for the guy debugging through logs what's happening behind the scenes. So, IMHO, it will increase code complexity to differentiate tasks through some variable, handle it in base.py, code for changing log entries, for no real gain.
Regards, Aline Manera
Regards, -- Lucio Correia Software Engineer IBM LTC Brazil
On 08/22/2016 02:39 PM, Lucio Correia wrote:
On 22-08-2016 13:52, Aline Manera wrote:
Hi Lucio,
Hi,
Task is an internal mechanism to Wok and its plugins execute long time processing. So that is not part of user knowledge.
User log functionality is for admins, not regular users, right?
Correct. But even though an admin does not know how the backend works. He/she only wants to know which actions were taken in the system.
Adding a log record as Task will make the user confused IMO.
I don't think so, have you seen my patches running? I've changed the UI too. It's pretty clear IMHO.
No! I am concerned about the backend part by now.
So my proposal is: when the Task is started in the backend, add a log record and set its status as 'pending' Once the Task is completed (with success or not), change the log record to success or failure according to what happened there.
To do that you will need to find a way to query a log entry in the JSON file and edit/replace it to the updated entry.
What do you think about it?
To do that we will also need to differentiate in wok/control/base.py the type of request (if it generates task or not) and I tried to avoid that with my design.
It is already done in the control/base.py. Look for generate_action_handler_task() function in control/base.py All the actions which rely on Task are done by this function.
Also, I believe the way I proposed to do it makes it more clear for the guy debugging through logs what's happening behind the scenes.
This feature is not for debug! It is for an admin identifies which actions were taken in the system in a visual way.
So, IMHO, it will increase code complexity to differentiate tasks through some variable, handle it in base.py, code for changing log entries, for no real gain.
Regards, Aline Manera
Regards,
On 22-08-2016 15:29, Aline Manera wrote:
On 08/22/2016 02:39 PM, Lucio Correia wrote:
On 22-08-2016 13:52, Aline Manera wrote:
Hi Lucio,
Hi,
Task is an internal mechanism to Wok and its plugins execute long time processing. So that is not part of user knowledge.
User log functionality is for admins, not regular users, right?
Correct. But even though an admin does not know how the backend works. He/she only wants to know which actions were taken in the system.
I think it's important for him/her to know how much time a task is taking, and which other requests were done between the start and end of it. My proposal covers it.
Adding a log record as Task will make the user confused IMO.
I don't think so, have you seen my patches running? I've changed the UI too. It's pretty clear IMHO.
No! I am concerned about the backend part by now.
Yes, you can use the backend to download the log file as well. It's a working example of this RFC.
So my proposal is: when the Task is started in the backend, add a log record and set its status as 'pending' Once the Task is completed (with success or not), change the log record to success or failure according to what happened there.
To do that you will need to find a way to query a log entry in the JSON file and edit/replace it to the updated entry.
What do you think about it?
To do that we will also need to differentiate in wok/control/base.py the type of request (if it generates task or not) and I tried to avoid that with my design.
It is already done in the control/base.py.
Look for generate_action_handler_task() function in control/base.py All the actions which rely on Task are done by this function.
That's not correct. I'm tracking AsyncTask instances. Severeal POST requests on collections generate an AsyncTask (Kimchi examples: create storage volume, create guest, etc.). Others don't. They will need to be differentiated as I told. On the other side, not all APIs handled by generate_action_handler_task() use AsyncTask instance, and will also need to be differentiated, increasing code complexity. Kimchi examples for generate_action_handler_task(): do not generate AsyncTask: restart guest, shutdown guest.... generate AsyncTask: migrate guest, clone guest
Also, I believe the way I proposed to do it makes it more clear for the guy debugging through logs what's happening behind the scenes.
This feature is not for debug! It is for an admin identifies which actions were taken in the system in a visual way.
Let's say analysis instead of debug. It's good to know how much time a task took to finish, and which other requests/tasks were run meanwhile.
So, IMHO, it will increase code complexity to differentiate tasks through some variable, handle it in base.py, code for changing log entries, for no real gain.
Regards, Aline Manera
Regards,
-- Lucio Correia Software Engineer IBM LTC Brazil
I will send new RFC after talking to Aline offline. -- Lucio Correia Software Engineer IBM LTC Brazil
participants (3)
-
Aline Manera -
Daniel Henrique Barboza -
Lucio Correia