Structured Logging

Florian Demmer - www.floriandemmer.com

a short intro

Django Friends Meetup, 2016-11-09

Logging Use Cases

• record errors
• aid in debugging
• monitoring
• analytics
• auditing

Generators

log statement:

logger.info(username + " successfully logged in")

log lines:

2016:11:09T17:32:23.3435 INFO user@django.com successfully logged in

examples:

• [    4.030984] r8169 0000:03:00.0 enp3s0: link down

• 64.242.88.10 - - [07/Mar/2004:16:47:12 -0800] "GET /robots.txt HTTP/1.1" 200 68

   

Consumers

• humans
• computers

Computers

• specialized scripts ...?
• import modules ...?
• Perl, regex, ...?

Structured Logging

>>> log.info("key_value_logging", out_of_the_box=True, effort=0)

2016-04-20 16:20.13 key_value_logging   effort=0 out_of_the_box=True


>>> log = log.bind(user="anonymous", some_key=23)

>>> log = log.bind(user="hynek", another_key=42)

>>> log.info("user.logged_in", happy=True)

2016-04-20 16:20.13 user.logged_in      another_key=42 happy=True some_key=23 user='hynek'

https://github.com/hynek/structlog

Formatting Output

• input is a dictionary
• output is whatever...
  • json for easy parsing
  • classic loglines
  • colored for console output

Configuration

import structlog
from foo import censor_filter

structlog.configure(
    processors=[
        structlog.stdlib.filter_by_level,
        censor_filter,
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
        # structlog.processors.JSONRenderer(sort_keys=True),
        structlog.processors.KeyValueRenderer(
            sort_keys=True, key_order=['event']
        )
    ],
    context_class=dict,
    logger_factory=structlog.stdlib.LoggerFactory(),
    wrapper_class=structlog.stdlib.BoundLogger,
    cache_logger_on_first_use=True,
)

Filter

CENSOR_LIST = {'password',}
CENSOR_VALUE = "***"


def censor_filter(_, __, event_dict):
    for key in CENSOR_LIST:
        if key in event_dict.keys() and event_dict[key] is not None:
            event_dict[key] = CENSOR_VALUE
    return event_dict

Python classes

class StructlogMixin(object):
    def __init__(self, *args, **kwargs):
        if not getattr(self, 'log', None):
            self.log = structlog.get_logger(self.__class__.__name__).new()
        super(StructlogMixin, self).__init__(*args, **kwargs)

usage:

self.log = self.log.bind(token=token)
[...]
self.log.info('sent delete token', really=True)
[...]

Django Views

class StructlogViewMixin(object):
    def dispatch(self, request, *args, **kwargs):
        logger = structlog.getLogger(__name__)
        self.log = logger.bind()
        return super(StructlogViewMixin, self).dispatch(request, *args, **kwargs)

docs:

http://www.structlog.org/en/stable/api.html?highlight=getlogger#structlog.BoundLogger

So, computers?

• https://www.elastic.co/products/logstash
• https://www.graylog.org

• https://www.splunk.com
• https://www.loggly.com
• https://papertrailapp.com

All the things

• http://gregoryszorc.com/blog/category/logging/

• https://github.com/hynek/structlog

• http://www.structlog.org

• me: http://www.floriandemmer.com

• my twitter: @fdemmer

• slides: https://slides.com/fdemmer