[Kimchi-devel] [PATCH] [Wok 3/7] Update Request Logger to handle AsyncTask status
Aline Manera
alinefm at linux.vnet.ibm.com
Thu Sep 1 16:48:46 UTC 2016
On 09/01/2016 01:31 PM, Lucio Correia wrote:
> On 01-09-2016 13:19, Aline Manera wrote:
>>
>>
>> On 09/01/2016 12:56 PM, Lucio Correia wrote:
>>> On 01-09-2016 10:35, Aline Manera wrote:
>>>>
>>>>
>>>> On 08/31/2016 06:06 PM, Lucio Correia wrote:
>>>>> * Add ID to each entry
>>>>> * Change log entry format to one JSON per line
>>>>> * Modify getRecords() to apply AsyncTask entry status
>>>>> to original request entry
>>>>>
>>>>> Signed-off-by: Lucio Correia <luciojhc at linux.vnet.ibm.com>
>>>>> ---
>>>>> src/wok/message.py | 2 +-
>>>>> src/wok/reqlogger.py | 142
>>>>> +++++++++++++++++++++++++++++----------------------
>>>>> 2 files changed, 82 insertions(+), 62 deletions(-)
>>>>>
>>>>> diff --git a/src/wok/message.py b/src/wok/message.py
>>>>> index ff4cbc9..28462b7 100644
>>>>> --- a/src/wok/message.py
>>>>> +++ b/src/wok/message.py
>>>>> @@ -51,7 +51,7 @@ class WokMessage(object):
>>>>> wok_app = cherrypy.tree.apps.get('', None)
>>>>>
>>>>> # get app from plugin path if specified
>>>>
>>>>> - if self.plugin:
>>>>> + if self.plugin and self.plugin != 'wok':
>>>>
>>>> Why is that needed? Why wok is different from the rest of the
>>>> application?
>>>
>>> This is consequence of returning 'wok' as default instead of None in
>>> get_plugin_from_request. I will rethink it in case I can return None
>>> there.
>>>
>>>>
>>>>> app = cherrypy.tree.apps.get(self.plugin, None)
>>>>> # if on request, try to get app from it
>>>>> elif cherrypy.request.app:
>>>>> diff --git a/src/wok/reqlogger.py b/src/wok/reqlogger.py
>>>>> index 9f1d2c8..2923d7c 100644
>>>>> --- a/src/wok/reqlogger.py
>>>>> +++ b/src/wok/reqlogger.py
>>>>> @@ -24,6 +24,7 @@ import logging
>>>>> import logging.handlers
>>>>> import os.path
>>>>> import time
>>>>> +import uuid
>>>>>
>>>>> from cherrypy.process.plugins import BackgroundTask
>>>>> from tempfile import NamedTemporaryFile
>>>>> @@ -32,7 +33,7 @@ from wok.config import config,
>>>>> get_log_download_path
>>>>> from wok.exception import InvalidParameter, OperationFailed
>>>>> from wok.message import WokMessage
>>>>> from wok.stringutils import ascii_dict
>>>>> -from wok.utils import remove_old_files
>>>>> +from wok.utils import plugin_root, remove_old_files
>>>>>
>>>>>
>>>>> # Log search setup
>>>>> @@ -62,6 +63,9 @@ UNSAFE_REQUEST_PARAMETERS = ['password', 'passwd']
>>>>> REQUEST_LOG_FILE = "wok-req.log"
>>>>> WOK_REQUEST_LOGGER = "wok_request_logger"
>>>>
>>>>
>>>>> +# AsyncTask handling
>>>>> +ASYNCTASK_REQUEST_METHOD = 'TASK'
>>>>> +
>>>>
>>>> I am curious to see how this constant is used.
>>>>
>>>>> class RequestLogger(object):
>>>>> def __init__(self):
>>>>> @@ -114,19 +118,17 @@ class RequestParser(object):
>>>>>
>>>>> return LOG_DOWNLOAD_URI % os.path.basename(fd.name)
>>>>>
>>>>> - def getTranslatedMessage(self, record, params, detParams):
>>>>> - code = record.get('msgCode', '')
>>>>> - app = record.get('app', 'wok')
>>>>> - plugin = None
>>>>> - if app != 'wok':
>>>>> - plugin = "/plugins/%s" % app
>>>>> -
>>>>
>>>>> + def getTranslatedMessage(self, message, error, app):
>>>>> + plugin = plugin_root.get(app, 'wok')
>>>>
>>>> Do not set 'wok' as plugin name. It is not true as wok is not a
>>>> plugin.
>>>
>>> The var is named plugin but it means app.. wok or any plugin. I may
>>> change the variable name.
>>>
>>>>
>>>>> + code = message.get('code', '')
>>>>> + params = message.get('params', {})
>>>>> msg = WokMessage(code, params, plugin)
>>>>> text = msg.get_text(prepend_code=False, translate=True)
>>>>>
>>>>> - detCode = record.get('detCode', '')
>>>>> - if detCode:
>>>>> - msg = WokMessage(detCode, detParams, plugin)
>>>>> + if error:
>>>>> + code = error.get('code', '')
>>>>> + params = error.get('params', {})
>>>>> + msg = WokMessage(code, params, plugin)
>>>>> text += ' ' + msg.get_text(prepend_code=True,
>>>>> translate=True)
>>>>>
>>>>> return text
>>>>> @@ -137,8 +139,40 @@ class RequestParser(object):
>>>>> for filename in glob.glob(self.baseFile + "-*[!.gz]"):
>>>>> records.extend(self.getRecordsFromFile(filename))
>>>>>
>>>>> - # Return ordered by latest events first
>>>>> - return sorted(records, key=lambda k: k['date'] + k['time'],
>>>>> + # sort records chronologically
>>>>> + sort = sorted(records, key=lambda k: k['info']['date'] +
>>>>> + k['info']['time'])
>>>>> +
>>>>
>>>>> + # normalize entries
>>>>> + normalized = {}
>>>>> + asynctask_updates = []
>>>>> + for record in sort:
>>>>
>>>>> + # async task entries are left to the end
>>>>
>>>> Why?
>>>
>>> Because they are just updates to the original request log entry. And
>>> the task log entry may be written before the task finishes since runs
>>> in separate thread.
>>>
>>
>> Ok. Please, add more comments related to that so it is easy to
>> understand the code proposal.
>
> OK
>
>>
>>>>
>>>>> + if record['info']['req'] == ASYNCTASK_REQUEST_METHOD:
>>>>> + asynctask_updates.append(record)
>>>>> + continue
>>>>> +
>>>>
>>>> Could you explain why do we need to add an specific 'req' information
>>>> for task?
>>>
>>> I use it to differentiate task finish log entries from regular request
>>> log entries.
>>>
>>>
>>
>> You can use the status parameter for that. We don't need an extra
>> parameter.
>
> I'm not creating a new parameter, I'm using method (request type)
> instead of status. So instead of POST, PUT, it will be TASK.
>
> It's the same right? Or there is a reason to not use request type?
> This is not showed to the user.
>
I'd say to do not mix things. A parameter related to HTTP methods should
not handle any other information.
Why do not use the status code? Wouldn't be the status code used by UI
to update the information to user?
>
>>
>>>>
>>>>> + # initial request entry: generate message text
>>>>> + message = record.pop('message')
>>>>> + error = record.pop('error', None)
>>>>> + plugin = record['info']['app']
>>>>> + text = self.getTranslatedMessage(message, error, plugin)
>>>>> + record['info']['message'] = text
>>>>> +
>>>>> + id = record.pop('id')
>>>>> + normalized[id] = record['info']
>>>>> +
>>>>> + # async task entries: update only status
>>>>> + for record in asynctask_updates:
>>>>> + id = record.pop('id')
>>>>> +
>>>>> + # task id may not exist, since GET requests are not
>>>>> logged but
>>>>> + # may generate tasks (i.e. AsyncResource)
>>>>> + if id in normalized:
>>>>> + normalized[id]['status'] = record['info']['status']
>>>>> +
>>>>> + # return results in chronological reverse order
>>>>> + return sorted(normalized.values(), key=lambda k: k['date'] +
>>>>> k['time'],
>>>>> reverse=True)
>>>>>
>>>>> def getRecordsFromFile(self, filename):
>>>>> @@ -151,34 +185,12 @@ class RequestParser(object):
>>>>> if not os.path.exists(filename):
>>>>> return []
>>>>>
>>>>> - # read records from file
>>>>> try:
>>>>> with open(filename) as f:
>>>>> line = f.readline()
>>>>> while line != "":
>>>>> - data = line.split(">>>")
>>>>> - if len(data) > 1:
>>>>> - record = json.JSONDecoder().decode(data[0])
>>>>> -
>>>>> - if len(data) > 2:
>>>>> - # new log format: translate message on
>>>>> the fly
>>>>> - params =
>>>>> json.JSONDecoder().decode(data[1])
>>>>> - detParams = None
>>>>> -
>>>>> - # has original exception details
>>>>> - if len(data) > 3:
>>>>> - detParams =
>>>>> json.JSONDecoder().decode(data[2])
>>>>> -
>>>>> - msg = self.getTranslatedMessage(record,
>>>>> params,
>>>>> - detParams)
>>>>> - else:
>>>>> - # make it compatible with v2.2 log
>>>>> files,
>>>>> which
>>>>> - # messages are already translated
>>>>> - msg = data[1].strip()
>>>>> -
>>>>> - record['message'] = msg
>>>>> - records.append(record)
>>>>> -
>>>>> + record = json.JSONDecoder().decode(line)
>>>>> + records.append(record)
>>>>> line = f.readline()
>>>>>
>>>>> f. close()
>>>>> @@ -217,20 +229,32 @@ class RequestParser(object):
>>>>>
>>>>>
>>>>> class RequestRecord(object):
>>>>> - def __init__(self, msgParams, details, **kwargs):
>>>>> - # log record data
>>>>> - self.logData = kwargs
>>>>> - self.details = details
>>>>> -
>>>>> + def __init__(self, message, error, id=None, **kwargs):
>>>>> # data for message translation
>>>>> - self.code = self.logData['msgCode']
>>>>> - self.params = self.getSafeReqParams(msgParams)
>>>>> -
>>>>> - # register timestamp in local time
>>>>> + self.message = {
>>>>> + 'code': message['code'],
>>>>> + 'params': self.getSafeReqParams(message['params']),
>>>>> + }
>>>>> +
>>>>> + # data for error translation (WokException)
>>>>> + self.error = None
>>>>> + if error:
>>>>> + self.error = {
>>>>> + 'code': error.code,
>>>>> + 'params': error.params,
>>>>> + }
>>>>> +
>>>>> + # log entry info
>>>>> + self.id = id or str(uuid.uuid4())
>>>>> + self.info = kwargs
>>>>> +
>>>>> + # generate timestamp
>>>>> timestamp = time.localtime()
>>>>> - self.logData['date'] = time.strftime(TS_DATE_FORMAT,
>>>>> timestamp)
>>>>> - self.logData['time'] = time.strftime(TS_TIME_FORMAT,
>>>>> timestamp)
>>>>> - self.logData['zone'] = time.strftime(TS_ZONE_FORMAT,
>>>>> timestamp)
>>>>> + self.info.update({
>>>>> + 'date': time.strftime(TS_DATE_FORMAT, timestamp),
>>>>> + 'time': time.strftime(TS_TIME_FORMAT, timestamp),
>>>>> + 'zone': time.strftime(TS_ZONE_FORMAT, timestamp),
>>>>> + })
>>>>>
>>>>> def getSafeReqParams(self, params):
>>>>> result = params.copy()
>>>>> @@ -239,20 +263,16 @@ class RequestRecord(object):
>>>>> return result
>>>>>
>>>>> def __str__(self):
>>>>> - # original exception details
>>>>> - details = ''
>>>>> - if self.details:
>>>>> - self.logData['detCode'] = self.details.code
>>>>> - details = ">>> %s" %
>>>>> json.JSONEncoder().encode(self.details.params)
>>>>> -
>>>>> - # request log message
>>>>> - msg = WokMessage(self.code, self.params)
>>>>> - msgText = msg.get_text(prepend_code=False, translate=False)
>>>>> - logData = json.JSONEncoder().encode(self.logData)
>>>>> - msgParams = json.JSONEncoder().encode(self.params)
>>>>> + entry = {
>>>>> + "id": self.id,
>>>>> + "message": self.message,
>>>>> + "error": self.error,
>>>>> + "info": self.info,
>>>>> + }
>>>>>
>>>>> - return '%s >>> %s %s >>> %s' % (logData, msgParams, details,
>>>>> msgText)
>>>>> + return json.JSONEncoder().encode(entry)
>>>>>
>>>>> def log(self):
>>>>> reqLogger = logging.getLogger(WOK_REQUEST_LOGGER)
>>>>> reqLogger.info(self)
>>>>> + return self.id
>>>>
>>>
>>>
>>
>
>
More information about the Kimchi-devel
mailing list