Loggers: regain control over your application

Slide 1

Slide 1 text

Loggers: regain control over your application Bartek Zdanowski 1

Slide 2

Slide 2 text

Loggers: regain control Hello. Bartek Zdanowski @bartekzdanowski 2

Slide 3

Slide 3 text

Loggers: regain control Hello. 3 developer @ 25yrs in front of a Computer 14yrs of professional experience three kids, two dogs, one wife

Slide 4

Slide 4 text

Loggers: regain control Let’s go! 4

Slide 5

Slide 5 text

3..2..1..boom 5 source: https://techcrunch.com/wp-content/uploads/2017/09/rocket-fail.gif

Slide 6

Slide 6 text

Loggers: regain control logging 6

Slide 7

Slide 7 text

logging 7 source: http://www.australiangeographic.com.au/blogs/on-this-day/2016/03/on-this-day-the-black-box-was-born

Slide 8

Slide 8 text

logging 8 source: https://www.dcourier.com/news/2007/dec/21/howd-they-do-that-polygraphs-never-or-at-least-ra/

Slide 9

Slide 9 text

logging 9 source: http://jan.ucc.nau.edu/~daa/heartlung/ekgfile/ekg12.gif

Slide 10

Slide 10 text

Loggers: regain control logging ■ Logs are streams of events ■ Logging is the act of keeping a log ■ Tells what is the state of a system ■ Helps recreate erroneous situation ■ Tracks user / system activities 10

Slide 11

Slide 11 text

logging 11 source: https://logmatic.io/blog/youre-doing-php-logging-wrong/

Slide 12

Slide 12 text

Loggers: regain control Simplest log 12

Slide 13

Slide 13 text

Loggers: regain control Simplest log 13 System.out.print("Processing some data " + data); print 'processing data ' . $data; print 'processing data ' + data

Slide 14

Slide 14 text

Loggers: regain control Simplest log 14 System.err.print("Something bad happened", exception); fwrite(fopen('php://stderr', 'w'), 'Exception! ' . $ex); sys.stderr.write('Exception ' + ex )

Slide 15

Slide 15 text

Loggers: regain control Explosion of Logging Frameworks 15

Slide 16

Slide 16 text

Loggers: regain control Loggers ■ Log4j, JUL, JCL, Logback, Log4j2 ■ PSR-3 interface, Monolog, Analog, Log4php 16 ■ ELMAH, NLog, Microsoft Enterprise Library, NSpring, log4Net ■ Py std logging mod, logbook Loooots of logging frameworks

Slide 17

Slide 17 text

Loggers: regain control Loggers 17 log.error("Error logging in", authException); log.info("Returning user with billing for phoneNo " . phoneNo); log.trace("Received Http headers: " . responseEntity.getHeaders());

Slide 18

Slide 18 text

Loggers: regain control Logger construction 18

Slide 19

Slide 19 text

Loggers: regain control Logger construction 19 Typical loger structure ■ Logger - captures / accepts event or message ■ Formatter - formats output ■ Handler / Appender - pushes formatted log message / structure to destination sink

Slide 20

Slide 20 text

Loggers: regain control Logger construction 20 Logger ■ Has name or category ■ Event or message and opt. Exception ■ Severity level

Slide 21

Slide 21 text

Loggers: regain control Logger construction 21 Formatter ■ [%datetime%] %channel%.%level_name%: %message% %context% %extra% ■ yyyy-MM-dd HH:mm:ss.SSS, [%thread], %-5level %logger{36} - %msg%n ■ ${CONSOLE_LOG_PATTERN:-%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}

Slide 22

Slide 22 text

Loggers: regain control Logger construction Handler / Appender ■ Syslog ■ Console ■ File ■ Database ■ Mail ■ Logging System ■ others... 22

Slide 23

Slide 23 text

Loggers: regain control Logging levels 23

Slide 24

Slide 24 text

Loggers: regain control Logging levels ■ Logging levels map event importance and detail depth ■ Typical severity levels ● FATAL ● ERROR ● WARN ● INFO ● DEBUG ● TRACE 24

Slide 25

Slide 25 text

Loggers: regain control Logging levels Apache HTTP server / rfc5424 - syslog / monolog ■ Emerg - Emergencies — system is unusable ■ Alert - Immediate action required ■ Crit - Critical conditions ■ Error - Error conditions ■ Warn - Warning conditions ■ Notice - Normal but significant condition ■ Info - Informational ■ Debug - Debug-level messages ■ Trace1-8 - Trace messages 25

Slide 26

Slide 26 text

Loggers: regain control Logging levels Log4j / Logback / others / common sense ■ FATAL* ■ ERROR ■ WARN ■ INFO ■ DEBUG ■ TRACE *note: FATAL is mapped to ERROR in Logback 26

Slide 27

Slide 27 text

Loggers: regain control Logging levels FATAL Level ■ Unhandled exceptions 27

Slide 28

Slide 28 text

Loggers: regain control Logging levels ERROR Level ■ Handled exceptions ■ Invalid login attempts ■ Bad data, intercepted for reporting 28

Slide 29

Slide 29 text

Loggers: regain control Logging levels INFO Level ■ The start and end of major calls ■ Calls of an external systems ■ Important moments in application cycle 29

Slide 30

Slide 30 text

Loggers: regain control Logging levels DEBUG Level ■ Steps important for flow recreation ■ Major data ■ Developer tips on program execution 30

Slide 31

Slide 31 text

Loggers: regain control Logging levels TRACE Level ■ Detailed params and data ■ Detailed steps 31

Slide 32

Slide 32 text

Loggers: regain control Logging levels Staying alive ■ Use common sense ■ Don’t overuse logging ■ Don’t flood with logging events 32

Slide 33

Slide 33 text

Loggers: regain control Logging levels When rolling to production ■ Start with DEBUG or TRACE for your code ■ After some time upgrade to WARN ■ Split output to several files (app logic, SQL, exchange with other systems, security) 33

Slide 34

Slide 34 text

Loggers: regain control Mapped Diagnostic Context 34

Slide 35

Slide 35 text

Loggers: regain control MDC 35 ■ Contains call context that helps diagnose ■ Global to current call ■ Filled programmatically ● MDC.put(‘key’, ‘value’) ■ Available at all levels of program flow ● MDC.get(‘key’)

Slide 36

Slide 36 text

Loggers: regain control Multi-node environment 36

Slide 37

Slide 37 text

Loggers: regain control Multi-node environment 37 ■ Load balanced copies of system ■ Microservice nodes ■ Multi-system environments

Slide 38

Slide 38 text

Loggers: regain control Multi-node environment 38 Characteristics ■ Request spans across many nodes ■ Generate big amounts of logs ■ Introduces problem of tracking single request ● Add an unique call id and pass it to all nodes during req ● Add the unique call id to all logs (through MDC for ex)

Slide 39

Slide 39 text

Loggers: regain control Multi-node environment 39 ■ Use ELK to gather logs ■ Use tracing solution ● Opentracing.io ● Zipkin

Slide 40

Slide 40 text

Loggers: regain control Logging tips 40

Slide 41

Slide 41 text

Loggers: regain control Logging tips 41 Important rules ■ Set same log rules across all systems / services ● What data to which levels, not to confuse INFO with DEBUG ● Same logging formats / layouts

Slide 42

Slide 42 text

Loggers: regain control Logging tips 42 Important rules ■ Enable / implement dynamic level change ● Through observed logger config or JMX ● Crucial on production when problem occurs ■ Discuss rules with all Teams and sign it with blood

Slide 43

Slide 43 text

Loggers: regain control Logging tips 43 ■ Debugging is cool but not on production - you need logs ■ If you’d have to perform post-mortem debugging/analysis on remote system, you need good logs ■ If you’d support legacy system you will appreciate good logging

Slide 44

Slide 44 text

Loggers: regain control Logging tips 44 ■ Sometimes logs are an evidence that other Vendor’s system failed - not yours ■ From Bank or Telecom you will only get (obfuscated) logs ■ Tell Application Support guys that you don’t have logs in your app

Slide 45

Slide 45 text

Loggers: regain control Logging tips 45 ■ During crash generate some kind of ID (UUID) and store it in logs with stacktrace ■ Present User with error ID. They will help you discover error faster } catch (HttpClientErrorException e) { String errorID = UUID.randomUUID().toString(); log.error("Error fetching billing for phoneNo [{}]. Error ID [{}]", phoneNo, errorID, e); throw new ApplicationException(String.format("Error occurred while fetching billing. Error ID [%s]. Our engineers are fixing this!", errorID), e); }

Slide 46

Slide 46 text

Loggers: regain control Logging tips 46 ■ Use asynchronous Appenders source: http://logging.apache.org/log4j/2.x/manual/async.html

Slide 47

Slide 47 text

Loggers: regain control Logging Backend (ELK) 47

Slide 48

Slide 48 text

Elasticsearch+Logstash+Kibana 48

Slide 49

Slide 49 text

ELK 49

Slide 50

Slide 50 text

Loggers: regain control Demo 50

Slide 51

Slide 51 text

Loggers: regain control 51 APP Java Spring boot Logback mysql Billing PHP7 Monolog Straszny Operator

Slide 52

Slide 52 text

Loggers: regain control 52 APP Java Spring boot Logback mysql Billing PHP7 Monolog Straszny Operator ELK

Slide 53

Slide 53 text

Loggers: regain control Containers 53

Slide 54

Slide 54 text

Loggers: regain control Containers Kubernetes logging concept: (...)The easiest and most embraced logging method for containerized applications is to write to the standard output and standard error streams.(...) 54

Slide 55

Slide 55 text

Loggers: regain control Containers Kubernetes logging concept: 55

Slide 56

Slide 56 text

Loggers: regain control Containers Kubernetes logging concept: 56

Slide 57

Slide 57 text

Loggers: regain control Containers 57 System.out.print("Processing some data " + data); print 'processing data ' . $data; print 'processing data ' + data