Hanami Logging
Hanami logging is one of the worst aspects of working with a Hanami application. This was hinted at when discussing Hanami Containers earlier so we’re going to learn why Hanami’s default logger is a problem and how you can fix so you can have sensible logging that works for you rather than against you.
Table of Contents
…
Hanami Logging
Hanami logging is one of the worst aspects of working with a Hanami application. This was hinted at when discussing Hanami Containers earlier so we’re going to learn why Hanami’s default logger is a problem and how you can fix so you can have sensible logging that works for you rather than against you.
Table of Contents
Default
When you build a Hanami application, you’ll end up with Dry Logger as the default logger. This allows you to stay focused on implementing the specifics of your application but you’ll quickly outgrow what the default logger can provide for you when you need to ensure all of your logs are consistently formatted. Specifically, you’ll run into the following problems:
Dry Logger isn’t actively maintained and hasn’t been for some time now.
The documentation is extremely sparse and doesn’t come close to covering all capabilities. Instead, you’ll end up digging through the source code, looking at the test suite, and constantly hunting for examples and deeper understanding.
Hanami does not make replacing Dry Logger with a better logger — like Cogger which will be discussed in a moment — because you need to:
Create an application provider for logging messages.
Create a Rack middleware adapter for handling HTTP requests.
Create a custom Rack logger provider which uses the above adapter.
Patch the Dry Monitor SQL logger to ensure your logger is used for logging database queries.
In other words, swapping out the the default logger with a custom is not trivial but, fear not, because we’re going dive into each so you fully understand the problem and the corresponding solution.
Custom
Now that you understand the premise of the default logger and why it’s a problem, we can discuss the solution which means supplying your own custom logger. We’ll use Cogger to replace Dry Logger. Cogger was inspired by and born out of frustration of dealing with Dry Logger so is a great logger to add to your Hanami application for solving this problem. That said, if you want to use a different logger entirely, you should be able to take everything you learn here and apply it to using your custom logger with only a few tweaks.
Provider Implementation
You’ll need to create a custom application provider that allows your logger to be the main application logger. Using Cogger, here’s what that looks like:
# app/providers/logger.rb
module Demo
module Providers
# The logger provider.
class Logger < Hanami::Provider::Source
RESOLVER = proc { Object.const_get "Cogger" }
def initialize(environment: Hanami.env, resolver: RESOLVER, **)
@environment = environment
@resolver = resolver
@id = Hanami.app.namespace.to_s.downcase.to_sym
super(**)
end
def prepare = require "cogger"
def start
add_filters
register :logger, build_instance
end
private
attr_reader :environment, :resolver, :id
def add_filters = core.add_filters :csrf, :password, :password_confirmation
def build_instance
io = "log/#{environment}.log"
case environment
when :test
core.new(id:, io: StringIO.new, formatter: :json, level: :debug).add_stream io:
when :development then core.new(id:).add_stream(io:, formatter: :json)
else core.new id:, formatter: :json
end
end
def core
@core ||= resolver.call
end
end
end
end
The above ensures Cogger is properly prepared, started, and testable. The only oddity is the RESOLVER which ensures Cogger is lazy loaded for preparation and testing purposes because, due to the nature of provider lifecycles, you must wait for the provider to be properly prepared. Otherwise, you’d end up with a NameError.
💡 For a deeper diver, see the Subclasses section of Hanami Containers and the Cogger documentation for configuration details.
Finally, and assuming you are using RSpec for your test suite, it’s highly recommended you add this logger to your to your application dependencies shared context so you always have quick access to your application logger for testing purposes. Example:
# spec/support/shared_contexts/application_dependencies.rb
RSpec.shared_context "with application dependencies" do
let(:app) { Hanami.app }
let(:logger) { app[:logger] }
end
Here’s what log output looks like in the development environment console (minus the green color):
🟢 [demo] Provisioning device 123..."
Provider Registration
With our provider implementation in hand, we only need to register the provider so Hanami uses our custom logger provider as follows:
# config/providers/logger.rb
require_relative "../../app/providers/logger"
Hanami.app.register_provider :logger, source: Demo::Providers::Logger
If you’re thinking: “Wait, you said Hanami provides a default logger provider?”. You’re correct, Hanami does, but checks if a custom provider (as shown above) has been defined first. If so, then Hanami skips loading it’s default logger provider.
Oddly, this is the only default provider that Hanami grants this exception to as the inflector, rack logger, and DB logger providers do not support this behavior. This means we’ll have to work a little harder to work around this problem but we’ll tackle those issues shortly.
Rack Adapter
In addition to having a custom logger provider, you’ll need to build an adapter for logging HTTP requests which also allows you to replace Hanami’s default Rack logger. This is important especially when you want to use the same logger for all logging. Here’s what this looks like for Cogger:
# app/aspects/logging/rack_adapter.rb
module Demo
module Aspects
module Logging
# Adapts Cogger Rack middleware for provider registration.
module RackAdapter
module_function
def with logger
@logger = logger
self
end
def new application
@application = Cogger::Rack::Logger.new application, {logger: @logger}
end
def call(environment) = @application.call environment
end
end
end
end
RSpec Specification
# spec/app/aspects/logging/rack_adapter_spec.rb
require "hanami_helper"
RSpec.describe Demo::Aspects::Logging::Adapter do
subject(:adapter) { described_class }
include_context "with application dependencies"
let(:application) { proc { [200, {"Content-Type" => "text/plain"}, "test"] } }
describe ".with" do
it "answers itself" do
expect(adapter.with(nil)).to eq(adapter)
end
end
describe ".new" do
it "answers Cogger middleware" do
expect(adapter.with(logger).new(application)).to be_a(Cogger::Rack::Logger)
end
end
describe ".call" do
let(:middleware) { adapter.with(logger).new application }
it "answers application" do
expect(middleware.call({})).to eq([200, {"Content-Type" => "text/plain"}, "test"])
end
it "logs request" do
middleware.call({})
expect(logger.reread).to match(/level.+INFO.+status.+200/)
end
end
end
Where you place this adapter is up to you but the aspects namespace can useful for specialized objects. You might have also noticed this implementation mimics a generic Rack application by using a module instead of a class. This is done to reduce creating new objects that need to be garbage collected. Instead, this module wraps the Cogger Rack Logger within a Rack-like interface that is also compatible for registration as a Hanami provider because Hanami providers expect to be sent the .new message after being registered which is why the .with method is used to aid with initialization.
If this doesn’t click yet, hang tight, as this’ll make more sense when we look at the Rack Logger patch up next.
Rack Patch
Now that we have our adapter in hand, we can patch the Hanami’s Rack Logger. Unfortunately, we have to use a monkey patch to pull this off:
# config/initializers/rack_logger_patch.rb
# auto_register: false
require "dry/system"
# Patches Hanami's default providers.
module RackLoggerPatch
def prepare_app_providers
require "hanami/providers/inflector"
logger = Class.new Hanami::Provider::Source do
def start
slice.start :logger
register :monitor, Demo::Aspects::Logging::Adapter.with(slice[:logger])
end
end
register_provider :inflector, source: Hanami::Providers::Inflector
register_provider :rack, source: logger, namespace: true
register_provider :db_logging, source: Hanami::Providers::DBLogging
end
end
Hanami::App::ClassMethods.prepend RackLoggerPatch
Yes, monkey patches are the worst, but a necessary evil in this case since Hanami has no support in this respect. As you can see, the above patches Hanami’s prepare_app_providers method which can be found here. A couple notes to point out:
The logic for auto-detecting our custom application logger is completely deleted in this patch since Hanami will load our Cogger logger like any other provider. Same goes for all of the other conditional logic (feel free to tweak as necessary, though).
The main change is registering our Rack adapter in lieu of Hanami’s default monitor provider. This ensures our adapter delegates to Cogger for logging all HTTP requests.
Here’s what log output looks like in the development environment console (minus the green color):
🟢 [demo] [verb=GET] [ip=::1] [path=/screens] [params=] [length=] [status=200] [duration=114] [unit=ms]
SQL Patch
Sadly, we have to apply another monkey patch to ensure all SQL activity also uses our custom logger. Here’s the monkey patch:
# config/initializers/sql_logger_patch.rb
require "dry-monitor"
require "dry/monitor/sql/logger"
# Patches Hanami's default SQL logger.
module SQLLoggerPatch
def log_query time:, name:, query:
Hanami.app[:logger].info { {message: query, tags: [{db: name, duration: time}]} }
end
end
Dry::Monitor::SQL::Logger.prepend SQLLoggerPatch
Dry Monitor, also no longer maintained, is used for logging all database activity. As with Rack logging, we need to ensure our custom logger is used instead. In this case, we override the log_query method in order to use our logger. This method takes three keywords where query becomes our log message while name and time are added as tags.
Here’s what log output looks like in the development environment console (minus the green color):
🟢 [demo] [db=postgres] [duration=1] SELECT "screen"."id", "screen"."label", "screen"."created_at", "screen"."updated_at" FROM "screen" WHERE ("name" = 'plugin-a8739f') ORDER BY "screen"."label"
Application Configuration
With our Rack and SQL logger patches in hand, we only need to require them at the top of our application configuration as follows:
# config/app.rb
require_relative "initializers/rack_logger_patch"
require_relative "initializers/sql_logger_patch"
That’s it, thankfully. At this point, you’ll be using a single logger instance for all messages within your application. Even better you can inject this custom logger within any application object with minimal effort.
Conclusion
You’ve learned that Dry Logger is Hanami’s default logger and how deeply entwined it is. You’ve also learned learned how to swap in your own logger, like Cogger, to provide your own custom implementation by doing the following:
Implementing and registering a custom provider.
Adding a Rack adapter (and patching Dry Monitor) for logging HTTP requests.
Further patching Dry Monitor to ensure database activity is logged using your custom logger.
Patching your application configuration so all of this is wired up properly.
Is this ideal? Definitely not and — because monkey patches are applied — you must be diligent with Hanami upgrades since implementation updates could break your patches. This is always the downside of monkey patching.
On the upside, you now understand how logging is currently wired up within Hanami so you can adjust accordingly especially if you want all of your logging to have multiple streams that are consistently formatted. Even better, Cogger is actively maintained with the goal to keep improving so that Hanami logging gets better but logging for any application, in general, improves as well.