* [PATCH 1/2] pure: fix reentrancy of request_time
2015-02-27 22:45 [PATCH 0/2] fixes for pure-Ruby users Eric Wong
@ 2015-02-27 22:45 ` Eric Wong
2015-02-27 22:45 ` [PATCH 2/2] pure: use monotonic clock if possible Eric Wong
1 sibling, 0 replies; 3+ messages in thread
From: Eric Wong @ 2015-02-27 22:45 UTC (permalink / raw)
To: clogger-public
For users unable to compile the C extension, multithreaded usage
of clogger could return invalid request time measurements.
This does not affect users of the C extension.
---
lib/clogger/pure.rb | 17 +++++++++--------
1 file changed, 9 insertions(+), 8 deletions(-)
diff --git a/lib/clogger/pure.rb b/lib/clogger/pure.rb
index bb3fc16..9efb00c 100644
--- a/lib/clogger/pure.rb
+++ b/lib/clogger/pure.rb
@@ -6,7 +6,7 @@
class Clogger
attr_accessor :env, :status, :headers, :body
- attr_writer :body_bytes_sent
+ attr_writer :body_bytes_sent, :start
def initialize(app, opts = {})
# trigger autoload to avoid thread-safety issues later on
@@ -28,10 +28,10 @@ def initialize(app, opts = {})
end
def call(env)
- @start = Time.now
+ start = Time.now
resp = @app.call(env)
unless resp.instance_of?(Array) && resp.size == 3
- log(env, 500, {})
+ log(env, 500, {}, start)
raise TypeError, "app response not a 3 element Array: #{resp.inspect}"
end
status, headers, body = resp
@@ -39,13 +39,14 @@ def call(env)
if @wrap_body
@reentrant = env['rack.multithread'] if @reentrant.nil?
wbody = @reentrant ? self.dup : self
+ wbody.start = start
wbody.env = env
wbody.status = status
wbody.headers = headers
wbody.body = body
return [ status, headers, wbody ]
end
- log(env, status, headers)
+ log(env, status, headers, start)
[ status, headers, body ]
end
@@ -60,8 +61,8 @@ def each
def close
@body.close if @body.respond_to?(:close)
- ensure
- log(@env, @status, @headers)
+ ensure
+ log(@env, @status, @headers)
end
def reentrant?
@@ -153,7 +154,7 @@ def time_format(sec, usec, format, div)
format % [ sec, usec / div ]
end
- def log(env, status, headers)
+ def log(env, status, headers, start = @start)
str = @fmt_ops.map { |op|
case op[0]
when OP_LITERAL; op[1]
@@ -164,7 +165,7 @@ def log(env, status, headers)
when OP_TIME_LOCAL; Time.now.strftime(op[1])
when OP_TIME_UTC; Time.now.utc.strftime(op[1])
when OP_REQUEST_TIME
- t = Time.now - @start
+ t = Time.now - start
time_format(t.to_i, (t - t.to_i) * 1000000, op[1], op[2])
when OP_TIME
t = Time.now
--
EW
^ permalink raw reply related [flat|nested] 3+ messages in thread
* [PATCH 2/2] pure: use monotonic clock if possible
2015-02-27 22:45 [PATCH 0/2] fixes for pure-Ruby users Eric Wong
2015-02-27 22:45 ` [PATCH 1/2] pure: fix reentrancy of request_time Eric Wong
@ 2015-02-27 22:45 ` Eric Wong
1 sibling, 0 replies; 3+ messages in thread
From: Eric Wong @ 2015-02-27 22:45 UTC (permalink / raw)
To: clogger-public
Ruby 2.1.0 and later exposes Process.clock_gettime, resulting
in less garbage and access to the monotonic clock if it is
available. Try to use it to achieve feature parity with the
C extension (which has always used the monotonic clock if possible).
---
lib/clogger/pure.rb | 14 ++++++++++++--
1 file changed, 12 insertions(+), 2 deletions(-)
diff --git a/lib/clogger/pure.rb b/lib/clogger/pure.rb
index 9efb00c..5e7ccfe 100644
--- a/lib/clogger/pure.rb
+++ b/lib/clogger/pure.rb
@@ -28,7 +28,7 @@ def initialize(app, opts = {})
end
def call(env)
- start = Time.now
+ start = mono_now
resp = @app.call(env)
unless resp.instance_of?(Array) && resp.size == 3
log(env, 500, {}, start)
@@ -165,7 +165,7 @@ def log(env, status, headers, start = @start)
when OP_TIME_LOCAL; Time.now.strftime(op[1])
when OP_TIME_UTC; Time.now.utc.strftime(op[1])
when OP_REQUEST_TIME
- t = Time.now - start
+ t = mono_now - start
time_format(t.to_i, (t - t.to_i) * 1000000, op[1], op[2])
when OP_TIME
t = Time.now
@@ -185,4 +185,14 @@ def log(env, status, headers, start = @start)
end
nil
end
+
+ # favor monotonic clock if possible, and try to use clock_gettime in
+ # more recent Rubies since it generates less garbage
+ if defined?(Process::CLOCK_MONOTONIC)
+ def mono_now; Process.clock_gettime(Process::CLOCK_MONOTONIC); end
+ elsif defined?(Process::CLOCK_REALTIME)
+ def mono_now; Process.clock_gettime(Process::CLOCK_REALTIME); end
+ else
+ def mono_now; Time.now.to_f; end
+ end
end
--
EW
^ permalink raw reply related [flat|nested] 3+ messages in thread