Un-broken logging - the foundation of software operability - Operability.io - 2015 - Matthew Skelton

Slide 1

Slide 1 text

Un-Broken Logging the foundation of software operability Operability.io conference #OIO15 Friday 25th September 2015 Matthew Skelton Skelton Thatcher Consulting @matthewpskelton

Slide 2

Slide 2 text

No content

Slide 3

Slide 3 text

The way we use logging is (often) broken How to make our logging more awesome Why we should care

Slide 4

Slide 4 text

No content

Slide 5

Slide 5 text

No content

Slide 6

Slide 6 text

No content

Slide 7

Slide 7 text

Matthew Skelton @matthewpskelton #OIO15

Slide 8

Slide 8 text

No content

Slide 9

Slide 9 text

No content

Slide 10

Slide 10 text

No content

Slide 11

Slide 11 text

No content

Slide 12

Slide 12 text

@Operability #operability WhoOwnsMyOperability.com

Slide 13

Slide 13 text

confession: I am a big fan of logging

Slide 14

Slide 14 text

No content

Slide 15

Slide 15 text

exceptional situations edge cases metrics analytics ‘audits’ … @evanphx

Slide 16

Slide 16 text

execution trace

Slide 17

Slide 17 text

BAD STUFF

Slide 18

Slide 18 text

Logging is often unloved 1. Discontinuous 2. Errors only, or arbitrary 3. ‘Bolted on’ 4. No aggregation & search 5. Specify severity up front

Slide 19

Slide 19 text

GOOD STUFF

Slide 20

Slide 20 text

How to make logging awesome 1. Continuous event IDs 2. Transaction tracing 3. Log aggregation & search tools 4. Design for logging 5. Decoupled severity

Slide 21

Slide 21 text

reduce time-to-detect increase team engagement increase configurability enhance DevOps collaboration #operability

Slide 22

Slide 22 text

Background

Slide 23

Slide 23 text

Autonomous weather station

Slide 24

Slide 24 text

No content

Slide 25

Slide 25 text

No content

Slide 26

Slide 26 text

MRI brain scan imaging

Slide 27

Slide 27 text

No content

Slide 28

Slide 28 text

No content

Slide 29

Slide 29 text

Oil well monitoring

Slide 30

Slide 30 text

No content

Slide 31

Slide 31 text

No content

Slide 32

Slide 32 text

Web-scale systems

Slide 33

Slide 33 text

No content

Slide 34

Slide 34 text

No content

Slide 35

Slide 35 text

No content

Slide 36

Slide 36 text

No content

Slide 37

Slide 37 text

No content

Slide 38

Slide 38 text

No content

Slide 39

Slide 39 text

logging makes things work

Slide 40

Slide 40 text

(event sourcing) (structured logging) (CQRS)

Slide 41

Slide 41 text

How is logging usually broken?

Slide 42

Slide 42 text

Logging is often unloved 1. Discontinuous 2. Errors only, or arbitrary 3. ‘Bolted on’ 4. No aggregation & search 5. Specify severity up front

Slide 43

Slide 43 text

No content

Slide 44

Slide 44 text

using logging mainly for errors

Slide 45

Slide 45 text

No content

Slide 46

Slide 46 text

inconsistent use of logging

Slide 47

Slide 47 text

No content

Slide 48

Slide 48 text

logging slows down the software

Slide 49

Slide 49 text

No content

Slide 50

Slide 50 text

logging ‘pollutes’ my precious domain model

Slide 51

Slide 51 text

No content

Slide 52

Slide 52 text

logging is just for those weird Ops people

Slide 53

Slide 53 text

No content

Slide 54

Slide 54 text

logging assumed to be free ($0) to implement no budget for aggregating logs across machines

Slide 55

Slide 55 text

No content

Slide 56

Slide 56 text

log aggregation happens only in Production logs not available to Devs

Slide 57

Slide 57 text

No content

Slide 58

Slide 58 text

fights over log severity levels

Slide 59

Slide 59 text

No content

Slide 60

Slide 60 text

poor time synchronisation

Slide 61

Slide 61 text

No content

Slide 62

Slide 62 text

Some history, with pirates

Slide 63

Slide 63 text

No content

Slide 64

Slide 64 text

No content

Slide 65

Slide 65 text

No content

Slide 66

Slide 66 text

No content

Slide 67

Slide 67 text

weather, course, sightings, latitude, longitude, … (even when quiet)

Slide 68

Slide 68 text

John Harrison

Slide 69

Slide 69 text

Why log?

Slide 70

Slide 70 text

verification traceability accountability charting the waters

Slide 71

Slide 71 text

No content

Slide 72

Slide 72 text

- June 13th – Pirates!!!! - Weds – Sharks!!! - 19th Jun –BIGGER sharks!!!!

Slide 73

Slide 73 text

How to make logging awesome

Slide 74

Slide 74 text

How to make logging awesome 1. Continuous event IDs 2. Transaction tracing 3. Log aggregation & search tools 4. Design for logging 5. Decoupled severity

Slide 75

Slide 75 text

No content

Slide 76

Slide 76 text

Storage I/O Worker Job Queue Upload

Slide 77

Slide 77 text

Continuous event IDs

Slide 78

Slide 78 text

How many distinct event types (state transitions) in your application?

Slide 79

Slide 79 text

No content

Slide 80

Slide 80 text

represent distinct states

Slide 81

Slide 81 text

enum Human-readable sets: unique values, sparse, immutable C#, Java, Python, node (Ruby, PHP, …)

Slide 82

Slide 82 text

public enum EventID { // Badly-initialised logging data NotSet = 0, // An unrecognised event has occurred UnexpectedError = 10000, ApplicationStarted = 20000, ApplicationShutdownNoticeReceived = 20001, PageGenerationStarted = 30000, PageGenerationCompleted = 30001, MessageQueued = 40000, MessagePeeked = 40001, BasketItemAdded = 60001, BasketItemRemoved = 60002, CreditCardDetailsSubmitted = 70001, // ... }

Slide 83

Slide 83 text

Technical Domain public enum EventID { // Badly-initialised logging data NotSet = 0, // An unrecognised event has occurred UnexpectedError = 10000, ApplicationStarted = 20000, ApplicationShutdownNoticeReceived = 20001, PageGenerationStarted = 30000, PageGenerationCompleted = 30001, MessageQueued = 40000, MessagePeeked = 40001, BasketItemAdded = 60001, BasketItemRemoved = 60002, CreditCardDetailsSubmitted = 70001, // ... }

Slide 84

Slide 84 text

BasketItemAdded = 60001

Slide 85

Slide 85 text

BasketItemAdded = 60001 BasketItemRemoved = 60002

Slide 86

Slide 86 text

BasketItemAdded = 60001 BasketItemRemoved = 60002

Slide 87

Slide 87 text

represent distinct states

Slide 88

Slide 88 text

No content

Slide 89

Slide 89 text

OrderSvc_BasketItemAdded

Slide 90

Slide 90 text

No content

Slide 91

Slide 91 text

Monolith to microservices: debugger does not have the full view

Slide 92

Slide 92 text

Even with remote debugger, it’s boring to attach and detach

Slide 93

Slide 93 text

No content

Slide 94

Slide 94 text

Storage I/O Worker Job Queue Upload

Slide 95

Slide 95 text

No content

Slide 96

Slide 96 text

No content

Slide 97

Slide 97 text

No content

Slide 98

Slide 98 text

Transaction tracing

Slide 99

Slide 99 text

‘Unique-ish’ identifier for each request Passed through downstream layers

Slide 100

Slide 100 text

Unique-ish ID

Slide 101

Slide 101 text

What about APM?

Slide 102

Slide 102 text

APM gives us application insight BUT How much do we learn? Is APM available on the Dev box? It’s not just ‘an Ops problem’!

Slide 103

Slide 103 text

No content

Slide 104

Slide 104 text

Helps us to understand how the software really works Small overhead is worth it

Slide 105

Slide 105 text

Configurable severity levels

Slide 106

Slide 106 text

Which log level is right?

Slide 107

Slide 107 text

DEBUG, INFO, WARNING, ERROR, CRITICAL

Slide 108

Slide 108 text

Log level should *not* be fixed at compile or build time!

Slide 109

Slide 109 text

Tune log levels

Slide 110

Slide 110 text

Tune log levels

Slide 111

Slide 111 text

Tune log levels

Slide 112

Slide 112 text

{ "eventmappings": { "events": { "event": [ { "id": "CacheServiceStarted", "severity": { "level": "Information" } }, { "id": "PageCachePurged", "severity": { "level": "Debug" }, "state": { "enabled": false } }, { "id": "DatabaseConnectionTimeOut", "severity": { "level": "Error" } } ] } } }

Slide 113

Slide 113 text

No content

Slide 114

Slide 114 text

Tune severity levels of specific event IDs

Slide 115

Slide 115 text

No content

Slide 116

Slide 116 text

Event tracing Use enumerations (or closest thing) Technical and Domain event types Distributed systems: debuggers less useful Trace calls with ‘unique-enough’ handles Tune log levels via config

Slide 117

Slide 117 text

Log aggregation & search tools

Slide 118

Slide 118 text

No content

Slide 119

Slide 119 text

No content

Slide 120

Slide 120 text

No content

Slide 121

Slide 121 text

No content

Slide 122

Slide 122 text

Design for log aggregation

Slide 123

Slide 123 text

develop the software using log aggregation as a first-class thing

Slide 124

Slide 124 text

No content

Slide 125

Slide 125 text

No content

Slide 126

Slide 126 text

stories for testing logging

Slide 127

Slide 127 text

BasketItemAdded grep BasketItem

Slide 128

Slide 128 text

logging is (‘just’) another system component

Slide 129

Slide 129 text

NTP

Slide 130

Slide 130 text

Dev and Ops collaboration* * and testers too!

Slide 131

Slide 131 text

No content

Slide 132

Slide 132 text

Where?

Slide 133

Slide 133 text

No content

Slide 134

Slide 134 text

auditing compliance pre-emptive fault diagnosis performance metrics …

Slide 135

Slide 135 text

Recap

Slide 136

Slide 136 text

Logging is often unloved 1. Discontinuous 2. Errors only, or arbitrary 3. ‘Bolted on’ 4. No aggregation & search 5. Specify severity up front

Slide 137

Slide 137 text

How to make logging awesome 1. Continuous event IDs 2. Transaction tracing 3. Log aggregation & search tools 4. Design for logging 5. Decoupled severity

Slide 138

Slide 138 text

logging makes things work

Slide 139

Slide 139 text

“There is no thought behind aspect-oriented programming”

Slide 140

Slide 140 text

MINDFUL LOGGING (?!)

Slide 141

Slide 141 text

database transaction logs

Slide 142

Slide 142 text

‘Structured Logging’ TW: “Adopt” (May 2015) https://www.thoughtworks.com/radar/techniques/structured-logging http://gregoryszorc.com/ .NET: http://serilog.net/ Java: https://github.com/fluent/fluent-logger-java

Slide 143

Slide 143 text

sanity

Slide 144

Slide 144 text

No content

Slide 145

Slide 145 text

More Ditch the Debugger and Use Log Analysis Instead Matthew Skelton https://blog.logentries.com/2015/07/ditch- the-debugger-and-use-log-analysis-instead/

Slide 146

Slide 146 text

More Using Log Aggregation Across Dev & Ops: The Pricing Advantage Rob Thatcher https://blog.logentries.com/2015/08/using- log-aggregation-across-dev-ops-the-pricing- advantage/

Slide 147

Slide 147 text

Evan Phoenix (@evanphx) youtube.com/watch?v=Z-JskKlIBOA

Slide 148

Slide 148 text

Books operabilitybook.com operationalfeatures.com

Slide 149

Slide 149 text

Thank you http://skeltonthatcher.com/ enquiries@skeltonthatcher.com @SkeltonThatcher +44 (0)20 8242 4103 @matthewpskelton