How to make Unicorn and Rails log with consistent output tagging

application.rb

# this is an example of: config/application.rb

require 'rails/all'
require 'rspec-rails'

# Require the gems listed in Gemfile, including any gems
# you've limited to :test, :development, or :production.
Bundler.require(*Rails.groups)

module UnicornHostedRailsApp
  class Application < Rails::Application
    #
    # Under Unicorn logging behaves differently than under Rails standard server.
    # Rails Rack loads middleware that replaces the Logger::Formatter with Logger::SimpleLogFormatter. 
    # So create a logger attached to STDOUT, set the formatter to one compatible with Unicorn, and feed 
    # that logger instance to the TaggedLogging logger that Rails normally instantiates 
    # 
    config.unicorn_logger = Logger.new(STDOUT)
    config.unicorn_logger.formatter = Logger::Formatter.new
    config.logger = ActiveSupport::TaggedLogging.new(config.unicorn_logger)
    
    # set logger level as you wish (:trace, :debug, :info, :warn, :error, etc)
    config.logger.level = Logger.const_get('DEBUG')
    config.log_level = :debug
  end
end

log_tagger.rb

# this could be put in: config/initializers/log_tagger.rb

# This puts the request id and session id as prefix values for each log entry.
# This helps aggregate papertrail logs. These will be prepended to your Rails 
# logging messages
Rails.application.config.log_tags = [
  lambda { |request| "#{request.uuid}"[0..15] },
  lambda { |request| "#{request.cookie_jar["_web_session"]}"[0..15] },
]

unicorn.stdout.log

This demonstrates how the uniform log tagging flows across unicorn and rails app

==> Normal unicorn output
I, [2015-11-10T06:02:13.585735 #24990]  INFO -- : worker=0 ready
I, [2015-11-10T06:02:38.269497 #24916]  INFO -- : reaped #<Process::Status: pid 24990 exit 0> worker=0
I, [2015-11-10T06:02:38.269960 #24916]  INFO -- : reaped #<Process::Status: pid 24920 exit 0> worker=1
I, [2015-11-10T06:02:38.272589 #24916]  INFO -- : master complete
I, [2015-11-10T06:03:09.010613 #25043]  INFO -- : Refreshing Gem list
I, [2015-11-10T06:03:12.780875 #25043]  INFO -- : listening on addr=0.0.0.0:8080 fd=11
I, [2015-11-10T06:03:13.002498 #25043]  INFO -- : master process ready
Fast Debugger (ruby-debug-ide 0.4.32, debase 0.1.4) listens on 127.0.0.1:55971
Fast Debugger (ruby-debug-ide 0.4.32, debase 0.1.4) listens on 127.0.0.1:55972
I, [2015-11-10T06:03:13.015207 #25053]  INFO -- : worker=0 ready
I, [2015-11-10T06:03:13.016840 #25054]  INFO -- : worker=1 ready

==> rails logs output through unicorn, maintains format that includes unicork worker details, plus tags we added in our Rails logging messages
D, [2015-11-10T06:03:14.500142 #25053] DEBUG -- : [7a2b0dc6-d909-4d] [U2U0OWd2NjNOQnk0] 
D, [2015-11-10T06:03:14.500372 #25053] DEBUG -- : [7a2b0dc6-d909-4d] [U2U0OWd2NjNOQnk0] 
I, [2015-11-10T06:03:14.501488 #25053]  INFO -- : [7a2b0dc6-d909-4d] [U2U0OWd2NjNOQnk0] Started GET "//api/v1/order/lookup?userOrderNumber[0]=123456" for 127.0.0.1 at 2015-11-10 06:03:14 -0800
D, [2015-11-10T06:03:14.599771 #25053] DEBUG -- : [7a2b0dc6-d909-4d] [U2U0OWd2NjNOQnk0]   ActiveRecord::SchemaMigration Load (0.4ms)  SELECT "schema_migrations".* FROM "schema_migrations"
I, [2015-11-10T06:03:14.976982 #25053]  INFO -- : [7a2b0dc6-d909-4d] [U2U0OWd2NjNOQnk0] Processing by OrdersController#lookup as HTML
I, [2015-11-10T06:03:14.977229 #25053]  INFO -- : [7a2b0dc6-d909-4d] [U2U0OWd2NjNOQnk0]   Parameters: {"userOrderNumber"=>"123456"}

etc...