Log Everything with Fluentd

Log Everything with Fluentd

23f4d5d797a91b6d17d627b90b5a42d9?s=128

Kentaro Kuribayashi

February 15, 2013
Tweet

Transcript

  1. Log Everything @kentaro

  2. @kentaro Software engineer Rubyist / Perl Monger Kentaro Kuribayashi paperboy&co.

    PHPer
  3. None
  4. Contributions to Fluentd World

  5. out_flatten https://github.com/kentaro/fluent-plugin-flatten out_extract_query_params https://github.com/kentaro/fluent-plugin-extract_query_params out_rewrite https://github.com/kentaro/fluent-plugin-rewrite

  6. None
  7. Log Format

  8. None
  9. • Easy to extend • Easy to parse

  10. Key Description Apache Nginx time Time request is received %t

    $time_local vhost Host name %v $host host Remote host %h $remote_addr method Request method %m $method path Request path %U%q $request_uri version HTTP version %H $server_protocol status Response status %>s $status size Response size %b $body_bytes_sent referer Referer %{Referer}i $http_referer ua User-agent %{User-Agent}i $http_user_agent restime Time elapsed for response %D $request_time ustime Time elapsed for upstream response - $upstream_response_time
  11. LogFormat "vhost:%V\ttime:%t\thost:%h\tmethod:%m\tpath:%U%q \tversion:%H\tstatus:%>s\tsize:%b\treferer:%{Referer}i\tua: %{User-Agent}i\trestime:%D" ltsv log_format ltsv "vhost:$host\ttime:$time_local\thost: $remote_addr\tmethod:$request_method\tpath:$request_uri \tversion:$server_protocol\tstatus:$status\tsize:

    $body_bytes_sent\treferer:$http_referer\tua: $http_user_agent\trestime:$request_time\tustime: $upstream_response_time"; Apache Nginx
  12. Log Everything to Access Log File

  13. with Log Everything to Access Log File

  14. fluent-plugin-php

  15. None
  16. apache_note()

  17. %{foo}n #=> bar apache_note(‘foo’, ‘bar’) PHP Code Apache Log Format

  18. Flags

  19. • URL Groups • User/Guest • Device • Bot Access

    • etc.
  20. Structuralize URLs • Visualization • Analysis • Rough grouping is

    enough
  21. Group Path read ^/book buy ^/cart ^/book/\d+/purchase find ^/special ^/label

    ^/users ^/books ^/authors write ^/admin ^/users/{account}/draft set ^/users/{account}/manage ^/users/{account}/profile ^/users/{account}/account communicate ^/users/{account}/contact ^/users/{account}/reaction top ^/$ ^$
  22. out_rewrite

  23. <match apache.log.**> type rewrite remove_prefix apache.log add_prefix filtered # url

    group <rule> key uriGroup pattern ^(.+)$ append_to_tag true fallback other </rule> ...
  24. ... # pc/smartphone <rule> key device pattern ^(pc|sp)$ append_to_tag true

    </rule> ...
  25. ... # user/guest <rule> key loggedIn pattern ^(user|guest)$ append_to_tag true

    </rule> </match>
  26. filtered.book.pc.user => { ... } filtered.book.sp.guest => { ... }

    filtered.read.pc.guest => { ... } ... uriGroup:book device:pc loggedIn:user ... ... uriGroup:book device:sp loggedIn:guest ... ... uriGroup:read device:pc loggedIn:guest ... Raw Log Lines Filtered Key/Values
  27. None
  28. Profiling

  29. Problem Hard to track results continuously

  30. class Foo { function hoge () { $this->profiler->start(‘method-hoge’); // ...

    do something ... $this->profiler->end(‘method-hoge’); } function fuga () { $this->profiler->start(‘method-fuga-foo’); // ... do something ... $this->profiler->end(‘method-fuga-foo’); $this->profiler->start(‘method-fuga-bar’); // ... do something ... $this->profiler->end(‘method-fuga-bar’); } }
  31. public function dispatchLoopShutdown() { $profile_result = Model_Measure::dump(); if (APPLICATION_ENV !==

    'production') { Pb_Logger::debug($profile_result); } Pb_Util::httpd_note('profile', json_encode($profile_result)); }
  32. static public function httpd_note($name, $value = '') { if (function_exists('apache_note'))

    { if ($value) { return apache_note($name, $value); } else { // do nothing... } } }
  33. ... profile:%{profile}n" ... profile:{\"book.index.get_book\":0.1010639667511, \"book.index.get_author\":0.2032630443573, \"book.index.get_chapters\":0.23988509178162, \"book.index.get_version\":0.039833068847656, \"book.index.check\":0.00014090538024902, \"book.index.get_pager\":0.00022792816162109} Log

    Format Raw Log Line
  34. out_flatten

  35. <match test.**> type flatten key foo add_tag_prefix flattened. remove_tag_prefix test.

    inner_key value_for_flat_key </match> "test" => { "foo" => '{"bar" : {"qux" : "quux", "hoe" : "poe" }, "baz" : "bazz" }', "hoge" => "fuga" } "flattened.foo.bar.qux" => { "value_for_flat_key" => "quux" } "flattened.foo.bar.hoe" => { "value_for_flat_key" => "poe" } "flattened.foo.baz" => { "value_for_flat_key" => "bazz" } flattened
  36. <match app.httpd.access> type flatten key profile inner_key response_time add_tag_prefix flattened.

    remove_tag_prefix app.httpd.access. </store>
  37. None
  38. None
  39. Bonus

  40. out_extract_query_params

  41. <match test.**> type extract_query_params key url add_tag_prefix extracted. only foo,

    baz </match> "test" => { "url" => "http://example.com/?foo=bar&baz=qux&hoge=fuga" } "extracted.test" => { "url" => "http://example.com/?foo=bar&baz=qux&hoge=fuga" "foo" => "bar", "baz" => "qux" } Extract Params
  42. <match access_log> type extract_query_params key path add_tag_prefix extracted. only hoge

    </match> method:%m path:%U%q version:%H #=> method:GET path:/foo/bar?campaign_id=1 version:HTTP1.1 extracted.access_log => { "method" : "GET", "path" : "/foo/bar?campaign_id=1", "version" : "HTTP1.1", "campaign_id" : "1" } Extract Params Works fine with LTSV
  43. Recap

  44. • Adopt LTSV asap • Log things as much as

    possible • My plugins help you