Upgrade to Pro — share decks privately, control downloads, hide ads and more …

Measuring and Logging Everything in Real Time

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.

8e82eb7e128a14a16d642ae55227339b?s=128

Bastian Hofmann

April 08, 2016
Tweet

Transcript

  1. Measuring & Logging Everything in Real-Time @BastianHofmann

  2. Logging

  3. Measuring

  4. Real-Time

  5. Many roads

  6. A few words about me

  7. None
  8. None
  9. None
  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

  19. bool error_log ( string $message [, int $message_type = 0

    [, string $destination [, string $extra_headers ]]] )
  20. None
  21. callable set_exception_handler( callable $exception_handler );

  22. Log additional info

  23. None
  24. Not only error codes

  25. Request Information

  26. Handling Notices, Warnings, Errors

  27. callable set_error_handler( callable $error_handler [, int $error_types = E_ALL |

    E_STRICT ] );
  28. set_error_handler( function($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; });
  29. Or directly turn them into Exceptions

  30. set_error_handler( function($errno, $msg, $file, $line) { switch ($errno) { case

    E_RECOVERABLE_ERROR: case E_USER_ERROR: throw new \ErrorException($msg, null, $errno, $file, $line); case E_WARNING: case E_USER_WARNING: case E_CORE_WARNING: case E_COMPILE_WARNING: throw new WarningException($msg, null, $errno, $file, $line); case E_NOTICE: case E_USER_NOTICE: throw new NoticeException($msg, null, $errno, $file, $line); case E_STRICT: throw new StrictException($msg, null, $errno, $file, $line); } return true; }); $a = []; try { $b = $a['doesNotExist']; } catch (NoticeException $e) { }
  31. But what about fatal errors

  32. Use error_get_last() in a Shutdown Handler http://php.net/manual/en/function.error- get-last.php

  33. None
  34. http://php.net/manual/en/class.error.php

  35. Access Logs

  36. 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/"
  37. 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
  38. http://de.php.net/apache_note string apache_note ( string $note_name [, string $note_value =

    "" ] )
  39. LogFormat "...\"%{referer}i\" \"%{user- agent}i\" %{session_id}n %{account_id}n..." custom

  40. Debug Logs

  41. https://github.com/Seldaek/monolog/

  42. <?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');
  43. Handlers •Stream •Mail •FirePHP •ChromePHP •Socket •Roating File •MongoDB •Syslog

    •Gelf •Null •Test •FingersCrossed
  44. Log in a structured way

  45. JSON http://www.ietf.org/rfc/rfc4627.txt

  46. <?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);
  47. Logs from other services

  48. web server http service http service http service http service

    user request log log log log log
  49. Correlation / Tracing ID

  50. 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
  51. X-Trace-Id: bbr8ehb984tbab894

  52. 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
  53. None
  54. None
  55. None
  56. Aggregate the logs in a central place

  57. Make them easily full-text searchable

  58. Make them aggregate-able

  59. Always Log to file

  60. Directly to a database

  61. webserver webserver webserver DB

  62. Disadvantages

  63. Database is down?

  64. Database is slow?

  65. Database is full?

  66. How to integrate access logs?

  67. Influences application performance

  68. Frontend?

  69. Better solutions?

  70. Logstash + Elasticsearch + Kibana

  71. Full text search

  72. Structured Messages

  73. Always Log to file

  74. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash

    logstash logstash
  75. logstash http://logstash.net/

  76. input filter output

  77. Very rich plugin system

  78. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash

    logstash logstash
  79. 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" ] }
  80. 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}..." } }
  81. output { amqp { host => "amqp.host" exchange_type => "fanout"

    name => "logs" } }
  82. Logstash elasticsearch webserver webserver webserver AMQP log log log logstash

    logstash logstash
  83. input {
 rabbitmq {
 queue => "logs"
 host => "amqp.host"


    exchange => "ls_exchange"
 exclusive => false
 }
 }
  84. filter { grok {
 match => [
 'Type','EntityNotFoundException| TimeoutException'
 ]


    break_on_match => true
 add_tag => ['not_serious']
 tag_on_failure => ['serious']
 } }
  85. output {
 elasticsearch {
 embedded => false
 bind_host => "localhost"


    bind_port => "9305"
 host => "localhost"
 cluster => "logs"
 }
 }
  86. Kibana http://www.elasticsearch.org/overview/kibana/

  87. None
  88. Measuring

  89. For knowing what happens

  90. https://metrics.librato.com/

  91. None
  92. Graphite http://graphite.wikidot.com/

  93. None
  94. webserver webserver webserver graphite TCP

  95. StatsD https://github.com/etsy/statsd/

  96. webserver webserver webserver graphite UDP statsd TCP

  97. webserver webserver webserver statsd statsd statsd graphite

  98. webserver webserver webserver statsd statsd statsd graphite statsd

  99. Metric?

  100. Counters

  101. Timers

  102. Gauges

  103. Anomaly detection

  104. http://codeascraft.com/2013/06/11/introducing-kale/

  105. What can we measure?

  106. Business Metrics

  107. Experiments (A/B Testing)

  108. Partial rollouts

  109. Technical Metrics

  110. Response Times

  111. Easiest approach: Get it out of the access log

  112. 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/"
  113. Or measure it in your PHP process

  114. Is this actually what we want to measure?

  115. External Resources CSS JavaScript Images Slow connections Slow Browsers SSL

    Handshakes DNS resolving
  116. http://www.stevesouders.com/blog/2012/02/10/the-performance-golden-rule/

  117. That is what we want to measure!

  118. Navigation Timing API https://developer.mozilla.org/en-US/docs/ Navigation_timing

  119. None
  120. Resource Timing API http://www.w3.org/TR/resource-timing/

  121. None
  122. https://github.com/lognormal/boomerang

  123. Getting it back to the server

  124. Tracking request

  125. https://tracking.example.com/? page=profile&backend=123&co mplete=890&domReady=580

  126. browser JS: boomerang logstash trackingServer access log requests tracking image

    with timing information as query parameters graphite statsd
  127. Can we measure more?

  128. Load balancer

  129. Slow query logs

  130. From within your PHP app

  131. browser JS: boomerang logstash trackingServer access log requests tracking image

    with timing information as query parameters graphite statsd logstash load balancer access log logstash service access log
  132. Database Queries

  133. HTTP calls

  134. Cache access

  135. Rendering time

  136. More fine grained metrics

  137. By pages

  138. By component

  139. By browser

  140. By country

  141. Logged in / out

  142. Profiling information

  143. XHProf https://github.com/facebook/xhprof

  144. Use it in production for a subset of requests

  145. XHGUI https://github.com/perftools/xhgui

  146. None
  147. None
  148. None
  149. None
  150. https://blackfire.io/

  151. https://tidyways.io/

  152. None
  153. None
  154. Symfony Debug Toolbar

  155. None
  156. None
  157. Extend it http://symfony.com/doc/current/cookbook/profiler/ data_collector.html

  158. None
  159. None
  160. None
  161. None
  162. None
  163. None
  164. Aggregate it

  165. None
  166. https://joind.in/talk/43978

  167. 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