diff --git a/actionpack/CHANGELOG b/actionpack/CHANGELOG index 10ee29807d206..cb61c8d2dd3a8 100644 --- a/actionpack/CHANGELOG +++ b/actionpack/CHANGELOG @@ -6,11 +6,11 @@ * Changed logging format to be millisecond based and skip misleading stats [DHH]. Went from: - Completed in 0.10000 (4 reqs/sec) | Rendering: 0.40000 (40%) | DB: 0.04000 (4%) | 200 OK [http://example.com] + Completed in 0.10000 (4 reqs/sec) | Rendering: 0.04000 (40%) | DB: 0.00400 (4%) | 200 OK [http://example.com] ...to: - Completed in 100.00ms (View: 400.00, DB: 40.00) | 200 OK [http://example.com] + Completed in 100ms (View: 40, DB: 4) | 200 OK [http://example.com] * Add support for shallow nesting of routes. #838 [S. Brent Faulkner] diff --git a/actionpack/lib/action_controller/benchmarking.rb b/actionpack/lib/action_controller/benchmarking.rb index a2bd61889f811..746894497cbad 100644 --- a/actionpack/lib/action_controller/benchmarking.rb +++ b/actionpack/lib/action_controller/benchmarking.rb @@ -24,7 +24,7 @@ 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} (#{('%.2f' % (seconds * 1000))}ms)") + logger.add(log_level, "#{title} (#{('%.1f' % (seconds * 1000))}ms)") result else yield @@ -69,7 +69,7 @@ def perform_action_with_benchmark logging_view = defined?(@view_runtime) logging_active_record = Object.const_defined?("ActiveRecord") && ActiveRecord::Base.connected? - log_message = "Completed in #{sprintf("%.2f", seconds * 1000)}ms" + log_message = "Completed in #{sprintf("%.0f", seconds * 1000)}ms" if logging_view || logging_active_record log_message << " (" @@ -86,21 +86,21 @@ def perform_action_with_benchmark log_message << " [#{complete_request_uri rescue "unknown"}]" logger.info(log_message) - response.headers["X-Runtime"] = "#{sprintf("%.2f", seconds * 1000)}ms" + response.headers["X-Runtime"] = "#{sprintf("%.0f", seconds * 1000)}ms" else perform_action_without_benchmark end end def view_runtime - "View: %.2f" % (@view_runtime * 1000) + "View: %.0f" % (@view_runtime * 1000) 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: %.2f" % (db_runtime * 1000) + "DB: %.0f" % (db_runtime * 1000) end end end diff --git a/actionpack/lib/action_view/helpers/benchmark_helper.rb b/actionpack/lib/action_view/helpers/benchmark_helper.rb index 2401338896373..bd72cda700386 100644 --- a/actionpack/lib/action_view/helpers/benchmark_helper.rb +++ b/actionpack/lib/action_view/helpers/benchmark_helper.rb @@ -15,7 +15,7 @@ module BenchmarkHelper # <%= expensive_files_operation %> # <% end %> # - # That would add something like "Process data files (345.23ms)" to the log, + # That would add something like "Process data files (345.2ms)" to the log, # which you can then use to compare timings when optimizing your code. # # You may give an optional logger level as the second argument @@ -23,7 +23,7 @@ module BenchmarkHelper def benchmark(message = "Benchmarking", level = :info) if controller.logger seconds = Benchmark.realtime { yield } - controller.logger.send(level, "#{message} (#{'%.2f' % (seconds * 1000)}ms)") + controller.logger.send(level, "#{message} (#{'%.1f' % (seconds * 1000)}ms)") else yield end diff --git a/activerecord/lib/active_record/base.rb b/activerecord/lib/active_record/base.rb index cd66844dae408..907495a416bbd 100755 --- a/activerecord/lib/active_record/base.rb +++ b/activerecord/lib/active_record/base.rb @@ -1313,7 +1313,7 @@ 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} (#{'%.2f' % (seconds * 1000)}ms)") + logger.add(log_level, "#{title} (#{'%.1f' % (seconds * 1000)}ms)") result else yield diff --git a/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb b/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb index a3cb6f3214276..7c379163678ba 100755 --- a/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb +++ b/activerecord/lib/active_record/connection_adapters/abstract_adapter.rb @@ -149,7 +149,7 @@ def decrement_open_transactions def log_info(sql, name, seconds) if @logger && @logger.debug? - name = "#{name.nil? ? "SQL" : name} (#{sprintf("%.2f", seconds * 1000)}ms)" + name = "#{name.nil? ? "SQL" : name} (#{sprintf("%.1f", seconds * 1000)}ms)" @logger.debug(format_log_entry(name, sql.squeeze(' '))) end end