Metrics and an application log - FOSDEM

Do you remember the time you spent an afternoon putting print statements in your app trying to debug an issue and removed them before shipping the fix, only to add them back in a day later to work on another issue? Wouldn't it be great if those debug statements could just stay in your code forever? Like a little gift that keeps on giving, not just for you, but for everyone else on your team too.

That's what an application log is for! Logs aren't just for when things go wrong. They're for helping you to keep track of what's going on within your application.

We take a look at how you can add helpful messages throughout your codebase and leave them there, even in production! We'll cover common logging strategies, log aggregation and how to efficiently work with your logs to get the data back out again.

We'll also take a look at metrics solutions such as Graphite that can help augment your logs to help work out what was going on by correlating event logs with peaks/drops in other monitoring systems.

Transcript

1. Metrics and an application log: Your new best friend Michael Heap (@mheap) Presented at FOSDEM, February 2017
2. Me! I’m Michael I’m @mheap Freelance @ Intechrity
3. Logging
4. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
5. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
6. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
7. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
8. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
9. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
10. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
11. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
12. Sound good?
13. Good!
14. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
15. Why log?
16. What went wrong? (Error log)
17. Who visited us? (Access log)
18. Who enabled <X>? (Audit log)
19. Runtime documentation (Application log)
20. I’m sold!
21. Can I have it for free?
22. Actually, yes!
23. (And more)
24. But that doesn’t help my application
25. Two types of log
26. Human readable
27. Machine readable
28. Two types of log
29. One type of log
30. Machine and Human readable
31. JSON / logfmt
32. What is an application log?
33. Debug information
34. Narrative information
35. Business information
36. “An application log signposts every twist and turn through the code”
37. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
38. Four W’s
39. When?
40. Who?
41. Where?
42. Why?
43. Getting started
44. error_log()
45. <?php function countConsonants($str){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); error_log("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael");
46. <?php function countConsonants($str){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); error_log("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael");
47. <?php ini_set("error_log", "/var/log/my-app.log"); function countConsonants($str){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); error_log("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael");
48. Pros ✴ It’s built in
49. Cons ✴ Is it semantically correct? ✴ Errors mixed with informational logs ✴ It’s not very powerful
50. Logging frameworks
51. 1) Monolog 2) Everything else
52. <?php require_once 'vendor/autoload.php'; $log = new Monolog\Logger('my-app'); $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG)); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael", $log);
53. <?php require_once 'vendor/autoload.php'; $log = new Monolog\Logger('my-app'); $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG)); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael", $log);
54. <?php require_once 'vendor/autoload.php'; $log = new Monolog\Logger('my-app'); $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG)); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael", $log);
55. <?php require_once 'vendor/autoload.php'; $log = new Monolog\Logger('my-app'); $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG)); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael", $log);
56. <?php require_once 'vendor/autoload.php'; $log = new Monolog\Logger('my-app'); $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG)); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael", $log);
57. [2016-05-25 03:56:01] my-app.INFO: Consonants in Michael: 4 [] []
58. FingersCrossedHandler
59. $log = new Monolog\Logger('my-app'); $streamHandler = new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG); $fcHandler = new Monolog\Handler\FingersCrossedHandler($streamHandler, Monolog\Logger::ERROR); $log->pushHandler($fcHandler); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael", $log);
60. $log = new Monolog\Logger('my-app'); $streamHandler = new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG); $fcHandler = new Monolog\Handler\FingersCrossedHandler($streamHandler, Monolog\Logger::ERROR); $log->pushHandler($fcHandler); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael", $log);
61. $log = new Monolog\Logger('my-app'); $streamHandler = new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG); $fcHandler = new Monolog\Handler\FingersCrossedHandler($streamHandler, Monolog\Logger::ERROR); $log->pushHandler($fcHandler); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); return $c; } echo countConsonants("Michael", $log);
63. $log = new Monolog\Logger('my-app'); $streamHandler = new Monolog\Handler\StreamHandler('/tmp/app.log', Monolog\Logger::DEBUG); $fcHandler = new Monolog\Handler\FingersCrossedHandler($streamHandler, Monolog\Logger::ERROR); $log->pushHandler($fcHandler); function countConsonants($str, $log){ $c = strlen(str_replace(['a','e','i','o','u'],'', $str)); $log->info("Consonants in {$str}: {$c}"); $log->error("Something bad happened"); return $c; } echo countConsonants("Michael", $log);
64. [2016-05-25 03:56:01] my-app.INFO: Consonants in Michael: 4 [] []
 [2016-05-25 03:56:01] my-app.ERROR: Something bad happened [] []
65. Pros ✴ It’s an object! Dependency injection FTW ✴ Supports multiple log writers ✴ Log level support
66. Cons ✴ Instantiating an instance can be complicated
67. Error Levels
68. 0. Emergency System is unusable 1. Alert Should be corrected immediately 2. Critical Critical conditions 3. Error Error conditions 4. Warning May indicate that an error will occur if action is not taken. 5. Notice Events that are unusual, but not error conditions. 6. Informational Normal operational messages that require no action. 7. Debug Information useful to developers for debugging the application. Syslog (RFC 5424)
69. 0. Emergency System is unusable 1. Alert Should be corrected immediately 2. Critical Critical conditions 3. Error Error conditions 4. Warning May indicate that an error will occur if action is not taken. 5. Notice Events that are unusual, but not error conditions. 6. Informational Normal operational messages that require no action. 7. Debug Information useful to developers for debugging the application. PSR-3
70. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
71. Everything is on fire
72. The ELK Stack
73. Elasticsearch Logstash Kibana
74. Logstash Elasticsearch Kibana
75. Logstash
76. Beats CouchDB_Changes Drupal_DBLog Elasticsearch Exec Event log File Ganglia Gelf Generator Graphite Github Heartbeat Heroku HTTP HTTP_Poller IRC IMAP JDBC JMX
 Kafka Log4J Lumberjack Meetup Pipe Puppet_Facter Relp RSS Backspace RabbitMQ Redis Salesforce SNMPTrap Stdin sqlite S3 SQS Stomp Syslog TCP Twitter Unix UDP Varnishlog WMI Web socket XMPP Zenoss ZeroMQ Inputs
77. Filters
78. filter { json { source => "message" add_field => [ “my_field", “mheap_%{host}” ] } }
79. filter { kv { default_keys => [ "from", "logstash@example.com", "to", "default@dev.null" ] } }
80. Accepted publickey for root from 172.14.183.11 port 22 ssh2
81. Accepted publickey for root from 172.14.183.11 port 22 ssh2
82. filter { grok { match => { "message" => "Accepted %{WORD:auth_method} for %{USER:username} from %{IP:src_ip} port %{INT:src_port} ssh2" } } } Accepted publickey for root from 172.14.183.11 port 22 ssh2
83. filter { grok { match => { "message" => "Accepted %{WORD:auth_method} for %{USER:username} from %{IP:src_ip} port %{INT:src_port} ssh2" } } } Accepted publickey for root from 172.14.183.11 port 22 ssh2
84. http://grokdebug.herokuapp.com/
85. Boundary Circus CSV Cloud watch Datadog Datadog_Metrics Email Elastic search Exec File Google BigQuery Google Cloud Storage Ganglia Gelf Graphtastic Graphite Hipchat HTTP IRC InfluxDB Juggernaut Jira Kafka Lumberjack Librato Loggly MongoDB MetricCatcher Nagios Null OpenTSDB Pagerduty Pipe Riemann Redmine Rackspace RabbitMQ Redis Riak S3 SQS Stomp StatsD Solr SNS Syslog Stdout TCP UDP WebHDFS Websocket XMPP Outputs Zabbix ZeroMQ
86. Input -> Filter -> Output
87. Logstash is slow(ish)
88. Elasticsearch
89. Kibana
90. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
95. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
96. Asimov’s Law
97. “A robot may not injure a human being or, through inaction, allow a human being to come to harm.”
98. @mheap’s Law
99. “An application log may not injure a an application’s performance or readability”
100. Plan for bursts of data
101. Disk space
102. Index management
103. Ship what’s relevant
104. Devs create dashboards
105. Unique request IDs
106. Normalise timezones
107. No really. Normalise timezones
108. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
109. Filebeat
110. Graphite / Grafana
114. Pagerduty
116. 1. Logging 2. Getting started 3. The ELK stack 4. Logs and dashboards 5. Log management 6. Supporting tools 7. Conclusion
117. Logging is required
118. Developers are empowered
119. Logging isn’t free
120. “Would you rather fly slowly or fly blind?”
121. Thanks! I’ve been @mheap, you’ve been awesome. Any questions? https://joind.in/talk/54183