Work in tandem with ContentLength. Avoid dup per request.

Signed-off-by: Joshua Peek <josh@joshpeek.com>

2 files changed, 61 insertions, 53 deletions

diff --git a/lib/rack/commonlogger.rb b/lib/rack/commonlogger.rb
index 5e68ac62..880f0fbf 100644
--- a/lib/rack/commonlogger.rb
+++ b/lib/rack/commonlogger.rb
@@ -2,60 +2,51 @@ module Rack
   # Rack::CommonLogger forwards every request to an +app+ given, and
   # logs a line in the Apache common log format to the +logger+, or
   # rack.errors by default.
-
   class CommonLogger
+    # Common Log Format: http://httpd.apache.org/docs/1.3/logs.html#common
+    # lilith.local - - [07/Aug/2006 23:58:02] "GET / HTTP/1.1" 500 -
+    #             %{%s - %s [%s] "%s %s%s %s" %d %s\n} %
+    FORMAT = %{%s - %s [%s] "%s %s%s %s" %d %s %0.4f\n}
+
     def initialize(app, logger=nil)
       @app = app
       @logger = logger
     end
 
     def call(env)
-      dup._call(env)
-    end
-
-    def _call(env)
-      @env = env
-      @logger ||= self
-      @time = Time.now
-      @status, @header, @body = @app.call(env)
-      [@status, @header, self]
+      began_at = Time.now
+      status, header, body = @app.call(env)
+      log(env, status, header, began_at)
+      [status, header, body]
     end
 
-    def close
-      @body.close if @body.respond_to? :close
+    private
+
+    def log(env, status, header, began_at)
+      now = Time.now
+      length = extract_content_length(header)
+
+      logger = @logger || env['rack.errors']
+      logger.write FORMAT % [
+        env['HTTP_X_FORWARDED_FOR'] || env["REMOTE_ADDR"] || "-",
+        env["REMOTE_USER"] || "-",
+        now.strftime("%d/%b/%Y %H:%M:%S"),
+        env["REQUEST_METHOD"],
+        env["PATH_INFO"],
+        env["QUERY_STRING"].empty? ? "" : "?"+env["QUERY_STRING"],
+        env["HTTP_VERSION"],
+        status.to_s[0..3],
+        length,
+        now - began_at ]
     end
 
-    # By default, log to rack.errors.
-    def <<(str)
-      @env["rack.errors"].write(str)
-      @env["rack.errors"].flush
-    end
-
-    def each
-      length = 0
-      @body.each { |part|
-        length += part.size
-        yield part
-      }
-
-      @now = Time.now
-
-      # Common Log Format: http://httpd.apache.org/docs/1.3/logs.html#common
-      # lilith.local - - [07/Aug/2006 23:58:02] "GET / HTTP/1.1" 500 -
-      #             %{%s - %s [%s] "%s %s%s %s" %d %s\n} %
-      @logger << %{%s - %s [%s] "%s %s%s %s" %d %s %0.4f\n} %
-        [
-         @env['HTTP_X_FORWARDED_FOR'] || @env["REMOTE_ADDR"] || "-",
-         @env["REMOTE_USER"] || "-",
-         @now.strftime("%d/%b/%Y %H:%M:%S"),
-         @env["REQUEST_METHOD"],
-         @env["PATH_INFO"],
-         @env["QUERY_STRING"].empty? ? "" : "?"+@env["QUERY_STRING"],
-         @env["HTTP_VERSION"],
-         @status.to_s[0..3],
-         (length.zero? ? "-" : length.to_s),
-         @now - @time
-        ]
+    def extract_content_length(headers)
+      headers.each do |key, value|
+        if key.downcase == 'content-length'
+          return value.to_s == '0' ? '-' : value
+        end
+      end
+      '-'
     end
   end
 end
diff --git a/test/spec_rack_commonlogger.rb b/test/spec_rack_commonlogger.rb
index ba03b78a..9d212d5e 100644
--- a/test/spec_rack_commonlogger.rb
+++ b/test/spec_rack_commonlogger.rb
@@ -8,25 +8,42 @@ require 'rack/mock'
 context "Rack::CommonLogger" do
   app = lambda { |env|
     [200,
+     {"Content-Type" => "text/html", "Content-Length" => length.to_s},
+     [obj]]}
+  app_without_length = lambda { |env|
+    [200,
      {"Content-Type" => "text/html"},
-     ["foo"]]}
+     []]}
+  app_with_zero_length = lambda { |env|
+    [200,
+     {"Content-Type" => "text/html", "Content-Length" => "0"},
+     []]}
 
   specify "should log to rack.errors by default" do
-    log = StringIO.new
     res = Rack::MockRequest.new(Rack::CommonLogger.new(app)).get("/")
 
     res.errors.should.not.be.empty
-    res.errors.should =~ /GET /
-    res.errors.should =~ / 200 / # status
-    res.errors.should =~ / 3 /   # length
+    res.errors.should =~ /"GET \/ " 200 #{length} /
   end
 
-  specify "should log to anything with <<" do
-    log = ""
+  specify "should log to anything with +write+" do
+    log = StringIO.new
     res = Rack::MockRequest.new(Rack::CommonLogger.new(app, log)).get("/")
 
-    log.should =~ /GET /
-    log.should =~ / 200 / # status
-    log.should =~ / 3 / # length
+    log.string.should =~ /"GET \/ " 200 #{length} /
+  end
+
+  specify "should log - content length if header is missing" do
+    res = Rack::MockRequest.new(Rack::CommonLogger.new(app_without_length)).get("/")
+
+    res.errors.should.not.be.empty
+    res.errors.should =~ /"GET \/ " 200 - /
+  end
+
+  specify "should log - content length if header is zero" do
+    res = Rack::MockRequest.new(Rack::CommonLogger.new(app_with_zero_length)).get("/")
+
+    res.errors.should.not.be.empty
+    res.errors.should =~ /"GET \/ " 200 - /
   end
 end