Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP
Browse files

Benchmark.ms

  • Loading branch information...
commit e8c4939fb3366472021c1af1331bfdfe5d7a5d75 1 parent c3fe6eb
@jeremy jeremy authored
View
16 actionpack/lib/action_controller/benchmarking.rb
@@ -23,8 +23,8 @@ module ClassMethods
def benchmark(title, log_level = Logger::DEBUG, use_silence = true)
if logger && logger.level == log_level
result = nil
- seconds = Benchmark.realtime { result = use_silence ? silence { yield } : yield }
- logger.add(log_level, "#{title} (#{('%.1f' % (seconds * 1000))}ms)")
+ ms = Benchmark.ms { result = use_silence ? silence { yield } : yield }
+ logger.add(log_level, "#{title} (#{('%.1f' % ms)}ms)")
result
else
yield
@@ -48,7 +48,7 @@ def render_with_benchmark(options = nil, extra_options = {}, &block)
end
render_output = nil
- @view_runtime = Benchmark::realtime { render_output = render_without_benchmark(options, extra_options, &block) }
+ @view_runtime = Benchmark.ms { render_output = render_without_benchmark(options, extra_options, &block) }
if Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected?
@db_rt_before_render = db_runtime
@@ -65,11 +65,11 @@ def render_with_benchmark(options = nil, extra_options = {}, &block)
private
def perform_action_with_benchmark
if logger
- seconds = [ Benchmark::measure{ perform_action_without_benchmark }.real, 0.0001 ].max
+ ms = [Benchmark.ms { perform_action_without_benchmark }, 0.01].max
logging_view = defined?(@view_runtime)
logging_active_record = Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected?
- log_message = "Completed in #{sprintf("%.0f", seconds * 1000)}ms"
+ log_message = 'Completed in %.0fms' % ms
if logging_view || logging_active_record
log_message << " ("
@@ -87,21 +87,21 @@ def perform_action_with_benchmark
log_message << " [#{complete_request_uri rescue "unknown"}]"
logger.info(log_message)
- response.headers["X-Runtime"] = "#{sprintf("%.0f", seconds * 1000)}ms"
+ response.headers["X-Runtime"] = "%.0f" % ms
else
perform_action_without_benchmark
end
end
def view_runtime
- "View: %.0f" % (@view_runtime * 1000)
+ "View: %.0f" % @view_runtime
end
def active_record_runtime
db_runtime = ActiveRecord::Base.connection.reset_runtime
db_runtime += @db_rt_before_render if @db_rt_before_render
db_runtime += @db_rt_after_render if @db_rt_after_render
- "DB: %.0f" % (db_runtime * 1000)
+ "DB: %.0f" % db_runtime
end
end
end
View
12 actionpack/lib/action_controller/request_profiler.rb
@@ -20,7 +20,7 @@ def benchmark(n, profiling = false)
@quiet = true
print ' '
- result = Benchmark.realtime do
+ ms = Benchmark.ms do
n.times do |i|
run(profiling)
print_progress(i)
@@ -28,7 +28,7 @@ def benchmark(n, profiling = false)
end
puts
- result
+ ms
ensure
@quiet = false
end
@@ -88,7 +88,7 @@ def run
puts 'Warming up once'
elapsed = warmup(sandbox)
- puts '%.2f sec, %d requests, %d req/sec' % [elapsed, sandbox.request_count, sandbox.request_count / elapsed]
+ puts '%.0f ms, %d requests, %d req/sec' % [elapsed, sandbox.request_count, 1000 * sandbox.request_count / elapsed]
puts "\n#{options[:benchmark] ? 'Benchmarking' : 'Profiling'} #{options[:n]}x"
options[:benchmark] ? benchmark(sandbox) : profile(sandbox)
@@ -106,13 +106,13 @@ def profile(sandbox)
def benchmark(sandbox, profiling = false)
sandbox.request_count = 0
- elapsed = sandbox.benchmark(options[:n], profiling).to_f
+ elapsed = sandbox.benchmark(options[:n], profiling)
count = sandbox.request_count.to_i
- puts '%.2f sec, %d requests, %d req/sec' % [elapsed, count, count / elapsed]
+ puts '%.0f ms, %d requests, %d req/sec' % [elapsed, count, 1000 * count / elapsed]
end
def warmup(sandbox)
- Benchmark.realtime { sandbox.run(false) }
+ Benchmark.ms { sandbox.run(false) }
end
def default_options
View
6 actionpack/lib/action_view/helpers/benchmark_helper.rb
@@ -22,12 +22,12 @@ module BenchmarkHelper
# (:debug, :info, :warn, :error); the default value is :info.
def benchmark(message = "Benchmarking", level = :info)
if controller.logger
- seconds = Benchmark.realtime { yield }
- controller.logger.send(level, "#{message} (#{'%.1f' % (seconds * 1000)}ms)")
+ ms = Benchmark.ms { yield }
+ controller.logger.send(level, '%s (%.1fms)' % [message, ms])
else
yield
end
end
end
end
-end
+end
View
4 activerecord/lib/active_record/base.rb
@@ -1417,8 +1417,8 @@ def sanitize(object) #:nodoc:
def benchmark(title, log_level = Logger::DEBUG, use_silence = true)
if logger && logger.level <= log_level
result = nil
- seconds = Benchmark.realtime { result = use_silence ? silence { yield } : yield }
- logger.add(log_level, "#{title} (#{'%.1f' % (seconds * 1000)}ms)")
+ ms = Benchmark.ms { result = use_silence ? silence { yield } : yield }
+ logger.add(log_level, '%s (%.1fms)' % [title, ms])
result
else
yield
View
10 activerecord/lib/active_record/connection_adapters/abstract_adapter.rb
@@ -160,9 +160,9 @@ def decrement_open_transactions
@open_transactions -= 1
end
- def log_info(sql, name, seconds)
+ def log_info(sql, name, ms)
if @logger && @logger.debug?
- name = "#{name.nil? ? "SQL" : name} (#{sprintf("%.1f", seconds * 1000)}ms)"
+ name = '%s (%.1fms)' % [name || 'SQL', ms]
@logger.debug(format_log_entry(name, sql.squeeze(' ')))
end
end
@@ -171,9 +171,9 @@ def log_info(sql, name, seconds)
def log(sql, name)
if block_given?
result = nil
- seconds = Benchmark.realtime { result = yield }
- @runtime += seconds
- log_info(sql, name, seconds)
+ ms = Benchmark.ms { result = yield }
+ @runtime += ms
+ log_info(sql, name, ms)
result
else
log_info(sql, name, 0)
View
4 activeresource/lib/active_resource/connection.rb
@@ -146,8 +146,8 @@ def head(path, headers = {})
def request(method, path, *arguments)
logger.info "#{method.to_s.upcase} #{site.scheme}://#{site.host}:#{site.port}#{path}" if logger
result = nil
- time = Benchmark.realtime { result = http.send(method, path, *arguments) }
- logger.info "--> %d %s (%d %.2fs)" % [result.code, result.message, result.body ? result.body.length : 0, time] if logger
+ ms = Benchmark.ms { result = http.send(method, path, *arguments) }
+ logger.info "--> %d %s (%d %.0fms)" % [result.code, result.message, result.body ? result.body.length : 0, ms] if logger
handle_response(result)
rescue Timeout::Error => e
raise TimeoutError.new(e.message)
View
2  activesupport/CHANGELOG
@@ -1,5 +1,7 @@
*2.3.0 [Edge]*
+* Add Benchmark.ms convenience method to benchmark realtime in milliseconds. [Jeremy Kemper]
+
* Multibyte: add multibyte-safe Chars#ord rather than falling back to String#ord. #1483 [Jason Cheow]
* I18n support for Array#to_sentence. Introduces support.array.words_connector, .two_words_connector, and .last_word_connector translation keys. #1397 [Akira Matsuda]
View
4 activesupport/lib/active_support/cache.rb
@@ -143,13 +143,13 @@ def fetch(key, options = {})
log("miss", key, options)
value = nil
- seconds = Benchmark.realtime { value = yield }
+ ms = Benchmark.ms { value = yield }
@logger_off = true
write(key, value, options)
@logger_off = false
- log("write (will save #{'%.2f' % (seconds * 1000)}ms)", key, nil)
+ log('write (will save %.2fms)' % ms, key, nil)
value
end
View
19 activesupport/lib/active_support/core_ext/benchmark.rb
@@ -1,12 +1,19 @@
require 'benchmark'
class << Benchmark
- remove_method :realtime
+ # Earlier Ruby had a slower implementation.
+ if RUBY_VERSION < '1.8.7'
+ remove_method :realtime
- def realtime
- r0 = Time.now
- yield
- r1 = Time.now
- r1.to_f - r0.to_f
+ def realtime
+ r0 = Time.now
+ yield
+ r1 = Time.now
+ r1.to_f - r0.to_f
+ end
+ end
+
+ def ms
+ 1000 * realtime { yield }
end
end
Please sign in to comment.
Something went wrong with that request. Please try again.