Override request started log line

lib/log_overrider.rb

@@ -31,3 +31,16 @@ class ActionController::LogSubscriber
     Rails.logger.info(log_string)
   end
 end
+
+module Rails
+  module Rack
+    class Logger
+      def before_dispatch(env)
+        request = ActionDispatch::Request.new(env)
+        path = request.fullpath
+
+        Rails.logger.info("event=request_started verb=#{env["REQUEST_METHOD"]} path=#{path} ip=#{request.ip} ")
+      end
+    end
+  end
+end

spec/controllers/home_controller_spec.rb

@@ -33,19 +33,18 @@ describe HomeController do
     end
     context 'cross-stage' do
       before do
+        pending "This might require patching Rails"
         get :show
         @lines = Rails.logger.infos
-        @id = @lines.first.match(/r_id=(\w+)\s/).captures.first
+        @id = @lines[1].match(/r_id=(\w+)\s/).captures.first
       end
       it 'logs a unified id in a request' do
-        pending "This might require patching Rails"
         id = @lines.first.match(/r_id=(\w+)\s/).captures.first
         @lines.each do |line| 
           line.match(/r_id=(\w+)\s/).captures.first.should == @id
         end
       end
       it 'logs different ids in different requests' do
-        pending "This might require patching Rails"
         get :show
         old_lines = Rails.logger.infos.select do |line| 
           line.match(/r_id=(\w+)\s/).captures.first == @id
@@ -53,6 +52,16 @@ describe HomeController do
         old_lines.length.should == Rails.logger.infos.length/2
       end
     end
+    context 'starting' do
+      before do
+        pending "This code is never reached in tests, but it seems to work in actual requests"
+        get :show
+        @line = Rails.logger.infos.first
+      end
+      it 'logs it' do
+        @line.should match /event=request_started/
+      end
+    end
     context 'rendering' do
       before do
         get :show, :lasers => 'green'