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

Aline Manera alinefm at linux.vnet.ibm.com
Mon Sep 5 18:58:30 UTC 2016



On 09/02/2016 06:52 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
> * Use plugin_root to fix issue in plugin lookup
>
> Signed-off-by: Lucio Correia <luciojhc at linux.vnet.ibm.com>
> ---
>   src/wok/reqlogger.py | 142 +++++++++++++++++++++++++++++----------------------
>   1 file changed, 80 insertions(+), 62 deletions(-)
>
> diff --git a/src/wok/reqlogger.py b/src/wok/reqlogger.py
> index b675478..2dcfd05 100644
> --- a/src/wok/reqlogger.py
> +++ b/src/wok/reqlogger.py
> @@ -25,6 +25,7 @@ import logging
>   import logging.handlers
>   import os.path
>   import time
> +import uuid
>
>   from cherrypy.process.plugins import BackgroundTask
>   from tempfile import NamedTemporaryFile
> @@ -34,7 +35,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
> @@ -64,6 +65,9 @@ UNSAFE_REQUEST_PARAMETERS = ['password', 'passwd']
>   REQUEST_LOG_FILE = "wok-req.log"
>   WOK_REQUEST_LOGGER = "wok_request_logger"


> +# AsyncTask handling
> +ASYNCTASK_REQUEST_METHOD = 'TASK'
> +

This is not needed. Check the status == 202

>   def log_request(code, params, exception, method, status, app=None, user=None,
>                   ip=None):
> @@ -140,20 +144,18 @@ 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, None)
> +        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)
> -            text += ' ' + msg.get_text(prepend_code=True, translate=True)
> +        if error:
> +            code = error.get('code', '')
> +            params = error.get('params', {})
> +            msg = WokMessage(code, params, plugin)
> +            text += ' (%s)' % msg.get_text(prepend_code=True, translate=True)
>
>           return text
>
> @@ -163,8 +165,38 @@ 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'],
> +        # normalize entries
> +        normalized = {}
> +        asynctask_updates = []
> +        for record in records:
> +            # because async tasks run in another thread, their record entry
> +            # may be recorded before original request record. Since we use
> +            # them to just update original request record, do it afterwards

> +            if record['info']['req'] == ASYNCTASK_REQUEST_METHOD:

if record[info][status] == 202

> +                asynctask_updates.append(record)
> +                continue
> +
> +            # initial request entry: generate translated message text
> +            message = record.pop('message')
> +            error = record.pop('error', None)

> +            app = record['info']['app']
> +            text = self.getTranslatedMessage(message, error, app)

Seems this 'app' is only being used to get the translated message, is 
that correct?

If so, isn't better to record the app URI (instead its name)? So we 
don't need to store a global variable to do that. All the information 
would be on log record params.

> +            record['info']['message'] = text
> +
> +            id = record.pop('id')
> +            normalized[id] = record['info']
> +
> +        # time to update original records based on async task records
> +        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):
> @@ -177,34 +209,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()
> @@ -243,20 +253,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()
> @@ -265,20 +287,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