[PATCH V2] [Wok 0/2] Show error reason in log of failed user requests
Changes in v2: * removed getCode and getParams from exception Lucio Correia (2): Fix issue #140 - Add original exception to user request log message Update tests src/wok/control/base.py | 9 +++++++++ src/wok/exception.py | 1 + src/wok/reqlogger.py | 33 ++++++++++++++++++++++++++++----- src/wok/root.py | 7 ++++++- tests/test_api.py | 4 ---- 5 files changed, 44 insertions(+), 10 deletions(-) -- 1.9.1
Now the user request log entries for failed requests will contain the original exception causing the request failure. Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- src/wok/control/base.py | 9 +++++++++ src/wok/exception.py | 1 + src/wok/reqlogger.py | 33 ++++++++++++++++++++++++++++----- src/wok/root.py | 7 ++++++- 4 files changed, 44 insertions(+), 6 deletions(-) diff --git a/src/wok/control/base.py b/src/wok/control/base.py index f563aed..04cf2cb 100644 --- a/src/wok/control/base.py +++ b/src/wok/control/base.py @@ -119,6 +119,7 @@ class Resource(object): def wrapper(*args, **kwargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500 method = 'POST' @@ -149,6 +150,7 @@ class Resource(object): status = cherrypy.response.status return result except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) finally: @@ -157,6 +159,7 @@ class Resource(object): reqParams = utf8_dict(self.log_args, request) RequestRecord( reqParams, + details, app=get_plugin_from_request(), msgCode=code, req=method, @@ -190,6 +193,7 @@ class Resource(object): def index(self, *args, **kargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500 method = validate_method(('GET', 'DELETE', 'PUT'), @@ -206,6 +210,7 @@ class Resource(object): status = cherrypy.response.status except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) except cherrypy.HTTPError, e: @@ -217,6 +222,7 @@ class Resource(object): code = self.getRequestMessage(method) RequestRecord( self.log_args, + details, app=get_plugin_from_request(), msgCode=code, req=method, @@ -427,6 +433,7 @@ class Collection(object): def index(self, *args, **kwargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500 params = {} @@ -444,6 +451,7 @@ class Collection(object): status = cherrypy.response.status return result except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) except cherrypy.HTTPError, e: @@ -456,6 +464,7 @@ class Collection(object): reqParams = utf8_dict(self.log_args, params) RequestRecord( reqParams, + details, app=get_plugin_from_request(), msgCode=code, req=method, diff --git a/src/wok/exception.py b/src/wok/exception.py index f8f4bd4..09ab998 100644 --- a/src/wok/exception.py +++ b/src/wok/exception.py @@ -30,6 +30,7 @@ class WokException(Exception): args = {} self.httpStatusCode = 500 self.code = code + self.params = args msg = WokMessage(code, args).get_text() cherrypy.log.error_log.error(msg) Exception.__init__(self, msg) diff --git a/src/wok/reqlogger.py b/src/wok/reqlogger.py index f82ae6b..9f1d2c8 100644 --- a/src/wok/reqlogger.py +++ b/src/wok/reqlogger.py @@ -114,7 +114,7 @@ class RequestParser(object): return LOG_DOWNLOAD_URI % os.path.basename(fd.name) - def getTranslatedMessage(self, record, params): + def getTranslatedMessage(self, record, params, detParams): code = record.get('msgCode', '') app = record.get('app', 'wok') plugin = None @@ -122,7 +122,14 @@ class RequestParser(object): plugin = "/plugins/%s" % app msg = WokMessage(code, params, plugin) - return msg.get_text(prepend_code=False, translate=True) + 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) + + return text def getRecords(self): records = self.getRecordsFromFile(self.baseFile) @@ -156,7 +163,14 @@ class RequestParser(object): if len(data) > 2: # new log format: translate message on the fly params = json.JSONDecoder().decode(data[1]) - msg = self.getTranslatedMessage(record, params) + 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 @@ -203,9 +217,10 @@ class RequestParser(object): class RequestRecord(object): - def __init__(self, msgParams, **kwargs): + def __init__(self, msgParams, details, **kwargs): # log record data self.logData = kwargs + self.details = details # data for message translation self.code = self.logData['msgCode'] @@ -224,11 +239,19 @@ 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) - return '%s >>> %s >>> %s' % (logData, msgParams, msgText) + + return '%s >>> %s %s >>> %s' % (logData, msgParams, details, msgText) def log(self): reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) diff --git a/src/wok/root.py b/src/wok/root.py index 08f4981..e54bf38 100644 --- a/src/wok/root.py +++ b/src/wok/root.py @@ -153,6 +153,7 @@ class WokRoot(Root): @cherrypy.expose def login(self, *args): + details = None method = 'POST' code = self.getRequestMessage(method, 'login') app = 'wok' @@ -163,8 +164,11 @@ class WokRoot(Root): username = params['username'] password = params['password'] except KeyError, item: + details = e = MissingParameter('WOKAUTH0003E', {'item': str(item)}) + RequestRecord( params, + details, app=app, msgCode=code, req=method, @@ -173,7 +177,6 @@ class WokRoot(Root): ip=ip ).log() - e = MissingParameter('WOKAUTH0003E', {'item': str(item)}) raise cherrypy.HTTPError(400, e.message) try: @@ -185,6 +188,7 @@ class WokRoot(Root): finally: RequestRecord( params, + details, app=app, msgCode=code, req=method, @@ -206,6 +210,7 @@ class WokRoot(Root): RequestRecord( params, + None, app='wok', msgCode=code, req=method, -- 1.9.1
On 08/10/2016 03:08 PM, Lucio Correia wrote:
Now the user request log entries for failed requests will contain the original exception causing the request failure.
Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- src/wok/control/base.py | 9 +++++++++ src/wok/exception.py | 1 + src/wok/reqlogger.py | 33 ++++++++++++++++++++++++++++----- src/wok/root.py | 7 ++++++- 4 files changed, 44 insertions(+), 6 deletions(-)
diff --git a/src/wok/control/base.py b/src/wok/control/base.py index f563aed..04cf2cb 100644 --- a/src/wok/control/base.py +++ b/src/wok/control/base.py @@ -119,6 +119,7 @@ class Resource(object): def wrapper(*args, **kwargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500
method = 'POST' @@ -149,6 +150,7 @@ class Resource(object): status = cherrypy.response.status return result except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) finally: @@ -157,6 +159,7 @@ class Resource(object): reqParams = utf8_dict(self.log_args, request) RequestRecord( reqParams, + details, app=get_plugin_from_request(), msgCode=code, req=method, @@ -190,6 +193,7 @@ class Resource(object): def index(self, *args, **kargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500
method = validate_method(('GET', 'DELETE', 'PUT'), @@ -206,6 +210,7 @@ class Resource(object):
status = cherrypy.response.status except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) except cherrypy.HTTPError, e: @@ -217,6 +222,7 @@ class Resource(object): code = self.getRequestMessage(method) RequestRecord( self.log_args, + details, app=get_plugin_from_request(), msgCode=code, req=method, @@ -427,6 +433,7 @@ class Collection(object): def index(self, *args, **kwargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500
params = {} @@ -444,6 +451,7 @@ class Collection(object): status = cherrypy.response.status return result except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) except cherrypy.HTTPError, e: @@ -456,6 +464,7 @@ class Collection(object): reqParams = utf8_dict(self.log_args, params) RequestRecord( reqParams, + details, app=get_plugin_from_request(), msgCode=code, req=method, diff --git a/src/wok/exception.py b/src/wok/exception.py index f8f4bd4..09ab998 100644 --- a/src/wok/exception.py +++ b/src/wok/exception.py @@ -30,6 +30,7 @@ class WokException(Exception): args = {} self.httpStatusCode = 500 self.code = code + self.params = args msg = WokMessage(code, args).get_text() cherrypy.log.error_log.error(msg) Exception.__init__(self, msg) diff --git a/src/wok/reqlogger.py b/src/wok/reqlogger.py index f82ae6b..9f1d2c8 100644 --- a/src/wok/reqlogger.py +++ b/src/wok/reqlogger.py @@ -114,7 +114,7 @@ class RequestParser(object):
return LOG_DOWNLOAD_URI % os.path.basename(fd.name)
- def getTranslatedMessage(self, record, params): + def getTranslatedMessage(self, record, params, detParams): code = record.get('msgCode', '') app = record.get('app', 'wok') plugin = None @@ -122,7 +122,14 @@ class RequestParser(object): plugin = "/plugins/%s" % app
msg = WokMessage(code, params, plugin) - return msg.get_text(prepend_code=False, translate=True) + 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) + + return text
def getRecords(self): records = self.getRecordsFromFile(self.baseFile) @@ -156,7 +163,14 @@ class RequestParser(object): if len(data) > 2: # new log format: translate message on the fly params = json.JSONDecoder().decode(data[1]) - msg = self.getTranslatedMessage(record, params) + 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 @@ -203,9 +217,10 @@ class RequestParser(object):
class RequestRecord(object): - def __init__(self, msgParams, **kwargs): + def __init__(self, msgParams, details, **kwargs): # log record data self.logData = kwargs + self.details = details
# data for message translation self.code = self.logData['msgCode'] @@ -224,11 +239,19 @@ 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) - return '%s >>> %s >>> %s' % (logData, msgParams, msgText)
+ + return '%s >>> %s %s >>> %s' % (logData, msgParams, details, msgText)
The entire log entry should be contained in the JSON object. The same I commented before.
def log(self): reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) diff --git a/src/wok/root.py b/src/wok/root.py index 08f4981..e54bf38 100644 --- a/src/wok/root.py +++ b/src/wok/root.py @@ -153,6 +153,7 @@ class WokRoot(Root):
@cherrypy.expose def login(self, *args): + details = None method = 'POST' code = self.getRequestMessage(method, 'login') app = 'wok' @@ -163,8 +164,11 @@ class WokRoot(Root): username = params['username'] password = params['password'] except KeyError, item: + details = e = MissingParameter('WOKAUTH0003E', {'item': str(item)}) + RequestRecord( params, + details, app=app, msgCode=code, req=method, @@ -173,7 +177,6 @@ class WokRoot(Root): ip=ip ).log()
- e = MissingParameter('WOKAUTH0003E', {'item': str(item)}) raise cherrypy.HTTPError(400, e.message)
try: @@ -185,6 +188,7 @@ class WokRoot(Root): finally: RequestRecord( params, + details, app=app, msgCode=code, req=method, @@ -206,6 +210,7 @@ class WokRoot(Root):
RequestRecord( params, + None, app='wok', msgCode=code, req=method,
On 08/22/2016 01:19 PM, Aline Manera wrote:
On 08/10/2016 03:08 PM, Lucio Correia wrote:
Now the user request log entries for failed requests will contain the original exception causing the request failure.
Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- src/wok/control/base.py | 9 +++++++++ src/wok/exception.py | 1 + src/wok/reqlogger.py | 33 ++++++++++++++++++++++++++++----- src/wok/root.py | 7 ++++++- 4 files changed, 44 insertions(+), 6 deletions(-)
diff --git a/src/wok/control/base.py b/src/wok/control/base.py index f563aed..04cf2cb 100644 --- a/src/wok/control/base.py +++ b/src/wok/control/base.py @@ -119,6 +119,7 @@ class Resource(object): def wrapper(*args, **kwargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500
method = 'POST' @@ -149,6 +150,7 @@ class Resource(object): status = cherrypy.response.status return result except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) finally: @@ -157,6 +159,7 @@ class Resource(object): reqParams = utf8_dict(self.log_args, request) RequestRecord( reqParams, + details, app=get_plugin_from_request(), msgCode=code, req=method, @@ -190,6 +193,7 @@ class Resource(object): def index(self, *args, **kargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500
method = validate_method(('GET', 'DELETE', 'PUT'), @@ -206,6 +210,7 @@ class Resource(object):
status = cherrypy.response.status except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) except cherrypy.HTTPError, e: @@ -217,6 +222,7 @@ class Resource(object): code = self.getRequestMessage(method) RequestRecord( self.log_args, + details, app=get_plugin_from_request(), msgCode=code, req=method, @@ -427,6 +433,7 @@ class Collection(object): def index(self, *args, **kwargs): # status must be always set in order to request be logged. # use 500 as fallback for "exception not handled" cases. + details = None status = 500
params = {} @@ -444,6 +451,7 @@ class Collection(object): status = cherrypy.response.status return result except WokException, e: + details = e status = e.getHttpStatusCode() raise cherrypy.HTTPError(status, e.message) except cherrypy.HTTPError, e: @@ -456,6 +464,7 @@ class Collection(object): reqParams = utf8_dict(self.log_args, params) RequestRecord( reqParams, + details, app=get_plugin_from_request(), msgCode=code, req=method, diff --git a/src/wok/exception.py b/src/wok/exception.py index f8f4bd4..09ab998 100644 --- a/src/wok/exception.py +++ b/src/wok/exception.py @@ -30,6 +30,7 @@ class WokException(Exception): args = {} self.httpStatusCode = 500 self.code = code + self.params = args msg = WokMessage(code, args).get_text() cherrypy.log.error_log.error(msg) Exception.__init__(self, msg) diff --git a/src/wok/reqlogger.py b/src/wok/reqlogger.py index f82ae6b..9f1d2c8 100644 --- a/src/wok/reqlogger.py +++ b/src/wok/reqlogger.py @@ -114,7 +114,7 @@ class RequestParser(object):
return LOG_DOWNLOAD_URI % os.path.basename(fd.name)
- def getTranslatedMessage(self, record, params): + def getTranslatedMessage(self, record, params, detParams): code = record.get('msgCode', '') app = record.get('app', 'wok') plugin = None @@ -122,7 +122,14 @@ class RequestParser(object): plugin = "/plugins/%s" % app
msg = WokMessage(code, params, plugin) - return msg.get_text(prepend_code=False, translate=True) + 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) + + return text
def getRecords(self): records = self.getRecordsFromFile(self.baseFile) @@ -156,7 +163,14 @@ class RequestParser(object): if len(data) > 2: # new log format: translate message on the fly params = json.JSONDecoder().decode(data[1]) - msg = self.getTranslatedMessage(record, params) + 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 @@ -203,9 +217,10 @@ class RequestParser(object):
class RequestRecord(object): - def __init__(self, msgParams, **kwargs): + def __init__(self, msgParams, details, **kwargs): # log record data self.logData = kwargs + self.details = details
# data for message translation self.code = self.logData['msgCode'] @@ -224,11 +239,19 @@ 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) - return '%s >>> %s >>> %s' % (logData, msgParams, msgText)
+ + return '%s >>> %s %s >>> %s' % (logData, msgParams, details, msgText)
The entire log entry should be contained in the JSON object. The same I commented before.
Doing that, we can also rename the file to .json instead of .log as it is a file used for input data for a feature.
def log(self): reqLogger = logging.getLogger(WOK_REQUEST_LOGGER) diff --git a/src/wok/root.py b/src/wok/root.py index 08f4981..e54bf38 100644 --- a/src/wok/root.py +++ b/src/wok/root.py @@ -153,6 +153,7 @@ class WokRoot(Root):
@cherrypy.expose def login(self, *args): + details = None method = 'POST' code = self.getRequestMessage(method, 'login') app = 'wok' @@ -163,8 +164,11 @@ class WokRoot(Root): username = params['username'] password = params['password'] except KeyError, item: + details = e = MissingParameter('WOKAUTH0003E', {'item': str(item)}) + RequestRecord( params, + details, app=app, msgCode=code, req=method, @@ -173,7 +177,6 @@ class WokRoot(Root): ip=ip ).log()
- e = MissingParameter('WOKAUTH0003E', {'item': str(item)}) raise cherrypy.HTTPError(400, e.message)
try: @@ -185,6 +188,7 @@ class WokRoot(Root): finally: RequestRecord( params, + details, app=app, msgCode=code, req=method, @@ -206,6 +210,7 @@ class WokRoot(Root):
RequestRecord( params, + None, app='wok', msgCode=code, req=method,
_______________________________________________ Kimchi-devel mailing list Kimchi-devel@ovirt.org http://lists.ovirt.org/mailman/listinfo/kimchi-devel
Now with variable keys in the record, this test does not make sense. Remove it. Signed-off-by: Lucio Correia <luciojhc@linux.vnet.ibm.com> --- tests/test_api.py | 4 ---- 1 file changed, 4 deletions(-) diff --git a/tests/test_api.py b/tests/test_api.py index c4ca755..f2e252a 100644 --- a/tests/test_api.py +++ b/tests/test_api.py @@ -83,9 +83,5 @@ class APITests(unittest.TestCase): records = conf.get('records', []) self.assertGreaterEqual(records, 1) for record in records: - keys = [u'zone', u'ip', u'app', u'req', u'user', u'time', u'date', - u'message', u'msgCode', u'status'] - self.assertEquals(sorted(keys), sorted(record.keys())) - # Test search by app self.assertEquals(record['app'], 'wok') -- 1.9.1
Applied to master. Thanks! On 08/10/2016 03:08 PM, Lucio Correia wrote:
Changes in v2: * removed getCode and getParams from exception
Lucio Correia (2): Fix issue #140 - Add original exception to user request log message Update tests
src/wok/control/base.py | 9 +++++++++ src/wok/exception.py | 1 + src/wok/reqlogger.py | 33 ++++++++++++++++++++++++++++----- src/wok/root.py | 7 ++++++- tests/test_api.py | 4 ---- 5 files changed, 44 insertions(+), 10 deletions(-)
participants (3)
-
Aline Manera -
Daniel Henrique Barboza -
Lucio Correia