From 7f51d199b6925a6c8f0ddd883a8e2f5dd706fa6d Mon Sep 17 00:00:00 2001 From: Tony Hsu Date: Mon, 26 Jun 2023 14:13:12 +0200 Subject: [PATCH] Improve semantic logger test --- .../semantic_logger/instrumentation.rb | 1 + .../semantic_logger/instrumentation_spec.rb | 161 ++++++++++++------ 2 files changed, 106 insertions(+), 56 deletions(-) diff --git a/lib/datadog/tracing/contrib/semantic_logger/instrumentation.rb b/lib/datadog/tracing/contrib/semantic_logger/instrumentation.rb index 152c347c1eb..705005e00e0 100644 --- a/lib/datadog/tracing/contrib/semantic_logger/instrumentation.rb +++ b/lib/datadog/tracing/contrib/semantic_logger/instrumentation.rb @@ -15,6 +15,7 @@ def self.included(base) # Instance methods for configuration module InstanceMethods def log(log, message = nil, progname = nil, &block) + return super unless Datadog.configuration.tracing.log_injection return super unless Datadog.configuration.tracing[:semantic_logger].enabled return super unless log.is_a?(::SemanticLogger::Log) diff --git a/spec/datadog/tracing/contrib/semantic_logger/instrumentation_spec.rb b/spec/datadog/tracing/contrib/semantic_logger/instrumentation_spec.rb index f1806286bed..a540d878884 100644 --- a/spec/datadog/tracing/contrib/semantic_logger/instrumentation_spec.rb +++ b/spec/datadog/tracing/contrib/semantic_logger/instrumentation_spec.rb @@ -5,98 +5,147 @@ require 'datadog/tracing/utils' RSpec.describe Datadog::Tracing::Contrib::SemanticLogger::Instrumentation do - let(:instrumented) { SemanticLogger::Logger.new('TestClass') } + let(:logger) { SemanticLogger::Logger.new('TestClass') } + let(:log_injection) { true } + let(:semantic_logger_enabled) { true } before do Datadog.configure do |c| - c.tracing.instrument :semantic_logger + c.tracing.log_injection = log_injection + c.tracing.instrument :semantic_logger, enabled: semantic_logger_enabled end end + after do + Datadog.configuration.tracing.reset! + Datadog.configuration.tracing[:semantic_logger].reset_options! + end + + let(:log_output) do + StringIO.new + end + + around do |example| + SemanticLogger.add_appender(io: log_output) + example.run + SemanticLogger.clear_appenders! + SemanticLogger.close + end + describe '#log' do subject(:log) do ThreadHelpers.with_leaky_thread_creation('semantic_logger log') do - instrumented.log(event) + logger.log(event).tap do + SemanticLogger.flush + end end end - let(:event) { SemanticLogger::Log.new('test', :info).tap { |e| e.named_tags = original_tags } } - let(:original_tags) { { original: 'tag' } } + + let(:event) do + SemanticLogger::Log.new('Mamamia!', :info).tap do |e| + e.named_tags = { original: 'tag' } + end + end + + let(:trace_id) { Datadog::Tracing::Utils.next_id } + let(:span_id) { Datadog::Tracing::Utils.next_id } let(:correlation) do Datadog::Tracing::Correlation::Identifier.new( trace_id: trace_id, span_id: span_id, - env: env, - service: service, - version: version, + env: 'production', + service: 'MyService', + version: '1.2.3' , ) end - let(:trace_id) { Datadog::Tracing::Utils.next_id } - let(:span_id) { Datadog::Tracing::Utils.next_id } - let(:env) { 'env' } - let(:service) { 'service' } - let(:version) { 'version' } before do - expect(Datadog::Tracing).to receive(:correlation).and_return(correlation) + allow(Datadog::Tracing).to receive(:correlation).and_return(correlation) end - it 'merges correlation data with original options' do - assertion = proc do |event| - expect(event.named_tags).to eq( - { original: 'tag', - dd: { - env: 'env', - service: 'service', - span_id: span_id.to_s, - trace_id: trace_id.to_s, - version: 'version' - }, - ddsource: 'ruby' } - ) + context "when log_injection and semantic_logger enabled"do + it 'merges correlation data with original options' do + log + + log_entry = log_output.string + + expect(log_entry).to include 'Mamamia!' + expect(log_entry).to include 'original: tag' + + expect(log_entry).to include trace_id.to_s + expect(log_entry).to include span_id.to_s + expect(log_entry).to include 'production' + expect(log_entry).to include 'MyService' + expect(log_entry).to include '1.2.3' + expect(log_entry).to include 'ddsource: ruby' end + end - if SemanticLogger::Logger.respond_to?(:call_subscribers) - expect(SemanticLogger::Logger).to receive(:call_subscribers, &assertion) # semantic_logger >= 4.4.0 - else - ThreadHelpers.with_leaky_thread_creation('semantic_logger processor') do - expect(SemanticLogger::Processor).to receive(:<<, &assertion) # semantic_logger < 4.4.0 - end + context "when log_injection disabled" do + let(:log_injection) { false } + + it 'does not merges correlation data with original options' do + log + + log_entry = log_output.string + + expect(log_entry).to include 'Mamamia!' + expect(log_entry).to include 'original: tag' + + expect(log_entry).not_to include trace_id.to_s + expect(log_entry).not_to include span_id.to_s + expect(log_entry).not_to include 'production' + expect(log_entry).not_to include 'MyService' + expect(log_entry).not_to include '1.2.3' + expect(log_entry).not_to include 'ddsource: ruby' end + end + + context "when ssemantic_logger disabled" do + let(:semantic_logger_enabled) { false } + + it 'does not merges correlation data with original options' do + log + + log_entry = log_output.string + + expect(log_entry).to include 'Mamamia!' + expect(log_entry).to include 'original: tag' - log + expect(log_entry).not_to include trace_id.to_s + expect(log_entry).not_to include span_id.to_s + expect(log_entry).not_to include 'production' + expect(log_entry).not_to include 'MyService' + expect(log_entry).not_to include '1.2.3' + expect(log_entry).not_to include 'ddsource: ruby' + + end end context 'when log in Logger compatible mode' do subject(:log) do ThreadHelpers.with_leaky_thread_creation('semantic_logger log_compatible') do - instrumented.log(::Logger::INFO, 'test') + logger.log(::Logger::INFO, 'Mamamia!').tap do + SemanticLogger.flush + end end end - it 'merges correlation data with original options' do - assertion = proc do |event| - expect(event.named_tags).to eq( - { dd: { - env: 'env', - service: 'service', - span_id: span_id.to_s, - trace_id: trace_id.to_s, - version: 'version' - }, - ddsource: 'ruby' } - ) - end + it 'merges correlation data' do + log - if SemanticLogger::Logger.respond_to?(:call_subscribers) - expect(SemanticLogger::Logger).to receive(:call_subscribers, &assertion) # semantic_logger >= 4.4.0 - else - ThreadHelpers.with_leaky_thread_creation('semantic_logger processor') do - expect(SemanticLogger::Processor).to receive(:<<, &assertion) # semantic_logger < 4.4.0 - end - end + log_entry = log_output.string - log + expect(log_entry).to include 'Mamamia!' + expect(log_entry).not_to include 'original: tag' + + expect(log_entry).to include trace_id.to_s + expect(log_entry).to include span_id.to_s + expect(log_entry).to include 'production' + expect(log_entry).to include 'MyService' + expect(log_entry).to include '1.2.3' + expect(log_entry).to include 'ddsource: ruby' end end end