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
5. A few words about me
14. Questions? Ask
15. http://speakerdeck.com/u/bastianhofmann
16. Logging
17. For when something goes wrong
18. server error log access log debug logs slow query log ...
19. $ ssh my_simple_server!
20. $ tail -f error.log! ! $ cat error.log | grep Exception ! !
21. Error Logs
22. ErrorLog /var/logs/apache/error.log
23. bool error_log ( string $message [, int $message_type = 0 [, string $destination [, string $extra_headers ]]] )
24. callable set_exception_handler( callable $exception_handler   );
26. HTTP Response Codes http://www.w3.org/Protocols/rfc2616/rfc2616- sec6.html
28. Log additional info
29. Not only error codes
30. Request Information
31. Handling Notices, Warnings, Errors
32. callable set_error_handler( callable $error_handler [, int $error_types = E_ALL | E_STRICT ]   );
33. public function handle($errno, $msg, $file, $line) {! $e = new \Exception();! $error = [! 'type' => $errno,! 'message' => $msg,! 'file' => $file,! 'line' => $line,! 'trace' => $e->getTrace(),! ];! ! error_log(json_encode($error));! ! return true;! }
34. But what about fatal errors
35. Use error_get_last() in a Shutdown Handler http://php.net/manual/en/function.error- get-last.php
36. Access Logs
37. 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/"
38. 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
39. http://de.php.net/apache_note string apache_note ( string $note_name [, string $note_value = "" ] )
40. LogFormat "...\"%{referer}i\" \"%{user- agent}i\" %{session_id}n %{account_id}n..." custom
41. Debug Logs
42. https://github.com/Seldaek/monolog/
43. <?php! ! use Monolog\Logger;! use Monolog\Handler\StreamHandler;! ! // create a log channel! $log = new Logger('name');! $log->pushHandler(! new StreamHandler(! 'path/to/your.log', Logger::WARNING! )! );! ! // add records to the log! $log->addWarning('Foo');! $log->addError('Bar');!
44. Handlers •Stream •Mail •FirePHP •ChromePHP •Socket •Roating File •MongoDB •Syslog •Gelf •Null •Test •FingersCrossed
45. Log in a structured way
46. JSON http://www.ietf.org/rfc/rfc4627.txt
47. <?php! ! use Monolog\Logger;! use Monolog\Handler\StreamHandler;! use Monolog\Formatter\JsonFormatter;! ! $log = new Logger('name');! $handler = new StreamHandler(! 'path/to/your.log', Logger::WARNING! );! $handler->setFormatter(new JsonFormatter());! $log->pushHandler($handler);! ! !
48. Logs from other services
49. web server http service http service http service http service user request log log log log log
50. Correlation / Tracing ID
51. 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
52. X-Trace-Id: bbr8ehb984tbab894
53. 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
57. Aggregate the logs in a central place
58. Make them easily full-text searchable
59. Make them aggregate-able
60. Always Log to file
61. Seriously...
62. Always Log to file
63. Directly to a database
64. webserver webserver webserver DB
65. Disadvantages
66. Database is down?
67. Database is slow?
68. Database is full?
69. How to integrate access logs?
70. Influences application performance
71. Frontend?
72. Better solutions?
73. Logstash + Elasticsearch + Kibana
74. Full text search
75. Structured Messages
76. Always Log to file
77. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash logstash logstash
78. logstash http://logstash.net/
79. input filter output
80. Very rich plugin system
81. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash logstash logstash
82. 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" ]! }!
83. 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}..."! }! }
84. output {! amqp {! host => "amqp.host"! exchange_type => "fanout"! name => "logs"! }! }
85. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash logstash logstash
86. input {
 rabbitmq {
 queue => "logs"
 host => "amqp.host"
 exchange => "ls_exchange"
 exclusive => false
 }
 }
87. filter {! grok {
 match => [
 'Type','EntityNotFoundException| TimeoutException'
 ]
 break_on_match => true
 add_tag => ['not_serious']
 tag_on_failure => ['serious']
 }! ! }
88. output {
 elasticsearch {
 embedded => false
 bind_host => "localhost"
 bind_port => "9305"
 host => "localhost"
 cluster => "logs"
 }
 }
89. Kibana http://www.elasticsearch.org/overview/kibana/
91. Measuring
92. For knowing what happens
93. Technical Metrics
94. Business Metrics
95. Define your KPIs
96. Graphite http://graphite.wikidot.com/
97. webserver webserver webserver graphite UDP
98. StatsD https://github.com/etsy/statsd/
99. webserver webserver webserver graphite UDP statsd
100. webserver webserver webserver statsd statsd statsd graphite aggregated UPD message
101. webserver webserver webserver statsd statsd statsd graphite aggregated UPD message statsd
102. Metric?
103. Counters
104. Timers
105. Gauges
107. https://metrics.librato.com/
108. http://mashable.com/2010/10/13/etsy-office-pics/
109. Anomaly detection
110. http://codeascraft.com/2013/06/11/introducing-kale/
111. Remember: Response Times
112. Easiest approach:
     Get it out of the access log
113. 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/"
114. Is this actually what we want to measure?
115. External Resources CSS JavaScript Images Slow connections Slow Browsers SSL Handshakes DNS resolving
116. That is what we want to measure!
117. https://github.com/lognormal/boomerang
118. browser JS: boomerang logstash trackingServer access log requests tracking image with timing information as query parameters graphite statsd
119. 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