[Kimchi-devel] [RFC] [Wok] Issue 141 - Track asynchronous tasks in user request log

[Lucio Correia]

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