Skip to content

Commit

Permalink
Add record's __dict__ to structPayload
Browse files Browse the repository at this point in the history
  • Loading branch information
vmarkovtsev committed Aug 9, 2016
1 parent 930342a commit 92871e8
Show file tree
Hide file tree
Showing 6 changed files with 140 additions and 59 deletions.
44 changes: 42 additions & 2 deletions gcloud/logging/handlers/handlers.py
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@

"""Python :mod:`logging` handlers for Google Cloud Logging."""

import itertools
import logging

from gcloud.logging.handlers.transports import BackgroundThreadTransport
Expand Down Expand Up @@ -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::
Expand All @@ -70,22 +77,55 @@ 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.
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):
Expand Down
41 changes: 40 additions & 1 deletion gcloud/logging/handlers/test_handlers.py
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@
# limitations under the License.

import logging
import os

import unittest2

Expand All @@ -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):
Expand Down Expand Up @@ -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
Expand Down
24 changes: 10 additions & 14 deletions gcloud/logging/handlers/transports/background_thread.py
Original file line number Diff line number Diff line change
Expand Up @@ -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()
Expand All @@ -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)
16 changes: 7 additions & 9 deletions gcloud/logging/handlers/transports/base.py
Original file line number Diff line number Diff line change
Expand Up @@ -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()
22 changes: 9 additions & 13 deletions gcloud/logging/handlers/transports/sync.py
Original file line number Diff line number Diff line change
Expand Up @@ -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)
52 changes: 32 additions & 20 deletions gcloud/logging/handlers/transports/test_background_thread.py
Original file line number Diff line number Diff line change
Expand Up @@ -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'
Expand All @@ -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,
Expand All @@ -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()
Expand All @@ -91,42 +103,42 @@ 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()
self.assertTrue(worker.batch.commit_called)

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()
while not worker.started:
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
Expand Down

0 comments on commit 92871e8

Please sign in to comment.