Module: ActiveRecordQueryCounter

Defined in:
lib/active_record_query_counter.rb,
lib/active_record_query_counter/counter.rb,
lib/active_record_query_counter/query_info.rb,
lib/active_record_query_counter/thresholds.rb,
lib/active_record_query_counter/rack_middleware.rb,
lib/active_record_query_counter/transaction_info.rb,
lib/active_record_query_counter/sidekiq_middleware.rb,
lib/active_record_query_counter/transaction_details.rb,
lib/active_record_query_counter/transaction_extension.rb,
lib/active_record_query_counter/connection_adapter_extension.rb

Overview

Everything you need to count ActiveRecord queries and row counts within a block.

Examples:


ActiveRecordQueryCounter.count_queries do
  yield
  puts ActiveRecordQueryCounter.query_count
  puts ActiveRecordQueryCounter.row_count
end

Defined Under Namespace

Modules: ConnectionAdapterExtension, TransactionExtension Classes: Counter, QueryInfo, RackMiddleware, SidekiqMiddleware, Thresholds, TransactionDetails, TransactionInfo

Constant Summary collapse

VERSION = 
File.read(File.join(__dir__, "..", "VERSION")).strip
CPU_CLOCK_ID =

Clock used to measure the CPU time consumed by the current thread. It is not available on every platform (e.g. Windows), in which case CPU time is not measured and is treated as zero.

(Process::CLOCK_THREAD_CPUTIME_ID))

Class Attribute Summary collapse

Class Method Summary collapse

Class Attribute Details

.default_thresholds ⇒ ActiveRecordQueryCounter::Thresholds (readonly)

The global notification thresholds for sending notifications. The values set in these thresholds are used as the default values.

Returns:



410
411
412
 
# File 'lib/active_record_query_counter.rb', line 410

def default_thresholds
  @default_thresholds
end

Class Method Details

.add_query(sql, name, binds, row_count, start_time, end_time, gc_time, cpu_time, connection_time = 0.0, connection: nil) ⇒ void

This method is part of a private API. You should avoid using this method if possible, as it may be removed or be changed in the future.

This method returns an undefined value.

Increment the query counters.

The reported query time is the wall clock time spent executing the query with the GC time, Ruby thread CPU time, and connection setup time subtracted out so that it reflects the time actually spent waiting on the database as closely as possible (see database_query_time). This query time, rather than the raw wall clock time, is what is accumulated, compared against the threshold, and used as the duration of the emitted notification.

Parameters:

  • sql (String) —

    the SQL statement that was executed

  • name (String, nil) —

    the name of the query

  • binds (Array) —

    the bind parameters

  • row_count (Integer) —

    the number of rows returned by the query

  • start_time (Float) —

    the monotonic time when the query started

  • end_time (Float) —

    the monotonic time when the query ended

  • gc_time (Float) —

    the GC time in seconds that elapsed while the query ran

  • cpu_time (Float) —

    the thread CPU time in seconds spent while the query ran

  • connection_time (Float) (defaults to: 0.0) —

    the time in seconds spent establishing, verifying, or reconnecting the database connection while the query ran

  • connection (Object, nil) (defaults to: nil) —

    the connection adapter the query was executed on; used to attach the query to the transaction currently open on that connection, if any



101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
 
# File 'lib/active_record_query_counter.rb', line 101

def add_query(sql, name, binds, row_count, start_time, end_time, gc_time, cpu_time, connection_time = 0.0, connection: nil)
  return if IGNORED_STATEMENTS.include?(name)

  counter = current_counter
  return unless counter.is_a?(Counter)

  elapsed_time = end_time - start_time
  query_time = database_query_time(elapsed_time, gc_time, cpu_time, connection_time)
  counter.query_count += 1
  counter.row_count += row_count
  counter.query_time += query_time

  queries = transaction_queries(connection)
  if queries
    queries << QueryInfo.new(
      sql: sql,
      name: name,
      row_count: row_count,
      start_time: start_time,
      end_time: end_time,
      gc_time: gc_time,
      cpu_time: cpu_time,
      connection_time: connection_time
    )
  end

  # The notification duration is the database query time, so the event ends that long after
  # it started rather than at the raw wall clock end time.
  notification_end_time = start_time + query_time

  trace = nil
  query_time_threshold = counter.thresholds.query_time || -1
  if query_time_threshold.between?(0, query_time)
    trace = backtrace
    payload = notification_payload(sql: sql, binds: binds, row_count: row_count, trace: trace, elapsed_time: elapsed_time, gc_time: gc_time, cpu_time: cpu_time, connection_time: connection_time)
    send_notification("query_time", start_time, notification_end_time, **payload)
  end

  row_count_threshold = counter.thresholds.row_count || -1
  if row_count_threshold.between?(0, row_count)
    trace ||= backtrace
    payload = notification_payload(sql: sql, binds: binds, row_count: row_count, trace: trace, elapsed_time: elapsed_time, gc_time: gc_time, cpu_time: cpu_time, connection_time: connection_time)
    send_notification("row_count", start_time, notification_end_time, **payload)
  end
end

.add_transaction(start_time, end_time, queries: [], gc_time: 0.0, cpu_time: 0.0) ⇒ void

This method is part of a private API. You should avoid using this method if possible, as it may be removed or be changed in the future.

This method returns an undefined value.

Increment the transaction counters.

Parameters:

  • start_time (Float) —

    the time the transaction started

  • end_time (Float) —

    the time the transaction ended

  • queries (Array<ActiveRecordQueryCounter::QueryInfo>) (defaults to: []) —

    the queries executed within the transaction

  • gc_time (Float) (defaults to: 0.0) —

    the GC time in seconds that elapsed while the transaction was open

  • cpu_time (Float) (defaults to: 0.0) —

    the thread CPU time in seconds spent while the transaction was open



157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
 
# File 'lib/active_record_query_counter.rb', line 157

def add_transaction(start_time, end_time, queries: [], gc_time: 0.0, cpu_time: 0.0)
  counter = current_counter
  return unless counter.is_a?(Counter)

  # The details object holds the full query information. Only the counts and timings
  # derived from it are retained on the counter; the details are released when this
  # method returns so the query data does not accumulate in memory.
  details = TransactionDetails.new(
    start_time: start_time,
    end_time: end_time,
    trace: backtrace,
    queries: queries,
    gc_time: gc_time,
    cpu_time: cpu_time
  )

  counter.add_transaction(
    trace: details.trace,
    start_time: start_time,
    end_time: end_time,
    query_count: details.query_count,
    gc_time: gc_time,
    cpu_time: cpu_time,
    idle_time: details.idle_time
  )

  transaction_time_threshold = counter.thresholds.transaction_time || -1
  if transaction_time_threshold.between?(0, end_time - start_time)
    send_notification(
      "transaction_time",
      start_time,
      end_time,
      trace: details.trace,
      queries: details.queries,
      gc_time: (gc_time * 1000.0).round(6),
      cpu_time: (cpu_time * 1000.0).round(6),
      idle_time: (details.idle_time * 1000.0).round(6)
    )
  end
end

.cached_query_count ⇒ Integer?

Return the number of queries that hit the query cache and were not sent to the database that have been counted within the current block. Returns nil if not inside a block where queries are being counted.

Returns:

  • (Integer, nil) 


308
309
310
311
 
# File 'lib/active_record_query_counter.rb', line 308

def cached_query_count
  counter = current_counter
  counter.cached_query_count if counter.is_a?(Counter)
end

.count_queries ⇒ Object

Enable query counting within a block.

Returns:

  • (Object) —

    the result of the block



42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
 
# File 'lib/active_record_query_counter.rb', line 42

def count_queries
  save_counter = current_counter
  begin
    counter = Counter.new
    self.current_counter = counter

    retval = yield

    transaction_count = counter.transaction_count
    if transaction_count > 0
      transaction_threshold = counter.thresholds.transaction_count || -1
      if transaction_threshold.between?(0, transaction_count)
        send_notification("transaction_count", counter.first_transaction_start_time, counter.last_transaction_end_time, transactions: counter.transactions)
      end
    end

    retval
  ensure
    self.current_counter = save_counter
  end
end

.current_cpu_time ⇒ Float

This method is part of a private API. You should avoid using this method if possible, as it may be removed or be changed in the future.

The current thread CPU time in seconds, or 0.0 when the platform does not support it.

Returns:

  • (Float) 


213
214
215
 
# File 'lib/active_record_query_counter.rb', line 213

def current_cpu_time
  CPU_CLOCK_ID ? Process.clock_gettime(CPU_CLOCK_ID) : 0.0
end

.disable(&block) ⇒ Object

Disable query counting in a block. Any queries or transactions inside the block will not be counted.

Returns:

  • (Object) —

    the return value of the block



68
69
70
71
72
73
74
75
76
 
# File 'lib/active_record_query_counter.rb', line 68

def disable(&block)
  counter = current_counter
  begin
    self.current_counter = nil
    yield
  ensure
    self.current_counter = counter
  end
end

.enable!(connection_class) ⇒ void

This method returns an undefined value.

Enable the query counting behavior on a connection adapter class.

Parameters:

  • connection_class (Class) —

    the connection adapter class to extend



422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
 
# File 'lib/active_record_query_counter.rb', line 422

def enable!(connection_class)
  ActiveSupport.on_load(:active_record) do
    ConnectionAdapterExtension.inject(connection_class)
    TransactionExtension.inject(ActiveRecord::ConnectionAdapters::RealTransaction)
  end

  @lock.synchronize do
    @cache_subscription ||= ActiveSupport::Notifications.subscribe("sql.active_record") do |_name, _start_time, _end_time, _id, payload|
      if payload[:cached] && !IGNORED_STATEMENTS.include?(payload[:name])
        counter = current_counter
        counter.cached_query_count += 1 if counter.is_a?(Counter)
      end
    end
  end
end

.first_transaction_start_time ⇒ Float?

Return the time when the first transaction began within the current block. Returns nil if not inside a block where queries are being counted or there are no transactions.

Returns:

  • (Float, nil) —

    the monotonic time when the first transaction began,



353
354
355
356
 
# File 'lib/active_record_query_counter.rb', line 353

def first_transaction_start_time
  counter = current_counter
  counter.first_transaction_start_time if counter.is_a?(Counter)
end

.increment_rollbacks ⇒ Integer?

Return the number of rollbacks that have been counted within the current block. Returns nil if not inside a block where queries are being counted.

Returns:

  • (Integer, nil) 


202
203
204
205
206
207
 
# File 'lib/active_record_query_counter.rb', line 202

def increment_rollbacks
  counter = current_counter
  return unless counter.is_a?(Counter)

  counter.rollback_count += 1
end

.info ⇒ Hash?

Return the query info as a hash with keys :query_count, :row_count, :query_time :transaction_count, and :transaction_type or nil if not inside a block where queries are being counted.

Returns:

  • (Hash, nil) 


390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
 
# File 'lib/active_record_query_counter.rb', line 390

def info
  counter = current_counter
  if counter.is_a?(Counter)
    {
      query_count: counter.query_count,
      row_count: counter.row_count,
      query_time: counter.query_time,
      cached_query_count: counter.cached_query_count,
      cache_hit_rate: counter.cache_hit_rate,
      transaction_count: counter.transaction_count,
      transaction_time: counter.transaction_time,
      rollback_count: counter.rollback_count
    }
  end
end

.last_transaction_end_time ⇒ Float?

Return the time when the last transaction ended within the current block. Returns nil if not inside a block where queries are being counted or there are no transactions.

Returns:

  • (Float, nil) —

    the monotonic time when the last transaction ended,



362
363
364
365
 
# File 'lib/active_record_query_counter.rb', line 362

def last_transaction_end_time
  counter = current_counter
  counter.last_transaction_end_time if counter.is_a?(Counter)
end

.measure_connection_setup { ... } ⇒ Object

This method is part of a private API. You should avoid using this method if possible, as it may be removed or be changed in the future.

Measure the wall clock time a connection setup operation (connect, reconnect, or verify) takes and accumulate it onto the current query's connection timer. When no query is being measured, or when a connection setup operation is already being measured (for example when verify! delegates to reconnect!), the block is yielded without recording so the interval is only counted once.

Yields:

  • the connection setup operation

Returns:

  • (Object) —

    the result of the block



280
281
282
283
284
285
286
287
288
289
290
291
292
 
# File 'lib/active_record_query_counter.rb', line 280

def measure_connection_setup
  timer = connection_timer
  return yield if timer.nil? || timer[:measuring]

  timer[:measuring] = true
  start_time = Process.clock_gettime(Process::CLOCK_MONOTONIC)
  begin
    yield
  ensure
    timer[:elapsed] += Process.clock_gettime(Process::CLOCK_MONOTONIC) - start_time
    timer[:measuring] = false
  end
end

.query_count ⇒ Integer?

Return the number of queries that have been counted within the current block. Returns nil if not inside a block where queries are being counted.

Returns:

  • (Integer, nil) 


298
299
300
301
 
# File 'lib/active_record_query_counter.rb', line 298

def query_count
  counter = current_counter
  counter.query_count if counter.is_a?(Counter)
end

.query_time ⇒ Float?

Return the total time spent executing queries within the current block. Returns nil if not inside a block where queries are being counted.

Returns:

  • (Float, nil) 


326
327
328
329
 
# File 'lib/active_record_query_counter.rb', line 326

def query_time
  counter = current_counter
  counter.query_time if counter.is_a?(Counter)
end

.register_transaction_queries(connection) ⇒ Array<ActiveRecordQueryCounter::QueryInfo>

This method is part of a private API. You should avoid using this method if possible, as it may be removed or be changed in the future.

Register a new query list for a transaction that was opened on a connection. Queries executed on that connection will be appended to the list until it is unregistered. Registering a connection always replaces any list already registered for it.

The list is bound to the counter that is active when the transaction is opened. Queries counted by a different counter (e.g. a nested count_queries block) are not appended, so the recorded query count for the transaction stays consistent with the counter that recorded the transaction.

Parameters:

  • connection (Object) —

    the connection adapter the transaction was opened on

Returns:



229
230
231
232
233
234
 
# File 'lib/active_record_query_counter.rb', line 229

def register_transaction_queries(connection)
  registry = ActiveSupport::IsolatedExecutionState[:active_record_query_counter_transaction_queries] ||= {}
  queries = []
  registry[connection] = {counter: current_counter, queries: queries}
  queries
end

.rollback_count ⇒ Integer?

Return the number of transactions that have rolled back within the current block. Returns nil if not inside a block where queries are being counted.

Returns:

  • (Integer, nil) 


380
381
382
383
 
# File 'lib/active_record_query_counter.rb', line 380

def rollback_count
  counter = current_counter
  counter.rollback_count if counter.is_a?(Counter)
end

.row_count ⇒ Integer?

Return the number of rows that have been counted within the current block. Returns nil if not inside a block where queries are being counted.

Returns:

  • (Integer, nil) 


317
318
319
320
 
# File 'lib/active_record_query_counter.rb', line 317

def row_count
  counter = current_counter
  counter.row_count if counter.is_a?(Counter)
end

.start_connection_timer ⇒ Object?

This method is part of a private API. You should avoid using this method if possible, as it may be removed or be changed in the future.

Begin measuring the time spent establishing, verifying, or reconnecting the database connection for a single query. Returns the timer that was previously in effect so it can be restored by stop_connection_timer; this keeps nested queries (should they ever occur) from leaking connection time into one another.

Returns:

  • (Object, nil) —

    the previous connection timer



253
254
255
256
257
 
# File 'lib/active_record_query_counter.rb', line 253

def start_connection_timer
  previous_timer = connection_timer
  self.connection_timer = {elapsed: 0.0, measuring: false}
  previous_timer
end

.stop_connection_timer(previous_timer) ⇒ Float

This method is part of a private API. You should avoid using this method if possible, as it may be removed or be changed in the future.

Finish measuring connection setup time for the current query and restore the previously active timer.

Parameters:

Returns:

  • (Float) —

    the connection setup time in seconds accumulated for the query



265
266
267
268
269
 
# File 'lib/active_record_query_counter.rb', line 265

def stop_connection_timer(previous_timer)
  timer = connection_timer
  self.connection_timer = previous_timer
  timer ? timer[:elapsed] : 0.0
end

.thresholds ⇒ Object

Get the current local notification thresholds. These thresholds are only used within the current count_queries block.



414
415
416
 
# File 'lib/active_record_query_counter.rb', line 414

def thresholds
  current_counter&.thresholds || default_thresholds.dup
end

.transaction_count ⇒ Integer?

Return the number of transactions that have been counted within the current block. Returns nil if not inside a block where queries are being counted.

Returns:

  • (Integer, nil) 


335
336
337
338
 
# File 'lib/active_record_query_counter.rb', line 335

def transaction_count
  counter = current_counter
  counter.transaction_count if counter.is_a?(Counter)
end

.transaction_time ⇒ Float?

Return the total time spent in transactions that have been counted within the current block. Returns nil if not inside a block where queries are being counted.

Returns:

  • (Float, nil) 


344
345
346
347
 
# File 'lib/active_record_query_counter.rb', line 344

def transaction_time
  counter = current_counter
  counter.transaction_time if counter.is_a?(Counter)
end

.transactions ⇒ Array<ActiveRecordQueryCounter::TransactionInfo>?

Return an array of transaction information for any transactions that have been counted within the current block. Returns nil if not inside a block where queries are being counted.

Returns:



371
372
373
374
 
# File 'lib/active_record_query_counter.rb', line 371

def transactions
  counter = current_counter
  counter.transactions if counter.is_a?(Counter)
end

.unregister_transaction_queries(connection) ⇒ void

This method is part of a private API. You should avoid using this method if possible, as it may be removed or be changed in the future.

This method returns an undefined value.

Remove the registered query list for a connection when its transaction has ended.

Parameters:

  • connection (Object) —

    the connection adapter the transaction was opened on



241
242
243
244
 
# File 'lib/active_record_query_counter.rb', line 241

def unregister_transaction_queries(connection)
  ActiveSupport::IsolatedExecutionState[:active_record_query_counter_transaction_queries]&.delete(connection)
  nil
end