Skip to content

Commit

Permalink
Fix assertion for old rails_semantic_logger
Browse files Browse the repository at this point in the history
  • Loading branch information
TonyCTHsu committed Jun 22, 2023
1 parent 99cebf4 commit 8b08633
Showing 1 changed file with 103 additions and 66 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,9 @@
[logging_test_controller]
end

# RailsSemanticLogger starting from `4.3.0`, uses `swap_subscriber` strategy,
# Replacing the default ones with its own.
# ::ActionView::LogSubscriber => ::RailsSemanticLogger::ActionView::LogSubscriber
#
# This request-response cycle would creates 6 log entries
#
Expand All @@ -22,6 +25,15 @@
# 5. ActionView -- Rendered
# 6. LoggingTestController -- Completed
#
# Before `4.3.0`, without its own LogSubscriber, it would creates 5 log entries
#
# 1. Rack -- Started
# 2. LoggingTestController -- Processing
# 3. LoggingTestController -- MY VOICE SHALL BE HEARD
# 4. (Missing)
# 5. ActionView -- Rendered
# 6. LoggingTestController -- Completed
#
let(:logging_test_controller) do
stub_const(
'LoggingTestController',
Expand Down Expand Up @@ -56,7 +68,7 @@ def index
Datadog.configuration.tracing[:semantic_logger].reset_options!
end

context 'with log injection enabled', if: Rails.version >= '4.0' do
context 'with log injection enabled' do
let(:log_injection) { true }

context 'with Semantic Logger' do
Expand All @@ -78,36 +90,43 @@ def index

expect(logs).to_not be_empty

expect(log_entries).to have(6).items

expect(log_entries).to all include trace.id.to_s
expect(log_entries).to all include 'ddsource: ruby'

rack_started_entry,
controller_processing_entry,
controller_entry,
_rendering_entry,
_rendered_entry,
controller_completed_entry = log_entries

rack_span, controller_span, _render_span = spans

expect(rack_started_entry).to include rack_span.id.to_s
expect(controller_processing_entry).to include rack_span.id.to_s
expect(controller_entry).to include controller_span.id.to_s

# Flaky specs between tests due to ordering of active support subscriptions from
# Datadog tracing and LogSubscriber. To debug, check the value for
# `::ActiveSupport::Notifications.notifier.listeners_for("render_template.action_view")`
#
# The correct order should be
# 1. RailsSemanticLogger::ActionView::LogSubscriber
# 2. Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription
#
# expect(_rendering_entry).to include controller_span.id.to_s
# expect(_rendered_entry).to include _render_span.id.to_s

expect(controller_completed_entry).to include rack_span.id.to_s
if defined?(RailsSemanticLogger::ActionView::LogSubscriber)
expect(log_entries).to have(6).items

expect(log_entries).to all include trace.id.to_s
expect(log_entries).to all include 'ddsource: ruby'

rack_started_entry,
controller_processing_entry,
controller_entry,
_rendering_entry,
_rendered_entry,
controller_completed_entry = log_entries

rack_span, controller_span, _render_span = spans

expect(rack_started_entry).to include rack_span.id.to_s
expect(controller_processing_entry).to include rack_span.id.to_s
expect(controller_entry).to include controller_span.id.to_s

# Flaky specs between tests due to ordering of active support subscriptions from
# Datadog tracing and LogSubscriber. To debug, check the value for
# `::ActiveSupport::Notifications.notifier.listeners_for("render_template.action_view")`
#
# The correct order should be
# 1. RailsSemanticLogger::ActionView::LogSubscriber
# 2. Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription
#
# expect(_rendering_entry).to include controller_span.id.to_s
# expect(_rendered_entry).to include _render_span.id.to_s

expect(controller_completed_entry).to include rack_span.id.to_s
else
expect(log_entries).to have(5).items

expect(log_entries).to all include trace.id.to_s
expect(log_entries).to all include 'ddsource: ruby'
end
end
end

Expand All @@ -121,47 +140,57 @@ def index
# force flush
SemanticLogger.flush


expect(logs).to_not be_empty

expect(log_entries).to have(6).items

expect(log_entries).to all include(trace.id.to_s)
expect(log_entries).to all include('ddsource: ruby')
expect(log_entries).to all include('some_tag')
expect(log_entries).to all include('some_value')

rack_started_entry,
controller_processing_entry,
controller_entry,
_rendering_entry,
_rendered_entry,
controller_completed_entry = log_entries

rack_span, controller_span, _render_span = spans

expect(rack_started_entry).to include rack_span.id.to_s
expect(controller_processing_entry).to include rack_span.id.to_s
expect(controller_entry).to include controller_span.id.to_s

# Flaky specs between tests due to ordering of active support subscriptions from
# Datadog tracing and LogSubscriber. To debug, check the value for
# `::ActiveSupport::Notifications.notifier.listeners_for("render_template.action_view")`
#
# The correct order should be
# 1. RailsSemanticLogger::ActionView::LogSubscriber
# 2. Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription
#
# expect(_rendering_entry).to include controller_span.id.to_s
# expect(_rendered_entry).to include _render_span.id.to_s

expect(controller_completed_entry).to include rack_span.id.to_s
if defined?(RailsSemanticLogger::ActionView::LogSubscriber)
expect(log_entries).to have(6).items

expect(log_entries).to all include(trace.id.to_s)
expect(log_entries).to all include('ddsource: ruby')
expect(log_entries).to all include('some_tag')
expect(log_entries).to all include('some_value')

rack_started_entry,
controller_processing_entry,
controller_entry,
_rendering_entry,
_rendered_entry,
controller_completed_entry = log_entries

rack_span, controller_span, _render_span = spans

expect(rack_started_entry).to include rack_span.id.to_s
expect(controller_processing_entry).to include rack_span.id.to_s
expect(controller_entry).to include controller_span.id.to_s

# Flaky specs between tests due to ordering of active support subscriptions from
# Datadog tracing and LogSubscriber. To debug, check the value for
# `::ActiveSupport::Notifications.notifier.listeners_for("render_template.action_view")`
#
# The correct order should be
# 1. RailsSemanticLogger::ActionView::LogSubscriber
# 2. Datadog::Tracing::Contrib::ActiveSupport::Notifications::Subscription
#
# expect(_rendering_entry).to include controller_span.id.to_s
# expect(_rendered_entry).to include _render_span.id.to_s

expect(controller_completed_entry).to include rack_span.id.to_s
else
expect(log_entries).to have(5).items

expect(log_entries).to all include(trace.id.to_s)
expect(log_entries).to all include('ddsource: ruby')
expect(log_entries).to all include('some_tag')
expect(log_entries).to all include('some_value')
end
end
end
end
end
end

context 'with log injection disabled', if: Rails.version >= '4.0' do
context 'with log injection disabled' do
let(:log_injection) { false }

before do
Expand All @@ -187,7 +216,11 @@ def index

expect(logs).to_not be_empty

expect(log_entries).to have(6).items
if defined?(RailsSemanticLogger::ActionView::LogSubscriber)
expect(log_entries).to have(6).items
else
expect(log_entries).to have(5).items
end

log_entries.each do |l|
expect(l).to_not be_empty
Expand All @@ -210,7 +243,11 @@ def index

expect(logs).to_not be_empty

expect(log_entries).to have(6).items
if defined?(RailsSemanticLogger::ActionView::LogSubscriber)
expect(log_entries).to have(6).items
else
expect(log_entries).to have(5).items
end

log_entries.each do |l|
expect(l).to_not be_empty
Expand Down

0 comments on commit 8b08633

Please sign in to comment.