From 1fd0a0f272539c1fe117dd1a22b5ed4cc59e980f Mon Sep 17 00:00:00 2001 From: Steven Harman Date: Thu, 2 May 2024 11:33:07 -0400 Subject: [PATCH 1/4] Add new LogTarget MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Which defaults to the `:json` formatter with a `:passthrough` transform. For now… --- lib/puma/plugin/telemetry.rb | 1 + lib/puma/plugin/telemetry/config.rb | 1 + .../plugin/telemetry/targets/log_target.rb | 29 +++++++++++++++++++ .../telemetry/targets/log_target_spec.rb | 23 +++++++++++++++ 4 files changed, 54 insertions(+) create mode 100644 lib/puma/plugin/telemetry/targets/log_target.rb create mode 100644 spec/puma/plugin/telemetry/targets/log_target_spec.rb diff --git a/lib/puma/plugin/telemetry.rb b/lib/puma/plugin/telemetry.rb index 592ec50..acec95f 100644 --- a/lib/puma/plugin/telemetry.rb +++ b/lib/puma/plugin/telemetry.rb @@ -7,6 +7,7 @@ require 'puma/plugin/telemetry/data' require 'puma/plugin/telemetry/targets/datadog_statsd_target' require 'puma/plugin/telemetry/targets/io_target' +require 'puma/plugin/telemetry/targets/log_target' require 'puma/plugin/telemetry/targets/open_telemetry_target' require 'puma/plugin/telemetry/config' diff --git a/lib/puma/plugin/telemetry/config.rb b/lib/puma/plugin/telemetry/config.rb index 96df50a..5dd8e01 100644 --- a/lib/puma/plugin/telemetry/config.rb +++ b/lib/puma/plugin/telemetry/config.rb @@ -35,6 +35,7 @@ class Config TARGETS = { dogstatsd: Telemetry::Targets::DatadogStatsdTarget, io: Telemetry::Targets::IOTarget, + log: Telemetry::Targets::LogTarget, open_telemetry: Telemetry::Targets::OpenTelemetryTarget }.freeze diff --git a/lib/puma/plugin/telemetry/targets/log_target.rb b/lib/puma/plugin/telemetry/targets/log_target.rb new file mode 100644 index 0000000..68a1c9d --- /dev/null +++ b/lib/puma/plugin/telemetry/targets/log_target.rb @@ -0,0 +1,29 @@ +# frozen_string_literal: true + +require 'logger' +require_relative 'base_formatting_target' + +module Puma + class Plugin + module Telemetry + module Targets + # Simple Log Target, publishing metrics to a Ruby ::Logger at stdout + # at the INFO log level + class LogTarget < BaseFormattingTarget + def initialize(logger: ::Logger.new($stdout), formatter: :json, transform: :passthrough) + super(formatter: formatter, transform: transform) + @logger = logger + end + + def call(telemetry) + logger.info(formatter.call(transform.call(telemetry))) + end + + private + + attr_reader :logger + end + end + end + end +end diff --git a/spec/puma/plugin/telemetry/targets/log_target_spec.rb b/spec/puma/plugin/telemetry/targets/log_target_spec.rb new file mode 100644 index 0000000..d6cd70f --- /dev/null +++ b/spec/puma/plugin/telemetry/targets/log_target_spec.rb @@ -0,0 +1,23 @@ +# frozen_string_literal: true + +module Puma + class Plugin + module Telemetry + module Targets + RSpec.describe LogTarget do + subject(:target) { described_class.new(logger: logger, formatter: kvpair) } + let(:logger) { ::Logger.new(io) } + let(:io) { StringIO.new } + let(:telemetry) { { foo: 'bar' } } + let(:kvpair) { ->(telemetry) { telemetry.map { |k, v| "#{k}=#{v}" }.join(' ') } } + + it 'logs the telemetry at the INFO level' do + target.call(telemetry) + + expect(io.string).to include('INFO').and(include('foo=bar')) + end + end + end + end + end +end From 67e4b22a0ffdeb5f93ef2319e4b5afd43836eb18 Mon Sep 17 00:00:00 2001 From: Steven Harman Date: Wed, 3 Jul 2024 16:55:19 -0400 Subject: [PATCH 2/4] Add Logfmt formatter This is also the default `formatter:` of the new LogTarget. --- CHANGELOG.md | 5 +++- README.md | 28 +++++++++++++++++-- .../telemetry/formatters/logfmt_formatter.rb | 16 +++++++++++ .../targets/base_formatting_target.rb | 26 ++++++++++------- .../plugin/telemetry/targets/log_target.rb | 2 +- .../formatters/logfmt_formatter_spec.rb | 25 +++++++++++++++++ 6 files changed, 88 insertions(+), 14 deletions(-) create mode 100644 lib/puma/plugin/telemetry/formatters/logfmt_formatter.rb create mode 100644 spec/puma/plugin/telemetry/formatters/logfmt_formatter_spec.rb diff --git a/CHANGELOG.md b/CHANGELOG.md index 4ec55ef..fcab14a 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -7,6 +7,10 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ## [Unreleased] +### Added +- New `LogTarget` for logging metrics to any `::Logger` compatible logger +- New `formatter:` option `:logfmt`. + ## [1.2.0] ### Added @@ -43,7 +47,6 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 - Check for support for 'ubuntu-20.04' - Check for support for Ruby 2.6 and 2.7 - ## [1.1.4] ### Changed diff --git a/README.md b/README.md index 95dcec4..8fac5c1 100644 --- a/README.md +++ b/README.md @@ -46,7 +46,7 @@ end A basic I/O target will emit telemetry data to `STDOUT`, formatted in JSON. ```ruby -config.add_target :io +config.add_target(:io) ``` #### Options @@ -55,6 +55,7 @@ This target has configurable `formatter:` and `transform:` options. The `formatter:` options are * `:json` _(default)_ - Print the logs in JSON. +* `:logfmt` - Print the logs in key/value pairs, as per `logfmt`. * `:passthrough` - A passthrough formatter which returns the telemetry `Hash` unaltered, passing it directly to the `io:` instance. The `transform:` options are @@ -62,6 +63,29 @@ The `transform:` options are * `:cloud_watch` _(default)_ - Transforms telemetry keys, replacing dots with dashes to support AWS CloudWatch Log Metrics filters. * `:passthrough` - A passthrough transform which returns the telemetry `Hash` unaltered. +### Log target + +While emitting to `STDOUT` via the basic `IOTarget` can work for getting telemetry into logs, we also provide an explicit `LogTarget`. +This target will defaults to emitting telemetry at the `INFO` log level via a [standard library `::Logger`][logger] instance. +That default logger will print to `STDOUT` in [the `logfmt` format][logfmt]. + +```ruby +config.add_target(:log) +``` + +You can pass an explicit `logger:` option if you wanted to, for example, use the same logger as Rails. + +```ruby +config.add_target(:log, logger: Rails.logger) +``` + +This target also has configurable `formatter:` and `transform:` options. +The [possible options are the same as for the `IOTarget`](#options), but the defaults are different. +The `LogTarget` defaults to `formatter: :logfmt`, and `transform: :passthrough`. + +[logfmt]: https://brandur.org/logfmt "logfmt - Structured log format" +[logger]: https://rubyapi.org/o/logger "Ruby's Logger, from the stdlib" + ### Datadog StatsD target A target for the Datadog StatsD client, that uses batch operation to publish metrics. @@ -73,7 +97,7 @@ gem "dogstatsd-ruby" ``` ```ruby -config.add_target :dogstatsd, client: Datadog::Statsd.new +config.add_target(:dogstatsd, client: Datadog::Statsd.new) ``` You can provide all the tags, namespaces, and other configuration options as always to `Datadog::Statsd.new` method. diff --git a/lib/puma/plugin/telemetry/formatters/logfmt_formatter.rb b/lib/puma/plugin/telemetry/formatters/logfmt_formatter.rb new file mode 100644 index 0000000..348b83e --- /dev/null +++ b/lib/puma/plugin/telemetry/formatters/logfmt_formatter.rb @@ -0,0 +1,16 @@ +# frozen_string_literal: true + +module Puma + class Plugin + module Telemetry + module Formatters + # Logfmt formatter, expects `call` method accepting telemetry hash + class LogfmtFormatter + def self.call(telemetry) + telemetry.map { |k, v| "#{String(k)}=#{v.inspect}" }.join(' ') + end + end + end + end + end +end diff --git a/lib/puma/plugin/telemetry/targets/base_formatting_target.rb b/lib/puma/plugin/telemetry/targets/base_formatting_target.rb index cba5a48..550b2dd 100644 --- a/lib/puma/plugin/telemetry/targets/base_formatting_target.rb +++ b/lib/puma/plugin/telemetry/targets/base_formatting_target.rb @@ -1,6 +1,7 @@ # frozen_string_literal: true require_relative '../formatters/json_formatter' +require_relative '../formatters/logfmt_formatter' require_relative '../formatters/passthrough_formatter' require_relative '../transforms/cloud_watch_transform' require_relative '../transforms/passthrough_transform' @@ -12,16 +13,8 @@ module Targets # A base class for other Targets concerned with formatting telemetry class BaseFormattingTarget def initialize(formatter: :json, transform: :cloud_watch) - @transform = case transform - when :cloud_watch then Transforms::CloudWatchTransform - when :passthrough then Transforms::PassthroughTransform - else transform - end - @formatter = case formatter - when :json then Formatters::JSONFormatter - when :passthrough then Formatters::PassthroughFormatter - else formatter - end + @formatter = FORMATTERS.fetch(formatter) { formatter } + @transform = TRANSFORMS.fetch(transform) { transform } end def call(_telemetry) @@ -31,6 +24,19 @@ def call(_telemetry) private attr_reader :formatter, :transform + + FORMATTERS = { + json: Formatters::JSONFormatter, + logfmt: Formatters::LogfmtFormatter, + passthrough: Formatters::PassthroughFormatter + }.freeze + private_constant :FORMATTERS + + TRANSFORMS = { + cloud_watch: Transforms::CloudWatchTransform, + passthrough: Transforms::PassthroughTransform + }.freeze + private_constant :TRANSFORMS end end end diff --git a/lib/puma/plugin/telemetry/targets/log_target.rb b/lib/puma/plugin/telemetry/targets/log_target.rb index 68a1c9d..3860cb9 100644 --- a/lib/puma/plugin/telemetry/targets/log_target.rb +++ b/lib/puma/plugin/telemetry/targets/log_target.rb @@ -10,7 +10,7 @@ module Targets # Simple Log Target, publishing metrics to a Ruby ::Logger at stdout # at the INFO log level class LogTarget < BaseFormattingTarget - def initialize(logger: ::Logger.new($stdout), formatter: :json, transform: :passthrough) + def initialize(logger: ::Logger.new($stdout), formatter: :logfmt, transform: :passthrough) super(formatter: formatter, transform: transform) @logger = logger end diff --git a/spec/puma/plugin/telemetry/formatters/logfmt_formatter_spec.rb b/spec/puma/plugin/telemetry/formatters/logfmt_formatter_spec.rb new file mode 100644 index 0000000..1d8be56 --- /dev/null +++ b/spec/puma/plugin/telemetry/formatters/logfmt_formatter_spec.rb @@ -0,0 +1,25 @@ +# frozen_string_literal: true + +module Puma + class Plugin + module Telemetry + module Formatters + RSpec.describe LogfmtFormatter do + subject(:formatter) { described_class } + + it 'formats the telemetry in key/value pairs' do + string = formatter.call('foo' => 'bar', 'count' => 2) + + expect(string).to include('foo="bar"').and(include('count=2')) + end + + it 'handles symbol keys' do + string = formatter.call(foo: 'bar') + + expect(string).to include('foo="bar"') + end + end + end + end + end +end From bcbc7cc38e7fe79ab289d2305460e632928f0567 Mon Sep 17 00:00:00 2001 From: Steven Harman Date: Thu, 2 May 2024 15:04:56 -0400 Subject: [PATCH 3/4] Add L2Met transform see: https://github.com/ryandotsmith/l2met --- CHANGELOG.md | 1 + README.md | 2 ++ .../targets/base_formatting_target.rb | 2 ++ .../telemetry/transforms/l2met_transform.rb | 19 ++++++++++++++ .../transforms/l2met_transform_spec.rb | 25 +++++++++++++++++++ 5 files changed, 49 insertions(+) create mode 100644 lib/puma/plugin/telemetry/transforms/l2met_transform.rb create mode 100644 spec/puma/plugin/telemetry/transforms/l2met_transform_spec.rb diff --git a/CHANGELOG.md b/CHANGELOG.md index fcab14a..1849f1d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Added - New `LogTarget` for logging metrics to any `::Logger` compatible logger - New `formatter:` option `:logfmt`. +- New `transform:` option `:l2met`. ## [1.2.0] diff --git a/README.md b/README.md index 8fac5c1..f7ba86e 100644 --- a/README.md +++ b/README.md @@ -61,6 +61,7 @@ The `formatter:` options are The `transform:` options are * `:cloud_watch` _(default)_ - Transforms telemetry keys, replacing dots with dashes to support AWS CloudWatch Log Metrics filters. +* `:l2met` - Transforms telemetry keys, prepending `sample#` for [L2Met][l2met] consumption. * `:passthrough` - A passthrough transform which returns the telemetry `Hash` unaltered. ### Log target @@ -83,6 +84,7 @@ This target also has configurable `formatter:` and `transform:` options. The [possible options are the same as for the `IOTarget`](#options), but the defaults are different. The `LogTarget` defaults to `formatter: :logfmt`, and `transform: :passthrough`. +[l2met]: https://github.com/ryandotsmith/l2met "l2met - Logs to metrics" [logfmt]: https://brandur.org/logfmt "logfmt - Structured log format" [logger]: https://rubyapi.org/o/logger "Ruby's Logger, from the stdlib" diff --git a/lib/puma/plugin/telemetry/targets/base_formatting_target.rb b/lib/puma/plugin/telemetry/targets/base_formatting_target.rb index 550b2dd..6b602ff 100644 --- a/lib/puma/plugin/telemetry/targets/base_formatting_target.rb +++ b/lib/puma/plugin/telemetry/targets/base_formatting_target.rb @@ -4,6 +4,7 @@ require_relative '../formatters/logfmt_formatter' require_relative '../formatters/passthrough_formatter' require_relative '../transforms/cloud_watch_transform' +require_relative '../transforms/l2met_transform' require_relative '../transforms/passthrough_transform' module Puma @@ -34,6 +35,7 @@ def call(_telemetry) TRANSFORMS = { cloud_watch: Transforms::CloudWatchTransform, + l2met: Transforms::L2metTransform, passthrough: Transforms::PassthroughTransform }.freeze private_constant :TRANSFORMS diff --git a/lib/puma/plugin/telemetry/transforms/l2met_transform.rb b/lib/puma/plugin/telemetry/transforms/l2met_transform.rb new file mode 100644 index 0000000..984e4f1 --- /dev/null +++ b/lib/puma/plugin/telemetry/transforms/l2met_transform.rb @@ -0,0 +1,19 @@ +# frozen_string_literal: true + +module Puma + class Plugin + module Telemetry + module Transforms + # L2Met (Logs to Metrics) transform that makes all keys a `sample#` in the L2Met format. + class L2metTransform + def self.call(telemetry) + telemetry.transform_keys { |k| "sample##{k}" }.tap do |data| + data['name'] = 'Puma::Plugin::Telemetry' + # data['source'] = ?? + end + end + end + end + end + end +end diff --git a/spec/puma/plugin/telemetry/transforms/l2met_transform_spec.rb b/spec/puma/plugin/telemetry/transforms/l2met_transform_spec.rb new file mode 100644 index 0000000..1d0f2e7 --- /dev/null +++ b/spec/puma/plugin/telemetry/transforms/l2met_transform_spec.rb @@ -0,0 +1,25 @@ +# frozen_string_literal: true + +module Puma + class Plugin + module Telemetry + module Transforms + RSpec.describe L2metTransform do + subject(:transform) { described_class } + + it 'transforms the telemetry key to an L2Met sample' do + data = transform.call('widgets.size' => 2, 'speed' => 10.5) + + expect(data).to include('sample#widgets.size' => 2, 'sample#speed' => 10.5) + end + + it 'handles symbol keys' do + data = transform.call('queue.depth': 2) + + expect(data).to include('sample#queue.depth' => 2) + end + end + end + end + end +end From 7c9222cedaae60c2e70a89df06da89421a3e9f8c Mon Sep 17 00:00:00 2001 From: Steven Harman Date: Thu, 2 May 2024 17:56:40 -0400 Subject: [PATCH 4/4] Add L2Met source attribute It will pull from the ENV `L2MET_SOURCE` and then `DYNO`, falling back to building a string based on the current Host name and executing program name. --- .../telemetry/transforms/l2met_transform.rb | 31 +++++++++++++++++-- .../transforms/l2met_transform_spec.rb | 27 +++++++++++++++- 2 files changed, 55 insertions(+), 3 deletions(-) diff --git a/lib/puma/plugin/telemetry/transforms/l2met_transform.rb b/lib/puma/plugin/telemetry/transforms/l2met_transform.rb index 984e4f1..48abcb3 100644 --- a/lib/puma/plugin/telemetry/transforms/l2met_transform.rb +++ b/lib/puma/plugin/telemetry/transforms/l2met_transform.rb @@ -1,5 +1,8 @@ # frozen_string_literal: true +require 'English' +require 'pathname' + module Puma class Plugin module Telemetry @@ -7,11 +10,35 @@ module Transforms # L2Met (Logs to Metrics) transform that makes all keys a `sample#` in the L2Met format. class L2metTransform def self.call(telemetry) + new.call(telemetry) + end + + def initialize(host_env: ENV, program_name: $PROGRAM_NAME, socket: Socket) + @host_env = host_env + @program_name = program_name + @socket = socket + end + + def call(telemetry) telemetry.transform_keys { |k| "sample##{k}" }.tap do |data| - data['name'] = 'Puma::Plugin::Telemetry' - # data['source'] = ?? + data['name'] ||= 'Puma::Plugin::Telemetry' + data['source'] ||= source end end + + private + + attr_reader :host_env, :program_name, :socket + + def source + @source ||= host_env['L2MET_SOURCE'] || + host_env['DYNO'] || # For Heroku + host_with_exe_name # Last-ditch effort + end + + def host_with_exe_name + "#{socket.gethostname}/#{Pathname(program_name).basename}" + end end end end diff --git a/spec/puma/plugin/telemetry/transforms/l2met_transform_spec.rb b/spec/puma/plugin/telemetry/transforms/l2met_transform_spec.rb index 1d0f2e7..786f2ad 100644 --- a/spec/puma/plugin/telemetry/transforms/l2met_transform_spec.rb +++ b/spec/puma/plugin/telemetry/transforms/l2met_transform_spec.rb @@ -5,7 +5,10 @@ class Plugin module Telemetry module Transforms RSpec.describe L2metTransform do - subject(:transform) { described_class } + subject(:transform) { described_class.new(host_env: fake_env, socket: fake_socket) } + + let(:fake_env) { {} } + let(:fake_socket) { class_double('Socket', gethostname: 'GIBSON') } it 'transforms the telemetry key to an L2Met sample' do data = transform.call('widgets.size' => 2, 'speed' => 10.5) @@ -18,6 +21,28 @@ module Transforms expect(data).to include('sample#queue.depth' => 2) end + + it 'adds source from L2MET_SOURCE in ENV' do + fake_env['L2MET_SOURCE'] = 'some-machine' + + data = transform.call('queue.depth' => 2) + + expect(data).to include('source' => 'some-machine') + end + + it 'adds source from DYNO in ENV' do + fake_env['DYNO'] = 'web.10' + + data = transform.call('queue.depth' => 2) + + expect(data).to include('source' => 'web.10') + end + + it 'adds source from $PROGRAM_NAME when L2MET_SOURCE nor DYNO are in ENV' do + data = transform.call('queue.depth' => 2) + + expect(data).to include('source' => 'GIBSON/rspec') + end end end end