Skip to content

Commit

Permalink
Merge pull request #43502 from Shopify/rework-process-clock-gettime-uses
Browse files Browse the repository at this point in the history
Refactor `Process.clock_gettime` uses
  • Loading branch information
byroot authored Oct 21, 2021
2 parents 0983917 + 9636b4d commit 571779a
Show file tree
Hide file tree
Showing 10 changed files with 38 additions and 37 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -527,13 +527,13 @@ def attempt_to_checkout_all_existing_connections(raise_on_acquisition_timeout =
end

newly_checked_out = []
timeout_time = Concurrent.monotonic_time + (@checkout_timeout * 2)
timeout_time = Process.clock_gettime(Process::CLOCK_MONOTONIC) + (@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 - Concurrent.monotonic_time
remaining_timeout = timeout_time - Process.clock_gettime(Process::CLOCK_MONOTONIC)
remaining_timeout = 0 if remaining_timeout < 0
conn = checkout_for_exclusive_access(remaining_timeout)
collected_conns << conn
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -110,7 +110,7 @@ def no_wait_poll
def wait_poll(timeout)
@num_waiting += 1

t0 = Concurrent.monotonic_time
t0 = Process.clock_gettime(Process::CLOCK_MONOTONIC)
elapsed = 0
loop do
ActiveSupport::Dependencies.interlock.permit_concurrent_loads do
Expand All @@ -119,7 +119,7 @@ def wait_poll(timeout)

return remove if any?

elapsed = Concurrent.monotonic_time - t0
elapsed = Process.clock_gettime(Process::CLOCK_MONOTONIC) - 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]
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -88,7 +88,7 @@ def initialize(connection, logger = nil, config = {}) # :nodoc:
@logger = logger
@config = config
@pool = ActiveRecord::ConnectionAdapters::NullPool.new
@idle_since = Concurrent.monotonic_time
@idle_since = Process.clock_gettime(Process::CLOCK_MONOTONIC)
@visitor = arel_visitor
@statements = build_statement_pool
@lock = ActiveSupport::Concurrency::LoadInterlockAwareMonitor.new
Expand Down Expand Up @@ -242,7 +242,7 @@ def expire
"Current thread: #{Thread.current}."
end

@idle_since = Concurrent.monotonic_time
@idle_since = Process.clock_gettime(Process::CLOCK_MONOTONIC)
@owner = nil
else
raise ActiveRecordError, "Cannot expire connection, it is not currently leased."
Expand All @@ -265,7 +265,7 @@ def steal! # :nodoc:
# Seconds since this connection was returned to the pool
def seconds_idle # :nodoc:
return 0 if in_use?
Concurrent.monotonic_time - @idle_since
Process.clock_gettime(Process::CLOCK_MONOTONIC) - @idle_since
end

def unprepared_statement
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -30,9 +30,9 @@ def write_query?(sql) # :nodoc:

def explain(arel, binds = [])
sql = "EXPLAIN #{to_sql(arel, binds)}"
start = Concurrent.monotonic_time
start = Process.clock_gettime(Process::CLOCK_MONOTONIC)
result = exec_query(sql, "EXPLAIN", binds)
elapsed = Concurrent.monotonic_time - start
elapsed = Process.clock_gettime(Process::CLOCK_MONOTONIC) - start

MySQL::ExplainPrettyPrinter.new.pp(result, elapsed)
end
Expand Down
4 changes: 2 additions & 2 deletions activerecord/lib/active_record/future_result.rb
Original file line number Diff line number Diff line change
Expand Up @@ -102,12 +102,12 @@ def canceled?

def execute_or_wait
if pending?
start = Concurrent.monotonic_time
start = Process.clock_gettime(Process::CLOCK_MONOTONIC, :float_millisecond)
@mutex.synchronize do
if pending?
execute_query(@pool.connection)
else
@lock_wait = (Concurrent.monotonic_time - start) * 1_000
@lock_wait = (Process.clock_gettime(Process::CLOCK_MONOTONIC, :float_millisecond) - start)
end
end
else
Expand Down
8 changes: 4 additions & 4 deletions activerecord/test/cases/connection_pool_test.rb
Original file line number Diff line number Diff line change
Expand Up @@ -211,15 +211,15 @@ def test_idle_timeout_configuration

idle_conn.instance_variable_set(
:@idle_since,
Concurrent.monotonic_time - 0.01
Process.clock_gettime(Process::CLOCK_MONOTONIC) - 0.01
)

@pool.flush
assert_equal 1, @pool.connections.length

idle_conn.instance_variable_set(
:@idle_since,
Concurrent.monotonic_time - 0.02
Process.clock_gettime(Process::CLOCK_MONOTONIC) - 0.02
)

@pool.flush
Expand All @@ -238,7 +238,7 @@ def test_disable_flush

idle_conn.instance_variable_set(
:@idle_since,
Concurrent.monotonic_time - 1
Process.clock_gettime(Process::CLOCK_MONOTONIC) - 1
)

@pool.flush
Expand All @@ -257,7 +257,7 @@ def test_flush

idle_conn.instance_variable_set(
:@idle_since,
Concurrent.monotonic_time - 1000
Process.clock_gettime(Process::CLOCK_MONOTONIC) - 1000
)

@pool.flush(30)
Expand Down
4 changes: 2 additions & 2 deletions activesupport/lib/active_support/cache/memory_store.rb
Original file line number Diff line number Diff line change
Expand Up @@ -89,13 +89,13 @@ def prune(target_size, max_time = nil)
return if pruning?
@pruning = true
begin
start_time = Concurrent.monotonic_time
start_time = Process.clock_gettime(Process::CLOCK_MONOTONIC)
cleanup
instrument(:prune, target_size, from: @cache_size) do
keys = synchronize { @data.keys }
keys.each do |key|
delete_entry(key, **options)
return if @cache_size <= target_size || (max_time && Concurrent.monotonic_time - start_time > max_time)
return if @cache_size <= target_size || (max_time && Process.clock_gettime(Process::CLOCK_MONOTONIC) - start_time > max_time)
end
end
ensure
Expand Down
4 changes: 2 additions & 2 deletions activesupport/lib/active_support/notifications/fanout.rb
Original file line number Diff line number Diff line change
Expand Up @@ -236,13 +236,13 @@ def publish(name, *args)

def start(name, id, payload)
timestack = Thread.current[:_timestack_monotonic] ||= []
timestack.push Concurrent.monotonic_time
timestack.push Process.clock_gettime(Process::CLOCK_MONOTONIC)
end

def finish(name, id, payload)
timestack = Thread.current[:_timestack_monotonic]
started = timestack.pop
@delegate.call(name, started, Concurrent.monotonic_time, id, payload)
@delegate.call(name, started, Process.clock_gettime(Process::CLOCK_MONOTONIC), id, payload)
end
end

Expand Down
26 changes: 14 additions & 12 deletions activesupport/lib/active_support/notifications/instrumenter.rb
Original file line number Diff line number Diff line change
Expand Up @@ -62,12 +62,12 @@ class Event
def initialize(name, start, ending, transaction_id, payload)
@name = name
@payload = payload.dup
@time = start
@time = start ? start.to_f * 1_000.0 : start
@transaction_id = transaction_id
@end = ending
@end = ending ? ending.to_f * 1_000.0 : ending
@children = []
@cpu_time_start = 0
@cpu_time_finish = 0
@cpu_time_start = 0.0
@cpu_time_finish = 0.0
@allocation_count_start = 0
@allocation_count_finish = 0
end
Expand Down Expand Up @@ -102,7 +102,7 @@ def finish!
# Returns the CPU time (in milliseconds) passed since the call to
# +start!+ and the call to +finish!+
def cpu_time
(@cpu_time_finish - @cpu_time_start) * 1000
@cpu_time_finish - @cpu_time_start
end

# Returns the idle time time (in milliseconds) passed since the call to
Expand Down Expand Up @@ -130,7 +130,7 @@ def allocations
#
# @event.duration # => 1000.138
def duration
1000.0 * (self.end - time)
self.end - time
end

def <<(event)
Expand All @@ -143,28 +143,30 @@ def parent_of?(event)

private
def now
Concurrent.monotonic_time
Process.clock_gettime(Process::CLOCK_MONOTONIC, :float_millisecond)
end

begin
Process.clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID)
Process.clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :float_millisecond)

def now_cpu
Process.clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID)
Process.clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :float_millisecond)
end
rescue
def now_cpu
0
0.0
end
end

if defined?(JRUBY_VERSION)
begin
GC.stat(:total_allocated_objects)
rescue ArgumentError # Likely on JRuby
def now_allocations
0
end
else
def now_allocations
GC.stat :total_allocated_objects
GC.stat(:total_allocated_objects)
end
end
end
Expand Down
11 changes: 5 additions & 6 deletions activesupport/test/notifications_test.rb
Original file line number Diff line number Diff line change
Expand Up @@ -434,12 +434,11 @@ def test_event_is_pushed_even_without_block

class EventTest < TestCase
def test_events_are_initialized_with_details
time = Time.now
time = Time.now.to_f
event = event(:foo, time, time + 0.01, random_id, {})

assert_equal :foo, event.name
assert_equal time, event.time
assert_in_delta 10.0, event.duration, 0.00001
assert_in_delta 10.0, event.duration, 0.0001
end

def test_event_cpu_time_does_not_raise_error_when_start_or_finished_not_called
Expand All @@ -450,14 +449,14 @@ def test_event_cpu_time_does_not_raise_error_when_start_or_finished_not_called
end

def test_events_consumes_information_given_as_payload
event = event(:foo, Concurrent.monotonic_time, Concurrent.monotonic_time + 1, random_id, payload: :bar)
event = event(:foo, Process.clock_gettime(Process::CLOCK_MONOTONIC), Process.clock_gettime(Process::CLOCK_MONOTONIC) + 1, random_id, payload: :bar)
assert_equal Hash[payload: :bar], event.payload
end

def test_event_is_parent_based_on_children
time = Concurrent.monotonic_time
time = Process.clock_gettime(Process::CLOCK_MONOTONIC)

parent = event(:foo, Concurrent.monotonic_time, Concurrent.monotonic_time + 100, random_id, {})
parent = event(:foo, Process.clock_gettime(Process::CLOCK_MONOTONIC), Process.clock_gettime(Process::CLOCK_MONOTONIC) + 100, random_id, {})
child = event(:foo, time, time + 10, random_id, {})
not_child = event(:foo, time, time + 100, random_id, {})

Expand Down

0 comments on commit 571779a

Please sign in to comment.