Loggers: regain control over your application

A talk about efficient logging that allows regaining control over what happening inside your (distributed) system.

Transcript

1. Loggers: regain control over your application Bartek Zdanowski 1
2. Loggers: regain control Hello. Bartek Zdanowski @bartekzdanowski 2
3. Loggers: regain control Hello. 3 developer @ 25yrs in front of a Computer 14yrs of professional experience three kids, two dogs, one wife
4. Loggers: regain control Let’s go! 4
5. 3..2..1..boom 5 source: https://techcrunch.com/wp-content/uploads/2017/09/rocket-fail.gif
6. Loggers: regain control logging 6
7. logging 7 source: http://www.australiangeographic.com.au/blogs/on-this-day/2016/03/on-this-day-the-black-box-was-born
8. logging 8 source: https://www.dcourier.com/news/2007/dec/21/howd-they-do-that-polygraphs-never-or-at-least-ra/
9. logging 9 source: http://jan.ucc.nau.edu/~daa/heartlung/ekgfile/ekg12.gif
10. 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
11. logging 11 source: https://logmatic.io/blog/youre-doing-php-logging-wrong/
12. Loggers: regain control Simplest log 12
13. Loggers: regain control Simplest log 13 System.out.print("Processing some data " + data); print 'processing data ' . $data; print 'processing data ' + data
14. 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 )
15. Loggers: regain control Explosion of Logging Frameworks 15
16. 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
17. 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());
18. Loggers: regain control Logger construction 18
19. 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
20. Loggers: regain control Logger construction 20 Logger ▪ Has name or category ▪ Event or message and opt. Exception ▪ Severity level
21. 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}}
22. Loggers: regain control Logger construction Handler / Appender ▪ Syslog ▪ Console ▪ File ▪ Database ▪ Mail ▪ Logging System ▪ others... 22
23. Loggers: regain control Logging levels 23
24. Loggers: regain control Logging levels ▪ Logging levels map event importance and detail depth ▪ Typical severity levels • FATAL • ERROR • WARN • INFO • DEBUG • TRACE 24
25. 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
26. 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
27. Loggers: regain control Logging levels FATAL Level ▪ Unhandled exceptions 27
28. Loggers: regain control Logging levels ERROR Level ▪ Handled exceptions ▪ Invalid login attempts ▪ Bad data, intercepted for reporting 28
29. 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
30. Loggers: regain control Logging levels DEBUG Level ▪ Steps important for flow recreation ▪ Major data ▪ Developer tips on program execution 30
31. Loggers: regain control Logging levels TRACE Level ▪ Detailed params and data ▪ Detailed steps 31
32. Loggers: regain control Logging levels Staying alive ▪ Use common sense ▪ Don’t overuse logging ▪ Don’t flood with logging events 32
33. 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
34. Loggers: regain control Mapped Diagnostic Context 34
35. 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’)
36. Loggers: regain control Multi-node environment 36
37. Loggers: regain control Multi-node environment 37 ▪ Load balanced copies of system ▪ Microservice nodes ▪ Multi-system environments
38. 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)
39. Loggers: regain control Multi-node environment 39 ▪ Use ELK to gather logs ▪ Use tracing solution • Opentracing.io • Zipkin
40. Loggers: regain control Logging tips 40
41. 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
42. 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
43. 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
44. 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
45. 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); }
46. Loggers: regain control Logging tips 46 ▪ Use asynchronous Appenders source: http://logging.apache.org/log4j/2.x/manual/async.html
47. Loggers: regain control Logging Backend (ELK) 47
48. Elasticsearch+Logstash+Kibana 48
49. ELK 49
50. Loggers: regain control Demo 50
51. Loggers: regain control 51 APP Java Spring boot Logback mysql Billing PHP7 Monolog Straszny Operator
52. Loggers: regain control 52 APP Java Spring boot Logback mysql Billing PHP7 Monolog Straszny Operator ELK
53. Loggers: regain control Containers 53
54. 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
55. Loggers: regain control Containers Kubernetes logging concept: 55
56. Loggers: regain control Containers Kubernetes logging concept: 56
57. Loggers: regain control Containers 57 System.out.print("Processing some data " + data); print 'processing data ' . $data; print 'processing data ' + data
58. Loggers: regain control Q&A 58
59. 59 source: https://media.giphy.com/media/26DNbCqVfLJbYrXIA/giphy.gif
60. Thank you! Loggers: regain control over you application Bartek Zdanowski 60