Metrics and an application log - FOSDEM

Do you remember the time you spent an afternoon putting print statements in your app trying to debug an issue and removed them before shipping the fix, only to add them back in a day later to work on another issue? Wouldn't it be great if those debug statements could just stay in your code forever? Like a little gift that keeps on giving, not just for you, but for everyone else on your team too.

That's what an application log is for! Logs aren't just for when things go wrong. They're for helping you to keep track of what's going on within your application.

We take a look at how you can add helpful messages throughout your codebase and leave them there, even in production! We'll cover common logging strategies, log aggregation and how to efficiently work with your logs to get the data back out again.

We'll also take a look at metrics solutions such as Graphite that can help augment your logs to help work out what was going on by correlating event logs with peaks/drops in other monitoring systems.

Transcript

1. Metrics and an application log: Your
   new best friend
   Michael Heap (@mheap)
   Presented at FOSDEM, February 2017
   

   View Slide

2. Me!
   I’m Michael
   I’m @mheap
   Freelance @ Intechrity
   

   View Slide

3. Logging
   

   View Slide

4. 1. Logging
   2. Getting started
   3. The ELK stack
   4. Logs and dashboards
   5. Log management
   6. Supporting tools
   7. Conclusion
   

   View Slide

5. 1. Logging
   2. Getting started
   3. The ELK stack
   4. Logs and dashboards
   5. Log management
   6. Supporting tools
   7. Conclusion
   

   View Slide

6. 1. Logging
   2. Getting started
   3. The ELK stack
   4. Logs and dashboards
   5. Log management
   6. Supporting tools
   7. Conclusion
   

   View Slide

7. 1. Logging
   2. Getting started
   3. The ELK stack
   4. Logs and dashboards
   5. Log management
   6. Supporting tools
   7. Conclusion
   

   View Slide

8. 1. Logging
   2. Getting started
   3. The ELK stack
   4. Logs and dashboards
   5. Log management
   6. Supporting tools
   7. Conclusion
   

   View Slide

9. 1. Logging
   2. Getting started
   3. The ELK stack
   4. Logs and dashboards
   5. Log management
   6. Supporting tools
   7. Conclusion
   

   View Slide

10. 1. Logging
    2. Getting started
    3. The ELK stack
    4. Logs and dashboards
    5. Log management
    6. Supporting tools
    7. Conclusion
    

    View Slide

11. 1. Logging
    2. Getting started
    3. The ELK stack
    4. Logs and dashboards
    5. Log management
    6. Supporting tools
    7. Conclusion
    

    View Slide

12. Sound good?
    

    View Slide

13. Good!
    

    View Slide

14. 1. Logging
    2. Getting started
    3. The ELK stack
    4. Logs and dashboards
    5. Log management
    6. Supporting tools
    7. Conclusion
    

    View Slide

15. Why log?
    

    View Slide

16. What went wrong?
    (Error log)
    

    View Slide

17. Who visited us?
    (Access log)
    

    View Slide

18. Who enabled ?
    (Audit log)
    

    View Slide

19. Runtime documentation
    (Application log)
    

    View Slide

20. I’m sold!
    

    View Slide

21. Can I have it for free?
    

    View Slide

22. Actually, yes!
    

    View Slide

23. (And more)
    

    View Slide

24. But that doesn’t help
    my application
    

    View Slide

25. Two types of log
    

    View Slide

26. Human readable
    

    View Slide

27. Machine readable
    

    View Slide

28. Two types of log
    

    View Slide

29. One type of log
    

    View Slide

30. Machine and Human
    readable
    

    View Slide

31. JSON / logfmt
    

    View Slide

32. What is an application log?
    

    View Slide

33. Debug information
    

    View Slide

34. Narrative information
    

    View Slide

35. Business information
    

    View Slide

36. “An application log
    signposts every twist and
    turn through the code”
    

    View Slide

37. 1. Logging
    2. Getting started
    3. The ELK stack
    4. Logs and dashboards
    5. Log management
    6. Supporting tools
    7. Conclusion
    

    View Slide

38. Four W’s
    

    View Slide

39. When?
    

    View Slide

40. Who?
    

    View Slide

41. Where?
    

    View Slide

42. Why?
    

    View Slide

43. Getting started
    

    View Slide

44. error_log()
    

    View Slide

45. function countConsonants($str){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    error_log("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael");
    

    View Slide

46. function countConsonants($str){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    error_log("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael");
    

    View Slide

47. ini_set("error_log", "/var/log/my-app.log");
    function countConsonants($str){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    error_log("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael");
    

    View Slide

48. Pros
    ✴ It’s built in
    

    View Slide

49. Cons
    ✴ Is it semantically correct?
    ✴ Errors mixed with informational logs
    ✴ It’s not very powerful
    

    View Slide

50. Logging frameworks
    

    View Slide

51. 1) Monolog
    2) Everything else
    

    View Slide

52. require_once 'vendor/autoload.php';
    $log = new Monolog\Logger('my-app');
    $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG));
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

53. require_once 'vendor/autoload.php';
    $log = new Monolog\Logger('my-app');
    $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG));
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

54. require_once 'vendor/autoload.php';
    $log = new Monolog\Logger('my-app');
    $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG));
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

55. require_once 'vendor/autoload.php';
    $log = new Monolog\Logger('my-app');
    $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG));
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

56. require_once 'vendor/autoload.php';
    $log = new Monolog\Logger('my-app');
    $log->pushHandler(new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG));
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

57. [2016-05-25 03:56:01] my-app.INFO: Consonants in Michael: 4 [] []
    

    View Slide

58. FingersCrossedHandler
    

    View Slide

59. $log = new Monolog\Logger('my-app');
    $streamHandler = new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG);
    $fcHandler = new Monolog\Handler\FingersCrossedHandler($streamHandler,
    Monolog\Logger::ERROR);
    $log->pushHandler($fcHandler);
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

60. $log = new Monolog\Logger('my-app');
    $streamHandler = new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG);
    $fcHandler = new Monolog\Handler\FingersCrossedHandler($streamHandler,
    Monolog\Logger::ERROR);
    $log->pushHandler($fcHandler);
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

61. $log = new Monolog\Logger('my-app');
    $streamHandler = new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG);
    $fcHandler = new Monolog\Handler\FingersCrossedHandler($streamHandler,
    Monolog\Logger::ERROR);
    $log->pushHandler($fcHandler);
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

62. View Slide

63. $log = new Monolog\Logger('my-app');
    $streamHandler = new Monolog\Handler\StreamHandler('/tmp/app.log',
    Monolog\Logger::DEBUG);
    $fcHandler = new Monolog\Handler\FingersCrossedHandler($streamHandler,
    Monolog\Logger::ERROR);
    $log->pushHandler($fcHandler);
    function countConsonants($str, $log){
    $c = strlen(str_replace(['a','e','i','o','u'],'', $str));
    $log->info("Consonants in {$str}: {$c}");
    $log->error("Something bad happened");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

64. [2016-05-25 03:56:01] my-app.INFO: Consonants in Michael: 4 [] []

    [2016-05-25 03:56:01] my-app.ERROR: Something bad happened [] []
    

    View Slide

65. Pros
    ✴ It’s an object! Dependency injection FTW
    ✴ Supports multiple log writers
    ✴ Log level support
    

    View Slide

66. Cons
    ✴ Instantiating an instance can be complicated
    

    View Slide

67. Error Levels
    

    View Slide

68. 0. Emergency System is unusable
    1. Alert Should be corrected immediately
    2. Critical Critical conditions
    3. Error Error conditions
    4. Warning May indicate that an error will occur if action is not taken.
    5. Notice Events that are unusual, but not error conditions.
    6. Informational Normal operational messages that require no action.
    7. Debug Information useful to developers for debugging the application.
    Syslog (RFC 5424)
    

    View Slide

69. 0. Emergency System is unusable
    1. Alert Should be corrected immediately
    2. Critical Critical conditions
    3. Error Error conditions
    4. Warning May indicate that an error will occur if action is not taken.
    5. Notice Events that are unusual, but not error conditions.
    6. Informational Normal operational messages that require no action.
    7. Debug Information useful to developers for debugging the application.
    PSR-3
    

    View Slide

70. 1. Logging
    2. Getting started
    3. The ELK stack
    4. Logs and dashboards
    5. Log management
    6. Supporting tools
    7. Conclusion
    

    View Slide

71. Everything is on fire
    

    View Slide

72. The ELK Stack
    

    View Slide

73. Elasticsearch
    Logstash
    Kibana
    

    View Slide

74. Logstash
    Elasticsearch
    Kibana
    

    View Slide

75. Logstash
    

    View Slide

76. Beats
    CouchDB_Changes
    Drupal_DBLog
    Elasticsearch
    Exec
    Event log
    File
    Ganglia
    Gelf
    Generator
    Graphite
    Github
    Heartbeat
    Heroku
    HTTP
    HTTP_Poller
    IRC
    IMAP
    JDBC
    JMX

    Kafka
    Log4J
    Lumberjack
    Meetup
    Pipe
    Puppet_Facter
    Relp
    RSS
    Backspace
    RabbitMQ
    Redis
    Salesforce
    SNMPTrap
    Stdin
    sqlite
    S3
    SQS
    Stomp
    Syslog
    TCP
    Twitter
    Unix
    UDP
    Varnishlog
    WMI
    Web socket
    XMPP
    Zenoss
    ZeroMQ
    Inputs
    

    View Slide

77. Filters
    

    View Slide

78. filter {
    json {
    source => "message"
    add_field => [ “my_field", “mheap_%{host}” ]
    }
    }
    

    View Slide

79. filter {
    kv {
    default_keys => [ "from", "logstash@example.com",
    "to", "default@dev.null" ]
    }
    }
    

    View Slide

80. Accepted publickey for root from 172.14.183.11 port 22 ssh2
    

    View Slide

81. Accepted publickey for root from 172.14.183.11 port 22 ssh2
    

    View Slide

82. filter {
    grok {
    match => { "message" => "Accepted
    %{WORD:auth_method} for %{USER:username} from
    %{IP:src_ip} port %{INT:src_port} ssh2" }
    }
    }
    Accepted publickey for root from 172.14.183.11 port 22 ssh2
    

    View Slide

83. filter {
    grok {
    match => { "message" => "Accepted
    %{WORD:auth_method} for %{USER:username} from
    %{IP:src_ip} port %{INT:src_port} ssh2" }
    }
    }
    Accepted publickey for root from 172.14.183.11 port 22 ssh2
    

    View Slide

84. http://grokdebug.herokuapp.com/
    

    View Slide

85. Boundary
    Circus
    CSV
    Cloud watch
    Datadog
    Datadog_Metrics
    Email
    Elastic search
    Exec
    File
    Google BigQuery
    Google Cloud Storage
    Ganglia
    Gelf
    Graphtastic
    Graphite
    Hipchat
    HTTP
    IRC
    InfluxDB
    Juggernaut
    Jira
    Kafka
    Lumberjack
    Librato
    Loggly
    MongoDB
    MetricCatcher
    Nagios
    Null
    OpenTSDB
    Pagerduty
    Pipe
    Riemann
    Redmine
    Rackspace
    RabbitMQ
    Redis
    Riak
    S3
    SQS
    Stomp
    StatsD
    Solr
    SNS
    Syslog
    Stdout
    TCP
    UDP
    WebHDFS
    Websocket
    XMPP
    Outputs
    Zabbix
    ZeroMQ
    

    View Slide

86. Input -> Filter -> Output
    

    View Slide

87. Logstash is slow(ish)
    

    View Slide

88. Elasticsearch
    

    View Slide

89. Kibana
    

    View Slide

90. 1. Logging
    2. Getting started
    3. The ELK stack
    4. Logs and dashboards
    5. Log management
    6. Supporting tools
    7. Conclusion
    

    View Slide

91. View Slide

92. View Slide

93. View Slide

94. View Slide

95. 1. Logging
    2. Getting started
    3. The ELK stack
    4. Logs and dashboards
    5. Log management
    6. Supporting tools
    7. Conclusion
    

    View Slide

96. Asimov’s Law
    

    View Slide

97. “A robot may not injure a human being
    or, through inaction, allow a human being
    to come to harm.”
    

    View Slide

98. @mheap’s Law
    

    View Slide

99. “An application log may not injure a an
    application’s performance or readability”
    

    View Slide

100. Plan for bursts of data
     

     View Slide

101. Disk space
     

     View Slide

102. Index management
     

     View Slide

103. Ship what’s relevant
     

     View Slide

104. Devs create dashboards
     

     View Slide

105. Unique request IDs
     

     View Slide

106. Normalise timezones
     

     View Slide

107. No really.
     Normalise timezones
     

     View Slide

108. 1. Logging
     2. Getting started
     3. The ELK stack
     4. Logs and dashboards
     5. Log management
     6. Supporting tools
     7. Conclusion
     

     View Slide

109. Filebeat
     

     View Slide

110. Graphite / Grafana
     

     View Slide

111. View Slide

112. View Slide

113. View Slide

114. Pagerduty
     

     View Slide

115. View Slide

116. 1. Logging
     2. Getting started
     3. The ELK stack
     4. Logs and dashboards
     5. Log management
     6. Supporting tools
     7. Conclusion
     

     View Slide

117. Logging is required
     

     View Slide

118. Developers are empowered
     

     View Slide

119. Logging isn’t free
     

     View Slide

120. “Would you rather fly slowly
     or fly blind?”
     

     View Slide

121. Thanks!
     I’ve been @mheap, you’ve been awesome.
     Any questions?
     https://joind.in/talk/54183
     

     View Slide