Skip to content

Commit

Permalink
Fix data issue when capturing instance variables
Browse files Browse the repository at this point in the history
  • Loading branch information
@jgillson
jgillson committed Oct 28, 2020
1 parent 34650a5 commit 5657fd2
Show file tree
Hide file tree
Showing 6 changed files with 58 additions and 53 deletions.
2 changes: 1 addition & 1 deletion lib/debug_logging/class_notifier.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@ def notifies(*methods_to_notify)
proxy
end
ActiveSupport::Notifications.instrument(
debug_event_name_to_s(method_to_notify: method_to_notify), { args: args }.merge(payload)
debug_event_name_to_s(method_to_notify: method_to_notify), { debug_args: args }.merge(payload)
) do
original_method.call(*args, &block)
end
Expand Down
7 changes: 4 additions & 3 deletions lib/debug_logging/instance_notifier_modulizer.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -26,14 +26,15 @@ def self.to_mod(methods_to_notify: nil)
instance_variable_set(DebugLogging::Configuration.config_pointer('i', method_to_notify), proxy)
proxy
end
paydirt = { debug_args: args }
if payload.key?(:instance_variables)
payload[:instance_variables].each do |k|
payload[k] = instance_variable_get("@#{k}") if instance_variable_get("@#{k}")
paydirt[k] = instance_variable_get("@#{k}") if instance_variable_get("@#{k}")
end
payload.delete(:instance_variables)
end
paydirt.merge!(payload.reject { |k| k == :instance_variables })
ActiveSupport::Notifications.instrument(
self.class.debug_event_name_to_s(method_to_notify: method_to_notify), { args: args }.merge(payload)
self.class.debug_event_name_to_s(method_to_notify: method_to_notify), paydirt
) do
super(*args, &block)
end
Expand Down
32 changes: 16 additions & 16 deletions spec/debug_logging/class_notifier_spec.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,10 +20,10 @@
complete_notified_klass.k_with_dsplat(a: 'a')
end
expect(output).to match(/k_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[{:a=>"a"}\]}/)
expect(output).to match(/payload={:debug_args=>\[{:a=>"a"}\]}/)
expect(complete_notified_klass.instance_variable_get(DebugLogging::Configuration.config_pointer('k', :k_with_dsplat))).to receive(:log)
expect(@events).to contain_exactly(
have_attributes(name: 'k_with_dsplat.log', payload: { args: [{ a: 'a' }] })
have_attributes(name: 'k_with_dsplat.log', payload: { debug_args: [{ a: 'a' }] })
)
complete_notified_klass.k_with_dsplat(a: 'a')
end
Expand All @@ -34,10 +34,10 @@
complete_notified_klass.k_with_dsplat_payload(a: 'a')
end
expect(output).to match(/k_with_dsplat_payload.log/)
expect(output).to match(/payload={:args=>\[{:a=>"a"}\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}\n/)
expect(output).to match(/payload={:debug_args=>\[{:a=>"a"}\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}\n/)
expect(complete_notified_klass.instance_variable_get(DebugLogging::Configuration.config_pointer('k', :k_with_dsplat_payload))).to receive(:log).once.and_call_original
expect(@events).to contain_exactly(
have_attributes(name: 'k_with_dsplat_payload.log', payload: { args: [{ a: 'a' }], id: 1, first_name: 'Joe', last_name: 'Schmoe' })
have_attributes(name: 'k_with_dsplat_payload.log', payload: { debug_args: [{ a: 'a' }], id: 1, first_name: 'Joe', last_name: 'Schmoe' })
)
complete_notified_klass.k_with_dsplat_payload(a: 'a')
end
Expand All @@ -59,24 +59,24 @@
complete_notified_klass.k_with_dsplat
end
expect(output).to match(/i.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(output).to match(/i_with_ssplat.log/)
expect(output).to match(/payload={:args=>\[\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}/)
expect(output).to match(/payload={:debug_args=>\[\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}/)
expect(output).to match(/i_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[\], :salutation=>"Mr.", :suffix=>"Jr."}/)
expect(output).to match(/payload={:debug_args=>\[\], :salutation=>"Mr.", :suffix=>"Jr."}/)
expect(output).to match(/k.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(output).to match(/k_with_ssplat.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(output).to match(/k_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(@events).to contain_exactly(
have_attributes(name: 'i.log', payload: { args: [] }),
have_attributes(name: 'i_with_ssplat.log', payload: { args: [], id: 1, first_name: 'Joe', last_name: 'Schmoe' }),
have_attributes(name: 'i_with_dsplat.log', payload: { args: [], salutation: 'Mr.', suffix: 'Jr.' }),
have_attributes(name: 'k.log', payload: { args: [] }),
have_attributes(name: 'k_with_ssplat.log', payload: { args: [] }),
have_attributes(name: 'k_with_dsplat.log', payload: { args: [] })
have_attributes(name: 'i.log', payload: { debug_args: [] }),
have_attributes(name: 'i_with_ssplat.log', payload: { debug_args: [], id: 1, first_name: 'Joe', last_name: 'Schmoe' }),
have_attributes(name: 'i_with_dsplat.log', payload: { debug_args: [], salutation: 'Mr.', suffix: 'Jr.' }),
have_attributes(name: 'k.log', payload: { debug_args: [] }),
have_attributes(name: 'k_with_ssplat.log', payload: { debug_args: [] }),
have_attributes(name: 'k_with_dsplat.log', payload: { debug_args: [] })
)
end

Expand Down
20 changes: 10 additions & 10 deletions spec/debug_logging/configuration_spec.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -62,13 +62,13 @@
instance_notified_klass_explicit.new(action: 'Update', id: 1, msg: { greeting: 'hi' }).i_with_instance_vars
end
expect(output).to match(/i.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(output).to match(/i_with_ssplat.log/)
expect(output).to match(/payload={:args=>\[\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}/)
expect(output).to match(/payload={:debug_args=>\[\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}/)
expect(output).to match(/i_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[\], :salutation=>"Mr.", :suffix=>"Jr."}/)
expect(output).to match(/payload={:debug_args=>\[\], :salutation=>"Mr.", :suffix=>"Jr."}/)
expect(output).to match(/i_with_instance_vars.log/)
expect(output).to match(/payload={:args=>\[\], :action=>"Update", :id=>1, :msg=>{:greeting=>"hi"}}/)
expect(output).to match(/payload={:debug_args=>\[\], :action=>"Update", :id=>1, :msg=>{:greeting=>"hi"}}/)
end
end
context 'class logging' do
Expand Down Expand Up @@ -120,17 +120,17 @@
complete_notified_klass.k_with_dsplat
end
expect(output).to match(/i.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(output).to match(/i_with_ssplat.log/)
expect(output).to match(/payload={:args=>\[\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}/)
expect(output).to match(/payload={:debug_args=>\[\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}/)
expect(output).to match(/i_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[\], :salutation=>"Mr.", :suffix=>"Jr."}/)
expect(output).to match(/payload={:debug_args=>\[\], :salutation=>"Mr.", :suffix=>"Jr."}/)
expect(output).to match(/k.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(output).to match(/k_with_ssplat.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(output).to match(/k_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
end
end
end
Expand Down
44 changes: 24 additions & 20 deletions spec/debug_logging/instance_notifier_spec.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -20,20 +20,24 @@
instance_notified_klass_explicit.new.i_with_ssplat
instance_notified_klass_explicit.new.i_with_dsplat
instance_notified_klass_explicit.new(action: 'Update', id: 1, msg: { greeting: 'hi' }).i_with_instance_vars
instance_notified_klass_explicit.new(action: 'Create', id: 2, msg: { greeting: 'bye' }).i_with_instance_vars
end
expect(output).to match(/i.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(output).to match(/i_with_ssplat.log/)
expect(output).to match(/payload={:args=>\[\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}/)
expect(output).to match(/payload={:debug_args=>\[\], :id=>1, :first_name=>"Joe", :last_name=>"Schmoe"}/)
expect(output).to match(/i_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[\], :salutation=>"Mr.", :suffix=>"Jr."}/)
expect(output).to match(/payload={:debug_args=>\[\], :salutation=>"Mr.", :suffix=>"Jr."}/)
expect(output).to match(/i_with_instance_vars.log/)
expect(output).to match(/payload={:args=>\[\], :action=>"Update", :id=>1, :msg=>{:greeting=>"hi"}}/)
expect(output).to match(/payload={:debug_args=>\[\], :action=>"Update", :id=>1, :msg=>{:greeting=>"hi"}}/)
expect(output).to match(/i_with_instance_vars.log/)
expect(output).to match(/payload={:debug_args=>\[\], :action=>"Create", :id=>2, :msg=>{:greeting=>"bye"}}/)
expect(@events).to contain_exactly(
have_attributes(name: 'i.log', payload: { args: [] }),
have_attributes(name: 'i_with_ssplat.log', payload: { args: [], id: 1, first_name: 'Joe', last_name: 'Schmoe' }),
have_attributes(name: 'i_with_dsplat.log', payload: { args: [], salutation: 'Mr.', suffix: 'Jr.' }),
have_attributes(name: 'i_with_instance_vars.log', payload: { args: [], action: 'Update', id: 1, msg: { greeting: 'hi' } })
have_attributes(name: 'i.log', payload: { debug_args: [] }),
have_attributes(name: 'i_with_ssplat.log', payload: { debug_args: [], id: 1, first_name: 'Joe', last_name: 'Schmoe' }),
have_attributes(name: 'i_with_dsplat.log', payload: { debug_args: [], salutation: 'Mr.', suffix: 'Jr.' }),
have_attributes(name: 'i_with_instance_vars.log', payload: { debug_args: [], action: 'Update', id: 1, msg: { greeting: 'hi' } }),
have_attributes(name: 'i_with_instance_vars.log', payload: { debug_args: [], action: 'Create', id: 2, msg: { greeting: 'bye' } })
)
end

Expand All @@ -52,9 +56,9 @@
instance_notified_klass_dynamic.new.i
end
expect(output).to match(/i.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(@events).to contain_exactly(
have_attributes(name: 'i.log', payload: { args: [] })
have_attributes(name: 'i.log', payload: { debug_args: [] })
)
end

Expand All @@ -69,9 +73,9 @@
instance_notified_klass_dynamic.new.i_with_ssplat('a', 1, true, ['b', 2, false], { c: :d, e: :f })
end
expect(output).to match(/i_with_ssplat.log/)
expect(output).to match(/payload={:args=>\["a", 1, true, \["b", 2, false\], {:c=>:d, :e=>:f}\]}/)
expect(output).to match(/payload={:debug_args=>\["a", 1, true, \["b", 2, false\], {:c=>:d, :e=>:f}\]}/)
expect(@events).to contain_exactly(
have_attributes(name: 'i_with_ssplat.log', payload: { args: ['a', 1, true, ['b', 2, false], { c: :d, e: :f }] })
have_attributes(name: 'i_with_ssplat.log', payload: { debug_args: ['a', 1, true, ['b', 2, false], { c: :d, e: :f }] })
)
end

Expand All @@ -86,9 +90,9 @@
instance_notified_klass_dynamic.new.i_with_dsplat(a: 'a', b: 1, c: true, d: ['b', 2, false], e: { c: :d, e: :f })
end
expect(output).to match(/i_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[{:a=>"a", :b=>1, :c=>true, :d=>\["b", 2, false\], :e=>{:c=>:d, :e=>:f}}\]}/)
expect(output).to match(/payload={:debug_args=>\[{:a=>"a", :b=>1, :c=>true, :d=>\["b", 2, false\], :e=>{:c=>:d, :e=>:f}}\]}/)
expect(@events).to contain_exactly(
have_attributes(name: 'i_with_dsplat.log', payload: { args: [{ a: 'a', b: 1, c: true, d: ['b', 2, false], e: { c: :d, e: :f } }] })
have_attributes(name: 'i_with_dsplat.log', payload: { debug_args: [{ a: 'a', b: 1, c: true, d: ['b', 2, false], e: { c: :d, e: :f } }] })
)
end

Expand Down Expand Up @@ -123,9 +127,9 @@
singleton_notified_klass.k
end
expect(output).to match(/k.log/)
expect(output).to match(/payload={:args=>\[\]}/)
expect(output).to match(/payload={:debug_args=>\[\]}/)
expect(@events).to contain_exactly(
have_attributes(name: 'k.log', payload: { args: [] })
have_attributes(name: 'k.log', payload: { debug_args: [] })
)
end

Expand All @@ -141,9 +145,9 @@
end

expect(output).to match(/k_with_ssplat.log/)
expect(output).to match(/payload={:args=>\["a", 1, true, \["b", 2, false\], {:c=>:d, :e=>:f}\]}/)
expect(output).to match(/payload={:debug_args=>\["a", 1, true, \["b", 2, false\], {:c=>:d, :e=>:f}\]}/)
expect(@events).to contain_exactly(
have_attributes(name: 'k_with_ssplat.log', payload: { args: ['a', 1, true, ['b', 2, false], { c: :d, e: :f }] })
have_attributes(name: 'k_with_ssplat.log', payload: { debug_args: ['a', 1, true, ['b', 2, false], { c: :d, e: :f }] })
)
end

Expand All @@ -158,9 +162,9 @@
singleton_notified_klass.k_with_dsplat(a: 'a', b: 1, c: true, d: ['b', 2, false], e: { c: :d, e: :f })
end
expect(output).to match(/k_with_dsplat.log/)
expect(output).to match(/payload={:args=>\[{:a=>"a", :b=>1, :c=>true, :d=>\["b", 2, false\], :e=>{:c=>:d, :e=>:f}}\]}/)
expect(output).to match(/payload={:debug_args=>\[{:a=>"a", :b=>1, :c=>true, :d=>\["b", 2, false\], :e=>{:c=>:d, :e=>:f}}\]}/)
expect(@events).to contain_exactly(
have_attributes(name: 'k_with_dsplat.log', payload: { args: [{ a: 'a', b: 1, c: true, d: ['b', 2, false], e: { c: :d, e: :f } }] })
have_attributes(name: 'k_with_dsplat.log', payload: { debug_args: [{ a: 'a', b: 1, c: true, d: ['b', 2, false], e: { c: :d, e: :f } }] })
)
end

Expand Down
6 changes: 3 additions & 3 deletions spec/debug_logging/log_subscriber_spec.rb
View file
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,7 @@

expect(@log_subscriber.event).to be_a_kind_of(ActiveSupport::Notifications::Event)
expect(@log_subscriber.event.name).to eq('k_with_dsplat.log')
expect(@log_subscriber.event.payload).to eq({ args: [{ a: 'a' }] })
expect(@log_subscriber.event.payload).to eq({ debug_args: [{ a: 'a' }] })
end
end

Expand All @@ -32,7 +32,7 @@

expect(@log_subscriber.event).to be_a_kind_of(ActiveSupport::Notifications::Event)
expect(@log_subscriber.event.name).to eq('k_with_dsplat_payload.log')
expect(@log_subscriber.event.payload).to eq({ args: [{ a: 'a' }], id: 1, first_name: 'Joe', last_name: 'Schmoe' })
expect(@log_subscriber.event.payload).to eq({ debug_args: [{ a: 'a' }], id: 1, first_name: 'Joe', last_name: 'Schmoe' })
end
end

Expand All @@ -45,7 +45,7 @@

expect(@log_subscriber.event).to be_a_kind_of(ActiveSupport::Notifications::Event)
expect(@log_subscriber.event.name).to eq('k_with_ssplat_error.log')
expect(@log_subscriber.event.payload).to include({ args: [{ a: 'a' }], exception: ['StandardError', 'bad method!'] })
expect(@log_subscriber.event.payload).to include({ debug_args: [{ a: 'a' }], exception: ['StandardError', 'bad method!'] })
end
end
end
Expand Down

0 comments on commit 5657fd2

Please sign in to comment.