Log Everything with Fluentd

Transcript

1. Log Everything
   @kentaro
   

   View Slide

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

   View Slide

3. View Slide

4. Contributions
   to
   Fluentd World
   

   View Slide

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
   

   View Slide

6. View Slide

7. Log Format
   

   View Slide

8. View Slide

9. • Easy to extend
   • Easy to parse
   

   View Slide

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
    

    View Slide

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
    

    View Slide

12. Log Everything
    to
    Access Log File
    

    View Slide

13. with
    Log Everything
    to
    Access Log File
    

    View Slide

14. fluent-plugin-php
    

    View Slide

15. View Slide

16. apache_note()
    

    View Slide

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

    View Slide

18. Flags
    

    View Slide

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

    View Slide

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

    View Slide

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 ^/$
    ^$
    

    View Slide

22. out_rewrite
    

    View Slide

23. 
    type rewrite
    remove_prefix apache.log
    add_prefix filtered
    # url group
    
    key uriGroup
    pattern ^(.+)$
    append_to_tag true
    fallback other
    
    ...
    

    View Slide

24. ...
    # pc/smartphone
    
    key device
    pattern ^(pc|sp)$
    append_to_tag true
    
    ...
    

    View Slide

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

    View Slide

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
    

    View Slide

27. View Slide

28. Profiling
    

    View Slide

29. Problem
    Hard to track results
    continuously
    

    View Slide

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’);
    }
    }
    

    View Slide

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));
    }
    

    View Slide

32. static public function httpd_note($name, $value = '')
    {
    if (function_exists('apache_note')) {
    if ($value) {
    return apache_note($name, $value);
    } else {
    // do nothing...
    }
    }
    }
    

    View Slide

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
    

    View Slide

34. out_flatten
    

    View Slide

35. 
    type flatten
    key foo
    add_tag_prefix flattened.
    remove_tag_prefix test.
    inner_key value_for_flat_key
    
    "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
    

    View Slide

36. 
    type flatten
    key profile
    inner_key response_time
    add_tag_prefix flattened.
    remove_tag_prefix app.httpd.access.
    
    

    View Slide

37. View Slide

38. View Slide

39. Bonus
    

    View Slide

40. out_extract_query_params
    

    View Slide

41. 
    type extract_query_params
    key url
    add_tag_prefix extracted.
    only foo, baz
    
    "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
    

    View Slide

42. 
    type extract_query_params
    key path
    add_tag_prefix extracted.
    only hoge
    
    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
    

    View Slide

43. Recap
    

    View Slide

44. • Adopt LTSV asap
    • Log things as much
    as possible
    • My plugins help you
    

    View Slide