diff options
Diffstat (limited to 'activerecord/test/cases/log_subscriber_test.rb')
-rw-r--r-- | activerecord/test/cases/log_subscriber_test.rb | 79 |
1 files changed, 45 insertions, 34 deletions
diff --git a/activerecord/test/cases/log_subscriber_test.rb b/activerecord/test/cases/log_subscriber_test.rb index 90ad970e16..e2742ed33e 100644 --- a/activerecord/test/cases/log_subscriber_test.rb +++ b/activerecord/test/cases/log_subscriber_test.rb @@ -1,3 +1,5 @@ +# frozen_string_literal: true + require "cases/helper" require "models/binary" require "models/developer" @@ -21,6 +23,7 @@ class LogSubscriberTest < ActiveRecord::TestCase TRANSACTION: REGEXP_CYAN, OTHER: REGEXP_MAGENTA } + Event = Struct.new(:duration, :payload) class TestDebugLogSubscriber < ActiveRecord::LogSubscriber attr_reader :debugs @@ -30,8 +33,9 @@ class LogSubscriberTest < ActiveRecord::TestCase super end - def debug(message) - @debugs << message + def debug(progname = nil, &block) + @debugs << progname + super end end @@ -55,25 +59,22 @@ class LogSubscriberTest < ActiveRecord::TestCase end def test_schema_statements_are_ignored - event = Struct.new(:duration, :payload) - logger = TestDebugLogSubscriber.new assert_equal 0, logger.debugs.length - logger.sql(event.new(0, sql: "hi mom!")) + logger.sql(Event.new(0.9, sql: "hi mom!")) assert_equal 1, logger.debugs.length - logger.sql(event.new(0, sql: "hi mom!", name: "foo")) + logger.sql(Event.new(0.9, sql: "hi mom!", name: "foo")) assert_equal 2, logger.debugs.length - logger.sql(event.new(0, sql: "hi mom!", name: "SCHEMA")) + logger.sql(Event.new(0.9, sql: "hi mom!", name: "SCHEMA")) assert_equal 2, logger.debugs.length end def test_sql_statements_are_not_squeezed - event = Struct.new(:duration, :payload) logger = TestDebugLogSubscriber.new - logger.sql(event.new(0, sql: "ruby rails")) + logger.sql(Event.new(0.9, sql: "ruby rails")) assert_match(/ruby rails/, logger.debugs.first) end @@ -86,56 +87,51 @@ class LogSubscriberTest < ActiveRecord::TestCase end def test_basic_query_logging_coloration - event = Struct.new(:duration, :payload) logger = TestDebugLogSubscriber.new logger.colorize_logging = true SQL_COLORINGS.each do |verb, color_regex| - logger.sql(event.new(0, sql: verb.to_s)) + logger.sql(Event.new(0.9, sql: verb.to_s)) assert_match(/#{REGEXP_BOLD}#{color_regex}#{verb}#{REGEXP_CLEAR}/i, logger.debugs.last) end end def test_basic_payload_name_logging_coloration_generic_sql - event = Struct.new(:duration, :payload) logger = TestDebugLogSubscriber.new logger.colorize_logging = true SQL_COLORINGS.each do |verb, _| - logger.sql(event.new(0, sql: verb.to_s)) - assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0.0ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) + logger.sql(Event.new(0.9, sql: verb.to_s)) + assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0\.9ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) - logger.sql(event.new(0, sql: verb.to_s, name: "SQL")) - assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA}SQL \(0.0ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) + logger.sql(Event.new(0.9, sql: verb.to_s, name: "SQL")) + assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA}SQL \(0\.9ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) end end def test_basic_payload_name_logging_coloration_named_sql - event = Struct.new(:duration, :payload) logger = TestDebugLogSubscriber.new logger.colorize_logging = true SQL_COLORINGS.each do |verb, _| - logger.sql(event.new(0, sql: verb.to_s, name: "Model Load")) - assert_match(/#{REGEXP_BOLD}#{REGEXP_CYAN}Model Load \(0.0ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) + logger.sql(Event.new(0.9, sql: verb.to_s, name: "Model Load")) + assert_match(/#{REGEXP_BOLD}#{REGEXP_CYAN}Model Load \(0\.9ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) - logger.sql(event.new(0, sql: verb.to_s, name: "Model Exists")) - assert_match(/#{REGEXP_BOLD}#{REGEXP_CYAN}Model Exists \(0.0ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) + logger.sql(Event.new(0.9, sql: verb.to_s, name: "Model Exists")) + assert_match(/#{REGEXP_BOLD}#{REGEXP_CYAN}Model Exists \(0\.9ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) - logger.sql(event.new(0, sql: verb.to_s, name: "ANY SPECIFIC NAME")) - assert_match(/#{REGEXP_BOLD}#{REGEXP_CYAN}ANY SPECIFIC NAME \(0.0ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) + logger.sql(Event.new(0.9, sql: verb.to_s, name: "ANY SPECIFIC NAME")) + assert_match(/#{REGEXP_BOLD}#{REGEXP_CYAN}ANY SPECIFIC NAME \(0\.9ms\)#{REGEXP_CLEAR}/i, logger.debugs.last) end end def test_query_logging_coloration_with_nested_select - event = Struct.new(:duration, :payload) logger = TestDebugLogSubscriber.new logger.colorize_logging = true SQL_COLORINGS.slice(:SELECT, :INSERT, :UPDATE, :DELETE).each do |verb, color_regex| - logger.sql(event.new(0, sql: "#{verb} WHERE ID IN SELECT")) - assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0.0ms\)#{REGEXP_CLEAR} #{REGEXP_BOLD}#{color_regex}#{verb} WHERE ID IN SELECT#{REGEXP_CLEAR}/i, logger.debugs.last) + logger.sql(Event.new(0.9, sql: "#{verb} WHERE ID IN SELECT")) + assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0\.9ms\)#{REGEXP_CLEAR} #{REGEXP_BOLD}#{color_regex}#{verb} WHERE ID IN SELECT#{REGEXP_CLEAR}/i, logger.debugs.last) end end def test_query_logging_coloration_with_multi_line_nested_select - event = Struct.new(:duration, :payload) logger = TestDebugLogSubscriber.new logger.colorize_logging = true SQL_COLORINGS.slice(:SELECT, :INSERT, :UPDATE, :DELETE).each do |verb, color_regex| @@ -145,13 +141,12 @@ class LogSubscriberTest < ActiveRecord::TestCase SELECT ID FROM THINGS ) EOS - logger.sql(event.new(0, sql: sql)) - assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0.0ms\)#{REGEXP_CLEAR} #{REGEXP_BOLD}#{color_regex}.*#{verb}.*#{REGEXP_CLEAR}/mi, logger.debugs.last) + logger.sql(Event.new(0.9, sql: sql)) + assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0\.9ms\)#{REGEXP_CLEAR} #{REGEXP_BOLD}#{color_regex}.*#{verb}.*#{REGEXP_CLEAR}/mi, logger.debugs.last) end end def test_query_logging_coloration_with_lock - event = Struct.new(:duration, :payload) logger = TestDebugLogSubscriber.new logger.colorize_logging = true sql = <<-EOS @@ -159,14 +154,14 @@ class LogSubscriberTest < ActiveRecord::TestCase (SELECT * FROM mytable FOR UPDATE) ss WHERE col1 = 5; EOS - logger.sql(event.new(0, sql: sql)) - assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0.0ms\)#{REGEXP_CLEAR} #{REGEXP_BOLD}#{SQL_COLORINGS[:LOCK]}.*FOR UPDATE.*#{REGEXP_CLEAR}/mi, logger.debugs.last) + logger.sql(Event.new(0.9, sql: sql)) + assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0\.9ms\)#{REGEXP_CLEAR} #{REGEXP_BOLD}#{SQL_COLORINGS[:LOCK]}.*FOR UPDATE.*#{REGEXP_CLEAR}/mi, logger.debugs.last) sql = <<-EOS LOCK TABLE films IN SHARE MODE; EOS - logger.sql(event.new(0, sql: sql)) - assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0.0ms\)#{REGEXP_CLEAR} #{REGEXP_BOLD}#{SQL_COLORINGS[:LOCK]}.*LOCK TABLE.*#{REGEXP_CLEAR}/mi, logger.debugs.last) + logger.sql(Event.new(0.9, sql: sql)) + assert_match(/#{REGEXP_BOLD}#{REGEXP_MAGENTA} \(0\.9ms\)#{REGEXP_CLEAR} #{REGEXP_BOLD}#{SQL_COLORINGS[:LOCK]}.*LOCK TABLE.*#{REGEXP_CLEAR}/mi, logger.debugs.last) end def test_exists_query_logging @@ -177,6 +172,22 @@ class LogSubscriberTest < ActiveRecord::TestCase assert_match(/SELECT .*?FROM .?developers.?/i, @logger.logged(:debug).last) end + def test_vebose_query_logs + ActiveRecord::Base.verbose_query_logs = true + + logger = TestDebugLogSubscriber.new + logger.sql(Event.new(0, sql: "hi mom!")) + assert_match(/↳/, @logger.logged(:debug).last) + ensure + ActiveRecord::Base.verbose_query_logs = false + end + + def test_verbose_query_logs_disabled_by_default + logger = TestDebugLogSubscriber.new + logger.sql(Event.new(0, sql: "hi mom!")) + assert_no_match(/↳/, @logger.logged(:debug).last) + end + def test_cached_queries ActiveRecord::Base.cache do Developer.all.load |