From e40895cf0d2f0baac4c3d069cf1bc04a73f32a1c Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Thu, 26 May 2016 10:26:04 -0700
Subject: [PATCH 01/18] =?UTF-8?q?Moving=20this=20out=20does=20not=20improv?=
 =?UTF-8?q?e=20the=20code,=20but=20I=20don=E2=80=99t=20feel=20like=20it=20?=
 =?UTF-8?q?belongs=20in=20Rory=20so=20I=20can=20at=20least=20hide=20it.?=
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

---
 lib/rory/application.rb    | 8 ++------
 lib/rory/sequel_connect.rb | 9 +++++++++
 2 files changed, 11 insertions(+), 6 deletions(-)
 create mode 100644 lib/rory/sequel_connect.rb

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index 3fb82f6..4cb8be4 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -6,6 +6,7 @@
 require 'rory/initializers'
 require 'rack/commonlogger'
 require 'rory/request_parameter_logger'
+require 'rory/sequel_connect'
 
 module Rory
   # Main application superclass.  Applications should subclass this class,
@@ -14,6 +15,7 @@ module Rory
   class Application
     # Exception raised if no root has been set for this Rory::Application subclass
     class RootNotConfigured < StandardError; end
+    include SequelConnect
 
     attr_reader :db, :db_config
     attr_accessor :config_path
@@ -109,12 +111,6 @@ def load_config_data(config_type)
       )
     end
 
-    def connect_db(environment = ENV['RORY_ENV'])
-      @db_config = load_config_data(:database)
-      @db = Sequel.connect(@db_config[environment.to_s])
-      @db.loggers << logger
-    end
-
     def use_middleware(*args, &block)
       middleware.use *args, &block
     end
diff --git a/lib/rory/sequel_connect.rb b/lib/rory/sequel_connect.rb
new file mode 100644
index 0000000..2b84d8e
--- /dev/null
+++ b/lib/rory/sequel_connect.rb
@@ -0,0 +1,9 @@
+module Rory
+  module SequelConnect
+    def connect_db(environment = ENV['RORY_ENV'])
+      @db_config = load_config_data(:database)
+      @db = Sequel.connect(@db_config[environment.to_s])
+      @db.loggers << logger
+    end
+  end
+end

From 11e8855c239db608cc7907f1692aaf280cfe27bc Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Thu, 26 May 2016 10:27:40 -0700
Subject: [PATCH 02/18] Move out default middleware setup with the thought that
 more could be added.

---
 lib/rory/application.rb                       | 23 ++++++-------------
 .../request_middleware.rb                     | 10 ++++++++
 2 files changed, 17 insertions(+), 16 deletions(-)
 create mode 100644 lib/rory/default_initializers/request_middleware.rb

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index 4cb8be4..2b39299 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -7,6 +7,7 @@
 require 'rack/commonlogger'
 require 'rory/request_parameter_logger'
 require 'rory/sequel_connect'
+require 'rory/default_initializers/request_middleware'
 
 module Rory
   # Main application superclass.  Applications should subclass this class,
@@ -50,16 +51,8 @@ def instance
       def root=(root_path)
         $:.unshift @root = Pathname.new(root_path).realpath
       end
-
-      def initializer_default_middleware
-        Rory::Application.initializers.add "rory.request_middleware" do |app|
-          app.request_middleware
-        end
-      end
     end
 
-    initializer_default_middleware
-
     def auto_require_paths
       @auto_require_paths ||= %w(models controllers helpers)
     end
@@ -124,12 +117,12 @@ def dispatcher
     end
 
     def request_logging_on?
-      @request_logging != false
+      !!Rory::Application.initializers.detect{|init| init.name == "rory.request_middleware" }
     end
 
     def turn_off_request_logging!
       reset_stack
-      @request_logging = false
+      Rory::Application.initializers.delete("rory.request_middleware")
     end
 
     def parameters_to_filter
@@ -149,14 +142,12 @@ def uuid_prefix
       Support.tokenize(self.class.name.gsub("::Application", ""))
     end
 
-    def request_middleware
-      return unless request_logging_on?
-      use_middleware Rory::RequestId, :uuid_prefix => uuid_prefix
-      use_middleware Rack::PostBodyContentTypeParser
-      use_middleware Rack::CommonLogger, logger
-      use_middleware Rory::RequestParameterLogger, logger, :filters => parameters_to_filter
+    def initializer_default_middleware
+      Rory.initialize_request_middleware
     end
 
+    initializer_default_middleware
+
     def run_initializers
       Rory::Application.initializers.run(self)
     end
diff --git a/lib/rory/default_initializers/request_middleware.rb b/lib/rory/default_initializers/request_middleware.rb
new file mode 100644
index 0000000..3248e74
--- /dev/null
+++ b/lib/rory/default_initializers/request_middleware.rb
@@ -0,0 +1,10 @@
+module Rory
+  def self.initialize_request_middleware
+    Rory::Application.initializers.add "rory.request_middleware" do |app|
+      app.middleware.use Rory::RequestId, :uuid_prefix => app.uuid_prefix
+      app.middleware.use Rack::PostBodyContentTypeParser
+      app.middleware.use Rack::CommonLogger, app.logger
+      app.middleware.use Rory::RequestParameterLogger, app.logger, :filters => app.parameters_to_filter
+    end
+  end
+end

From e26116aee530464086076f21fb706a0696026c0e Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Thu, 26 May 2016 10:29:55 -0700
Subject: [PATCH 03/18] Move out logging and make every attribute writable so
 that RfLogger can replace the default.

---
 lib/rory/application.rb           | 21 ++++----------------
 lib/rory/logging.rb               | 20 +++++++++++++++++++
 spec/lib/rory/application_spec.rb | 32 ++++++-------------------------
 3 files changed, 30 insertions(+), 43 deletions(-)
 create mode 100644 lib/rory/logging.rb

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index 2b39299..efad1e1 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -7,6 +7,7 @@
 require 'rack/commonlogger'
 require 'rory/request_parameter_logger'
 require 'rory/sequel_connect'
+require 'rory/logging'
 require 'rory/default_initializers/request_middleware'
 
 module Rory
@@ -17,16 +18,17 @@ class Application
     # Exception raised if no root has been set for this Rory::Application subclass
     class RootNotConfigured < StandardError; end
     include SequelConnect
+    include Logging
 
     attr_reader :db, :db_config
     attr_accessor :config_path
+    attr_writer :auto_require_paths
 
     class << self
       private :new
       attr_reader :root
 
       def inherited(subclass)
-        super
         Rory.application = subclass.instance
       end
 
@@ -75,18 +77,12 @@ def config_path
       @config_path ||= root_path.join('config')
     end
 
-    def log_path
-      @log_path ||= root_path.join('log')
-    end
-
     def set_routes(&block)
       @routes = RouteMapper.set_routes(&block)
     end
 
     def routes
-      unless @routes
-        load(File.join(config_path, 'routes.rb'))
-      end
+      load(File.join(config_path, 'routes.rb')) unless @routes
       @routes
     end
 
@@ -165,14 +161,5 @@ def stack
     def call(env)
       stack.call(env)
     end
-
-    def log_file
-      Dir.mkdir(log_path) unless File.exists?(log_path)
-      File.open(log_path.join("#{ENV['RORY_ENV']}.log"), 'a').tap { |file| file.sync = true }
-    end
-
-    def logger
-      @logger ||= Logger.new(log_file)
-    end
   end
 end
diff --git a/lib/rory/logging.rb b/lib/rory/logging.rb
new file mode 100644
index 0000000..d686057
--- /dev/null
+++ b/lib/rory/logging.rb
@@ -0,0 +1,20 @@
+module Rory
+  module Logging
+    attr_writer :logger, :log_file, :log_path
+
+    def log_path
+      @log_path ||= root_path.join('log')
+    end
+
+    def log_file
+      @log_file ||= begin
+        Dir.mkdir(log_path) unless File.exists?(log_path)
+         File.open(log_path.join("#{ENV['RORY_ENV']}.log"), 'a').tap { |file| file.sync = true }
+      end
+    end
+
+    def logger
+      @logger ||= Rory::Logger.new(log_file)
+    end
+  end
+end
diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index 549b34c..826d234 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -140,7 +140,7 @@ class RootlessApp < Rory::Application; end
 
   describe ".turn_off_request_logging!" do
     it "resets stack and turns off request logging" do
-      subject.instance.instance_variable_set(:@request_logging, :true)
+      subject.initializer_default_middleware
       expect(subject.request_logging_on?).to eq(true)
       expect(subject.instance).to receive(:reset_stack)
       subject.turn_off_request_logging!
@@ -172,7 +172,6 @@ class RootlessApp < Rory::Application; end
         and_return(:the_dispatcher)
       allow(Rack::Builder).to receive(:new).and_return(builder)
       subject.use_middleware :horse
-      expect(subject.instance).to receive(:request_middleware).with(no_args)
       expect(builder).to receive(:use).with(:horse)
       expect(builder).to receive(:run).with(:the_dispatcher)
       expect(subject.stack).to eq(builder)
@@ -185,25 +184,6 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".use_default_middleware" do
-    it "adds middleware when request logging is on" do
-      allow(subject.instance).to receive(:request_logging_on?).and_return(true)
-      allow(subject.instance).to receive(:parameters_to_filter).and_return([:horses])
-      allow(subject.instance).to receive(:logger).and_return(:the_logger)
-      expect(subject.instance).to receive(:use_middleware).with(Rory::RequestId, :uuid_prefix => Rory::Support.tokenize(test_rory_app_name))
-      expect(subject.instance).to receive(:use_middleware).with(Rack::PostBodyContentTypeParser)
-      expect(subject.instance).to receive(:use_middleware).with(Rack::CommonLogger, :the_logger)
-      expect(subject.instance).to receive(:use_middleware).with(Rory::RequestParameterLogger, :the_logger, :filters => [:horses])
-      subject.request_middleware
-    end
-
-    it "does not add middleware when request logging is off" do
-      allow(subject.instance).to receive(:request_logging_on?).and_return(false)
-      expect(subject.instance).to receive(:use_middleware).never
-      subject.request_middleware
-    end
-  end
-
   describe ".load_config_data" do
     it "returns parsed yaml file with given name from directory at config_path" do
       allow_any_instance_of(subject).to receive(:config_path).and_return('Africa the Great')
@@ -235,22 +215,22 @@ class RootlessApp < Rory::Application; end
 
   describe '.auto_require_paths' do
     after(:each) do
-      subject.instance.instance_variable_set(:@auto_require_paths, nil)
+      subject.instance.auto_require_paths = nil
     end
 
     it 'includes models, controllers, and helpers by default' do
-      expect(subject.auto_require_paths).to eq(['models', 'controllers', 'helpers'])
+      expect(subject.auto_require_paths).to eq(%w(models controllers helpers))
     end
 
     it 'accepts new paths' do
       subject.auto_require_paths << 'chocolates'
-      expect(subject.auto_require_paths).to eq(['models', 'controllers', 'helpers', 'chocolates'])
+      expect(subject.auto_require_paths).to eq(%w(models controllers helpers chocolates))
     end
   end
 
   describe '.require_all_files' do
     it 'requires all files in auto_require_paths' do
-      allow_any_instance_of(subject).to receive(:auto_require_paths).and_return(['goats', 'rhubarbs'])
+      allow_any_instance_of(subject).to receive(:auto_require_paths).and_return(%w(goats rhubarbs))
       [:goats, :rhubarbs].each do |folder|
         expect(Rory::Support).to receive(:require_all_files_in_directory).
           with(Pathname.new(subject.root).join("#{folder}"))
@@ -337,7 +317,7 @@ class RootlessApp < Rory::Application; end
 
     describe "#insert_before" do
       it "places the middleware order right after the given class" do
-        subject.instance.instance_variable_set(:@request_logging, :true)
+        subject.initializer_default_middleware
         Rory::Application.initializers.add "insert_before.dummy_middleware" do |app|
           app.middleware.insert_before Rory::RequestId, DummyMiddleware, :puppy
         end

From b6630eafedda64c8fdd140cc07c13d35aa8bc047 Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Thu, 26 May 2016 10:45:55 -0700
Subject: [PATCH 04/18] Refactor tests

---
 .../request_middleware.rb                     |  8 +--
 spec/lib/rory/application_spec.rb             | 52 +++++++++++++------
 2 files changed, 40 insertions(+), 20 deletions(-)

diff --git a/lib/rory/default_initializers/request_middleware.rb b/lib/rory/default_initializers/request_middleware.rb
index 3248e74..cb6ef8c 100644
--- a/lib/rory/default_initializers/request_middleware.rb
+++ b/lib/rory/default_initializers/request_middleware.rb
@@ -1,10 +1,10 @@
 module Rory
   def self.initialize_request_middleware
     Rory::Application.initializers.add "rory.request_middleware" do |app|
-      app.middleware.use Rory::RequestId, :uuid_prefix => app.uuid_prefix
-      app.middleware.use Rack::PostBodyContentTypeParser
-      app.middleware.use Rack::CommonLogger, app.logger
-      app.middleware.use Rory::RequestParameterLogger, app.logger, :filters => app.parameters_to_filter
+      app.use_middleware Rory::RequestId, :uuid_prefix => app.uuid_prefix
+      app.use_middleware Rack::PostBodyContentTypeParser
+      app.use_middleware Rack::CommonLogger, app.logger
+      app.use_middleware Rory::RequestParameterLogger, app.logger, :filters => app.parameters_to_filter
     end
   end
 end
diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index 826d234..5a5ca6b 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -40,7 +40,7 @@
     end
   end
 
-  describe ".configure" do
+  describe "#configure" do
     it 'yields the given block to self' do
       subject.configure do |c|
         expect(c).to eq(subject.instance)
@@ -103,7 +103,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".call" do
+  describe "#call" do
     it "calls the stack with the given environment" do
       stack = double
       allow(stack).to receive(:call).with(:the_env).and_return(:expected)
@@ -112,7 +112,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".log_file" do
+  describe "#log_file" do
     it "creates the log file directory if it does not exist" do
       file = double(:sync= => true)
       allow(File).to receive(:exists?).and_return(false)
@@ -129,7 +129,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".logger" do
+  describe "#logger" do
     it "returns a logger" do
       logger = double
       allow_any_instance_of(subject).to receive(:log_file)
@@ -138,7 +138,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".turn_off_request_logging!" do
+  describe "#turn_off_request_logging!" do
     it "resets stack and turns off request logging" do
       subject.initializer_default_middleware
       expect(subject.request_logging_on?).to eq(true)
@@ -148,7 +148,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".filter_parameters" do
+  describe "#filter_parameters" do
     it "resets stack and sets parameters to filter" do
       expect(subject.instance).to receive(:reset_stack)
       subject.filter_parameters :dog, :kitty
@@ -156,7 +156,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".reset_stack" do
+  describe "#reset_stack" do
     it "clears memoization of stack" do
       stack = subject.stack
       expect(subject.stack).to eq(stack)
@@ -165,7 +165,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".stack" do
+  describe "#stack" do
     it "returns a rack builder instance with configured middleware" do
       builder = double
       allow(subject.instance).to receive(:dispatcher).
@@ -178,13 +178,33 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".parameters_to_filter" do
+  describe "#parameters_to_filter" do
     it "returns [:password] by default" do
       expect(subject.parameters_to_filter).to eq([:password])
     end
   end
 
-  describe ".load_config_data" do
+  describe "#initializer_default_middleware" do
+
+    before { subject.initializer_default_middleware }
+
+    it "adds middleware when request logging is on" do
+      allow(subject.instance).to receive(:parameters_to_filter).and_return([:horses])
+      allow(subject.instance).to receive(:logger).and_return(:the_logger)
+      expect(subject.instance).to receive(:use_middleware).with(Rory::RequestId, :uuid_prefix => Rory::Support.tokenize(test_rory_app_name))
+      expect(subject.instance).to receive(:use_middleware).with(Rack::PostBodyContentTypeParser)
+      expect(subject.instance).to receive(:use_middleware).with(Rack::CommonLogger, :the_logger)
+      expect(subject.instance).to receive(:use_middleware).with(Rory::RequestParameterLogger, :the_logger, :filters => [:horses])
+      subject.run_initializers
+    end
+
+    it "does not add middleware when request logging is off" do
+      subject.instance.turn_off_request_logging!
+      expect(Rory::Application.initializers.count).to eq 0
+    end
+  end
+
+  describe "#load_config_data" do
     it "returns parsed yaml file with given name from directory at config_path" do
       allow_any_instance_of(subject).to receive(:config_path).and_return('Africa the Great')
       allow(YAML).to receive(:load_file).with(
@@ -194,7 +214,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".connect_db" do
+  describe "#connect_db" do
     it "sets up sequel connection to DB from YAML file" do
       config = { 'development' => :expected }
       logger_array = []
@@ -206,7 +226,7 @@ class RootlessApp < Rory::Application; end
     end
   end
 
-  describe ".spin_up" do
+  describe "#spin_up" do
     it "connects the database" do
       expect_any_instance_of(Rory::Application).to receive(:connect_db)
       Rory::Application.spin_up
@@ -257,7 +277,7 @@ class RootlessApp < Rory::Application; end
 
   context "with fixture application" do
     subject { Fixture::Application }
-    describe ".routes" do
+    describe "#routes" do
       it "generates a collection of routing objects from route configuration" do
         expect(subject.routes).to eq [
           Rory::Route.new('foo/:id/bar', :to => 'foo#bar', :methods => [:get, :post]),
@@ -272,7 +292,7 @@ class RootlessApp < Rory::Application; end
       end
     end
 
-    describe ".parameters_to_filter" do
+    describe "#parameters_to_filter" do
       it "returns overridden parameters" do
         expect(subject.parameters_to_filter).to eq([:orcas, :noodles])
       end
@@ -280,7 +300,7 @@ class RootlessApp < Rory::Application; end
   end
 
   describe ".initializers" do
-    describe ".insert_after" do
+    describe "#insert_after" do
       it "inserts initializer before another" do
         probe = []
         Rory::Application.initializers.add("insert_after.A") { probe << "insert_after.A" }
@@ -292,7 +312,7 @@ class RootlessApp < Rory::Application; end
       end
     end
 
-    describe ".add" do
+    describe "#add" do
       it "runs the code inside any initializer block" do
         probe = :initializers_not_run
         Rory::Application.initializers.add "add.test" do

From 143cdd64d6cb45b54d17e31a2919fb6ea2328697 Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Tue, 31 May 2016 14:50:15 -0700
Subject: [PATCH 05/18] Separate request logging from request_id middleware

---
 lib/rory/application.rb                       |  7 ++++---
 .../request_middleware.rb                     | 21 +++++++++++++------
 spec/lib/rory/application_spec.rb             | 11 ++++++----
 3 files changed, 26 insertions(+), 13 deletions(-)

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index efad1e1..797437c 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -113,12 +113,12 @@ def dispatcher
     end
 
     def request_logging_on?
-      !!Rory::Application.initializers.detect{|init| init.name == "rory.request_middleware" }
+      !!Rory::Application.initializers.detect{|init| init.name == "rory.request_logging_middleware" }
     end
 
     def turn_off_request_logging!
       reset_stack
-      Rory::Application.initializers.delete("rory.request_middleware")
+      Rory::Application.initializers.delete("rory.request_logging_middleware")
     end
 
     def parameters_to_filter
@@ -139,7 +139,8 @@ def uuid_prefix
     end
 
     def initializer_default_middleware
-      Rory.initialize_request_middleware
+      Rory::RequestMiddleware.initialize_request_id
+      Rory::RequestMiddleware.initialize_logging
     end
 
     initializer_default_middleware
diff --git a/lib/rory/default_initializers/request_middleware.rb b/lib/rory/default_initializers/request_middleware.rb
index cb6ef8c..eaa3425 100644
--- a/lib/rory/default_initializers/request_middleware.rb
+++ b/lib/rory/default_initializers/request_middleware.rb
@@ -1,10 +1,19 @@
 module Rory
-  def self.initialize_request_middleware
-    Rory::Application.initializers.add "rory.request_middleware" do |app|
-      app.use_middleware Rory::RequestId, :uuid_prefix => app.uuid_prefix
-      app.use_middleware Rack::PostBodyContentTypeParser
-      app.use_middleware Rack::CommonLogger, app.logger
-      app.use_middleware Rory::RequestParameterLogger, app.logger, :filters => app.parameters_to_filter
+  module RequestMiddleware
+    class << self
+      def initialize_logging
+        Rory::Application.initializers.add "rory.request_logging_middleware" do |app|
+          app.use_middleware Rack::PostBodyContentTypeParser
+          app.use_middleware Rack::CommonLogger, app.logger
+          app.use_middleware Rory::RequestParameterLogger, app.logger, :filters => app.parameters_to_filter
+        end
+      end
+
+      def initialize_request_id
+        Rory::Application.initializers.add "rory.request_id_middleware" do |app|
+          app.use_middleware Rory::RequestId, :uuid_prefix => app.uuid_prefix
+        end
+      end
     end
   end
 end
diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index 5a5ca6b..b0fdb57 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -16,7 +16,8 @@
 
   before do
     Rory::Application.initializers.clear
-    Rory::Application.initializer_default_middleware
+    Rory::Application.initializers.clear
+    Rory::Application.middleware.clear
   end
 
   describe ".root=" do
@@ -185,7 +186,6 @@ class RootlessApp < Rory::Application; end
   end
 
   describe "#initializer_default_middleware" do
-
     before { subject.initializer_default_middleware }
 
     it "adds middleware when request logging is on" do
@@ -200,7 +200,7 @@ class RootlessApp < Rory::Application; end
 
     it "does not add middleware when request logging is off" do
       subject.instance.turn_off_request_logging!
-      expect(Rory::Application.initializers.count).to eq 0
+      expect(Rory::Application.initializers.map(&:name)).to eq ["rory.request_id_middleware"]
     end
   end
 
@@ -333,7 +333,10 @@ class RootlessApp < Rory::Application; end
   end
 
   describe "#middleware" do
-    before { subject.middleware.clear }
+    before do
+      subject.initializers.clear
+      subject.middleware.clear
+    end
 
     describe "#insert_before" do
       it "places the middleware order right after the given class" do

From d59b6f0a3563568a57acb43a8035e83e5c6c12d5 Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Tue, 31 May 2016 15:14:59 -0700
Subject: [PATCH 06/18] Remove duplicate line

---
 spec/lib/rory/application_spec.rb | 6 ------
 1 file changed, 6 deletions(-)

diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index b0fdb57..b6c7ece 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -15,7 +15,6 @@
   let(:root){"spec/fixture_app"}
 
   before do
-    Rory::Application.initializers.clear
     Rory::Application.initializers.clear
     Rory::Application.middleware.clear
   end
@@ -333,11 +332,6 @@ class RootlessApp < Rory::Application; end
   end
 
   describe "#middleware" do
-    before do
-      subject.initializers.clear
-      subject.middleware.clear
-    end
-
     describe "#insert_before" do
       it "places the middleware order right after the given class" do
         subject.initializer_default_middleware

From 251f696a2a7dea5a669ca605772723d394ddeddb Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Wed, 1 Jun 2016 17:00:42 -0700
Subject: [PATCH 07/18] Better grammer

---
 lib/rory/application.rb           | 4 ++--
 spec/lib/rory/application_spec.rb | 6 +++---
 2 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index 797437c..dbf4237 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -138,12 +138,12 @@ def uuid_prefix
       Support.tokenize(self.class.name.gsub("::Application", ""))
     end
 
-    def initializer_default_middleware
+    def initialize_default_middleware
       Rory::RequestMiddleware.initialize_request_id
       Rory::RequestMiddleware.initialize_logging
     end
 
-    initializer_default_middleware
+    initialize_default_middleware
 
     def run_initializers
       Rory::Application.initializers.run(self)
diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index b6c7ece..dd08d75 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -140,7 +140,7 @@ class RootlessApp < Rory::Application; end
 
   describe "#turn_off_request_logging!" do
     it "resets stack and turns off request logging" do
-      subject.initializer_default_middleware
+      subject.initialize_default_middleware
       expect(subject.request_logging_on?).to eq(true)
       expect(subject.instance).to receive(:reset_stack)
       subject.turn_off_request_logging!
@@ -185,7 +185,7 @@ class RootlessApp < Rory::Application; end
   end
 
   describe "#initializer_default_middleware" do
-    before { subject.initializer_default_middleware }
+    before { subject.initialize_default_middleware }
 
     it "adds middleware when request logging is on" do
       allow(subject.instance).to receive(:parameters_to_filter).and_return([:horses])
@@ -334,7 +334,7 @@ class RootlessApp < Rory::Application; end
   describe "#middleware" do
     describe "#insert_before" do
       it "places the middleware order right after the given class" do
-        subject.initializer_default_middleware
+        subject.initialize_default_middleware
         Rory::Application.initializers.add "insert_before.dummy_middleware" do |app|
           app.middleware.insert_before Rory::RequestId, DummyMiddleware, :puppy
         end

From 9c4a9781fae0df897cce3b78d76ecddc7bab6bac Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Wed, 1 Jun 2016 17:04:33 -0700
Subject: [PATCH 08/18] Move requires to their place of use.

---
 lib/rory/application.rb                             | 4 ----
 lib/rory/default_initializers/request_middleware.rb | 4 ++++
 lib/rory/logging.rb                                 | 2 ++
 3 files changed, 6 insertions(+), 4 deletions(-)

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index dbf4237..da871ea 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -1,11 +1,7 @@
 require 'pathname'
-require 'rory/logger'
-require 'rory/request_id'
 require 'rory/route_mapper'
 require 'rory/middleware_stack'
 require 'rory/initializers'
-require 'rack/commonlogger'
-require 'rory/request_parameter_logger'
 require 'rory/sequel_connect'
 require 'rory/logging'
 require 'rory/default_initializers/request_middleware'
diff --git a/lib/rory/default_initializers/request_middleware.rb b/lib/rory/default_initializers/request_middleware.rb
index eaa3425..aba3aaa 100644
--- a/lib/rory/default_initializers/request_middleware.rb
+++ b/lib/rory/default_initializers/request_middleware.rb
@@ -1,3 +1,7 @@
+require 'rack/commonlogger'
+require 'rory/request_parameter_logger'
+require 'rory/request_id'
+
 module Rory
   module RequestMiddleware
     class << self
diff --git a/lib/rory/logging.rb b/lib/rory/logging.rb
index d686057..6353248 100644
--- a/lib/rory/logging.rb
+++ b/lib/rory/logging.rb
@@ -1,3 +1,5 @@
+require 'rory/logger'
+
 module Rory
   module Logging
     attr_writer :logger, :log_file, :log_path

From f594854d6b5fc7db5145cdb447e038815e859ff8 Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Thu, 2 Jun 2016 13:59:54 -0700
Subject: [PATCH 09/18] Initializers/Middleware insert{after, before}.or_add

---
 lib/rory/initializers.rb               | 88 ++++++++++++++++++++++----
 lib/rory/middleware_stack.rb           | 49 +++++++++++---
 spec/lib/rory/initializers_spec.rb     | 30 ++++++++-
 spec/lib/rory/middleware_stack_spec.rb | 17 +++++
 4 files changed, 161 insertions(+), 23 deletions(-)

diff --git a/lib/rory/initializers.rb b/lib/rory/initializers.rb
index 13b4b6e..6afa26f 100644
--- a/lib/rory/initializers.rb
+++ b/lib/rory/initializers.rb
@@ -30,29 +30,80 @@ def call(app)
 
     def initialize
       @initializers = []
-      yield(self) if block_given?
     end
 
+    # @!macro add
+    #   @param [String] name the reference name of the initializer
+    #   @yield [app] block the code to be run for the initializer
+
+    ##
+    # @!macro add
     def unshift(name, &block)
       initializers.unshift(build_initializer(name, block))
     end
 
-    def insert(index, name, &block)
-      index = assert_index(index, :before)
-      initializers.insert(index, build_initializer(name, block))
+    # @!macro insert
+    #   @param [String, Integer] index either an index or a string reference
+    #   @param [String] name the reference name of the initializer
+    #   @yield [app] block the code to be run for the initializer
+    #   @raise [NoInitializerFound] when reference name is not found
+
+    # @!macro insert_optional
+    #   @param [String, Integer] index either an index or a string reference
+    #   @param [String] name the reference name of the initializer
+    #   @yield [app] block the code to be run for the initializer
+    #   @return [OrAdd, #or_add] Try to insert after but if that initializer reference cannot be found add on to the end.
+    #   @example
+    #     @method "init_name", "new_init" do |app|
+    #       ...
+    #     end #=> if "init_name" is not found raises NoInitializerFound
+    #
+    #     @method.or_add "init_name", "new_init" do |app|
+    #       ...
+    #     end #=> if "init_name" is not found add to the end
+
+    ##
+    # Insert before an already added initializer
+    # @!macro insert_optional
+    def insert(*args, &block)
+      if args.empty?
+        OrAdd.new(method(:_insert), method(:add))
+      else
+        _insert(*args, &block)
+      end
     end
 
     alias_method :insert_before, :insert
+    # Insert after an already added initializer
+    # @!macro insert_optional
+    def insert_after(*args, &block)
+      if args.empty?
+        OrAdd.new(method(:_insert_after), method(:add))
+      else
+        _insert_after(*args, &block)
+      end
+    end
 
-    def insert_after(index, name, &block)
-      index = assert_index(index, :after)
-      insert(index + 1, name, &block)
+    class OrAdd
+      def initialize(insert, add)
+        @insert = insert
+        @add    = add
+      end
+
+      # @!macro insert
+      def or_add(index, name, &block)
+        @insert.call(index, name, &block)
+      rescue NoInitializerFound
+        @add.call(name, &block)
+      end
     end
 
-    def delete(target)
-      initializers.delete_if { |m| m.name == target }
+    # @param [String] name the reference name of the initializer
+    def delete(name)
+      initializers.delete_if { |m| m.name == name }
     end
 
+    # @!macro add
     def add(name, &block)
       initializers.push(build_initializer(name, block))
     end
@@ -63,9 +114,21 @@ def run(app)
 
     private
 
-    def assert_index(index, where)
+    def _insert_after(index, name, &block)
+      index = assert_index(index, :after, name)
+      insert(index + 1, name, &block)
+    end
+
+    def _insert(index, name, &block)
+      index = assert_index(index, :before, name)
+      initializers.insert(index, build_initializer(name, block))
+    end
+
+    NoInitializerFound = Class.new(StandardError)
+
+    def assert_index(index, where, for_init)
       i     = index.is_a?(Integer) ? index : initializers.index { |m| m.name == index }
-      raise "No such initializer to insert #{where}: #{index.inspect}" unless i
+      raise NoInitializerFound, "No such initializer to insert #{where}: #{index.inspect} for #{for_init.inspect}" unless i
       i
     end
 
@@ -73,9 +136,10 @@ def build_initializer(name, block)
       Initializer.new(name, block).tap{ |i| assert_unique_name(i) }
     end
 
+    InitializerNameNotUnique = Class.new(StandardError)
     def assert_unique_name(i)
       unless (conflict = @initializers.select{|ii| ii == i}).empty?
-        raise "Initializer name: '#{i.name}' is already used. #{conflict.first.block}"
+        raise InitializerNameNotUnique, "Initializer name: '#{i.name}' is already used. #{conflict.first.block}"
       end
     end
   end
diff --git a/lib/rory/middleware_stack.rb b/lib/rory/middleware_stack.rb
index cbb11fb..3f00b45 100644
--- a/lib/rory/middleware_stack.rb
+++ b/lib/rory/middleware_stack.rb
@@ -42,8 +42,7 @@ def build(app)
     attr_accessor :middlewares
     def_delegators :middlewares, :each, :clear, :size, :last, :first, :[]
 
-    def initialize(on_change: -> {})
-
+    def initialize
       @middlewares = []
       yield(self) if block_given?
     end
@@ -52,16 +51,35 @@ def unshift(klass, *args, &block)
       middlewares.unshift(build_middleware(klass, args, block))
     end
 
-    def insert(index, klass, *args, &block)
-      index = assert_index(index, :before)
-      middlewares.insert(index, build_middleware(klass, args, block))
+    def insert(*args, &block)
+      if args.empty?
+        OrAdd.new(method(:_insert), method(:use))
+      else
+        _insert(*args, &block)
+      end
     end
 
     alias_method :insert_before, :insert
 
-    def insert_after(index, *args, &block)
-      index = assert_index(index, :after)
-      insert(index + 1, *args, &block)
+    def insert_after(*args, &block)
+      if args.empty?
+        OrAdd.new(method(:_insert_after), method(:use))
+      else
+        _insert_after(*args, &block)
+      end
+    end
+
+    class OrAdd
+      def initialize(insert, use)
+        @insert = insert
+        @use    = use
+      end
+
+      def or_add(*args, &block)
+        @insert.call(*args, &block)
+      rescue MiddlewareNotFound
+        @use.call(*args, &block)
+      end
     end
 
     def delete(target)
@@ -74,9 +92,20 @@ def use(klass, *args, &block)
 
     private
 
-    def assert_index(index, where)
+    def _insert(index, klass, *args, &block)
+      index = assert_index(index, :before, klass)
+      middlewares.insert(index, build_middleware(klass, args, block))
+    end
+
+    def _insert_after(index, klass, *args, &block)
+      index = assert_index(index, :after, klass)
+      insert(index + 1, klass, *args, &block)
+    end
+
+    MiddlewareNotFound = Class.new(StandardError)
+    def assert_index(index, where, for_middleware)
       i     = index.is_a?(Integer) ? index : middlewares.index { |m| m.klass == index }
-      raise "No such middleware to insert #{where}: #{index.inspect}" unless i
+      raise MiddlewareNotFound, "No such middleware to insert #{where}: #{index.inspect} for #{for_middleware.name}" unless i
       i
     end
 
diff --git a/spec/lib/rory/initializers_spec.rb b/spec/lib/rory/initializers_spec.rb
index fbb3d00..07784ee 100644
--- a/spec/lib/rory/initializers_spec.rb
+++ b/spec/lib/rory/initializers_spec.rb
@@ -24,6 +24,19 @@
     end
   end
 
+  describe "#insert_before.or_add" do
+    it "adds an item at certain point after a given initializer" do
+      subject.add("test.1insert_before") {}
+      subject.insert_before.or_add("test.1insert_before", "test.2insert_before") {}
+      expect(subject.initializers.map(&:name)).to eq %w(test.2insert_before test.1insert_before)
+    end
+
+    it "pushes an item on the list to be loaded when no initializer is found" do
+      subject.insert_before.or_add("test.1insert_before", "test.2insert_before") {}
+      expect(subject.initializers.map(&:name)).to eq %w(test.2insert_before)
+    end
+  end
+
   describe "#insert_after" do
     it "adds an item at certain point after a given initializer" do
       subject.add("test.1insert_after") {}
@@ -33,6 +46,21 @@
     end
   end
 
+  describe "#insert_after.or_add" do
+    it "adds an item at certain point after a given initializer" do
+      subject.add("test.1insert_after") {}
+      subject.add("test.2insert_after") {}
+      subject.insert_after.or_add("test.1insert_after", "test.3insert_after") {}
+      expect(subject.initializers.map(&:name)).to eq %w(test.1insert_after test.3insert_after test.2insert_after)
+    end
+
+    it "pushes an item on the list to be loaded when no initializer is found" do
+      subject.add("test.2insert_after") {}
+      subject.insert_after.or_add("test.1insert_after", "test.3insert_after") {}
+      expect(subject.initializers.map(&:name)).to eq %w(test.2insert_after test.3insert_after)
+    end
+  end
+
   describe "#delete" do
     it "removes a given initializer from loading" do
       subject.add("test.delete") {}
@@ -42,7 +70,7 @@
   end
 
   describe "#add" do
-    it "push an item on the list to be loaded" do
+    it "pushes an item on the list to be loaded" do
       subject.add("test.1add") {}
       subject.add("test.2add") {}
       expect(subject.initializers.map(&:name)).to eq %w(test.1add test.2add)
diff --git a/spec/lib/rory/middleware_stack_spec.rb b/spec/lib/rory/middleware_stack_spec.rb
index 8f0aa90..5d5669d 100644
--- a/spec/lib/rory/middleware_stack_spec.rb
+++ b/spec/lib/rory/middleware_stack_spec.rb
@@ -41,6 +41,23 @@
     end
   end
 
+  describe "#insert_after.or_add" do
+    it "adds an item at certain point after a given middleware" do
+      insert_after1 = double(name: "test.1insert_after")
+      subject.use(insert_after1) {}
+      subject.use(double(name: "test.2insert_after")) {}
+      subject.insert_after.or_add(insert_after1, double(name: "test.3insert_after")) {}
+      expect(middleware_order).to eq %w(test.1insert_after test.3insert_after test.2insert_after)
+    end
+
+    it "push an item on the list to be loaded when middleware not found" do
+      insert_after1 = double(name: "test.1insert_after")
+      subject.use(double(name: "test.2insert_after")) {}
+      subject.insert_after.or_add(insert_after1, double(name: "test.3insert_after")) {}
+      expect(middleware_order).to eq %w(test.2insert_after test.1insert_after)
+    end
+  end
+
   describe "#delete" do
     it "removes a given middleware from loading" do
       test_delete = double(name: "delete")

From 0e823c7257b556fa25e8f6b7f91b19b6cd0e5d93 Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Thu, 2 Jun 2016 15:01:27 -0700
Subject: [PATCH 10/18] version v.0.9.0

---
 lib/rory/version.rb | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/lib/rory/version.rb b/lib/rory/version.rb
index dee9344..2f0894f 100644
--- a/lib/rory/version.rb
+++ b/lib/rory/version.rb
@@ -1,3 +1,3 @@
 module Rory
-  VERSION = '0.8.1'
+  VERSION = '0.9.0'
 end

From e22c43166428c155d14c81e472b27487274995f7 Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Fri, 3 Jun 2016 11:03:18 -0700
Subject: [PATCH 11/18] Initializers state is shared between Rory::Application
 and {AppName}::Application

---
 lib/rory/application.rb           | 2 +-
 spec/lib/rory/application_spec.rb | 5 +++++
 2 files changed, 6 insertions(+), 1 deletion(-)

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index da871ea..2619091 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -34,7 +34,7 @@ def method_missing(*args, &block)
 
       # @return [Rory::Initializers]
       def initializers
-        @initializers ||= Initializers.new
+        @@initializers ||= Initializers.new
       end
 
       def respond_to?(method, private=false)
diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index dd08d75..201a287 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -329,6 +329,11 @@ class RootlessApp < Rory::Application; end
         expect { subject.run_initializers }.to change { probe }.from(:block_not_called).to(:block_called)
       end
     end
+
+    it "state is shared between Rory::Application and {AppName}::Application" do
+      Rory::Application.initializers.add("add.test") {}
+      expect(subject.initializers.map(&:name)).to eq(["add.test"])
+    end
   end
 
   describe "#middleware" do

From 3f6c89770211d51a46ed30a38a2c64b1f27619bd Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Fri, 3 Jun 2016 11:35:58 -0700
Subject: [PATCH 12/18] Fix issue that initializers are not run until the first
 request. Solution is to call .warmup on boot. A warning will be logged to
 notify user of to call this method if not already.

---
 lib/rory/application.rb           | 21 ++++++++++++++++++++-
 spec/lib/rory/application_spec.rb | 22 ++++++++++++++++++++++
 2 files changed, 42 insertions(+), 1 deletion(-)

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index 2619091..e0702a4 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -49,6 +49,16 @@ def instance
       def root=(root_path)
         $:.unshift @root = Pathname.new(root_path).realpath
       end
+
+      def warmup
+        self.warmed_up = true
+        run_initializers
+      end
+
+      attr_writer :warmed_up
+      def warmed_up?
+        !!@warmed_up
+      end
     end
 
     def auto_require_paths
@@ -147,7 +157,7 @@ def run_initializers
 
     def stack
       @stack ||= Rack::Builder.new.tap { |builder|
-        run_initializers
+        warmup_check
         middleware.each do |m|
           builder.use m.klass, *m.args, &m.block
         end
@@ -158,5 +168,14 @@ def stack
     def call(env)
       stack.call(env)
     end
+    private
+
+    def warmup_check
+      unless self.class.warmed_up?
+        logger.warn("#{self.class.name} was not warmed up before the first request. "\
+                    "Call #{self.class.name}.warmup on boot to ensure a quick first response.")
+        self.class.warmup
+      end
+    end
   end
 end
diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index 201a287..cccab14 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -291,6 +291,28 @@ class RootlessApp < Rory::Application; end
       end
     end
 
+    include Rack::Test::Methods
+    def app
+      Fixture::Application
+    end
+
+    context "when app is warmed up" do
+      it "does not log a warning" do
+        Fixture::Application.warmup
+        expect(subject.logger).to_not receive(:warn)
+        get 'for_reals/switching'
+      end
+    end
+
+    context "when app not is warmed up" do
+      it "does log a warning" do
+        Fixture::Application.warmed_up = nil
+        warm_msg = "Fixture::Application was not warmed up before the first request. Call Fixture::Application.warmup on boot to ensure a quick first response."
+        expect(Fixture::Application.logger).to receive(:warn).with(warm_msg)
+        get 'for_reals/switching'
+      end
+    end
+
     describe "#parameters_to_filter" do
       it "returns overridden parameters" do
         expect(subject.parameters_to_filter).to eq([:orcas, :noodles])

From c12646f28bd1942f6b65ac88a0c1997f33491a04 Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Fri, 3 Jun 2016 11:38:13 -0700
Subject: [PATCH 13/18] deprecated #spin_up in favor of calling connect_db
 directly.

---
 lib/rory/application.rb    | 5 +----
 lib/rory/sequel_connect.rb | 5 +++++
 2 files changed, 6 insertions(+), 4 deletions(-)

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index e0702a4..627b3c6 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -96,10 +96,6 @@ def configure
       yield self
     end
 
-    def spin_up
-      connect_db
-    end
-
     def load_config_data(config_type)
       YAML.load_file(
         File.expand_path(File.join(config_path, "#{config_type}.yml"))
@@ -168,6 +164,7 @@ def stack
     def call(env)
       stack.call(env)
     end
+
     private
 
     def warmup_check
diff --git a/lib/rory/sequel_connect.rb b/lib/rory/sequel_connect.rb
index 2b84d8e..b3b6f3c 100644
--- a/lib/rory/sequel_connect.rb
+++ b/lib/rory/sequel_connect.rb
@@ -5,5 +5,10 @@ def connect_db(environment = ENV['RORY_ENV'])
       @db = Sequel.connect(@db_config[environment.to_s])
       @db.loggers << logger
     end
+
+    # @deprecated Use {#connect_db} instead of this method because that's all it does any ways.
+    def spin_up
+      connect_db
+    end
   end
 end

From e745f75ff2b7a8ae8ca63dca024bbed6d1f3c6ce Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Fri, 3 Jun 2016 13:31:32 -0700
Subject: [PATCH 14/18] Add Rory.env to return then value of ENV["RORY_ENV"]

---
 lib/rory.rb           |  4 ++++
 spec/lib/rory_spec.rb | 12 +++++++++---
 2 files changed, 13 insertions(+), 3 deletions(-)

diff --git a/lib/rory.rb b/lib/rory.rb
index 0529e0d..7d8dda1 100644
--- a/lib/rory.rb
+++ b/lib/rory.rb
@@ -19,5 +19,9 @@ def root
       app = application
       app && app.root
     end
+
+    def env
+      ENV["RORY_ENV"]
+    end
   end
 end
diff --git a/spec/lib/rory_spec.rb b/spec/lib/rory_spec.rb
index 5ab2765..4504210 100644
--- a/spec/lib/rory_spec.rb
+++ b/spec/lib/rory_spec.rb
@@ -3,13 +3,19 @@
 
   describe '.application' do
     it 'is by default set to the Rory::Application instance' do
-      expect(Rory.application).to eq(new_app.instance)
+      expect(described_class.application).to eq(new_app.instance)
     end
   end
 
   describe '.root' do
     it 'returns root of application' do
-      expect(Rory.root).to eq(new_app.root)
+      expect(described_class.root).to eq(new_app.root)
     end
   end
-end
\ No newline at end of file
+
+  describe ".env" do
+    it "return the RORY_ENV value" do
+      expect(described_class.env).to eq "test"
+    end
+  end
+end

From edade15d76e7ce03d281188a9d28c31f3d1d175e Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Fri, 10 Jun 2016 09:37:29 -0700
Subject: [PATCH 15/18] Controller request logging

---
 lib/rory/application.rb                       |  10 +-
 lib/rory/controller/request_logger.rb         |  17 +++
 .../request_middleware.rb                     |  21 +++-
 lib/rory/dispatcher.rb                        |  15 ++-
 lib/rory/initializers.rb                      |   6 +-
 spec/fixture_app/log/test.log                 | 102 ++++++++++++++++++
 spec/lib/rory/application_spec.rb             |  13 ++-
 .../rory/controller/request_logging_spec.rb   |  17 +++
 spec/lib/rory/controller_spec.rb              |   4 +-
 spec/lib/rory/dispatcher_spec.rb              |  20 +++-
 10 files changed, 206 insertions(+), 19 deletions(-)
 create mode 100644 lib/rory/controller/request_logger.rb
 create mode 100644 spec/lib/rory/controller/request_logging_spec.rb

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index 627b3c6..949c237 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -17,7 +17,8 @@ class RootNotConfigured < StandardError; end
     include Logging
 
     attr_reader :db, :db_config
-    attr_accessor :config_path
+    attr_accessor :config_path, :controller_logger
+
     attr_writer :auto_require_paths
 
     class << self
@@ -115,12 +116,14 @@ def dispatcher
     end
 
     def request_logging_on?
-      !!Rory::Application.initializers.detect{|init| init.name == "rory.request_logging_middleware" }
+      !!(Rory::Application.initializers.detect { |init| init.name == "rory.request_logging_middleware" } ||
+        Rory::Application.initializers.detect { |init| init.name == "rory.controller_logger" })
     end
 
     def turn_off_request_logging!
       reset_stack
       Rory::Application.initializers.delete("rory.request_logging_middleware")
+      Rory::Application.initializers.delete("rory.controller_logger")
     end
 
     def parameters_to_filter
@@ -141,8 +144,7 @@ def uuid_prefix
     end
 
     def initialize_default_middleware
-      Rory::RequestMiddleware.initialize_request_id
-      Rory::RequestMiddleware.initialize_logging
+      Rory::RequestMiddleware.initialize_default_middleware
     end
 
     initialize_default_middleware
diff --git a/lib/rory/controller/request_logger.rb b/lib/rory/controller/request_logger.rb
new file mode 100644
index 0000000..a44b815
--- /dev/null
+++ b/lib/rory/controller/request_logger.rb
@@ -0,0 +1,17 @@
+module Rory
+  class Controller
+    class RequestLogger
+      def initialize(logger:)
+        @logger = logger
+      end
+
+      def call(controller:, action:, params:, path:)
+        logger.info("request -- #{{path: path, action: action, controller: controller, params: params }}")
+      end
+
+      private
+
+      attr_reader :logger
+    end
+  end
+end
diff --git a/lib/rory/default_initializers/request_middleware.rb b/lib/rory/default_initializers/request_middleware.rb
index aba3aaa..9272b65 100644
--- a/lib/rory/default_initializers/request_middleware.rb
+++ b/lib/rory/default_initializers/request_middleware.rb
@@ -1,13 +1,25 @@
 require 'rack/commonlogger'
 require 'rory/request_parameter_logger'
 require 'rory/request_id'
+require 'rory/controller/request_logger'
 
 module Rory
   module RequestMiddleware
     class << self
+      def initialize_post_body_type_parser
+        Rory::Application.initializers.add "rory.post_body_type_parser" do |app|
+          app.use_middleware Rack::PostBodyContentTypeParser
+        end
+      end
+
+      def initialize_controller_logger
+        Rory::Application.initializers.add "rory.controller_logger" do |app|
+          app.controller_logger = Controller::RequestLogger.new(logger: app.logger)
+        end
+      end
+
       def initialize_logging
         Rory::Application.initializers.add "rory.request_logging_middleware" do |app|
-          app.use_middleware Rack::PostBodyContentTypeParser
           app.use_middleware Rack::CommonLogger, app.logger
           app.use_middleware Rory::RequestParameterLogger, app.logger, :filters => app.parameters_to_filter
         end
@@ -18,6 +30,13 @@ def initialize_request_id
           app.use_middleware Rory::RequestId, :uuid_prefix => app.uuid_prefix
         end
       end
+
+      def initialize_default_middleware
+        initialize_post_body_type_parser
+        initialize_controller_logger
+        initialize_logging
+        initialize_request_id
+      end
     end
   end
 end
diff --git a/lib/rory/dispatcher.rb b/lib/rory/dispatcher.rb
index cf35b09..9b984e3 100644
--- a/lib/rory/dispatcher.rb
+++ b/lib/rory/dispatcher.rb
@@ -48,8 +48,9 @@ def route
     end
 
     def dispatch
-      if controller
-        controller.present
+      _controller = controller
+      if _controller
+        _controller.present
       else
         render_not_found
       end
@@ -69,12 +70,20 @@ def render_not_found
   private
 
     def controller
-      if klass = controller_class
+      if (klass = controller_class)
         @routing.merge!(:dispatcher => self)
+        log_request
         klass.new(request, @routing, @app)
       end
     end
 
+    def log_request
+      (@app.controller_logger || Proc.new {}).call(controller: @routing[:route].controller,
+                                                   action:     @routing[:route].action,
+                                                   params:     @request.params,
+                                                   path:       full_path)
+    end
+
     def controller_class
       if route
         controller_name = Rory::Support.camelize("#{route.controller}_controller")
diff --git a/lib/rory/initializers.rb b/lib/rory/initializers.rb
index 6afa26f..1844cc3 100644
--- a/lib/rory/initializers.rb
+++ b/lib/rory/initializers.rb
@@ -34,7 +34,7 @@ def initialize
 
     # @!macro add
     #   @param [String] name the reference name of the initializer
-    #   @yield [app] block the code to be run for the initializer
+    #   @yield [Rory::Application] block the code to be run for the initializer
 
     ##
     # @!macro add
@@ -45,13 +45,13 @@ def unshift(name, &block)
     # @!macro insert
     #   @param [String, Integer] index either an index or a string reference
     #   @param [String] name the reference name of the initializer
-    #   @yield [app] block the code to be run for the initializer
+    #   @yield [Rory::Application] block the code to be run for the initializer
     #   @raise [NoInitializerFound] when reference name is not found
 
     # @!macro insert_optional
     #   @param [String, Integer] index either an index or a string reference
     #   @param [String] name the reference name of the initializer
-    #   @yield [app] block the code to be run for the initializer
+    #   @yield [Rory::Application] block the code to be run for the initializer
     #   @return [OrAdd, #or_add] Try to insert after but if that initializer reference cannot be found add on to the end.
     #   @example
     #     @method "init_name", "new_init" do |app|
diff --git a/spec/fixture_app/log/test.log b/spec/fixture_app/log/test.log
index e69de29..2c6b40b 100644
--- a/spec/fixture_app/log/test.log
+++ b/spec/fixture_app/log/test.log
@@ -0,0 +1,102 @@
+W, [request_id= - 2016-06-09T16:57:42.307976 #62404]  WARN -- : TestRorycejho was not warmed up before the first request. Call TestRorycejho.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T16:57:42.320178 #62404]  WARN -- : TestRorypzojm was not warmed up before the first request. Call TestRorypzojm.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T16:57:42.339141 #62404]  WARN -- : TestRorysrwgz was not warmed up before the first request. Call TestRorysrwgz.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:17:11.019664 #63794]  WARN -- : TestRoryowgrt was not warmed up before the first request. Call TestRoryowgrt.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:17:11.024994 #63794]  WARN -- : TestRorynjokb was not warmed up before the first request. Call TestRorynjokb.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:17:11.042955 #63794]  WARN -- : TestRoryoxdcs was not warmed up before the first request. Call TestRoryoxdcs.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:18:16.968779 #64102]  WARN -- : TestRoryqlitf was not warmed up before the first request. Call TestRoryqlitf.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:18:16.972772 #64102]  WARN -- : TestRorydonvh was not warmed up before the first request. Call TestRorydonvh.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:18:16.990926 #64102]  WARN -- : TestRoryepsxi was not warmed up before the first request. Call TestRoryepsxi.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:18:58.531424 #64190]  WARN -- : TestRorybldwm was not warmed up before the first request. Call TestRorybldwm.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:18:58.554186 #64190]  WARN -- : TestRorywcfjg was not warmed up before the first request. Call TestRorywcfjg.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:18:58.701764 #64190]  WARN -- : TestRorylbmnx was not warmed up before the first request. Call TestRorylbmnx.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:13.755412 #64477]  WARN -- : TestRoryjhbym was not warmed up before the first request. Call TestRoryjhbym.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:13.779405 #64477]  WARN -- : TestRoryspuhd was not warmed up before the first request. Call TestRoryspuhd.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:13.935532 #64477]  WARN -- : TestRorynegua was not warmed up before the first request. Call TestRorynegua.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:36.667247 #64533]  WARN -- : TestRoryqihzg was not warmed up before the first request. Call TestRoryqihzg.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:36.694284 #64533]  WARN -- : TestRoryaplix was not warmed up before the first request. Call TestRoryaplix.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:36.824646 #64533]  WARN -- : TestRoryzhmte was not warmed up before the first request. Call TestRoryzhmte.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:54.757067 #64586]  WARN -- : TestRorycgojp was not warmed up before the first request. Call TestRorycgojp.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:54.790974 #64586]  WARN -- : TestRorybygru was not warmed up before the first request. Call TestRorybygru.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-09T17:23:55.044012 #64586]  WARN -- : TestRoryvmqsa was not warmed up before the first request. Call TestRoryvmqsa.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:24:59.497674 #68698]  WARN -- : TestRoryytcfo was not warmed up before the first request. Call TestRoryytcfo.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:24:59.523504 #68698]  WARN -- : TestRorytxykr was not warmed up before the first request. Call TestRorytxykr.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:24:59.883031 #68698]  WARN -- : TestRorygfouk was not warmed up before the first request. Call TestRorygfouk.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:26:17.274638 #68792]  WARN -- : TestRorytrzop was not warmed up before the first request. Call TestRorytrzop.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:26:17.350240 #68792]  WARN -- : TestRorydnqve was not warmed up before the first request. Call TestRorydnqve.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:26:17.649060 #68792]  WARN -- : TestRoryosvgn was not warmed up before the first request. Call TestRoryosvgn.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:26:35.928147 #68848]  WARN -- : TestRorytfdwe was not warmed up before the first request. Call TestRorytfdwe.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:26:35.988455 #68848]  WARN -- : TestRoryjfrmu was not warmed up before the first request. Call TestRoryjfrmu.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:26:36.182136 #68848]  WARN -- : TestRoryalecu was not warmed up before the first request. Call TestRoryalecu.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:27:20.909318 #68930]  WARN -- : TestRoryvikma was not warmed up before the first request. Call TestRoryvikma.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:27:20.933846 #68930]  WARN -- : TestRoryjylcw was not warmed up before the first request. Call TestRoryjylcw.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:27:21.096440 #68930]  WARN -- : TestRoryegfcv was not warmed up before the first request. Call TestRoryegfcv.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:29:57.632378 #69045]  WARN -- : TestRoryptexb was not warmed up before the first request. Call TestRoryptexb.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:29:57.655156 #69045]  WARN -- : TestRorypxlir was not warmed up before the first request. Call TestRorypxlir.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:29:57.778940 #69045]  WARN -- : TestRorydftzl was not warmed up before the first request. Call TestRorydftzl.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:33:29.160004 #69294]  WARN -- : TestRorybehsf was not warmed up before the first request. Call TestRorybehsf.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:33:29.235124 #69294]  WARN -- : TestRorynpyfz was not warmed up before the first request. Call TestRorynpyfz.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:33:29.280608 #69294]  WARN -- : TestRorysctnl was not warmed up before the first request. Call TestRorysctnl.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:33:38.014229 #69349]  WARN -- : TestRoryhxbri was not warmed up before the first request. Call TestRoryhxbri.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:33:38.059728 #69349]  WARN -- : TestRorywaibk was not warmed up before the first request. Call TestRorywaibk.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:33:38.350604 #69349]  WARN -- : TestRorykgfqj was not warmed up before the first request. Call TestRorykgfqj.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:36:37.901109 #69693]  WARN -- : TestRorydfmce was not warmed up before the first request. Call TestRorydfmce.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:36:37.931670 #69693]  WARN -- : TestRorydsryj was not warmed up before the first request. Call TestRorydsryj.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T09:36:38.136386 #69693]  WARN -- : TestRoryzljci was not warmed up before the first request. Call TestRoryzljci.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:13:36.247327 #72349]  WARN -- : TestRoryfelin was not warmed up before the first request. Call TestRoryfelin.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:13:36.256924 #72349]  WARN -- : TestRoryarvhy was not warmed up before the first request. Call TestRoryarvhy.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:13:36.350935 #72349]  WARN -- : TestRorygqrnh was not warmed up before the first request. Call TestRorygqrnh.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:14:32.649854 #72449]  WARN -- : TestRoryekizj was not warmed up before the first request. Call TestRoryekizj.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:14:32.676579 #72449]  WARN -- : TestRoryhvgfm was not warmed up before the first request. Call TestRoryhvgfm.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:14:32.791421 #72449]  WARN -- : TestRoryecjad was not warmed up before the first request. Call TestRoryecjad.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:15:01.423711 #72518]  WARN -- : TestRorypzeah was not warmed up before the first request. Call TestRorypzeah.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:15:01.453386 #72518]  WARN -- : TestRoryyhxas was not warmed up before the first request. Call TestRoryyhxas.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:15:01.603670 #72518]  WARN -- : TestRorysouit was not warmed up before the first request. Call TestRorysouit.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:15:49.929187 #72617]  WARN -- : TestRoryljtbw was not warmed up before the first request. Call TestRoryljtbw.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:15:49.967540 #72617]  WARN -- : TestRorygymnp was not warmed up before the first request. Call TestRorygymnp.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:15:50.178996 #72617]  WARN -- : TestRoryuynls was not warmed up before the first request. Call TestRoryuynls.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:16:10.821866 #72685]  WARN -- : TestRoryobqfj was not warmed up before the first request. Call TestRoryobqfj.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:16:10.847768 #72685]  WARN -- : TestRoryicvdp was not warmed up before the first request. Call TestRoryicvdp.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:16:11.050178 #72685]  WARN -- : TestRorykjyql was not warmed up before the first request. Call TestRorykjyql.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:20:39.750349 #73248]  WARN -- : TestRorykmrhf was not warmed up before the first request. Call TestRorykmrhf.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:20:39.768736 #73248]  WARN -- : TestRoryrolkw was not warmed up before the first request. Call TestRoryrolkw.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:20:39.949377 #73248]  WARN -- : TestRoryyolns was not warmed up before the first request. Call TestRoryyolns.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:22:06.211585 #73394]  WARN -- : TestRorybzmck was not warmed up before the first request. Call TestRorybzmck.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:22:06.228349 #73394]  WARN -- : TestRorywtpna was not warmed up before the first request. Call TestRorywtpna.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:22:06.353334 #73394]  WARN -- : TestRorymebrn was not warmed up before the first request. Call TestRorymebrn.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:22:36.806177 #73464]  WARN -- : TestRoryelgpj was not warmed up before the first request. Call TestRoryelgpj.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:22:36.831419 #73464]  WARN -- : TestRoryobumw was not warmed up before the first request. Call TestRoryobumw.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:22:36.992826 #73464]  WARN -- : TestRorykytls was not warmed up before the first request. Call TestRorykytls.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:23:53.010783 #73608]  WARN -- : TestRoryukhyz was not warmed up before the first request. Call TestRoryukhyz.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:23:53.025599 #73608]  WARN -- : TestRoryfzsmw was not warmed up before the first request. Call TestRoryfzsmw.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:23:53.206299 #73608]  WARN -- : TestRorycnygi was not warmed up before the first request. Call TestRorycnygi.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:24:23.549260 #73669]  WARN -- : TestRoryadqrm was not warmed up before the first request. Call TestRoryadqrm.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:24:23.616268 #73669]  WARN -- : TestRorytbwsd was not warmed up before the first request. Call TestRorytbwsd.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:24:23.835983 #73669]  WARN -- : TestRoryfixkh was not warmed up before the first request. Call TestRoryfixkh.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:45:20.289642 #75961]  WARN -- : TestRoryjmtse was not warmed up before the first request. Call TestRoryjmtse.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:45:20.306112 #75961]  WARN -- : TestRoryjwcpa was not warmed up before the first request. Call TestRoryjwcpa.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:45:20.438262 #75961]  WARN -- : TestRorykqfyb was not warmed up before the first request. Call TestRorykqfyb.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:45:42.947050 #76023]  WARN -- : TestRorydkjeg was not warmed up before the first request. Call TestRorydkjeg.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:45:42.968791 #76023]  WARN -- : TestRoryyepla was not warmed up before the first request. Call TestRoryyepla.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:45:43.089187 #76023]  WARN -- : TestRorycorgn was not warmed up before the first request. Call TestRorycorgn.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:46:32.705463 #76119]  WARN -- : TestRoryfagxc was not warmed up before the first request. Call TestRoryfagxc.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:46:32.720378 #76119]  WARN -- : TestRoryvhtjy was not warmed up before the first request. Call TestRoryvhtjy.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:46:32.850878 #76119]  WARN -- : TestRoryvxqzm was not warmed up before the first request. Call TestRoryvxqzm.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:46:49.699283 #76185]  WARN -- : TestRorynuvzi was not warmed up before the first request. Call TestRorynuvzi.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:46:49.728033 #76185]  WARN -- : TestRoryhkyme was not warmed up before the first request. Call TestRoryhkyme.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:46:49.863534 #76185]  WARN -- : TestRoryevryl was not warmed up before the first request. Call TestRoryevryl.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:49:38.108885 #76669]  WARN -- : TestRoryyroug was not warmed up before the first request. Call TestRoryyroug.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:49:38.118455 #76669]  WARN -- : TestRorygzeyl was not warmed up before the first request. Call TestRorygzeyl.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T10:49:38.206871 #76669]  WARN -- : TestRorybseja was not warmed up before the first request. Call TestRorybseja.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T11:16:13.035919 #77858]  WARN -- : TestRoryrtgdw was not warmed up before the first request. Call TestRoryrtgdw.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T11:16:13.060436 #77858]  WARN -- : TestRoryqives was not warmed up before the first request. Call TestRoryqives.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T11:16:13.194500 #77858]  WARN -- : TestRoryegphq was not warmed up before the first request. Call TestRoryegphq.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:00:09.960079 #3740]  WARN -- : TestRoryresxu was not warmed up before the first request. Call TestRoryresxu.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:00:09.975752 #3740]  WARN -- : TestRorybdtzv was not warmed up before the first request. Call TestRorybdtzv.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:00:10.089236 #3740]  WARN -- : TestRorywljvz was not warmed up before the first request. Call TestRorywljvz.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:01:06.487218 #3819]  WARN -- : TestRoryydbia was not warmed up before the first request. Call TestRoryydbia.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:01:06.505022 #3819]  WARN -- : TestRoryqzhrk was not warmed up before the first request. Call TestRoryqzhrk.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:01:06.696064 #3819]  WARN -- : TestRorytbhzm was not warmed up before the first request. Call TestRorytbhzm.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:01:28.187363 #3878]  WARN -- : TestRoryxtrwb was not warmed up before the first request. Call TestRoryxtrwb.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:01:28.217968 #3878]  WARN -- : TestRoryzwdqx was not warmed up before the first request. Call TestRoryzwdqx.warmup on boot to ensure a quick first response.
+W, [request_id= - 2016-06-10T14:01:28.356294 #3878]  WARN -- : TestRoryzjueb was not warmed up before the first request. Call TestRoryzjueb.warmup on boot to ensure a quick first response.
diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index cccab14..d55a131 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -194,12 +194,15 @@ class RootlessApp < Rory::Application; end
       expect(subject.instance).to receive(:use_middleware).with(Rack::PostBodyContentTypeParser)
       expect(subject.instance).to receive(:use_middleware).with(Rack::CommonLogger, :the_logger)
       expect(subject.instance).to receive(:use_middleware).with(Rory::RequestParameterLogger, :the_logger, :filters => [:horses])
+      expect(subject.instance).to receive(:controller_logger=) do |logger|
+        expect(logger).to be_an_instance_of(Rory::Controller::RequestLogger)
+      end
       subject.run_initializers
     end
 
     it "does not add middleware when request logging is off" do
       subject.instance.turn_off_request_logging!
-      expect(Rory::Application.initializers.map(&:name)).to eq ["rory.request_id_middleware"]
+      expect(Rory::Application.initializers.map(&:name)).to eq ["rory.post_body_type_parser", "rory.request_id_middleware"]
     end
   end
 
@@ -366,11 +369,11 @@ def app
           app.middleware.insert_before Rory::RequestId, DummyMiddleware, :puppy
         end
         subject.run_initializers
-        expect(subject.middleware.map(&:klass)).to eq [DummyMiddleware,
-                                                       Rory::RequestId,
-                                                       Rack::PostBodyContentTypeParser,
+        expect(subject.middleware.map(&:klass)).to eq [Rack::PostBodyContentTypeParser,
                                                        Rack::CommonLogger,
-                                                       Rory::RequestParameterLogger]
+                                                       Rory::RequestParameterLogger,
+                                                       DummyMiddleware,
+                                                       Rory::RequestId]
       end
     end
   end
diff --git a/spec/lib/rory/controller/request_logging_spec.rb b/spec/lib/rory/controller/request_logging_spec.rb
new file mode 100644
index 0000000..0c28ff6
--- /dev/null
+++ b/spec/lib/rory/controller/request_logging_spec.rb
@@ -0,0 +1,17 @@
+require "rory/controller/request_logger"
+
+RSpec.describe Rory::Controller::RequestLogger do
+  describe "#call" do
+    let(:log) { StringIO.new }
+    let(:logger) { Logger.new(log) }
+
+    it "log to info" do
+      described_class.new(logger: logger).call(action:     "show",
+                                               controller: "programs",
+                                               params:     { "program_id" => 3 },
+                                               path:       "programs/13")
+
+      expect(log.tap(&:rewind).read).to match /INFO -- : request -- {:path=>"programs\/13", :action=>"show", :controller=>"programs", :params=>{"program_id"=>3}}/
+    end
+  end
+end
diff --git a/spec/lib/rory/controller_spec.rb b/spec/lib/rory/controller_spec.rb
index 2cb7c53..0d6f75e 100644
--- a/spec/lib/rory/controller_spec.rb
+++ b/spec/lib/rory/controller_spec.rb
@@ -1,9 +1,9 @@
 describe Rory::Controller do
   subject { Rory::Controller.new(@request, @routing) }
 
-  before :each do
+  before do
     @routing = {
-      :route => Rory::Route.new('', :to => 'test#letsgo')
+      :route => Rory::Route.new('the path', :to => 'test#letsgo')
     }
 
     @request = double('Rack::Request', {
diff --git a/spec/lib/rory/dispatcher_spec.rb b/spec/lib/rory/dispatcher_spec.rb
index 0de519a..a82ea3b 100644
--- a/spec/lib/rory/dispatcher_spec.rb
+++ b/spec/lib/rory/dispatcher_spec.rb
@@ -1,5 +1,6 @@
 describe Rory::Dispatcher do
-  subject { Rory::Dispatcher.new(request, Fixture::Application) }
+  subject { Rory::Dispatcher.new(request, app) }
+  let(:app) { Fixture::Application }
   let(:request) { {} }
 
   describe "#extension" do
@@ -101,6 +102,23 @@
         :in_scoped_controller => true # see Goose::Wombat::RabbitsController in /spec/fixture_app
       })
     end
+
+    context "with params" do
+      let(:params) { { from_query: :value } }
+
+      it "logs the request" do
+        allow(request).to receive_messages(:path_info => "/rabbits/foo", :request_method => 'GET', :params => {}, params: params)
+        logger_called_with = :not_called
+        allow(app).to receive(:controller_logger).and_return(Proc.new { |**args| logger_called_with = args })
+        route = Rory::Route.new('rabbits', :to => 'rabbits#index', :module => 'goose/wombat')
+        allow(subject).to receive(:get_route).and_return(route)
+        subject.dispatch
+        expect(logger_called_with).to eq(:action     => "index",
+                                         :controller => "rabbits",
+                                         :params     => { :from_query => :value },
+                                         :path       => "rabbits/foo")
+      end
+    end
   end
 
   describe "#route" do

From 02656484c202a849609265823cadac853748435c Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Fri, 10 Jun 2016 13:51:40 -0700
Subject: [PATCH 16/18] Update thread-inheritable_attributes

---
 rory.gemspec | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/rory.gemspec b/rory.gemspec
index b3ea9f6..0c4ed41 100644
--- a/rory.gemspec
+++ b/rory.gemspec
@@ -32,7 +32,7 @@ EOF
   s.add_runtime_dependency 'rack-contrib', '~> 1.2'
   s.add_runtime_dependency 'sequel', '~> 4.0'
   s.add_runtime_dependency 'thin', '~> 1.0'
-  s.add_runtime_dependency 'thread-inheritable_attributes', '~> 0.1'
+  s.add_runtime_dependency 'thread-inheritable_attributes', '~> 0.2'
 
   s.add_development_dependency 'rake', '~> 10.4'
   s.add_development_dependency 'rspec', '~> 3'

From b9c1ae248d3baf6c0befeb1caf21c8ffaa5cdcba Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Fri, 10 Jun 2016 14:44:02 -0700
Subject: [PATCH 17/18] Fix flaky tests

---
 lib/rory/application.rb           | 1 +
 spec/lib/rory/application_spec.rb | 5 ++++-
 2 files changed, 5 insertions(+), 1 deletion(-)

diff --git a/lib/rory/application.rb b/lib/rory/application.rb
index 949c237..b182ac4 100644
--- a/lib/rory/application.rb
+++ b/lib/rory/application.rb
@@ -136,6 +136,7 @@ def filter_parameters(*params)
     end
 
     def reset_stack
+      self.class.warmed_up = nil
       @stack = nil
     end
 
diff --git a/spec/lib/rory/application_spec.rb b/spec/lib/rory/application_spec.rb
index d55a131..c3d5363 100644
--- a/spec/lib/rory/application_spec.rb
+++ b/spec/lib/rory/application_spec.rb
@@ -299,6 +299,10 @@ def app
       Fixture::Application
     end
 
+    before do
+      Fixture::Application.reset_stack
+    end
+
     context "when app is warmed up" do
       it "does not log a warning" do
         Fixture::Application.warmup
@@ -309,7 +313,6 @@ def app
 
     context "when app not is warmed up" do
       it "does log a warning" do
-        Fixture::Application.warmed_up = nil
         warm_msg = "Fixture::Application was not warmed up before the first request. Call Fixture::Application.warmup on boot to ensure a quick first response."
         expect(Fixture::Application.logger).to receive(:warn).with(warm_msg)
         get 'for_reals/switching'

From c47ea5bf6ccb9fb9bc8834662297b295bc60a2d2 Mon Sep 17 00:00:00 2001
From: Dustin Zeisler <dustin@zeisler.net>
Date: Mon, 13 Jun 2016 15:18:29 -0700
Subject: [PATCH 18/18] Minor refactorings

---
 lib/rory/dispatcher.rb | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/lib/rory/dispatcher.rb b/lib/rory/dispatcher.rb
index 9b984e3..407566b 100644
--- a/lib/rory/dispatcher.rb
+++ b/lib/rory/dispatcher.rb
@@ -17,8 +17,8 @@ def self.rack_app(app)
 
     def override_method
       requested_override = request.params['_method']
-      return nil unless requested_override
-      if ['put', 'patch', 'delete'].include?(requested_override.downcase)
+      return unless requested_override
+      if %w(put patch delete).include?(requested_override.downcase)
         requested_override.downcase
       end
     end
@@ -60,11 +60,11 @@ def redirect(path = '/')
       unless path =~ /\:\/\//
         path = "#{@request.scheme}://#{@request.host_with_port}#{path}"
       end
-      return [ 302, {'Content-type' => 'text/html', 'Location'=> path }, ['Redirecting...'] ]
+      [ 302, {'Content-type' => 'text/html', 'Location'=> path }, ['Redirecting...'] ]
     end
 
     def render_not_found
-      return [ 404, {'Content-type' => 'text/html' }, ['Four, oh, four.'] ]
+      [ 404, {'Content-type' => 'text/html' }, ['Four, oh, four.'] ]
     end
 
   private