$30 off During Our Annual Pro Sale. View Details »

A Boy and His Logs

A Boy and His Logs

Presentation for DevOpsATL 07/11/2012

John Vincent

July 12, 2012
Tweet

More Decks by John Vincent

Other Decks in Technology

Transcript

  1. A boy and his logs
    John E. Vincent
    (@lusis)
    DevOpsATL
    7/11/12

    View Slide

  2. Let me tell you a story about
    a boy....

    View Slide

  3. View Slide

  4. He's got logs over here..

    View Slide

  5. Huge logs...

    View Slide

  6. Can't make any sense of them...

    View Slide

  7. (Probably came from a Node app)

    View Slide

  8. There's a lot of data in these logs

    View Slide

  9. He just wants to get the over here

    View Slide

  10. Maybe analyze them?

    View Slide

  11. It's cool, man..

    View Slide

  12. Logstash makes logging sexy

    View Slide

  13. Have a seat over here and I'll tell you
    how.

    View Slide

  14. What is Logstash?

    View Slide

  15. Let's answer a different
    question first...

    View Slide

  16. What are logs?

    View Slide

  17. Jul 11 09:07:37 jvstratusmbp login[23211]: in pam_sm_acct_mgmt():
    OpenDirectory - Membership cache TTL set to 1800.
    Jul 11 09:07:37 jvstratusmbp login[23211]: in od_record_check_pwpolicy():
    retval: 0
    Jul 11 09:07:37 jvstratusmbp login[23211]: in
    od_record_attribute_create_cfstring(): returned 2 attributes for
    dsAttrTypeStandard:AuthenticationAuthority
    Jul 11 09:07:40 jvstratusmbp login[23266]: in pam_sm_acct_mgmt():
    OpenDirectory - Membership cache TTL set to 1800.
    Jul 11 09:07:40 jvstratusmbp login[23266]: in od_record_check_pwpolicy():
    retval: 0
    Jul 11 09:07:40 jvstratusmbp login[23266]: in
    od_record_attribute_create_cfstring(): returned 2 attributes for
    dsAttrTypeStandard:AuthenticationAuthority
    Jul 11 09:13:51 jvstratusmbp login[23333]: in pam_sm_acct_mgmt():
    OpenDirectory - Membership cache TTL set to 1800.
    Jul 11 09:13:51 jvstratusmbp login[23333]: in od_record_check_pwpolicy():
    retval: 0
    Jul 11 09:13:51 jvstratusmbp login[23333]: in
    od_record_attribute_create_cfstring(): returned 2 attributes for
    dsAttrTypeStandard:AuthenticationAuthority
    Jul 11 09:28:41 jvstratusmbp login[23416]: in pam_sm_acct_mgmt():
    OpenDirectory - Membership cache TTL set to 1800.
    Jul 11 09:28:41 jvstratusmbp login[23416]: in od_record_check_pwpolicy():
    retval: 0
    Jul 11 09:28:41 jvstratusmbp login[23416]: in
    od_record_attribute_create_cfstring(): returned 2 attributes for
    dsAttrTypeStandard:AuthenticationAuthority

    View Slide

  18. com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException:
    Column 'machine_image' cannot be null
    at sun.reflect.GeneratedConstructorAccessor491.newInstance(Unknown
    Source)
    at
    sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstruc
    torAccessorImpl.java:27)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
    at com.mysql.jdbc.Util.handleNewInstance(Util.java:406)
    at com.mysql.jdbc.Util.getInstance(Util.java:381)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1015)
    at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:956)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3558)
    at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3490)
    at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1959)
    at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2109)
    at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2648)
    at
    com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2077
    )
    at
    com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2362)
    at
    com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2280)
    at
    com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2265)
    at
    org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(Delegating
    PreparedStatement.java:105)
    at
    org.apache.commons.dbcp.DelegatingPreparedStatement.executeUpdate(Delegating
    PreparedStatement.java:105)

    View Slide

  19. [11 Jul 2012 00:08:42.066] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:08:42.116] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:08:42.105] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:08:42.105] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:08:42.140] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:39:02.078] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `provider_rdbms`.`admin_user`, `provider_rdbms`.`cloud_id`,
    `provider_rdbms`.`creation_timestamp`, `provider_rdbms`.`current_state`,
    `provider_rdbms`.`database_engine`, `provider_rdbms`.`description`,
    `provider_rdbms`.`dns_name`, `provider_rdbms`.`enstratus_rdbms_id`, `provider_rdbms`.`ha`,
    `provider_rdbms`.`host_port`, `provider_rdbms`.`maintenance_end_day`,
    `provider_rdbms`.`maintenance_end_hour`, `provider_rdbms`.`maintenance_end_minute`,
    `provider_rdbms`.`maintenance_start_day`, `provider_rdbms`.`maintenance_start_hour`,
    `provider_rdbms`.`maintenance_start_minute`, `provider_rdbms`.`name`,
    `provider_rdbms`.`product_size`, `provider_rdbms`.`provider_configuration_id`,
    `provider_rdbms`.`provider_data_center_id`, `provider_rdbms`.`provider_owner_id`,
    `provider_rdbms`.`provider_rdbms_id`, `provider_rdbms`.`provider_region_id`,
    `provider_rdbms`.`recovery_point_timestamp`, `provider_rdbms`.`snapshot_end_day`,
    `provider_rdbms`.`snapshot_end_hour`, `provider_rdbms`.`snapshot_end_minute`,
    `provider_rdbms`.`snapshot_retention_in_days`, `provider_rdbms`.`snapshot_start_day`,
    `provider_rdbms`.`snapshot_start_hour`, `provider_rdbms`.`snapshot_start_minute`,
    `provider_rdbms`.`storage_in_gb` FROM `provider_rdbms` WHERE `provider_rdbms`.`cloud_id` = ?
    AND `provider_rdbms`.`provider_owner_id` = ? AND `provider_rdbms`.`provider_region_id` = ?
    AND `provider_rdbms`.`provider_rdbms_id` = ?

    View Slide

  20. [11 Jul 2012 00:08:42.066] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:08:42.116] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:08:42.105] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:08:42.105] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:08:42.140] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `region`.`account`, `region`.`active`, `region`.`keypair`, `region`.`provider_region`,
    `region`.`provider_region_id`, `region`.`region_id` FROM `region` WHERE `region`.`account`
    = ? ORDER BY `region`.`provider_region_id`
    [11 Jul 2012 00:39:02.078] [WARN.org.dasein.persist.jdbc.Loader] SLOW QUERY: SELECT
    `provider_rdbms`.`admin_user`, `provider_rdbms`.`cloud_id`,
    `provider_rdbms`.`creation_timestamp`, `provider_rdbms`.`current_state`,
    `provider_rdbms`.`database_engine`, `provider_rdbms`.`description`,
    `provider_rdbms`.`dns_name`, `provider_rdbms`.`enstratus_rdbms_id`, `provider_rdbms`.`ha`,
    `provider_rdbms`.`host_port`, `provider_rdbms`.`maintenance_end_day`,
    `provider_rdbms`.`maintenance_end_hour`, `provider_rdbms`.`maintenance_end_minute`,
    `provider_rdbms`.`maintenance_start_day`, `provider_rdbms`.`maintenance_start_hour`,
    `provider_rdbms`.`maintenance_start_minute`, `provider_rdbms`.`name`,
    `provider_rdbms`.`product_size`, `provider_rdbms`.`provider_configuration_id`,
    `provider_rdbms`.`provider_data_center_id`, `provider_rdbms`.`provider_owner_id`,
    `provider_rdbms`.`provider_rdbms_id`, `provider_rdbms`.`provider_region_id`,
    `provider_rdbms`.`recovery_point_timestamp`, `provider_rdbms`.`snapshot_end_day`,
    `provider_rdbms`.`snapshot_end_hour`, `provider_rdbms`.`snapshot_end_minute`,
    `provider_rdbms`.`snapshot_retention_in_days`, `provider_rdbms`.`snapshot_start_day`,
    `provider_rdbms`.`snapshot_start_hour`, `provider_rdbms`.`snapshot_start_minute`,
    `provider_rdbms`.`storage_in_gb` FROM `provider_rdbms` WHERE `provider_rdbms`.`cloud_id` = ?
    AND `provider_rdbms`.`provider_owner_id` = ? AND `provider_rdbms`.`provider_region_id` = ?
    AND `provider_rdbms`.`provider_rdbms_id` = ?

    View Slide

  21. Jul 11 06:24:27 localhost haproxy[953]: 127.0.0.1:47963 [11/Jul/2012:06:14:29.940] api-fe
    api-be/api-c 0/0/0/597587/+597587 200 +181 - - ---- 9/9/9/5/0 0/0 {50.18.111.113} "GET
    /api/enstratus/2012-02-29/infrastructure/Snapshot?regionId=7141&volumeId=118593 HTTP/1.1"
    Jul 11 06:24:27 localhost haproxy[953]: 127.0.0.1:48044 [11/Jul/2012:06:24:25.601] api-fe
    api-be/api-b 0/0/0/1954/+1954 204 +89 - - ---- 9/9/8/4/0 0/0 {50.18.111.113} "DELETE
    /api/enstratus/2012-02-29/infrastructure/Snapshot/20908911 HTTP/1.1"
    Jul 11 06:24:27 localhost haproxy[953]: 127.0.0.1:48042 [11/Jul/2012:06:24:25.412] api-fe
    api-be/api-c 0/0/0/2389/+2389 204 +89 - - ---- 9/9/7/4/0 0/0 {50.18.111.113} "DELETE
    /api/enstratus/2012-02-29/infrastructure/Snapshot/20861069 HTTP/1.1"
    Jul 11 06:24:27 localhost haproxy[953]: 127.0.0.1:48046 [11/Jul/2012:06:24:26.092] api-fe
    api-be/api-c 0/0/0/1880/+1880 204 +89 - - ---- 9/9/6/3/0 0/0 {50.18.111.113} "DELETE
    /api/enstratus/2012-02-29/infrastructure/Snapshot/20908906 HTTP/1.1"
    Jul 11 06:24:29 localhost haproxy[953]: 127.0.0.1:48048 [11/Jul/2012:06:24:27.409] api-fe
    api-be/api-b 0/0/0/2000/+2000 204 +89 - - ---- 7/7/7/4/0 0/0 {50.18.111.113} "DELETE
    /api/enstratus/2012-02-29/infrastructure/Snapshot/20908912 HTTP/1.1"
    Jul 11 06:24:30 localhost haproxy[953]: 127.0.0.1:47965 [11/Jul/2012:06:14:30.013] api-fe
    api-be/api-b 0/0/0/-1/+600002 504 +194 - - sH-- 6/6/5/2/0 0/0 {50.18.111.113} "GET
    /api/enstratus/2012-02-29/infrastructure/Snapshot?regionId=7141&volumeId=148762 HTTP/1.1"
    Jul 11 06:24:30 localhost haproxy[953]: 127.0.0.1:47967 [11/Jul/2012:06:14:30.729] api-fe
    api-be/api-c 0/0/0/-1/+600001 504 +194 - - sH-- 4/4/4/2/0 0/0 {50.18.111.113} "GET
    /api/enstratus/2012-02-29/infrastructure/Snapshot?regionId=68&volumeId=133383 HTTP/1.1"
    Jul 11 06:24:30 localhost haproxy[953]: 127.0.0.1:47969 [11/Jul/2012:06:14:30.868] api-fe
    api-be/api-b 0/0/0/-1/+600002 504 +194 - - sH-- 3/3/3/1/0 0/0 {50.18.111.113} "GET
    /api/enstratus/2012-02-29/infrastructure/Snapshot?regionId=68&volumeId=102312 HTTP/1.1"
    Jul 11 06:24:31 localhost haproxy[953]: 127.0.0.1:48050 [11/Jul/2012:06:24:28.820] api-fe

    View Slide

  22. Jul 4 02:10:42 lb-api-a pound: api.enstratus.com 24.118.90.130 - - [04/Jul/2012:02:10:42
    +0000] "GET / HTTP/1.1" 404 955 "" "Mozilla/5.0 (Macin
    tosh; Intel Mac OS X 10_7_4) AppleWebKit/534.57.2 (KHTML, like Gecko) Version/5.1.7
    Safari/534.57.2"
    Jul 4 02:10:42 lb-api-a pound: api.enstratus.com 24.118.90.130 - - [04/Jul/2012:02:10:42
    +0000] "GET /favicon.ico HTTP/1.1" 200 824 "https://ap
    i.enstratus.com/" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_7_4) AppleWebKit/534.57.2
    (KHTML, like Gecko) Version/5.1.7 Safari/534.57.2"
    Jul 4 02:10:46 lb-api-a pound: api.enstratus.com 24.118.90.130 - - [04/Jul/2012:02:10:46
    +0000] "GET /ai HTTP/1.1" 404 961 "" "Mozilla/5.0 (Mac
    intosh; Intel Mac OS X 10_7_4) AppleWebKit/534.57.2 (KHTML, like Gecko) Version/5.1.7
    Safari/534.57.2"
    Jul 4 02:10:49 lb-api-a pound: api.enstratus.com 24.118.90.130 - - [04/Jul/2012:02:10:49
    +0000] "GET /api HTTP/1.1" 200 348 "" "Mozilla/5.0 (Ma
    cintosh; Intel Mac OS X 10_7_4) AppleWebKit/534.57.2 (KHTML, like Gecko) Version/5.1.7
    Safari/534.57.2"
    Jul 4 02:14:20 lb-api-a pound: api.enstratus.com:443 216.27.162.123 - -
    [04/Jul/2012:02:14:20 +0000] "GET /api/enstratus/2012-02-29/infrastruct
    ure/Server HTTP/1.1" 200 458 "" "enstratus.rb"
    Jul 4 02:14:21 lb-api-a pound: api.enstratus.com:443 216.27.162.123 - -
    [04/Jul/2012:02:14:21 +0000] "GET /api/enstratus/2012-02-29/infrastruct
    ure/Server HTTP/1.1" 200 458 "" "enstratus.rb"
    Jul 4 04:46:27 lb-api-a pound: api.enstratus.com 58.160.169.245 - - [04/Jul/2012:04:46:22
    +0000] "GET /api/enstratus/2012-02-29/infrastructure/
    Server?activeOnly=false HTTP/1.1" 200 19933 "" "enstratus.rb"
    Jul 4 04:47:15 lb-api-a pound: api.enstratus.com 58.160.169.245 - - [04/Jul/2012:04:46:39
    +0000] "GET /api/enstratus/2012-02-29/infrastructure/
    Server?activeOnly=false HTTP/1.1" 200 97563 "" "enstratus.rb"

    View Slide

  23. 2012-07-11 03:33:50.746 [info] <0.202.0>@riak_core:wait_for_service:410 Wait complete for
    service riak_pipe (0 seconds)
    2012-07-11 03:33:50.746 [info] <0.376.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_map) host starting (<0.376.0>)
    2012-07-11 03:33:50.750 [info] <0.377.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_map) host starting (<0.377.0>)
    2012-07-11 03:33:50.755 [info] <0.379.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_reduce) host starting (<0.379.0>)
    2012-07-11 03:33:50.759 [info] <0.380.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_reduce) host starting (<0.380.0>)
    2012-07-11 03:33:50.763 [info] <0.381.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_reduce) host starting (<0.381.0>)
    2012-07-11 03:33:50.767 [info] <0.382.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_reduce) host starting (<0.382.0>)
    2012-07-11 03:33:50.772 [info] <0.383.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_reduce) host starting (<0.383.0>)
    2012-07-11 03:33:50.776 [info] <0.384.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_reduce) host starting (<0.384.0>)
    2012-07-11 03:33:50.781 [info] <0.386.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_hook) host starting (<0.386.0>)
    2012-07-11 03:33:50.784 [info] <0.387.0>@riak_kv_js_vm:init:76 Spidermonkey VM (thread stack:
    16MB, max heap: 8MB, pool: riak_kv_js_hook) host starting (<0.387.0>)
    2012-07-11 03:33:50.802 [info] <0.7.0> Application bitcask started on node '[email protected]'
    2012-07-11 03:33:50.855 [info] <0.463.0>@riak_core:wait_for_application:396 Waiting for
    application riak_kv to start (0 seconds).
    2012-07-11 03:33:50.862 [info] <0.7.0> Application riak_kv started on node '[email protected]'
    2012-07-11 03:33:50.865 [info] <0.7.0> Application riak_search started on node
    '[email protected]'
    2012-07-11 03:33:50.865 [info] <0.7.0> Application basho_stats started on node
    '[email protected]'
    2012-07-11 03:33:50.880 [info] <0.7.0> Application runtime_tools started on node
    '[email protected]'
    2012-07-11 03:33:50.957 [info] <0.463.0>@riak_core:wait_for_application:390 Wait complete for
    application riak_kv (0 seconds)
    2012-07-11 03:33:51.258 [info] <0.308.0>@riak_core:wait_for_service:410 Wait complete for
    service riak_kv (0 seconds)

    View Slide

  24. Let's ignore the format for a
    moment

    View Slide

  25. Logs are just events. Events
    with context.

    View Slide

  26. So what is Logstash?

    View Slide

  27. Logstash

    An event processing pipeline

    Events come in (input plugins)

    Events get analyzed (filter plugins)

    Events go out (output plugins)

    Current stats

    24 inputs

    18 filters

    40 outputs!

    View Slide

  28. Even Bill O'Reilly can
    explain that!

    View Slide

  29. Config sample
    (Warning: NOT Ruby)
    input {
    file {
    type => "haproxy-log"
    path =>
    ["/var/log/haproxy/haproxy.log"]
    sincedb_path =>
    "/opt/logstash/agent/etc/"
    }
    }

    View Slide

  30. Inputs

    Line-oriented

    Supported formats – plain, json, json_event*

    Converts incoming events to a Ruby hash

    json_event is essentially to_json on the
    event hash

    View Slide

  31. Event Hash
    {
    "@source" => "",
    "@type" => "",
    "@tags" => [],
    "@fields" => {},
    "@timestamp" => "event>",
    "@source_host" => "hostname>",
    "@source_path" => "input>",
    "@message" => "the line>"
    }

    View Slide

  32. Filters

    The “analysis engine” of Logstash

    Kind of like a SlapChop

    This is where the real work is done

    Grok is OVER 9000!

    View Slide

  33. Grok by Example
    (Yes, this is important)

    View Slide

  34. May 11 06:00:27 localhost haproxy[7829]:
    50.18.111.113:43565 [11/May/2012:06:00:26.920] api-fe api-
    be/api-b 0/0/0/390/+390 200 +181 - - ---- 10/10/10/5/0 0/0
    {} "GET /api/enstratus/2011-12-15/admin/Job HTTP/1.1"

    View Slide

  35. May 11 06:00:27 localhost haproxy[7829]:
    50.18.111.113:43565 [11/May/2012:06:00:26.920] api-fe api-
    be/api-b 0/0/0/390/+390 200 +181 - - ---- 10/10/10/5/0 0/0
    {} "GET /api/enstratus/2011-12-15/admin/Job HTTP/1.1"

    View Slide

  36. filter {
    grok {
    type => "haproxy-log"
    patterns_dir =>
    ["/opt/logstash/agent/etc/patter
    ns/"]
    pattern => "%
    {ESHAPROXYHTTP}"
    add_tag => ["haproxy-event"]
    }
    }

    View Slide

  37. ESHAPROXYHTTP is
    really f'ing big
    (WARNING: Wall of Text
    incoming!)

    View Slide

  38. ESHAPROXYCAPTUREDREQUESTHEADERS %
    {DATA:request_header_x_forwarded_for}
    ESHAPROXYCAPTUREDRESPONSEHEADERS %
    {DATA:response_header_content_type}\|%
    {DATA:response_header_content_encoding}\|%
    {DATA:response_header_cache_control}\|%
    {DATA:response_header_last_modified}
    ESHAPROXYHTTP %{SYSLOGTIMESTAMP:syslog_timestamp} %
    {IPORHOST:syslog_server} %{SYSLOGPROG}: %{IP:client_ip}:%
    {INT:client_port} \[%{HAPROXYDATE:accept_date}\] %
    {NOTSPACE:frontend_name} %{NOTSPACE:backend_name}/%
    {NOTSPACE:server_name} %{INT:time_request}/%
    {INT:time_queue}/%{INT:time_backend_connect}/%
    {INT:time_backend_response}/\+%{NOTSPACE:time_duration} %
    {INT:http_status_code} \+%{NOTSPACE:bytes_read} %
    {DATA:captured_request_cookie} %
    {DATA:captured_response_cookie} %
    {NOTSPACE:termination_state} %{INT:actconn}/%{INT:feconn}/%
    {INT:beconn}/%{INT:srvconn}/%{NOTSPACE:retries} %
    {INT:srv_queue}/%{INT:backend_queue} \{%
    {ESHAPROXYCAPTUREDREQUESTHEADERS}\} "%{WORD:http_verb} %
    {URIPATHPARAM:http_request} HTTP/%{NUMBER:http_version}"

    View Slide

  39. ESHAPROXYCAPTUREDREQUESTHEADERS %
    {DATA:request_header_x_forwarded_for}
    ESHAPROXYCAPTUREDRESPONSEHEADERS %
    {DATA:response_header_content_type}\|%
    {DATA:response_header_content_encoding}\|%
    {DATA:response_header_cache_control}\|%
    {DATA:response_header_last_modified}
    ESHAPROXYHTTP %{SYSLOGTIMESTAMP:syslog_timestamp} %
    {IPORHOST:syslog_server} %{SYSLOGPROG}: %{IP:client_ip}:%
    {INT:client_port} \[%{HAPROXYDATE:accept_date}\] %
    {NOTSPACE:frontend_name} %{NOTSPACE:backend_name}/%
    {NOTSPACE:server_name} %{INT:time_request}/%
    {INT:time_queue}/%{INT:time_backend_connect}/%
    {INT:time_backend_response}/\+%{NOTSPACE:time_duration} %
    {INT:http_status_code} \+%{NOTSPACE:bytes_read} %
    {DATA:captured_request_cookie} %
    {DATA:captured_response_cookie} %
    {NOTSPACE:termination_state} %{INT:actconn}/%{INT:feconn}/%
    {INT:beconn}/%{INT:srvconn}/%{NOTSPACE:retries} %
    {INT:srv_queue}/%{INT:backend_queue} \{%
    {ESHAPROXYCAPTUREDREQUESTHEADERS}\} "%{WORD:http_verb} %
    {URIPATHPARAM:http_request} HTTP/%{NUMBER:http_version}"

    View Slide

  40. May 11 06:00:27
    %{SYSLOGTIMESTAMP:syslog_timestamp}
    SYSLOGTIMESTAMP %{MONTH} +%{MONTHDAY} %{TIME}
    MONTH \b(?:Jan(?:uary)?|Feb(?:ruary)?|
    Mar(?:ch)?|Apr(?:il)?|May|Jun(?:e)?|
    Jul(?:y)?|Aug(?:ust)?|Sep(?:tember)?|
    Oct(?:ober)?|Nov(?:ember)?|Dec(?:ember)?)\b
    MONTHDAY (?:(?:0[1-9])|(?:[12][0-9])|
    (?:3[01])|[1-9])
    TIME (?!<[0-9])%{HOUR}:%{MINUTE}(?::%
    {SECOND})(?![0-9])
    HOUR (?:2[0123]|[01][0-9])
    MINUTE (?:[0-5][0-9])
    SECOND (?:(?:[0-5][0-9]|60)(?:[.,][0-9]+)?)

    View Slide

  41. May 11 06:00:27
    %{SYSLOGTIMESTAMP:syslog_timestamp}
    SYSLOGTIMESTAMP %{MONTH} +%{MONTHDAY} %{TIME}
    MONTH \b(?:Jan(?:uary)?|Feb(?:ruary)?|Mar(?:ch)?|
    Apr(?:il)?|May|Jun(?:e)?|Jul(?:y)?|Aug(?:ust)?|
    Sep(?:tember)?|Oct(?:ober)?|Nov(?:ember)?|
    Dec(?:ember)?)\b
    MONTHDAY (?:(?:0[1-9])|(?:[12][0-9])|(?:3[01])|
    [1-9])
    TIME (?!<[0-9])%{HOUR}:%{MINUTE}(?::%{SECOND})(?!
    [0-9])
    HOUR (?:2[0123]|[01][0-9])
    MINUTE (?:[0-5][0-9])
    SECOND (?:(?:[0-5][0-9]|60)(?:[.,][0-9]+)?)

    View Slide

  42. May 11 06:00:27
    %{SYSLOGTIMESTAMP:syslog_timestamp}
    SYSLOGTIMESTAMP %{MONTH} +%{MONTHDAY} %{TIME}
    MONTH \b(?:Jan(?:uary)?|Feb(?:ruary)?|
    Mar(?:ch)?|Apr(?:il)?|May|Jun(?:e)?|
    Jul(?:y)?|Aug(?:ust)?|Sep(?:tember)?|
    Oct(?:ober)?|Nov(?:ember)?|Dec(?:ember)?)\b
    MONTHDAY (?:(?:0[1-9])|(?:[12][0-9])|
    (?:3[01])|[1-9])
    TIME (?!<[0-9])%{HOUR}:%{MINUTE}(?::%
    {SECOND})(?![0-9])
    HOUR (?:2[0123]|[01][0-9])
    MINUTE (?:[0-5][0-9])
    SECOND (?:(?:[0-5][0-9]|60)(?:[.,][0-9]+)?)

    View Slide

  43. May 11 06:00:27
    %{SYSLOGTIMESTAMP:syslog_timestamp}
    SYSLOGTIMESTAMP %{MONTH} +%{MONTHDAY} %{TIME}
    MONTH \b(?:Jan(?:uary)?|Feb(?:ruary)?|
    Mar(?:ch)?|Apr(?:il)?|May|Jun(?:e)?|
    Jul(?:y)?|Aug(?:ust)?|Sep(?:tember)?|
    Oct(?:ober)?|Nov(?:ember)?|Dec(?:ember)?)\b
    MONTHDAY (?:(?:0[1-9])|(?:[12][0-9])|
    (?:3[01])|[1-9])
    TIME (?!<[0-9])%{HOUR}:%{MINUTE}(?::%
    {SECOND})(?![0-9])
    HOUR (?:2[0123]|[01][0-9])
    MINUTE (?:[0-5][0-9])
    SECOND (?:(?:[0-5][0-9]|60)(?:[.,][0-9]+)?)

    View Slide

  44. Named Fields
    When you identify something it's added to the event hash at the @fields key
    {
    "@source" => "",
    "@type" => "",
    "@tags" => [“haproxy_event”],
    "@fields" => {“syslog_timestamp” => “May 11 06:00:27”},
    "@timestamp" => "",
    "@source_host" => "",
    "@source_path" => "",
    "@message" => ""
    }

    View Slide

  45. Rinse and Repeat

    Filters are processed in order

    Once a field is identified, can be used in
    interpolation later

    %{syslog_timestamp}

    %{@type}

    @ fields are special but not sacred.

    date and mutate filters for instance.

    View Slide

  46. Outputs

    An event can be routed to all or a subset of
    defined outputs based on various criteria

    Outputs block (sort of)

    Logstash takes a default position that you don't
    want to lose an event

    1 thread per defined output each

    ALWAYS use a stdout output for debugging

    Leverage variables for great justice

    This is where it gets REALLY cool

    View Slide

  47. Simplest output
    output {
    stdout => {
    debug => true
    debug_format => “json”
    }
    }

    View Slide

  48. ElasticSearch

    View Slide

  49. Graphite
    output {
    graphite { host => "10.1.1.217" metrics =>
    [ "stats.enstratus.apps.api.requests.version.
    %{es_api_version}", "1"] tags => ["haproxy-
    event"]}
    graphite { host => "10.1.1.217" metrics =>
    [ "stats.enstratus.apps.api.requests.%
    {es_api_scope}.%{es_api_object}", "1"] tags
    => ["haproxy-event"]}
    }

    View Slide

  50. Graphite

    View Slide

  51. Graphite

    View Slide

  52. Boundary

    View Slide

  53. DataDog

    View Slide

  54. Nagios

    View Slide

  55. PagerDuty

    View Slide

  56. Remember this guy?

    View Slide

  57. He has a thing...

    View Slide

  58. Can we get his logs into
    Circonus?

    View Slide

  59. Challenge Accepted!
    output {
    circonus {
    api_token => "XXXXXXXXXXXXXX"
    app_name => "logstash-testing"
    annotation => ["title", "Logstash
    test", "description", "%{@message}",
    "category", "logstash"]
    }

    View Slide

  60. View Slide

  61. You can still write to files if you want
    file {
    path => "/var/log/logstash/%
    {@source_host}/%{application}"
    message_format => "%{@timestamp} %
    {@message}"
    }

    View Slide

  62. Or you can write to ALL the things!

    View Slide

  63. Questions?

    http://github.com/logstash/logstash

    http://cookbook.logstash.net

    http://logstash.net

    @logstash

    @jordansissel/@fetep/@lusis

    View Slide