Permalink
Browse files

- Add tests for Vault::Log module.

- Update logging functionality to be compatible with L2met.
  • Loading branch information...
jkakar committed Mar 5, 2013
1 parent 0ec724f commit beab80f75c6024210773f745ea452185728b27f7
Showing with 131 additions and 54 deletions.
  1. +33 −41 lib/vault-tools/log.rb
  2. +84 −0 test/log_test.rb
  3. +14 −13 test/web_test.rb
View
@@ -1,62 +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)
+ # @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
@@ -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
@@ -23,44 +23,45 @@ def reload_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
# An internal server error causes a `web-50` log entry to be written. A
# 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'

0 comments on commit beab80f

Please sign in to comment.