Skip to content

HTTPS clone URL

Subversion checkout URL

You can clone with
or
.
Download ZIP
Browse files

use a hash to collect optional statistics about the instrumentation

  • Loading branch information...
commit b7e0408ca922cf51228818edbfdcd5c63e3cb84e 1 parent d02f2d2
@tenderlove tenderlove authored
View
18 activerecord/lib/active_record/connection_adapters/abstract_adapter.rb
@@ -36,9 +36,12 @@ class AbstractAdapter
define_callbacks :checkout, :checkin
+ @@row_even = true
+
def initialize(connection, logger = nil) #:nodoc:
@active = nil
@connection, @logger = connection, logger
+ @runtime = 0
@query_cache_enabled = false
@query_cache = {}
end
@@ -89,6 +92,11 @@ def prefetch_primary_key?(table_name = nil)
false
end
+ def reset_runtime #:nodoc:
+ rt, @runtime = @runtime, 0
+ rt
+ end
+
# QUOTING ==================================================
# Override to return the quoted table name. Defaults to column quoting.
@@ -191,10 +199,16 @@ def current_savepoint_name
def log(sql, name)
name ||= "SQL"
- ActiveSupport::Notifications.instrument("sql.active_record",
- :sql => sql, :name => name, :connection_id => object_id) do
+ instrumenter = ActiveSupport::Notifications.instrumenter
+ info = {}
+
+ result = instrumenter.instrument("sql.active_record",
+ {:sql => sql, :name => name, :connection_id => object_id}, info) do
yield
end
+ @runtime += info[:elapsed]
+
+ result
rescue Exception => e
message = "#{e.class.name}: #{e.message}: #{sql}"
@logger.debug message if @logger
View
16 activerecord/lib/active_record/log_subscriber.rb
@@ -1,25 +1,11 @@
module ActiveRecord
class LogSubscriber < ActiveSupport::LogSubscriber
- def self.runtime=(value)
- Thread.current["active_record_sql_runtime"] = value
- end
-
- def self.runtime
- Thread.current["active_record_sql_runtime"] ||= 0
- end
-
- def self.reset_runtime
- rt, self.runtime = runtime, 0
- rt
- end
-
def initialize
super
@odd_or_even = false
end
def sql(event)
- self.class.runtime += event.duration
return unless logger.debug?
name = '%s (%.1fms)' % [event.payload[:name], event.duration]
@@ -45,4 +31,4 @@ def logger
end
end
-ActiveRecord::LogSubscriber.attach_to :active_record
+ActiveRecord::LogSubscriber.attach_to :active_record
View
4 activerecord/lib/active_record/railties/controller_runtime.rb
@@ -11,9 +11,9 @@ module ControllerRuntime
def cleanup_view_runtime
if ActiveRecord::Base.connected?
- db_rt_before_render = ActiveRecord::LogSubscriber.reset_runtime
+ db_rt_before_render = ActiveRecord::Base.connection.reset_runtime
runtime = super
- db_rt_after_render = ActiveRecord::LogSubscriber.reset_runtime
+ db_rt_after_render = ActiveRecord::Base.connection.reset_runtime
self.db_runtime = db_rt_before_render + db_rt_after_render
runtime - db_rt_after_render
else
View
4 activerecord/test/cases/log_subscriber_test.rb
@@ -57,8 +57,4 @@ def test_cached_queries_doesnt_log_when_level_is_not_debug
wait
assert_equal 0, @logger.logged(:debug).size
end
-
- def test_initializes_runtime
- Thread.new { assert_equal 0, ActiveRecord::LogSubscriber.runtime }.join
- end
end
View
16 activesupport/lib/active_support/notifications.rb
@@ -47,11 +47,21 @@ class << self
attr_writer :notifier
delegate :publish, :unsubscribe, :to => :notifier
- def instrument(name, payload = {})
+ def instrument(name, payload = {}, info = nil)
if @instrumenters[name]
- instrumenter.instrument(name, payload) { yield payload if block_given? }
+ instrumenter.instrument(name, payload, info) {
+ yield payload if block_given?
+ }
else
- yield payload if block_given?
+ value = nil
+ if block_given?
+ if info
+ info[:elapsed] = Benchmark.ms { value = yield payload }
+ else
+ value = yield payload
+ end
+ end
+ value
end
end
View
11 activesupport/lib/active_support/notifications/instrumenter.rb
@@ -14,16 +14,19 @@ def initialize(notifier)
# Instrument the given block by measuring the time taken to execute it
# and publish it. Notice that events get sent even if an error occurs
# in the passed-in block
- def instrument(name, payload={})
- started = Time.now
-
+ def instrument(name, payload={}, info = nil)
begin
+ started = Time.now
yield
rescue Exception => e
payload[:exception] = [e.class.name, e.message]
raise e
ensure
- @notifier.publish(name, started, Time.now, @id, payload)
+ finished = Time.now
+ if info
+ info[:elapsed] = 1000.0 * (finished.to_f - started.to_f)
+ end
+ @notifier.publish(name, started, finished, @id, payload)
end
end
View
9 activesupport/test/notifications_test.rb
@@ -172,6 +172,15 @@ def test_instrument_publishes_when_exception_is_raised
:exception => ["RuntimeError", "FAIL"]], @events.last.payload
end
+ def test_elapsed
+ instrument(:something) do
+ sleep(0.001)
+ end
+
+ # Elapsed returns duration in ms
+ assert_in_delta 1, ActiveSupport::Notifications.instrumenter.elapsed, 100
+ end
+
def test_event_is_pushed_even_without_block
instrument(:awesome, :payload => "notifications")
assert_equal 1, @events.size
Please sign in to comment.
Something went wrong with that request. Please try again.