Measuring and Logging Everything in Real Time

Do you know what is happening in your web application right now, this second, how many requests, logins, exceptions you have, how many and what data your users are generating and what the click through rate of each of your registration step is? Or do you know exactly which exception with which stack trace caused the error your users are seeing? If not, this talk will show how you can easily measure and log everything that happens in your application with the help of open source tools, such as Graphite, StatsD, Elasticsearch and Logstash, without influencing your production environment.

Transcript

1. Measuring & Logging Everything in Real- Time @BastianHofmann
2. Logging
3. Measuring
4. Many roads
7. A few words about me
10. Questions? Ask
11. http://speakerdeck.com/u/bastianhofmann
12. Logging
13. For when something goes wrong
14. server error log access log debug logs slow query log ...
15. $ ssh my_simple_server
16. $ tail -f error.log $ cat error.log | grep Exception
17. Error Logs
18. ErrorLog /var/logs/apache/error.log
20. HTTP Response Codes http://www.w3.org/Protocols/rfc2616/rfc2616- sec6.html
22. Log additional info
23. Not only error codes
24. Request Information
25. Handling Notices, Warnings, Errors
26. Access Logs
27. 192.168.56.1 - - [09/Jul/2012:19:18:19 +0200] "GET /rg_trunk/webroot/c/af10c/ images/template/rg_logo_default.png HTTP/ 1.1" 200 882 "http://devm/rg_trunk/webroot/ directory/publications/"
28. LogFormat "%h %l %u %t \"%r\" %>s %b" custom CustomLog /var/logs/apache/access.log custom http://httpd.apache.org/docs/2.2/mod/ mod_log_config.html#logformat
29. Log additional info
30. Debug Logs
31. Log in a structured way
32. JSON http://www.ietf.org/rfc/rfc4627.txt
33. FingersCrossed
34. Logs from other services
35. web server http service http service http service http service user request log log log log log
36. Correlation / Tracing ID
37. web server http service http service http service http service create unique trace_id for request user request trace_id trace_id trace_id trace_id log log log log log
38. X-Trace-Id: bbr8ehb984tbab894
39. web server http service http service http service http service create unique trace_id for request user request trace_id trace_id trace_id trace_id log log log log log
43. Aggregate the logs in a central place
44. Make them easily full-text searchable
45. Make them aggregate-able
46. Always Log to file
47. Directly to a database
48. webserver webserver webserver DB
49. Disadvantages
50. Database is down?
51. Database is slow?
52. Database is full?
53. How to integrate access logs?
54. Influences application performance
55. Frontend?
56. Better solutions?
57. Logstash + Elasticsearch + Kibana
58. Full text search
59. Structured Messages
60. Always Log to file
61. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash logstash logstash
62. logstash http://logstash.net/
63. input filter output
64. Very rich plugin system
65. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash logstash logstash
66. input { file { type => "error" path => [ "/var/logs/php/*.log" ] add_field => [ "severity", "error" ] } file { type => "access" path => [ "/var/logs/apache/*_access.log" ] add_field => [ "severity", "info" ] }
67. filter{ grok { match => ["@source", "\/%{USERNAME:facility}\.log$"] } grok { type => "access" pattern => "^%{IP:OriginalIp} \s[a-zA-Z0-9_-]+\s[a-zA-Z0-9_-]+\s\[.*? \]\s\"%{DATA:Request}..." } }
68. output { amqp { host => "amqp.host" exchange_type => "fanout" name => "logs" } }
69. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash logstash logstash
70. input {
 rabbitmq {
 queue => "logs"
 host => "amqp.host"
 exchange => "ls_exchange"
 exclusive => false
 }
 }
71. filter { grok {
 match => [
 'Type','EntityNotFoundException| TimeoutException'
 ]
 break_on_match => true
 add_tag => ['not_serious']
 tag_on_failure => ['serious']
 } }
72. output {
 elasticsearch {
 embedded => false
 bind_host => "localhost"
 bind_port => "9305"
 host => "localhost"
 cluster => "logs"
 }
 }
73. Kibana http://www.elasticsearch.org/overview/kibana/
75. Measuring
76. For knowing what happens
77. Technical Metrics
78. Business Metrics
79. Define your KPIs
80. Graphite http://graphite.wikidot.com/
81. webserver webserver webserver graphite UDP
82. StatsD https://github.com/etsy/statsd/
83. webserver webserver webserver graphite UDP statsd
84. webserver webserver webserver statsd statsd statsd graphite aggregated UPD message
85. webserver webserver webserver statsd statsd statsd graphite aggregated UPD message statsd
86. Metric?
87. Counters
88. Timers
89. Gauges
91. https://www.librato.com
92. http://www.soasta.com/
93. http://mashable.com/2010/10/13/etsy-office-pics/
94. Anomaly detection
95. http://codeascraft.com/2013/06/11/introducing-kale/
96. Remember: Response Times
97. Easiest approach:
    Get it out of the access log
98. 192.168.56.1 - - [09/Jul/2012:19:18:19 +0200] "GET /rg_trunk/webroot/c/af10c/ images/template/rg_logo_default.png HTTP/ 1.1" 200 882 "http://devm/rg_trunk/webroot/ directory/publications/"
99. Is this actually what we want to measure?
101. External Resources CSS JavaScript Images Slow connections Slow Browsers SSL Handshakes DNS resolving
102. That is what we want to measure!
104. Navigation Timing API https://developer.mozilla.org/en-US/docs/ Navigation_timing
106. Resource Timing API http://www.w3.org/TR/resource-timing/
108. https://github.com/lognormal/boomerang
109. browser JS: boomerang logstash trackingServer access log requests tracking image with timing information as query parameters graphite statsd
110. input {
 file {
 type => "pagespeed-access"
 path => [ "/var/log/nginx/ access_log/monitoring-access.log" ]
 }
 }
111. filter{
 grok {
 type => "pagespeed-access"
 pattern => "^.*\s\"[A-Z]+\s[^\?\s]+ \?page=%{DATA:page}\&connectTime=% {NUMBER:connectTime}...)?\sHTTP\/\d\.\d\".* $"
 }
 grok {
 type => "pagespeed-access"
 match => ["page", "^(profile| home|...)\.logged(In|Out)$"]
 exclude_tags => ["_grokparsefailure"]
 }
 }
112. output { statsd { type => "pagespeed-access" exclude_tags => ["_grokparsefailure"] host => "localhost" port => 8126 namespace => "pagespeed" sender => "" timing => [ "%{page}.connect", "% {connectTime}", ... ] } }
113. Profiling
119. Use it locally on your dev machine
120. Use it in production for a subset of requests
129. Use it in production for a subset of requests
130. https://qafoolabs.com/
131. https://blackfire.io/
132. http://newrelic.com/
133. http://twitter.com/BastianHofmann http://profiles.google.com/bashofmann http://lanyrd.com/people/BastianHofmann http://speakerdeck.com/u/bastianhofmann https://github.com/bashofmann https://www.researchgate.net/profile/Bastian_Hofmann/ mail@bastianhofmann.de