Logging: Your new best friend

Logs are not just used when things go wrong. They also help you keep track of what is going on within your app. We will look at how you can add helpful messages throughout your codebase and leave them there, even in production! We will cover common logging strategies, log aggregation, and how to efficiently work with your logs to get the data back out. We will also look at Graphite, which can help work out what actually happened by correlating logs with peaks/drops in other systems.

Transcript

1. Logging: Your new best friend
   Michael Heap (@mheap)
   Developer at DataSift
   Presented at php|tek, May 2016
   

   View Slide

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

   View Slide

3. @mheap
   https://joind.in/17042
   

   View Slide

4. Logging
   

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

    View Slide

13. Sound good?
    

    View Slide

14. Good!
    

    View Slide

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

    View Slide

16. Why log?
    

    View Slide

17. What went wrong?
    (Error log)
    

    View Slide

18. Who visited us?
    (Access log)
    

    View Slide

19. Who enabled ?
    (Audit log)
    

    View Slide

20. Runtime documentation
    (Application log)
    

    View Slide

21. I’m sold!
    

    View Slide

22. Can I have it for free?
    

    View Slide

23. Actually, yes!
    

    View Slide

24. (And more)
    

    View Slide

25. But that doesn’t help
    my application
    

    View Slide

26. Two types of log
    

    View Slide

27. Human readable
    

    View Slide

28. Machine readable
    

    View Slide

29. We should log both
    

    View Slide

30. What is an application log?
    

    View Slide

31. Debug information
    

    View Slide

32. Narrative information
    

    View Slide

33. Business information
    

    View Slide

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

    View Slide

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

    View Slide

36. Four W’s
    

    View Slide

37. When?
    

    View Slide

38. Who?
    

    View Slide

39. Where?
    

    View Slide

40. Why?
    

    View Slide

41. Getting started
    

    View Slide

42. error_log()
    

    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. 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. ini_set("error_log", "/var/log/casino-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

46. Pros
    ✴ It’s built in
    

    View Slide

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

    View Slide

48. Logging frameworks
    

    View Slide

49. 1) Monolog
    2) Everything else
    

    View Slide

50. require_once 'vendor/autoload.php';
    $log = new Monolog\Logger('casino-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('casino-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('casino-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('casino-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('casino-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. [2016-05-25 03:56:01] casino-app.INFO: Consonants in Michael: 4 [] []
    

    View Slide

56. FingersCrossedHandler
    

    View Slide

57. $log = new Monolog\Logger('casino-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('casino-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('casino-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('casino-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

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

    View Slide

62. Cons
    ✴ Instantiating an instance can be complicated
    

    View Slide

63. Error Levels
    

    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.
    Syslog (RFC 5424)
    

    View Slide

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

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

    View Slide

67. Everything is on fire
    

    View Slide

68. The ELK Stack
    

    View Slide

69. Elasticsearch
    Logstash
    Kibana
    

    View Slide

70. Logstash
    Elasticsearch
    Kibana
    

    View Slide

71. Logstash
    

    View Slide

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

73. Filters
    

    View Slide

74. filter {
    json {
    source => "message"
    add_field => [ “my_field", "tek_%{host}" ]
    }
    }
    

    View Slide

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

    View Slide

76. Accepted publickey for root from 172.14.183.11 port 22 ssh2
    

    View Slide

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

80. http://grokdebug.herokuapp.com/
    

    View Slide

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

82. Input -> Filter -> Output
    

    View Slide

83. Logstash is slow(ish)
    

    View Slide

84. Elasticsearch
    

    View Slide

85. Kibana
    

    View Slide

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

    View Slide

87. View Slide

88. View Slide

89. View Slide

90. View Slide

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

    View Slide

92. Asimov’s Law
    

    View Slide

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

    View Slide

94. @mheap’s Law
    

    View Slide

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

    View Slide

96. Plan for bursts of data
    

    View Slide

97. Disk space
    

    View Slide

98. Index management
    

    View Slide

99. Ship what’s relevant
    

    View Slide

100. Devs create dashboards
     

     View Slide

101. Unique request IDs
     

     View Slide

102. Normalise timezones
     

     View Slide

103. No really.
     Normalise timezones
     

     View Slide

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

     View Slide

105. Beats
     

     View Slide

106. Graphite
     

     View Slide

107. View Slide

108. View Slide

109. Pagerduty
     

     View Slide

110. Elastalert
     

     View Slide

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

     View Slide

112. Logging is required
     

     View Slide

113. Developers are empowered
     

     View Slide

114. Use PSR-3
     

     View Slide

115. Logging isn’t free
     

     View Slide

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

     View Slide

117. Thanks!
     I’ve been @mheap, you’ve been awesome.
     Please leave feedback on Joind.in
     https://joind.in/17042
     

     View Slide