lib/clogger/pure.rb

   1 # -*- encoding: binary -*-
   2 # :stopdoc:
   3
   4 # Not at all optimized for performance, this was written based on
   5 # the original C extension code so it's not very Ruby-ish...
   6 class Clogger
   7
   8   attr_accessor :env, :status, :headers, :body
   9   attr_writer :body_bytes_sent
  10
  11   def initialize(app, opts = {})
  12     # trigger autoload to avoid thread-safety issues later on
  13     Rack::Utils::HeaderHash.new({})
  14
  15     @app = app
  16     @logger = opts[:logger]
  17     (@logger.sync = true) rescue nil
  18     @fmt_ops = compile_format(opts[:format] || Format::Common, opts)
  19     @wrap_body = need_wrap_body?(@fmt_ops)
  20     @reentrant = opts[:reentrant]
  21     @need_resp = need_response_headers?(@fmt_ops)
  22     @body_bytes_sent = 0
  23   end
  24
  25   def call(env)
  26     @start = Time.now
  27     resp = @app.call(env)
  28     unless resp.instance_of?(Array) && resp.size == 3
  29       log(env, 500, {})
  30       raise TypeError, "app response not a 3 element Array: #{resp.inspect}"
  31     end
  32     status, headers, body = resp
  33     headers = Rack::Utils::HeaderHash.new(headers) if @need_resp
  34     if @wrap_body
  35       @reentrant = env['rack.multithread'] if @reentrant.nil?
  36       wbody = @reentrant ? self.dup : self
  37       wbody.env = env
  38       wbody.status = status
  39       wbody.headers = headers
  40       wbody.body = body
  41       wbody = Clogger::ToPath.new(wbody) if body.respond_to?(:to_path)
  42       return [ status, headers, wbody ]
  43     end
  44     log(env, status, headers)
  45     [ status, headers, body ]
  46   end
  47
  48   def each
  49     @body_bytes_sent = 0
  50     @body.each do |part|
  51       @body_bytes_sent += Rack::Utils.bytesize(part)
  52       yield part
  53     end
  54     self
  55   end
  56
  57   def close
  58     @body.close if @body.respond_to?(:close)
  59     ensure
  60       log(@env, @status, @headers)
  61   end
  62
  63   def reentrant?
  64     @reentrant
  65   end
  66
  67   def wrap_body?
  68     @wrap_body
  69   end
  70
  71   def fileno
  72     @logger.fileno rescue nil
  73   end
  74
  75 private
  76
  77   def byte_xs(s)
  78     s = s.dup
  79     s.force_encoding(Encoding::BINARY) if defined?(Encoding::BINARY)
  80     s.gsub!(/(['"\x00-\x1f])/) { |x| "\\x#{$1.unpack('H2').first.upcase}" }
  81     s
  82   end
  83
  84   SPECIAL_RMAP = SPECIAL_VARS.inject([]) { |ary, (k,v)| ary[v] = k; ary }
  85
  86   def request_uri(env)
  87     ru = env['REQUEST_URI'] and return byte_xs(ru)
  88     qs = env['QUERY_STRING']
  89     qs.empty? or qs = "?#{byte_xs(qs)}"
  90     "#{byte_xs(env['PATH_INFO'])}#{qs}"
  91   end
  92
  93   def special_var(special_nr, env, status, headers)
  94     case SPECIAL_RMAP[special_nr]
  95     when :body_bytes_sent
  96       @body_bytes_sent.to_s
  97     when :status
  98       status = status.to_i
  99       status >= 100 && status <= 999 ? ('%03d' % status) : '-'
 100     when :request
 101       version = env['HTTP_VERSION'] and version = " #{byte_xs(version)}"
 102       qs = env['QUERY_STRING']
 103       qs.empty? or qs = "?#{byte_xs(qs)}"
 104       "#{env['REQUEST_METHOD']} " \
 105         "#{request_uri(env)}#{version}"
 106     when :request_uri
 107       request_uri(env)
 108     when :request_length
 109       env['rack.input'].size.to_s
 110     when :response_length
 111       @body_bytes_sent == 0 ? '-' : @body_bytes_sent.to_s
 112     when :ip
 113       xff = env['HTTP_X_FORWARDED_FOR'] and return byte_xs(xff)
 114       env['REMOTE_ADDR'] || '-'
 115     when :pid
 116       $$.to_s
 117     else
 118       raise "EDOOFUS #{special_nr}"
 119     end
 120   end
 121
 122   def time_format(sec, usec, format, div)
 123     format % [ sec, usec / div ]
 124   end
 125
 126   def log(env, status, headers)
 127     (@logger || env['rack.errors']) << @fmt_ops.map { |op|
 128       case op[0]
 129       when OP_LITERAL; op[1]
 130       when OP_REQUEST; byte_xs(env[op[1]] || "-")
 131       when OP_RESPONSE; byte_xs(headers[op[1]] || "-")
 132       when OP_SPECIAL; special_var(op[1], env, status, headers)
 133       when OP_EVAL; eval(op[1]).to_s rescue "-"
 134       when OP_TIME_LOCAL; Time.now.strftime(op[1])
 135       when OP_TIME_UTC; Time.now.utc.strftime(op[1])
 136       when OP_REQUEST_TIME
 137         t = Time.now - @start
 138         time_format(t.to_i, (t - t.to_i) * 1000000, op[1], op[2])
 139       when OP_TIME
 140         t = Time.now
 141         time_format(t.sec, t.usec, op[1], op[2])
 142       when OP_COOKIE
 143         (env['rack.request.cookie_hash'][op[1]] rescue "-") || "-"
 144       else
 145         raise "EDOOFUS #{op.inspect}"
 146       end
 147     }.join('')
 148   end
 149
 150   class ToPath
 151     def to_path
 152       rv = (body = clogger.body).to_path
 153
 154       # try to avoid unnecessary path lookups with to_io.stat instead of
 155       # File.stat
 156       clogger.body_bytes_sent =
 157         (body.respond_to?(:to_io) ? body.to_io.stat : File.stat(rv)).size
 158       rv
 159     end
 160   end
 161
 162 end