Metrics and an application log: Your new best friends

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. Logging: Your new best friend
   Michael Heap (@mheap)
   Presented at PHPConfPH, October 2016
   

   View Slide

2. Me!
   I’m Michael
   I’m @mheap
   Developer at digi.me
   

   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 services
   7. Conclusion
   

   View Slide

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

   View Slide

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

   View Slide

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

   View Slide

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

   View Slide

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

   View Slide

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

    View Slide

11. 1. Logging
    2. Getting started
    3. The ELK stack
    4. Logs and dashboards
    5. Log management
    6. Supporting services
    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 services
    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. We should log both
    

    View Slide

29. What is an application log?
    

    View Slide

30. Debug information
    

    View Slide

31. Narrative information
    

    View Slide

32. Business information
    

    View Slide

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

    View Slide

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

    View Slide

35. Four W’s
    

    View Slide

36. When?
    

    View Slide

37. Who?
    

    View Slide

38. Where?
    

    View Slide

39. Why?
    

    View Slide

40. Getting started
    

    View Slide

41. error_log()
    

    View Slide

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

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

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

45. Pros
    ✴ It’s built in
    

    View Slide

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

    View Slide

47. Logging frameworks
    

    View Slide

48. 1) Monolog
    2) Everything else
    

    View Slide

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

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

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

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. [2016-05-25 03:56:01] my-app.INFO: Consonants in Michael: 4 [] []
    

    View Slide

55. FingersCrossedHandler
    

    View Slide

56. $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

57. $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

58. $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

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}");
    $log->error("Something bad happened");
    return $c;
    }
    echo countConsonants("Michael", $log);
    

    View Slide

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

    View Slide

61. Cons
    ✴ Instantiating an instance can be complicated
    

    View Slide

62. Error Levels
    

    View Slide

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

64. 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.
    PSR3
    

    View Slide

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

    View Slide

66. Everything is on fire
    

    View Slide

67. The ELK Stack
    

    View Slide

68. Elasticsearch
    Logstash
    Kibana
    

    View Slide

69. Logstash
    Elasticsearch
    Kibana
    

    View Slide

70. Logstash
    

    View Slide

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

72. Filters
    

    View Slide

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

    View Slide

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

    View Slide

75. Accepted publickey for root from 172.14.183.11 port 22 ssh2
    

    View Slide

76. Accepted publickey for root from 172.14.183.11 port 22 ssh2
    

    View Slide

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

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

79. http://grokdebug.herokuapp.com/
    

    View Slide

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

81. Input -> Filter -> Output
    

    View Slide

82. Logstash is slow(ish)
    

    View Slide

83. Elasticsearch
    

    View Slide

84. Kibana
    

    View Slide

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

    View Slide

86. View Slide

87. View Slide

88. View Slide

89. View Slide

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

    View Slide

91. Asimov’s Law
    

    View Slide

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

    View Slide

93. @mheap’s Law
    

    View Slide

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

    View Slide

95. Plan for bursts of data
    

    View Slide

96. Disk space
    

    View Slide

97. Index management
    

    View Slide

98. Ship what’s relevant
    

    View Slide

99. Devs create dashboards
    

    View Slide

100. Unique request IDs
     

     View Slide

101. Normalise timezones
     

     View Slide

102. No really.
     Normalise timezones
     

     View Slide

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

     View Slide

104. Beats
     

     View Slide

105. Graphite
     

     View Slide

106. View Slide

107. View Slide

108. Pagerduty
     

     View Slide

109. Elastalert
     

     View Slide

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

     View Slide

111. Logging is required
     

     View Slide

112. Developers are empowered
     

     View Slide

113. Use PSR-3
     

     View Slide

114. Logging isn’t free
     

     View Slide

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

     View Slide

116. Thanks!
     I’ve been @mheap, you’ve been awesome.
     Any questions?
     

     View Slide