diff --git a/CHANGELOG b/CHANGELOG index 420538a..f057691 100644 --- a/CHANGELOG +++ b/CHANGELOG @@ -2,9 +2,13 @@ Change Log ========== v0.3.3 +------ * log message JSON serializaztion check pass or convert to str + * total revamp of log message parser. + * added verbose option to MongoLogHandler that will print all log entries to console v0.3.2 +------ * support for verbose and simple LogRecord Types * python 3 support * travis-ci support diff --git a/mongolog/handlers.py b/mongolog/handlers.py index 9028714..fc8027e 100644 --- a/mongolog/handlers.py +++ b/mongolog/handlers.py @@ -20,6 +20,8 @@ from logging import Handler, StreamHandler, NOTSET from datetime import datetime import json +import pprint +pp = pprint.PrettyPrinter(indent=4) import pymongo @@ -27,7 +29,7 @@ from mongolog.models import LogRecord import logging -logger = logging.getLogger('django') +logger = logging.getLogger('') class MongoLogHandler(Handler): @@ -38,7 +40,7 @@ class MongoLogHandler(Handler): VERBOSE='verbose' record_types = [SIMPLE, VERBOSE] - def __init__(self, level=NOTSET, connection=None, w=1, j=False, record_type="verbose", time_zone="local"): + def __init__(self, level=NOTSET, connection=None, w=1, j=False, record_type="verbose", verbose=None, time_zone="local"): self.connection = connection # Choose between verbose and simpel log record types @@ -47,6 +49,10 @@ def __init__(self, level=NOTSET, connection=None, w=1, j=False, record_type="ver # Used to determine which time setting is used in the simple record_type self.time_zone = time_zone + # If True will print each log_record to console before logging to mongo + # Useful for debugging since "func" will provides name of test method. + self.verbose = verbose + if not self.connection: print("'connection' key not provided in logging config") print("Will try to connect with default") @@ -64,6 +70,26 @@ def __unicode__(self): def __str__(self): return self.__unicode__() + @staticmethod + def handler(): + """ + Return the first MongoLogHander found in the current loggers + list of handlers + """ + logger = logging.getLogger('') + handler = None + for _handler in logger.handlers: + if isinstance(_handler, MongoLogHandler): + handler = _handler + break + return handler + + def get_collection(self): + """ + Return the collection being used by MongoLogHandler + """ + return getattr(self, "collection", None) + def connect(self): major_version = int(pymongo.version.split(".")[0]) @@ -78,7 +104,7 @@ def connect_pymongo3(self): info = self.client.server_info() except pymongo.errors.ServerSelectionTimeoutError as e: msg = "Unable to connect to mongo with (%s)" % self.connection - logger.exception(msg) + logger.exception({'note': 'mongolog', 'msg': msg}) raise pymongo.errors.ServerSelectionTimeoutError(msg) self.db = self.client.mongolog @@ -156,7 +182,10 @@ def simple_record(self, record): }) # Add exception info if record.exc_info: - log_record['exception'] = record.exc_text, + log_record['exception'] = { + 'info': record.exc_info, + 'trace': record.exc_text, + } return log_record @@ -172,38 +201,57 @@ def emit(self, record): elif self.record_type == "simple": log_record = self.simple_record(record) + # set this up so you can pass the verbose + if self.verbose: + print(json.dumps(log_record, sort_keys=True, indent=4, default=str)) + if int(pymongo.version[0]) < 3: self.collection.insert(log_record) else: self.collection.insert_one(log_record) + + def process_record(self, record): + # Make sure the entire log message is JSON serializable. + record.msg = self.ensure_json(record.msg) + return self.process_record_exception(record) - def process_tuple(self, items): - ret_items = [] - for item in items: - if isinstance(item, AttributeError): - item = str(item.message) - ret_items.append(str(item)) - return ret_items + def ensure_json(self, value): + """ + Use json.dumps(...) to ensure that 'value' is in json format. + The default=str option will attempt to convert any non serializable + objects/sub objects to a string. + + Once the object has been json serialized we again use json to json.loads + the json string into a python dictionary. We do this because pymongo + uses a slighlyt different serialization when inserting python data + into mongo and deserialization when pulling it out. + """ + return json.loads(json.dumps(value, default=str)) + + + def process_record_exception(self, record): + """ + Check for record attributes indicating the logger.exception(...) + method was called. If those attrbutes are found ensure that they + are converted to JSON serializable formats. exc_text is also + split up based on lines to make for nice stack trace prints inside + mongo. + """ + if hasattr(record, "exc_info"): + record.exc_info = self.ensure_json(record.exc_info) + + if hasattr(record, "exc_text"): + exc_text = record.exc_text.split("\n") if record.exc_text else None + record.exc_text = self.ensure_json(exc_text) - def process_record(self, record): - for k, v in record.__dict__.items(): - if k == 'exc_text' and v: - v = tuple(v.split("\n")) - if isinstance(v, tuple): - v = self.process_tuple(v) - - try: - test = json.dumps(v) - record.__dict__[k] = v - except TypeError as e: - if "is not JSON serializable" in str(e): - logger.exception("Failed to log message(%s) converting to str" % str(e)) - record.__dict__[k] = str(v) - else: - raise return record + + + + + diff --git a/mongolog/tests.py b/mongolog/tests.py index e817b17..12c3f74 100644 --- a/mongolog/tests.py +++ b/mongolog/tests.py @@ -17,6 +17,7 @@ """ import unittest import logging +import json from logging import config import pymongo pymongo_major_version = int(pymongo.version.split(".")[0]) @@ -39,6 +40,7 @@ # utc/local. Only used with record_type=simple 'time_zone': 'local', + 'verbose': True }, }, 'loggers': { @@ -72,31 +74,16 @@ class TestLogLevels(unittest.TestCase): test_key = 'info.msg.test' def setUp(self): - self.collection = self.get_monglog_collection() + self.handler = MongoLogHandler.handler() + self.collection = self.handler.get_collection() + self.handler.setLevel("DEBUG") - # Check for an preexsting mongolog test entries + # Check for any preexsting mongolog test entries self.remove_test_entries() def tearDown(self): self.remove_test_entries() - def get_monglog_collection(self): - """ - Get the collection used by the first MongoLogHandler - found in the root loggers list of handlers. - """ - for handler in logger.handlers: - if isinstance(handler, MongoLogHandler): - self.handler = handler - self.handler.setLevel("DEBUG") - self.collection = self.handler.collection - break - - if not hasattr(self, 'collection'): - raise ValueError("Perhaps you didn't a monglog handler?", self.handler.__dict__) - - return self.collection - def test_str_unicode_mongologhandler(self): self.assertEqual(self.handler.connection, u"%s" % self.handler) self.assertEqual(self.handler.connection, "%s" % self.handler) @@ -195,9 +182,7 @@ def test_logstructure_verbose(self): ) self.assertEqual(rec['thread']['name'], "MainThread") - self.assertEqual(rec['info']['filename'], "tests.py") - self.assertEqual(rec['process']['name'], "MainProcess") def test_logstructure_simple(self): @@ -206,17 +191,8 @@ def test_logstructure_simple(self): """ self.handler.set_record_type(MongoLogHandler.SIMPLE) self.handler.setLevel("DEBUG") + - log_msg = {'test': True, 'fruit': ['apple', 'orange'], 'error': ValueError, 'handler': MongoLogHandler()} - logger.info(log_msg) - - # We expect log_msg to be converted to a str because ValueError and MongoLogHandler() are not - # JSON serieliazable - query = {'msg': str(log_msg)} - - rec = self.collection.find_one(query) - self.assertEqual(rec['msg'], str(log_msg)) - # now test a serielazable dict with an exception call log_msg = {'test': True, 'fruits': ['apple', 'orange'], 'error': str(ValueError), 'handler': str(MongoLogHandler())} try: @@ -230,6 +206,30 @@ def test_logstructure_simple(self): set(['_id', 'exception', 'name', 'thread', 'time', 'process', 'level', 'msg', 'path', 'module', 'line', 'func', 'filename']) ) + # Now try an exception log with a complex log msg. + try: + raise ValueError + except ValueError as e: + logger.exception({ + 'test': True, + 'fruits': [ + 'apple', + 'orange', + {'tomatoes': ['roma', 'kmato', 'cherry', ValueError, 'plum']}, + {}, + {} + ], + 'object': MongoLogHandler, + 'instance': MongoLogHandler(), + }) + + rec = self.collection.find_one({'msg.fruits': {'$in': ['apple', 'orange']}}) + self.assertEqual( + set(rec.keys()), + set(['_id', 'exception', 'name', 'thread', 'time', 'process', 'level', 'msg', 'path', 'module', 'line', 'func', 'filename']) + ) + + def test_debug_verbose(self): self.handler.set_record_type(MongoLogHandler.VERBOSE) logger.debug({'test': True, 'msg': 'DEBUG TEST'})