Tweet
Tweet

Slide 1

Slide 1 text

Beyond grep Pragmatic Logging & Metrics https://ox.cx/b Hynek Schlawack

Slide 2

Slide 2 text

Hi! @hynek https://hynek.me https://github.com/hynek

Slide 3

Slide 3 text

Agenda

Slide 4

Slide 4 text

Agenda

Slide 5

Slide 5 text

Agenda

Slide 6

Slide 6 text

Agenda

Slide 7

Slide 7 text

Errors

Slide 8

Slide 8 text

Errors

Slide 9

Slide 9 text

Requirements

Slide 10

Slide 10 text

Requirements •fast

Slide 11

Slide 11 text

Requirements •fast •once

Slide 12

Slide 12 text

Requirements •fast •once

Slide 13

Slide 13 text

Requirements •fast •once •context

Slide 14

Slide 14 text

Requirements •fast •once •context

Slide 15

Slide 15 text

No content

Slide 16

Slide 16 text

No content

Slide 17

Slide 17 text

No content

Slide 18

Slide 18 text

No content

Slide 19

Slide 19 text

No content

Slide 20

Slide 20 text

No content

Slide 21

Slide 21 text

No content

Slide 22

Slide 22 text

No content

Slide 23

Slide 23 text

No content

Slide 24

Slide 24 text

Raven-Python

Slide 25

Slide 25 text

Raven-Python Integrations:

Slide 26

Slide 26 text

Raven-Python Integrations: • logging

Slide 27

Slide 27 text

Raven-Python Integrations: • logging • Django

Slide 28

Slide 28 text

Raven-Python Integrations: • logging • Django • WSGI

Slide 29

Slide 29 text

Raven-Python Integrations: • logging • Django • WSGI • …9 others

Slide 30

Slide 30 text

Vanilla from raven import Client client = Client("https://yoursentry") try: 1 / 0 except ZeroDivisionError: client.captureException()

Slide 31

Slide 31 text

Vanilla from raven import Client client = Client("https://yoursentry") try: 1 / 0 except ZeroDivisionError: client.captureException()

Slide 32

Slide 32 text

Vanilla from raven import Client client = Client("https://yoursentry") try: 1 / 0 except ZeroDivisionError: client.captureException()

Slide 33

Slide 33 text

Django INSTALLED_APPS = ( … "raven.contrib.django.raven_compat", … )

Slide 34

Slide 34 text

Progress!

Slide 35

Slide 35 text

Progress! ✓

Slide 36

Slide 36 text

Metrics

Slide 37

Slide 37 text

Metrics?

Slide 38

Slide 38 text

Metrics? • numbers in a DB

Slide 39

Slide 39 text

Metrics? • numbers in a DB • guessing vs knowing

Slide 40

Slide 40 text

System Metrics vs App Metrics • load • network traffic • I/O • …

Slide 41

Slide 41 text

System Metrics vs App Metrics • load • network traffic • I/O • … • counters

Slide 42

Slide 42 text

System Metrics vs App Metrics • load • network traffic • I/O • … • counters • timers

Slide 43

Slide 43 text

System Metrics vs App Metrics • load • network traffic • I/O • … • counters • timers • gauges

Slide 44

Slide 44 text

System Metrics vs App Metrics • load • network traffic • I/O • … • counters • timers • gauges • …

Slide 45

Slide 45 text

Aggregation

Slide 46

Slide 46 text

Correlation

Slide 47

Slide 47 text

Math

Slide 48

Slide 48 text

Math • # reqs / s?

Slide 49

Slide 49 text

Math • # reqs / s? • worst 0.01% ⟨req time⟩?

Slide 50

Slide 50 text

Math • # reqs / s? • worst 0.01% ⟨req time⟩? • don’t try this alone!

Slide 51

Slide 51 text

Monitoring

Slide 52

Slide 52 text

Monitoring • latency

Slide 53

Slide 53 text

Monitoring • latency • error rates

Slide 54

Slide 54 text

Monitoring • latency • error rates • anomalies

Slide 55

Slide 55 text

Storage

Slide 56

Slide 56 text

Librato Metrics

Slide 57

Slide 57 text

Graphite 800 pound gorilla

Slide 58

Slide 58 text

Grafana

Slide 59

Slide 59 text

InfluxDB Graphite++ in Go

Slide 60

Slide 60 text

InfluxDB Graphite++ in Go

Slide 61

Slide 61 text

Collecting

Slide 62

Slide 62 text

Approaches

Slide 63

Slide 63 text

Approaches 1. external aggregation: StatsD, Riemann

Slide 64

Slide 64 text

Approaches 1. external aggregation: StatsD, Riemann + no state, simple

Slide 65

Slide 65 text

Approaches 1. external aggregation: StatsD, Riemann + no state, simple – no direct introspection

Slide 66

Slide 66 text

Approaches 1. external aggregation: StatsD, Riemann + no state, simple – no direct introspection 2. aggregate in-app, deliver to DB

Slide 67

Slide 67 text

Approaches 1. external aggregation: StatsD, Riemann + no state, simple – no direct introspection 2. aggregate in-app, deliver to DB + in-app dashboard, useful in dev

Slide 68

Slide 68 text

Approaches 1. external aggregation: StatsD, Riemann + no state, simple – no direct introspection 2. aggregate in-app, deliver to DB + in-app dashboard, useful in dev – state w/i app

Slide 69

Slide 69 text

No content

Slide 70

Slide 70 text

(g|py)?statsd(py|-client)? import statsd c = statsd.StatsClient( "statsd.local", 8125 )

Slide 71

Slide 71 text

(g|py)?statsd(py|-client)?

Slide 72

Slide 72 text

(g|py)?statsd(py|-client)? c.incr("foo")

Slide 73

Slide 73 text

(g|py)?statsd(py|-client)? c.incr("foo") c.timing("stats.timed", 320)

Slide 74

Slide 74 text

Scales from greplin import scales from greplin.scales.meter import MeterStat STATS = scales.collection( "/Resource", MeterStat("reqs"), scales.PmfStat("request_time") )

Slide 75

Slide 75 text

Scales from greplin import scales from greplin.scales.meter import MeterStat STATS = scales.collection( "/Resource", MeterStat("reqs"), scales.PmfStat("request_time") )

Slide 76

Slide 76 text

Scales

Slide 77

Slide 77 text

Scales STATS.reqs.mark()

Slide 78

Slide 78 text

Scales STATS.reqs.mark() with STATS.request_time.time():

Slide 79

Slide 79 text

Scales STATS.reqs.mark() with STATS.request_time.time(): do_something_expensive()

Slide 80

Slide 80 text

Dashboard Scales

Slide 81

Slide 81 text

Dashboard Scales

Slide 82

Slide 82 text

Dashboard Scales … "request_time": { "count": 567315293, "99percentile": 0.10978688716888428, "75percentile": 0.013181567192077637, "min": 0.0002448558807373047, "max": 30.134822130203247, "98percentile": 0.08934824466705339, "95percentile": 0.027234303951263434, "median": 0.009176492691040039, "999percentile": 0.14235656142234793, "stddev": 0.01676855570363413, "mean": 0.013247184020535955 }, …

Slide 83

Slide 83 text

Progress! ✓

Slide 84

Slide 84 text

Progress! ✓ ✓

Slide 85

Slide 85 text

Logging

Slide 86

Slide 86 text

Splunk

Slide 87

Slide 87 text

Splunk

Slide 88

Slide 88 text

Papertrail

Slide 89

Slide 89 text

loggly

Slide 90

Slide 90 text

ELK Elasticsearch + Logstash + Kibana

Slide 91

Slide 91 text

Graylog

Slide 92

Slide 92 text

Graylog

Slide 93

Slide 93 text

Graylog

Slide 94

Slide 94 text

Graylog

Slide 95

Slide 95 text

No content

Slide 96

Slide 96 text

Goal @400000005270e0d604afce64 { "event": "logged_in", "user": "guido", "ip": "8.8.8.8", "referrer": "http://google.com" }

Slide 97

Slide 97 text

Context & Format

Slide 98

Slide 98 text

structlog

Slide 99

Slide 99 text

BoundLogger structlog

Slide 100

Slide 100 text

Original Logger BoundLogger structlog e.g. logging.Logger

Slide 101

Slide 101 text

Original Logger BoundLogger bind values log.bind(key=value) Context structlog

Slide 102

Slide 102 text

Original Logger BoundLogger bind values log.bind(key=value) Context log events log.info(event, another_key=another_value) + structlog

Slide 103

Slide 103 text

Original Logger BoundLogger Processor 1 Processor n Return Value Return Value bind values log.bind(key=value) Context log events log.info(event, another_key=another_value) + structlog

Slide 104

Slide 104 text

Original Logger BoundLogger Processor 1 Processor n Return Value Return Value bind values log.bind(key=value) Context log events log.info(event, another_key=another_value) + structlog

Slide 105

Slide 105 text

import logging, sys logger = logging.getLogger() logger.addHandler( logging.StreamHandler( sys.stdout ) )

Slide 106

Slide 106 text

import logging, sys logger = logging.getLogger() logger.addHandler( logging.StreamHandler( sys.stdout ) )

Slide 107

Slide 107 text

Capture

Slide 108

Slide 108 text

Capture • into files

Slide 109

Slide 109 text

Capture • into files • to syslog / a queue

Slide 110

Slide 110 text

Capture • into files • to syslog / a queue • pipe into a logging agent

Slide 111

Slide 111 text

log = log.bind(user="guido") log.info("user.login")

Slide 112

Slide 112 text

{"event": "user.login", "user": "guido"} log = log.bind(user="guido") log.info("user.login") structlog

Slide 113

Slide 113 text

{"event": "user.login", "user": "guido"} log = log.bind(user="guido") log.info("user.login") structlog stdout logging

Slide 114

Slide 114 text

{"event": "user.login", "user": "guido"} log = log.bind(user="guido") log.info("user.login") structlog stdout logging /var/log/app/current runit’s svlogd (adds TAI64 timestamp)

Slide 115

Slide 115 text

{"event": "user.login", "user": "guido"} log = log.bind(user="guido") log.info("user.login") structlog logstash-forwarder logstash stdout logging /var/log/app/current runit’s svlogd (adds TAI64 timestamp)

Slide 116

Slide 116 text

{"event": "user.login", "user": "guido"} log = log.bind(user="guido") log.info("user.login") structlog logstash-forwarder logstash 1010001101 Elasticsearch stdout logging /var/log/app/current runit’s svlogd (adds TAI64 timestamp)

Slide 117

Slide 117 text

Progress! ✓ ✓

Slide 118

Slide 118 text

Progress! ✓ ✓ ✓

Slide 119

Slide 119 text

Wait a Minute…

Slide 120

Slide 120 text

Ugh try: STATS.time.timing(): something() except Exception as e: log.error("omg", exc_info=e) raven_client.captureError() STATS.errors.mark()

Slide 121

Slide 121 text

Ugh try: STATS.time.timing(): something() except Exception as e: log.error("omg", exc_info=e) raven_client.captureError() STATS.errors.mark()

Slide 122

Slide 122 text

Awww try: something() except Exception as e: log.error("omg", exc_info=e)

Slide 123

Slide 123 text

Errors

Slide 124

Slide 124 text

Errors • logging integration

Slide 125

Slide 125 text

Errors • logging • structlog

Slide 126

Slide 126 text

Errors • logging • structlog • web apps: error views

Slide 127

Slide 127 text

Error View @view_config(context=Exception) def err(exc, request): return Response( "oops: " + raven_client.captureException() )

Slide 128

Slide 128 text

Metrics measure from outside

Slide 129

Slide 129 text

WSGI Servers

Slide 130

Slide 130 text

WSGI Servers • gunicorn: --statsd-host

Slide 131

Slide 131 text

WSGI Servers • gunicorn: --statsd-host • uWSGI:

Slide 132

Slide 132 text

WSGI Servers • gunicorn: --statsd-host • uWSGI: • --stats-push statsd:

Slide 133

Slide 133 text

WSGI Servers • gunicorn: --statsd-host • uWSGI: • --stats-push statsd: • --carbon

Slide 134

Slide 134 text

Middleware def timing_tween_factory(handler, registry): def timing_tween(request): with STATS.request_time.time(): return handler(request) return timing_tween

Slide 135

Slide 135 text

Middleware def timing_tween_factory(handler, registry): def timing_tween(request): with STATS.request_time.time(): return handler(request) return timing_tween

Slide 136

Slide 136 text

Extract from Logs

Slide 137

Slide 137 text

Leverage Monitoring

Slide 138

Slide 138 text

Remaining

Slide 139

Slide 139 text

Remaining 1. measure code paths

Slide 140

Slide 140 text

Remaining 1. measure code paths 2. expose gauges

Slide 141

Slide 141 text

Summary

Slide 142

Slide 142 text

Summary

Slide 143

Slide 143 text

Summary

Slide 144

Slide 144 text

Summary

Slide 145

Slide 145 text

Summary

Slide 146

Slide 146 text

ox.cx/b @hynek vrmd.de