From 84d35da86c14767c737783cb95dd4624632cc1bd Mon Sep 17 00:00:00 2001 From: Jean Boussier Date: Thu, 22 Sep 2016 15:00:30 +0200 Subject: [PATCH] Preserve cached queries name in AS notifications --- .../connection_adapters/abstract/query_cache.rb | 14 ++++++++++---- .../lib/active_record/explain_subscriber.rb | 7 +++++-- activerecord/lib/active_record/log_subscriber.rb | 1 + activerecord/test/cases/test_case.rb | 7 ++----- 4 files changed, 18 insertions(+), 11 deletions(-) diff --git a/activerecord/lib/active_record/connection_adapters/abstract/query_cache.rb b/activerecord/lib/active_record/connection_adapters/abstract/query_cache.rb index 6ca53c72ce..2f8a89e88e 100644 --- a/activerecord/lib/active_record/connection_adapters/abstract/query_cache.rb +++ b/activerecord/lib/active_record/connection_adapters/abstract/query_cache.rb @@ -65,7 +65,7 @@ module ActiveRecord if @query_cache_enabled && !locked?(arel) arel, binds = binds_from_relation arel, binds sql = to_sql(arel, binds) - cache_sql(sql, binds) { super(sql, name, binds, preparable: preparable) } + cache_sql(sql, name, binds) { super(sql, name, binds, preparable: preparable) } else super end @@ -73,11 +73,17 @@ module ActiveRecord private - def cache_sql(sql, binds) + def cache_sql(sql, name, binds) result = if @query_cache[sql].key?(binds) - ActiveSupport::Notifications.instrument("sql.active_record", - sql: sql, binds: binds, name: "CACHE", connection_id: object_id) + ActiveSupport::Notifications.instrument( + "sql.active_record", + sql: sql, + binds: binds, + name: name, + connection_id: object_id, + cached: true, + ) @query_cache[sql][binds] else @query_cache[sql][binds] = yield diff --git a/activerecord/lib/active_record/explain_subscriber.rb b/activerecord/lib/active_record/explain_subscriber.rb index 706b57842f..abd8cfc8f2 100644 --- a/activerecord/lib/active_record/explain_subscriber.rb +++ b/activerecord/lib/active_record/explain_subscriber.rb @@ -18,10 +18,13 @@ module ActiveRecord # # On the other hand, we want to monitor the performance of our real database # queries, not the performance of the access to the query cache. - IGNORED_PAYLOADS = %w(SCHEMA EXPLAIN CACHE) + IGNORED_PAYLOADS = %w(SCHEMA EXPLAIN) EXPLAINED_SQLS = /\A\s*(with|select|update|delete|insert)\b/i def ignore_payload?(payload) - payload[:exception] || IGNORED_PAYLOADS.include?(payload[:name]) || payload[:sql] !~ EXPLAINED_SQLS + payload[:exception] || + payload[:cached] || + IGNORED_PAYLOADS.include?(payload[:name]) || + payload[:sql] !~ EXPLAINED_SQLS end ActiveSupport::Notifications.subscribe("sql.active_record", new) diff --git a/activerecord/lib/active_record/log_subscriber.rb b/activerecord/lib/active_record/log_subscriber.rb index f31931316c..b27e84a5be 100644 --- a/activerecord/lib/active_record/log_subscriber.rb +++ b/activerecord/lib/active_record/log_subscriber.rb @@ -35,6 +35,7 @@ module ActiveRecord return if IGNORE_PAYLOAD_NAMES.include?(payload[:name]) name = "#{payload[:name]} (#{event.duration.round(1)}ms)" + name = "CACHE #{name}" if payload[:cached] sql = payload[:sql] binds = nil diff --git a/activerecord/test/cases/test_case.rb b/activerecord/test/cases/test_case.rb index 60ac3e08a1..8eddc5a9ed 100644 --- a/activerecord/test/cases/test_case.rb +++ b/activerecord/test/cases/test_case.rb @@ -125,12 +125,9 @@ module ActiveRecord end def call(name, start, finish, message_id, values) + return if values[:cached] + sql = values[:sql] - - # FIXME: this seems bad. we should probably have a better way to indicate - # the query was cached - return if "CACHE" == values[:name] - self.class.log_all << sql self.class.log << sql unless ignore.match?(sql) end