Re: [Kimchi-devel] [PATCH] [Wok 3/7] Update Request Logger to handle AsyncTask status

* 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(a)linux.vnet.ibm.com&gt; --- 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':

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' +

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')

+ 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

+ if record['info']['req'] == ASYNCTASK_REQUEST_METHOD: + asynctask_updates.append(record) + continue +

+ # 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