[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:19:11 UTC 2016
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.
>>
>>> + 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.
>>
>>> + # 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