1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
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
|
require "cases/helper"
require "models/developer"
require "models/post"
require "active_support/log_subscriber/test_helper"
class LogSubscriberTest < ActiveRecord::TestCase
include ActiveSupport::LogSubscriber::TestHelper
include ActiveSupport::BufferedLogger::Severity
class TestDebugLogSubscriber < ActiveRecord::LogSubscriber
attr_reader :debugs
def initialize
@debugs = []
super
end
def debug message
@debugs << message
end
end
fixtures :posts
def setup
@old_logger = ActiveRecord::Base.logger
@using_identity_map = ActiveRecord::IdentityMap.enabled?
ActiveRecord::IdentityMap.enabled = false
Developer.primary_key
super
ActiveRecord::LogSubscriber.attach_to(:active_record)
end
def teardown
super
ActiveRecord::LogSubscriber.log_subscribers.pop
ActiveRecord::Base.logger = @old_logger
ActiveRecord::IdentityMap.enabled = @using_identity_map
end
def set_logger(logger)
ActiveRecord::Base.logger = logger
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!' }))
assert_equal 1, logger.debugs.length
logger.sql(event.new(0, { :sql => 'hi mom!', :name => 'foo' }))
assert_equal 2, logger.debugs.length
logger.sql(event.new(0, { :sql => 'hi mom!', :name => 'SCHEMA' }))
assert_equal 2, logger.debugs.length
end
def test_ignore_binds_payload_with_nil_column
event = Struct.new(:duration, :payload)
logger = TestDebugLogSubscriber.new
logger.sql(event.new(0, :sql => 'hi mom!', :binds => [[nil, 1]]))
assert_equal 1, logger.debugs.length
end
def test_basic_query_logging
Developer.all
wait
assert_equal 1, @logger.logged(:debug).size
assert_match(/Developer Load/, @logger.logged(:debug).last)
assert_match(/SELECT .*?FROM .?developers.?/i, @logger.logged(:debug).last)
end
def test_exists_query_logging
Developer.exists? 1
wait
assert_equal 1, @logger.logged(:debug).size
assert_match(/Developer Exists/, @logger.logged(:debug).last)
assert_match(/SELECT .*?FROM .?developers.?/i, @logger.logged(:debug).last)
end
def test_cached_queries
ActiveRecord::Base.cache do
Developer.all
Developer.all
end
wait
assert_equal 2, @logger.logged(:debug).size
assert_match(/CACHE/, @logger.logged(:debug).last)
assert_match(/SELECT .*?FROM .?developers.?/i, @logger.logged(:debug).last)
end
def test_basic_query_doesnt_log_when_level_is_not_debug
@logger.level = INFO
Developer.all
wait
assert_equal 0, @logger.logged(:debug).size
end
def test_cached_queries_doesnt_log_when_level_is_not_debug
@logger.level = INFO
ActiveRecord::Base.cache do
Developer.all
Developer.all
end
wait
assert_equal 0, @logger.logged(:debug).size
end
def test_initializes_runtime
Thread.new { assert_equal 0, ActiveRecord::LogSubscriber.runtime }.join
end
def test_log
ActiveRecord::IdentityMap.use do
Post.find 1
Post.find 1
end
wait
assert_match(/From Identity Map/, @logger.logged(:debug).last)
end
end
|
