[Kimchi-devel] [PATCH] [Wok 3/7] Update Request Logger to handle AsyncTask status
Aline Manera
alinefm at linux.vnet.ibm.com
Thu Sep 1 13:35:32 UTC 2016
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?
> 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.
> + 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?
> + 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?
> + # 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