Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP
Browse files

Merge pull request #6 from heroku/l2met-compatible-logging

l2met-compatible-logging

- `Vault::Log` methods emit L2met-compatible output.  When an
  `APP_NAME` environment variable is present it will be prepended to
  measurement names.

- Tests for the `Vault::Log` module are now in place.

- Docstrings use YARD syntax now.
  • Loading branch information...
commit ce2ec084b88eb6b5ddc9a77b70bc2d75a9c8173d 2 parents 0829644 + 3e2a29f
@mattmanning mattmanning authored
View
9 lib/vault-tools/config.rb
@@ -18,8 +18,13 @@ def test?
env('RACK_ENV') == 'test'
end
- def app_name; env("APP_NAME"); end
- def port; env!("PORT").to_i; end
+ def app_name
+ env("APP_NAME")
+ end
+
+ def port
+ env!("PORT").to_i
+ end
def database_url(kind = '')
kind = "#{kind}_".upcase unless kind.empty?
View
77 lib/vault-tools/log.rb
@@ -1,61 +1,54 @@
module Vault
module Log
- extend self
-
- # Public: logs a counter
- #
- # name - Name of the counter
- #
- # Examples
- # Log.count('foo')
- # => "measure=true at=foo"
+ # Log a count metric.
#
- # Logs via Scrolls
- def count(name)
- log(measure: true, at: name)
+ # @param name [String] The name of the metric.
+ def self.count(name)
+ name = "#{Config.app_name}.#{name}" if Config.app_name
+ log(measure: name)
end
- # Public: logs an HTTP status code
+ # Log an HTTP status code. Two log metrics are written each time this
+ # method is invoked:
#
- # status - HTTP status code
+ # - The first one emits a metric called `http_200` for an HTTP 200
+ # response.
+ # - The second one emits a metric called `http_2xx` for the same code.
#
- # Examples
- # Log.count_status(400)
- # => "measure=true at=web-40"
+ # This makes it possible to easily measure individual HTTP status codes as
+ # well as classes of HTTP status codes.
#
- # Logs via Scrolls
- def count_status(status)
- if prefix = status.to_s.match(/\d\d/)[0]
- log(measure: true, at: "web-#{prefix}")
+ # @param status [Fixnum] The HTTP status code to record.
+ def self.count_status(status)
+ count("http_#{status}")
+ if status_prefix = status.to_s.match(/\d/)[0]
+ count("http_#{status_prefix}xx")
end
end
- # Public: logs the time of a web request
+ # Log a timing metric.
#
- # name - a Sinatra-formatted route url
- # t - time (integer seconds or milliseconds)
- #
- # Examples
- # Log.time(name, t)
- # => "measure=true at=web-40"
- #
- # Logs via Scrolls
- def time(name, t)
+ # @param name [String] A Sinatra-formatted route URL.
+ # @param duration [Fixnum] The duration to record, in seconds or
+ # milliseconds.
+ def self.time(name, duration)
if name
- name.
- gsub(/\/:\w+/,''). #remove param names from path
- gsub("/","-"). #remove slash from path
- gsub(/[^A-Za-z0-9\-\_]/, ''). #only keep subset of chars
- slice(1..-1).
- tap {|res| log(measure: true, fn: res, elapsed: t)}
+ name.gsub(/\/:\w+/, ''). # Remove param names from path.
+ gsub("/", "_"). # Replace slash with underscore.
+ gsub(/[^A-Za-z0-9\-\_]/, ''). # Only keep subset of chars.
+ slice(1..-1).
+ tap { |name| log(measure: name, val: duration) }
end
end
- # Internal: log something
- #
- # Logs via Scrolls
- def log(data, &blk)
- Scrolls.log(data, &blk)
+ # Write a message with key/value pairs to the log stream.
+ #
+ # @param data [Hash] A mapping of key/value pairs to include in the
+ # output.
+ # @param block [Proc] Optionally, a block of code to run before writing
+ # the log message.
+ def self.log(data, &block)
+ Scrolls.log(data, &block)
end
end
end
View
3  test/config_test.rb
@@ -1,7 +1,6 @@
require 'helper'
class ConfigTest < Vault::TestCase
-
# Config.production? is true when RACK_ENV=production
def test_production_mode
set_env 'RACK_ENV', nil
@@ -36,6 +35,8 @@ def test_database_url_raises_when_not_found
end
end
+ # Vault::Config.app_name returns the value of the APP_NAME environment
+ # variable.
def test_app_name
Vault::Config.app_name.must_equal nil
set_env 'APP_NAME', "my-app"
View
84 test/log_test.rb
@@ -0,0 +1,84 @@
+require 'helper'
+
+class LogTest < Vault::TestCase
+ # Vault::Log.count emits a metric, using the specified name, that represents
+ # a countable event.
+ def test_count
+ set_env('APP_NAME', nil)
+ Vault::Log.count('countable')
+ assert_match(/measure=countable/, Scrolls.stream.string)
+ end
+
+ # Vault::Log.count emits a metric that represents a countable event. If an
+ # APP_NAME environment variable is available it will be prepended to the
+ # measurement name.
+ def test_count_with_app_name
+ set_env('APP_NAME', 'vault_app')
+ Vault::Log.count('countable')
+ assert_match(/measure=vault_app.countable/, Scrolls.stream.string)
+ end
+
+ # Vault::Log.count_status emits metrics to measure HTTP responses. The
+ # exact HTTP status, and the status family, are recorded.
+ def test_count_status
+ set_env('APP_NAME', nil)
+ Vault::Log.count_status(201)
+ assert_match(/measure=http_201/, Scrolls.stream.string)
+ assert_match(/measure=http_2xx/, Scrolls.stream.string)
+ end
+
+ # Vault::Log.count_status emits metrics to measure HTTP responses. If an
+ # APP_NAME environment variable is available it will be prepended to the
+ # measurement name.
+ def test_count_status_with_app_name
+ set_env('APP_NAME', 'vault_app')
+ Vault::Log.count_status(201)
+ assert_match(/measure=vault_app.http_201/, Scrolls.stream.string)
+ assert_match(/measure=vault_app.http_2xx/, Scrolls.stream.string)
+ end
+
+ # Vault::Log.time emits a metric to measure the duration of an HTTP request.
+ # It converts slashes to underscores.
+ def test_time_replaces_slash_with_underscore
+ Vault::Log.time('/some/web/path', 123.4)
+ assert_match(/measure=some_web_path val=123.400/, Scrolls.stream.string)
+ assert_match(/val=123.4/, Scrolls.stream.string)
+ end
+
+ # Vault::Log.time removes parameters.
+ def test_time_removes_parameters
+ Vault::Log.time('/some/:web/path', 123.4)
+ assert_match(/measure=some_path val=123.400/, Scrolls.stream.string)
+ assert_match(/val=123.4/, Scrolls.stream.string)
+ end
+
+ # Vault::Log.time removes non-alphanumeric characters.
+ def test_time_removes_non_alphanumeric_characters
+ Vault::Log.time('/some/web+path', 123.4)
+ assert_match(/measure=some_webpath val=123.400/, Scrolls.stream.string)
+ assert_match(/val=123.4/, Scrolls.stream.string)
+ end
+
+ # Vault::Log.time is a no-op if a nil name is provided.
+ def test_time_without_name
+ Vault::Log.time(nil, 123.4)
+ assert_equal('', Scrolls.stream.string)
+ end
+
+ # Vault::Log.log emits a set of key/value metrics using data from the
+ # specified hash.
+ def test_log
+ Vault::Log.log(integer: 123, float: 123.4, string: 'string', bool: false)
+ assert_match(/integer=123 float=123.400 string=string bool=false/,
+ Scrolls.stream.string)
+ end
+
+ # Vault::Log.log can be used to measure the time spent in a block.
+ def test_log_with_block
+ Vault::Log.log(A: true) do
+ Vault::Log.log(B: true)
+ end
+ assert_match(/A=true at=start\nB=true\nA=true at=finish elapsed=0/,
+ Scrolls.stream.string)
+ end
+end
View
38 test/web_test.rb
@@ -14,38 +14,40 @@ def setup
reload_web!
end
- # middleware is attached at load time, so we have to
- # delete the web class and reload it to simulate being
- # loaded with a given ENV
+ # Middleware is attached at load time, so we have to delete the Vault::Web
+ # class and reload it to simulate being loaded with different environment
+ # variables.
def reload_web!
# remove the constant to force a clean reload
Vault.send(:remove_const, 'Web')
load 'lib/vault-tools/web.rb'
end
- # A successful request causes a `web-20` log entry to be written.
+ # An `http_200` and an `http_2xx` log metric is written for successful
+ # requests.
def test_head_status_check
head '/'
- assert_match(/measure=true/, Scrolls.stream.string)
- assert_match(/at=web-20/, Scrolls.stream.string)
+ assert_match(/measure=http_200/, Scrolls.stream.string)
+ assert_match(/measure=http_2xx/, Scrolls.stream.string)
assert_equal(200, last_response.status)
end
- # A successful request causes `web-20` log entry to be written and `OK`
- # content is returned in the response body.
+ # A GET /health request logs success metrics and returns 'OK' in the
+ # response body.
def test_get_health_check
get '/health'
- assert_match(/measure=true/, Scrolls.stream.string)
- assert_match(/at=web-20/, Scrolls.stream.string)
+ assert_match(/measure=http_200/, Scrolls.stream.string)
+ assert_match(/measure=http_2xx/, Scrolls.stream.string)
assert_equal(200, last_response.status)
assert_equal('OK', last_response.body)
end
- # A validation error causes a `web-40` log entry to be written.
+ # An `http_404` and an `http_4xx` log metric is written when a path doesn't
+ # match a known resource.
def test_head_with_unknown_endpoint
head '/unknown'
- assert_match(/measure=true/, Scrolls.stream.string)
- assert_match(/at=web-40/, Scrolls.stream.string)
+ assert_match(/measure=http_404/, Scrolls.stream.string)
+ assert_match(/measure=http_4xx/, Scrolls.stream.string)
assert_equal(404, last_response.status)
end
@@ -53,26 +55,28 @@ def test_head_with_unknown_endpoint
# traceback is also written to the response body to ease debugging.
def test_error_logs_500
get '/boom'
- assert_match(/measure=true/, Scrolls.stream.string)
- assert_match(/at=web-50/, Scrolls.stream.string)
+ assert_match(/measure=http_500/, Scrolls.stream.string)
+ assert_match(/measure=http_5xx/, Scrolls.stream.string)
assert_match(/^RuntimeError: An expected error occurred.$/m,
last_response.body)
assert_equal(500, last_response.status)
end
-
# SSL is enforced when we are in production mode
def test_ssl_enforced_in_production_mode
set_env 'RACK_ENV', 'production'
+ set_env 'VAULT_TOOLS_DISABLE_SSL', nil
reload_web!
get '/health'
assert_equal(301, last_response.status)
assert_match(/^https/, last_response.headers['Location'])
end
+ # SSL isn't enforced when the VAULT_TOOLS_DISABLE_SSL environment variable
+ # has a true value.
def test_ssl_can_be_disabled
set_env 'RACK_ENV', 'production'
- set_env 'VAULT_TOOLS_DISABLE_SSL', 'anything'
+ set_env 'VAULT_TOOLS_DISABLE_SSL', '1'
reload_web!
get '/health'
assert_equal(200, last_response.status)

0 comments on commit ce2ec08

Please sign in to comment.
Something went wrong with that request. Please try again.