From dda9452314bb904a3e2c850bd23f118eb80e3356 Mon Sep 17 00:00:00 2001 From: bogdanvlviv Date: Tue, 4 Dec 2018 23:24:23 +0200 Subject: Fix elapsed time calculations I've found a few places in Rails code base where I think it makes sense to calculate elapsed time more precisely by using `Concurrent.monotonic_time`: - Fix calculation of elapsed time in `ActiveSupport::Cache::MemoryStore#prune` - Fix calculation of elapsed time in `ActiveRecord::ConnectionAdapters::ConnectionPool::Queue#wait_poll` - Fix calculation of elapsed time in `ActiveRecord::ConnectionAdapters::ConnectionPool#attempt_to_checkout_all_existing_connections` - Fix calculation of elapsed time in `ActiveRecord::ConnectionAdapters::Mysql2Adapter#explain` See https://docs.ruby-lang.org/en/2.5.0/Process.html#method-c-clock_gettime https://blog.dnsimple.com/2018/03/elapsed-time-with-ruby-the-right-way Related to 7c4542146f0dde962205e5a90839349631ae60fb --- .../active_record/connection_adapters/abstract/connection_pool.rb | 8 ++++---- .../active_record/connection_adapters/abstract_mysql_adapter.rb | 4 ++-- 2 files changed, 6 insertions(+), 6 deletions(-) (limited to 'activerecord') diff --git a/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb b/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb index c8d5f679a8..1c8df3c08a 100644 --- a/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb +++ b/activerecord/lib/active_record/connection_adapters/abstract/connection_pool.rb @@ -185,7 +185,7 @@ module ActiveRecord def wait_poll(timeout) @num_waiting += 1 - t0 = Time.now + t0 = Concurrent.monotonic_time elapsed = 0 loop do ActiveSupport::Dependencies.interlock.permit_concurrent_loads do @@ -194,7 +194,7 @@ module ActiveRecord return remove if any? - elapsed = Time.now - t0 + elapsed = Concurrent.monotonic_time - t0 if elapsed >= timeout msg = "could not obtain a connection from the pool within %0.3f seconds (waited %0.3f seconds); all pooled connections were in use" % [timeout, elapsed] @@ -686,13 +686,13 @@ module ActiveRecord end newly_checked_out = [] - timeout_time = Time.now + (@checkout_timeout * 2) + timeout_time = Concurrent.monotonic_time + (@checkout_timeout * 2) @available.with_a_bias_for(Thread.current) do loop do synchronize do return if collected_conns.size == @connections.size && @now_connecting == 0 - remaining_timeout = timeout_time - Time.now + remaining_timeout = timeout_time - Concurrent.monotonic_time remaining_timeout = 0 if remaining_timeout < 0 conn = checkout_for_exclusive_access(remaining_timeout) collected_conns << conn diff --git a/activerecord/lib/active_record/connection_adapters/abstract_mysql_adapter.rb b/activerecord/lib/active_record/connection_adapters/abstract_mysql_adapter.rb index 7b69a63f6e..569c146f92 100644 --- a/activerecord/lib/active_record/connection_adapters/abstract_mysql_adapter.rb +++ b/activerecord/lib/active_record/connection_adapters/abstract_mysql_adapter.rb @@ -166,9 +166,9 @@ module ActiveRecord def explain(arel, binds = []) sql = "EXPLAIN #{to_sql(arel, binds)}" - start = Time.now + start = Concurrent.monotonic_time result = exec_query(sql, "EXPLAIN", binds) - elapsed = Time.now - start + elapsed = Concurrent.monotonic_time - start MySQL::ExplainPrettyPrinter.new.pp(result, elapsed) end -- cgit v1.2.3