[Kimchi-devel] [PATCH] [Wok 4/7] Log AsyncTask success or failure

[Aline Manera]

On 09/01/2016 01:08 PM, Lucio Correia wrote:
> On 01-09-2016 10:45, Aline Manera wrote:
>>
>>
>> On 08/31/2016 06:06 PM, Lucio Correia wrote:
>>> * Add plugin and log_id attributes to AsyncTask
>>> * Create _log() function to log AsyncTask exit status
>>> * Create auxiliary method to save log entry ID for a task
>>> * Handle WokException separately in order to add it in
>>> translatable form to user log
>>>
>>> Signed-off-by: Lucio Correia <luciojhc at linux.vnet.ibm.com>
>>> ---
>>>   src/wok/asynctask.py | 46
>>> ++++++++++++++++++++++++++++++++++++++++------
>>>   src/wok/i18n.py      |  2 ++
>>>   2 files changed, 42 insertions(+), 6 deletions(-)
>>>
>>> diff --git a/src/wok/asynctask.py b/src/wok/asynctask.py
>>> index 021b76c..633c96f 100644
>>> --- a/src/wok/asynctask.py
>>> +++ b/src/wok/asynctask.py
>>> @@ -25,10 +25,13 @@ import time
>>>   import traceback
>>>   import uuid
>>>
>>> -
>>> -from wok.exception import InvalidOperation, OperationFailed
>>> +from wok.exception import InvalidOperation, OperationFailed,
>>> WokException
>>> +from wok.reqlogger import RequestRecord, ASYNCTASK_REQUEST_METHOD
>>> +from wok.utils import get_plugin_from_uri
>>>
>>>
>>> +MSG_FAILED = 'WOKASYNC0002L'
>>> +MSG_SUCCESS = 'WOKASYNC0001L'
>>>   tasks_queue = {}
>>>
>>>
>>> @@ -43,27 +46,54 @@ def clean_old_tasks():
>>>                   task.remove()
>>>
>>
>>> +def save_request_log_id(log_id, task_id):
>>> +    tasks_queue[task_id].log_id = log_id
>>> +
>>> +
>>
>> You can use "tasks_queue[task_id].log_id = log_id " directly in the 
>> code.
>> You are replacing one line code by one function. I don't see much gain
>> on it specially while reviewing the code where you can grab the function
>> to simply to understand it.
>
> Yes I could. But I did prefer to create this function due to code 
> maintenance. This is the module that knows how to deal with tasks, so 
> if that changes (we just did that moving tasks from objstore to 
> memory), we change only code here and not through all the code.
>

Ok. I got your point.

> It's also good to avoid another module to access a control structure 
> like tasks_queue directly and do some bad stuff.
>
>

tasks_queue is a global variable =)

>
>>
>>>   class AsyncTask(object):
>>>       def __init__(self, target_uri, fn, opaque=None, kill_cb=None):
>>> +        # task info
>>>           self.id = str(uuid.uuid1())
>>>           self.target_uri = target_uri
>>>           self.fn = fn
>>>           self.kill_cb = kill_cb
>>> +        self.log_id = None
>>
>>> +        self.plugin = get_plugin_from_uri(target_uri)
>>
>> The target_uri may be anything!
>> Usually on Kimchi, we have a pattern to be the the plugin base URI +
>> resource URI but it may be not true to every plugin.
>> I suggest to get that info from cherrypy
>
> I see. I will try to use cherrypy, but I'm not sure it will work due 
> to my past work with user logs and requests.
>
>
>>
>>> +        self.timestamp = time.time()
>>> +
>>> +        # task context
>>>           self.status = 'running'
>>>           self.message = 'The request is being processing.'
>>> -        self.timestamp = time.time()
>>>           self._cp_request = cherrypy.serving.request
>>>           self.thread = threading.Thread(target=self._run_helper,
>>>                                          args=(opaque, 
>>> self._status_cb))
>>>           self.thread.setDaemon(True)
>>>           self.thread.start()
>>> +
>>>           # let's prevent memory leak in tasks_queue
>>>           clean_old_tasks()
>>>           tasks_queue[self.id] = self
>>>
>>> -    def _status_cb(self, message, success=None):
>>
>>> +    def _log(self, code, status, exception=None):
>>> +        RequestRecord(
>>> +            {'code': code, 'params': {'target_uri': self.target_uri}},
>>> +            exception,
>>> +            self.log_id,
>>> +            app=self.plugin,
>>> +            req=ASYNCTASK_REQUEST_METHOD,
>>> +            status=status,
>>> +            user='',
>>> +            ip='',
>>> +        ).log()
>>> +
>>
>> Isn't this function the same you created on Patch 1? Can't you reuse the
>> other one?
>
> Yes, now that that function is in control/utils.py I believe I can use 
> it here.
>
>
>>
>>> +    def _status_cb(self, message, success=None, exception=None):
>>>           if success is not None:
>>> -            self.status = 'finished' if success else 'failed'
>>> +            if success:
>>> +                self._log(MSG_SUCCESS, 200)
>>> +                self.status = 'finished'
>>> +            else:
>>> +                self._log(MSG_FAILED, 400, exception)
>>> +                self.status = 'failed'
>>>
>>>           if message.strip():
>>>               self.message = message
>>> @@ -72,10 +102,14 @@ class AsyncTask(object):
>>>           cherrypy.serving.request = self._cp_request
>>>           try:
>>>               self.fn(cb, opaque)
>>> +        except WokException, e:
>>> +            cherrypy.log.error_log.error("Error in async_task %s " %
>>> self.id)
>>> + cherrypy.log.error_log.error(traceback.format_exc())
>>> +            cb(e.message, success=False, exception=e)
>>>           except Exception, e:
>>>               cherrypy.log.error_log.error("Error in async_task %s " %
>>> self.id)
>>> cherrypy.log.error_log.error(traceback.format_exc())
>>> -            cb(e.message, False)
>>> +            cb(e.message, success=False)
>>>
>>>       def remove(self):
>>>           try:
>>> diff --git a/src/wok/i18n.py b/src/wok/i18n.py
>>> index 7ba7c24..4893be7 100644
>>> --- a/src/wok/i18n.py
>>> +++ b/src/wok/i18n.py
>>> @@ -59,6 +59,8 @@ messages = {
>>>       "WOKPROXY0001E": _("Unable to (re)start system's nginx.service.
>>> Details: '%(error)s'"),
>>>
>>>       # These messages (ending with L) are for user log purposes
>>> +    "WOKASYNC0001L": _("Successfully completed task 
>>> '%(target_uri)s'"),
>>> +    "WOKASYNC0002L": _("Failed to complete task '%(target_uri)s'"),
>>>       "WOKCOL0001L": _("Request made on collection"),
>>>       "WOKRES0001L": _("Request made on resource"),
>>>       "WOKROOT0001L": _("User '%(username)s' login"),
>>
>
>