diff --git a/gcloud/logging/handlers/handlers.py b/gcloud/logging/handlers/handlers.py index 2d0d05356c6f..c9e9acbc662c 100644 --- a/gcloud/logging/handlers/handlers.py +++ b/gcloud/logging/handlers/handlers.py @@ -14,6 +14,7 @@ """Python :mod:`logging` handlers for Google Cloud Logging.""" +import itertools import logging from gcloud.logging.handlers.transports import BackgroundThreadTransport @@ -52,6 +53,12 @@ class CloudLoggingHandler(logging.StreamHandler, object): Defaults to BackgroundThreadTransport. The other option is SyncTransport. + :type extra_fields: iterable, e.g. tuple, list, set + :param extra_fields: the container with LogRecord.__dict__ fields which + are forcefully submitted. Please note that some + whitelisted fields like process or threadName are + included by default. + Example: .. doctest:: @@ -70,14 +77,46 @@ class CloudLoggingHandler(logging.StreamHandler, object): """ + LOG_RECORD_DATA_WHITELIST = ( + 'process', 'processName', 'thread', 'threadName', 'created', + 'relativeCreated', 'pathname', 'filename', 'lineno', 'module', + 'funcName', 'levelno' + ) + def __init__(self, client, name=DEFAULT_LOGGER_NAME, - transport=BackgroundThreadTransport): + transport=BackgroundThreadTransport, + extra_fields=tuple()): super(CloudLoggingHandler, self).__init__() self.name = name self.client = client + self.extra_fields = extra_fields self.transport = transport(client, name) + def generate_log_struct_kwargs(self, record, message): + """Produces the dictionary of chosen LogRecord fields. extra_fields + are taken into account. + + :type record: :class:`logging.LogRecord` + :param record: Python log record + + :type message: str + :param message: The formatted log message + + :return: dict with keyword arguments for + :method:`gcloud.logging.Logger.log_struct()`. + """ + data = {k: getattr(record, k, None) for k in itertools.chain( + self.LOG_RECORD_DATA_WHITELIST, self.extra_fields)} + return { + 'info': { + 'message': message, + 'python_logger': record.name, + 'data': data + }, + 'severity': record.levelname + } + def emit(self, record): """ Overrides the default emit behavior of StreamHandler. @@ -85,7 +124,8 @@ def emit(self, record): See: https://docs.python.org/2/library/logging.html#handler-objects """ message = super(CloudLoggingHandler, self).format(record) - self.transport.send(record, message) + kwargs = self.generate_log_struct_kwargs(record, message) + self.transport.send(kwargs) def setup_logging(handler, excluded_loggers=EXCLUDE_LOGGER_DEFAULTS): diff --git a/gcloud/logging/handlers/test_handlers.py b/gcloud/logging/handlers/test_handlers.py index 8ac7cc086cb0..9219dc675852 100644 --- a/gcloud/logging/handlers/test_handlers.py +++ b/gcloud/logging/handlers/test_handlers.py @@ -13,6 +13,7 @@ # limitations under the License. import logging +import os import unittest2 @@ -33,15 +34,52 @@ def test_ctor(self): handler = self._makeOne(client, transport=_Transport) self.assertEqual(handler.client, client) + def test_generate_log_struct_kwargs(self): + client = _Client(self.PROJECT) + handler = self._makeOne(client, transport=_Transport) + LOGNAME = 'loggername' + MESSAGE = 'hello world' + record = _Record(LOGNAME, logging.INFO, MESSAGE) + kwargs = handler.generate_log_struct_kwargs(record, MESSAGE) + self.assertIsInstance(kwargs, dict) + self.assertEqual(len(kwargs), 2) + self.assertIn('info', kwargs) + self.assertIn('severity', kwargs) + info = kwargs['info'] + self.assertIsInstance(info, dict) + self.assertEqual(len(info), 3) + self.assertIn('message', info) + self.assertIn('python_logger', info) + self.assertIn('data', info) + self.assertEqual(info['message'], MESSAGE) + self.assertEqual(info['python_logger'], LOGNAME) + data = info['data'] + self.assertIsInstance(data, dict) + for field in handler.LOG_RECORD_DATA_WHITELIST: + self.assertIn(field, data) + self.assertEqual(data[field], getattr(record, field)) + + def test_ctor_extra_fields(self): + client = _Client(self.PROJECT) + handler = self._makeOne(client, transport=_Transport, + extra_fields=('secret',)) + LOGNAME = 'loggername' + MESSAGE = 'hello world' + record = _Record(LOGNAME, logging.INFO, MESSAGE) + record.secret = 'top' + kwargs = handler.generate_log_struct_kwargs(record, MESSAGE) + self.assertEqual(kwargs['info']['data']['secret'], 'top') + def test_emit(self): client = _Client(self.PROJECT) handler = self._makeOne(client, transport=_Transport) LOGNAME = 'loggername' MESSAGE = 'hello world' record = _Record(LOGNAME, logging.INFO, MESSAGE) + kwargs = handler.generate_log_struct_kwargs(record, MESSAGE) handler.emit(record) - self.assertEqual(handler.transport.send_called_with, (record, MESSAGE)) + self.assertEqual(handler.transport.send_called_with, (kwargs,)) class TestSetupLogging(unittest2.TestCase): @@ -109,6 +147,7 @@ def __init__(self, name, level, message): self.exc_info = None self.exc_text = None self.stack_info = None + self.process = os.getpid() def getMessage(self): return self.message diff --git a/gcloud/logging/handlers/transports/background_thread.py b/gcloud/logging/handlers/transports/background_thread.py index 44151ea51401..df3ba876942f 100644 --- a/gcloud/logging/handlers/transports/background_thread.py +++ b/gcloud/logging/handlers/transports/background_thread.py @@ -120,16 +120,14 @@ def _stop(self): self._stop_condition.release() self.stopped = True - def enqueue(self, record, message): + def enqueue(self, kwargs): """enqueue queues up a log entry to be written by the background thread. """ try: self._entries_condition.acquire() if self.stopping: return - self.batch.log_struct({"message": message, - "python_logger": record.name}, - severity=record.levelname) + self.batch.log_struct(**kwargs) self._entries_condition.notify() finally: self._entries_condition.release() @@ -149,15 +147,13 @@ def __init__(self, client, name): logger = self.client.logger(name) self.worker = _Worker(logger) - def send(self, record, message): - """Overrides Transport.send(). record is the LogRecord - the handler was called with, message is the message from LogRecord - after being formatted by associated log formatters. + def send(self, kwargs): + """Overrides Transport.send(). kwargs is the dictionary + with keyword arguments which will be passed to + :method:`gcloud.logging.Logger.log_struct()`. - :type record: :class:`logging.LogRecord` - :param record: Python log record - - :type message: str - :param message: The formatted log message + :type kwargs: dict + :param kwargs: {'info': ..., 'severity': ...} - keyword arguments + passed to :method:`gcloud.logging.Logger.log_struct()`. """ - self.worker.enqueue(record, message) + self.worker.enqueue(kwargs) diff --git a/gcloud/logging/handlers/transports/base.py b/gcloud/logging/handlers/transports/base.py index 556766568a67..9d3970ee5370 100644 --- a/gcloud/logging/handlers/transports/base.py +++ b/gcloud/logging/handlers/transports/base.py @@ -24,15 +24,13 @@ class Transport(object): def __init__(self, client, name): pass # pragma: NO COVER - def send(self, record, message): - """Must be overriden by transport options. record is the LogRecord - the handler was called with, message is the message from LogRecord - after being formatted by associated log formatters. + def send(self, kwargs): + """Must be overriden by transport options. kwargs is the dictionary + with keyword arguments which will be passed to + :method:`gcloud.logging.Logger.log_struct()`. - :type record: :class:`logging.LogRecord` - :param record: Python log record - - :type message: str - :param message: The formatted log message + :type kwargs: dict + :param kwargs: {'info': ..., 'severity': ...} - keyword arguments + passed to :method:`gcloud.logging.Logger.log_struct()`. """ raise NotImplementedError() diff --git a/gcloud/logging/handlers/transports/sync.py b/gcloud/logging/handlers/transports/sync.py index 8b5fb98cafa3..ac8fa7135d91 100644 --- a/gcloud/logging/handlers/transports/sync.py +++ b/gcloud/logging/handlers/transports/sync.py @@ -26,17 +26,13 @@ def __init__(self, client, name): super(SyncTransport, self).__init__(client, name) self.logger = client.logger(name) - def send(self, record, message): - """Overrides transport.send(). record is the LogRecord - the handler was called with, message is the message from LogRecord - after being formatted by associated log formatters. - - :type record: :class:`logging.LogRecord` - :param record: Python log record - - :type message: str - :param message: The formatted log message + def send(self, kwargs): + """Overrides transport.send(). kwargs is the dictionary + with keyword arguments which will be passed to + :method:`gcloud.logging.Logger.log_struct()`. + + :type kwargs: dict + :param kwargs: {'info': ..., 'severity': ...} - keyword arguments + passed to :method:`gcloud.logging.Logger.log_struct()`. """ - self.logger.log_struct({"message": message, - "python_logger": record.name}, - severity=record.levelname) + self.logger.log_struct(**kwargs) diff --git a/gcloud/logging/handlers/transports/test_background_thread.py b/gcloud/logging/handlers/transports/test_background_thread.py index fc739e7422f5..f98315116b1b 100644 --- a/gcloud/logging/handlers/transports/test_background_thread.py +++ b/gcloud/logging/handlers/transports/test_background_thread.py @@ -18,6 +18,17 @@ import unittest2 +def generate_log_struct_kwargs(record, message, data): + return { + 'info': { + 'message': message, + 'python_logger': record.name, + 'data': data + }, + 'severity': record.levelname + } + + class TestBackgroundThreadHandler(unittest2.TestCase): PROJECT = 'PROJECT' @@ -32,24 +43,25 @@ def _makeOne(self, *args, **kw): def test_ctor(self): client = _Client(self.PROJECT) - NAME = "python_logger" + NAME = 'python_logger' transport = self._makeOne(client, NAME) self.assertEquals(transport.worker.logger.name, NAME) def test_send(self): client = _Client(self.PROJECT) - NAME = "python_logger" + NAME = 'python_logger' transport = self._makeOne(client, NAME) transport.worker.batch = client.logger(NAME).batch() - PYTHON_LOGGER_NAME = "mylogger" - MESSAGE = "hello world" + PYTHON_LOGGER_NAME = 'mylogger' + MESSAGE = 'hello world' record = _Record(PYTHON_LOGGER_NAME, logging.INFO, MESSAGE) - transport.send(record, MESSAGE) + transport.send(generate_log_struct_kwargs(record, MESSAGE, {'one': 1})) EXPECTED_STRUCT = { - "message": MESSAGE, - "python_logger": PYTHON_LOGGER_NAME + 'message': MESSAGE, + 'python_logger': PYTHON_LOGGER_NAME, + 'data': {'one': 1} } EXPECTED_SENT = (EXPECTED_STRUCT, logging.INFO) self.assertEqual(transport.worker.batch.log_struct_called_with, @@ -67,18 +79,18 @@ def _makeOne(self, *args, **kw): return self._getTargetClass()(*args, **kw) def test_ctor(self): - NAME = "python_logger" + NAME = 'python_logger' logger = _Logger(NAME) worker = self._makeOne(logger) self.assertEquals(worker.batch, logger._batch) def test_run(self): - NAME = "python_logger" + NAME = 'python_logger' logger = _Logger(NAME) worker = self._makeOne(logger) - PYTHON_LOGGER_NAME = "mylogger" - MESSAGE = "hello world" + PYTHON_LOGGER_NAME = 'mylogger' + MESSAGE = 'hello world' record = _Record(PYTHON_LOGGER_NAME, logging.INFO, MESSAGE) worker._start() @@ -91,7 +103,7 @@ def test_run(self): while not worker.started: time.sleep(1) # pragma: NO COVER - worker.enqueue(record, MESSAGE) + worker.enqueue(generate_log_struct_kwargs(record, MESSAGE, {'one': 1})) # Set timeout to none so worker thread finishes worker._stop_timeout = None worker._stop() @@ -99,12 +111,12 @@ def test_run(self): def test_run_after_stopped(self): # No-op - NAME = "python_logger" + NAME = 'python_logger' logger = _Logger(NAME) worker = self._makeOne(logger) - PYTHON_LOGGER_NAME = "mylogger" - MESSAGE = "hello world" + PYTHON_LOGGER_NAME = 'mylogger' + MESSAGE = 'hello world' record = _Record(PYTHON_LOGGER_NAME, logging.INFO, MESSAGE) worker._start() @@ -112,21 +124,21 @@ def test_run_after_stopped(self): time.sleep(1) # pragma: NO COVER worker._stop_timeout = None worker._stop() - worker.enqueue(record, MESSAGE) + worker.enqueue(generate_log_struct_kwargs(record, MESSAGE, {})) self.assertFalse(worker.batch.commit_called) worker._stop() def test_run_enqueue_early(self): # No-op - NAME = "python_logger" + NAME = 'python_logger' logger = _Logger(NAME) worker = self._makeOne(logger) - PYTHON_LOGGER_NAME = "mylogger" - MESSAGE = "hello world" + PYTHON_LOGGER_NAME = 'mylogger' + MESSAGE = 'hello world' record = _Record(PYTHON_LOGGER_NAME, logging.INFO, MESSAGE) - worker.enqueue(record, MESSAGE) + worker.enqueue(generate_log_struct_kwargs(record, MESSAGE, None)) worker._start() while not worker.started: time.sleep(1) # pragma: NO COVER