Rails2.3からwebサーバとのmiddlewareとしてRackが使われていますが、Rackでの処理時間はRailsのログには記録されません。

class RealLog
  def initialize(app)
    @app = app
    @logger = Logger.new("realtime.log")
  end

  def call(env)
    start_time = Time.now
    ret = @app.call(env)
    @logger.info "[#{Time.now - start_time}] #{env["PATH_INFO"] || env["REQUEST_URI"]}"
    ret
  end
end

こんな計測ツールをRackの一番上に積んでみます。 config/environment.rb

ActionController::Dispatcher.middleware.insert 0, RealLog

適当なページにアクセスして、Railsログの時間とrealtime.logに記録された時間を比べると、500msくらいの差がありました。 Railsのログだけみて、レスポンスが早くなったと考えるのは早計のようです。

もともとRailsのログはアクションの処理時間を計測したものなので、それより上の話はあまり関係ないといえばないのですが。