feat: Refine logging offense consolidation even more (3ad60ef5) · Commits · GitLab.org / ruby / gems / labkit-ruby

lib/labkit/logging/field_validator/log_interceptor.rb

+15 −1

Original line number	Diff line number	Diff line
		@@ -57,6 +57,16 @@ module Labkit
		def reset_context_callsite!
		@context_callsite = nil
		end

		# The context prefix that Labkit::Context applies to every field it
		# stores (see Labkit::Context::LOG_KEY). Any deprecated field with
		# this prefix is by convention a context field — owned by whichever
		# provider populates the context (e.g. ApplicationContext) — even
		# when a particular log call happens to pass it directly. Lazily
		# built so the constant is not referenced at load time.
		def context_field_prefix
		@context_field_prefix \|\|= "#{::Labkit::Context::LOG_KEY}."
		end
		end

		def format_data(severity, timestamp, progname, message)
		@@ -75,6 +85,7 @@ module Labkit
		# ApplicationContext) and should be attributed to the context callsite rather
		# than the individual log call site.
		direct_keys = message.is_a?(Hash) ? message.transform_keys(&:to_s).keys.to_set : Set.new
		context_prefix = LogInterceptor.context_field_prefix

		deprecated_lookup = Labkit::Fields::Deprecated.all
		if data.is_a?(Hash)
		@@ -83,7 +94,10 @@ module Labkit
		standard_field = deprecated_lookup[key_str]
		next unless standard_field

		if direct_keys.include?(key_str)
		# context_prefix is the Labkit::Context namespace — the field is conceptually
		# context-owned even if the caller happens to pass it directly. Otherwise
		# use direct-vs-context based on whether the caller actually included it.
		if direct_keys.include?(key_str) && !key_str.start_with?(context_prefix)
		Registry.instance.record_offense(callsite_path, location.lineno, key_str, standard_field, logger_class)
		else
		Registry.instance.record_offense(

spec/labkit/logging/field_validator/log_interceptor_spec.rb

+52 −11

Original line number	Diff line number	Diff line
		@@ -20,7 +20,10 @@ RSpec.describe Labkit::Logging::FieldValidator::LogInterceptor do

		before do
		registry.clear!
		allow(Labkit::Fields::Deprecated).to receive(:all).and_return({ 'meta.user_id' => 'gl_user_id' })
		allow(Labkit::Fields::Deprecated).to receive(:all).and_return({
		'meta.user_id' => 'gl_user_id', # context-namespace field
		'old_field' => 'new_field' # non-namespace field
		})
		end

		around do \|example\|
		@@ -49,8 +52,8 @@ RSpec.describe Labkit::Logging::FieldValidator::LogInterceptor do
		expect(offense['deprecated_field']).to eq('meta.user_id')
		end

		it 'records the logger class' do
		test_logger.format_message('INFO', Time.now.utc, 'test', { 'meta.user_id' => 123 })
		it 'records the logger class for non-meta direct-message offenses' do
		test_logger.format_message('INFO', Time.now.utc, 'test', { 'old_field' => 123 })

		offense = registry.offenses.first
		# Anonymous classes use 'AnonymousLogger' as fallback
		@@ -161,28 +164,43 @@ RSpec.describe Labkit::Logging::FieldValidator::LogInterceptor do
		end
		end

		context 'when deprecated field is passed directly in the message' do
		context 'when a non-meta deprecated field is passed directly in the message' do
		before do
		allow(test_logger).to receive(:determine_callsite).and_return(mock_location)
		end

		it 'attributes the offense to the actual callsite' do
		test_logger.format_message('INFO', Time.now.utc, 'test', { 'meta.user_id' => 123 })
		it 'attributes the offense to the actual callsite with the actual logger class' do
		test_logger.format_message('INFO', Time.now.utc, 'test', { 'old_field' => 123 })

		expect(registry.offenses).not_to be_empty
		offense = registry.offenses.first
		expect(offense['callsite']).to eq('app/test.rb')
		expect(offense['deprecated_field']).to eq('meta.user_id')
		expect(offense['deprecated_field']).to eq('old_field')
		expect(offense['logger_class']).to eq('AnonymousLogger')
		end
		end

		it 'uses the actual callsite even when the same key is also in the context' do
		Labkit::Context.with_context('meta.user_id' => 456) do
		test_logger.format_message('INFO', Time.now.utc, 'test', { 'meta.user_id' => 123 })
		context 'when a meta.* deprecated field is passed directly in the message' do
		before do
		allow(test_logger).to receive(:determine_callsite).and_return(mock_location)
		end

		it 'attributes the offense to the context callsite (meta.* is the Labkit context namespace)' do
		test_logger.format_message('INFO', Time.now.utc, 'test', { 'meta.user_id' => 123 })

		expect(registry.offenses).not_to be_empty
		offense = registry.offenses.first
		expect(offense['callsite']).to eq('app/test.rb')
		expect(offense['callsite']).to eq(described_class.context_callsite)
		expect(offense['logger_class']).to eq(described_class::ANY_LOGGER)
		end

		it 'attributes the offense to the context callsite even when the same key is also in the context' do
		Labkit::Context.with_context('meta.user_id' => 456) do
		test_logger.format_message('INFO', Time.now.utc, 'test', { 'meta.user_id' => 123 })
		end

		expect(registry.offenses.size).to eq(1)
		expect(registry.offenses.first['callsite']).to eq(described_class.context_callsite)
		end
		end

		@@ -225,6 +243,29 @@ RSpec.describe Labkit::Logging::FieldValidator::LogInterceptor do
		expect(removed.size).to eq(1)
		expect(removed.first['deprecated_field']).to eq('meta.user_id')
		end

		it 'detects removed offenses for context-attributed baseline entries' do
		# Baseline entry attributed to the context callsite (the new format)
		File.write(config_path, {
		'offenses' => [
		{
		'callsite' => described_class.context_callsite,
		'deprecated_field' => 'meta.user_id',
		'standard_field' => 'Labkit::Fields::GL_USER_ID',
		'logger_class' => described_class::ANY_LOGGER
		}
		]
		}.to_yaml)

		allow(Labkit::Fields).to receive(:constant_name_for).and_return(nil)
		allow(Labkit::Fields).to receive(:constant_name_for).with('gl_user_id').and_return('GL_USER_ID')

		test_logger.format_message('INFO', Time.now.utc, 'test', { 'gl_user_id' => 123 })

		_detected, _new, removed = registry.finalize
		expect(removed.size).to eq(1)
		expect(removed.first['callsite']).to eq(described_class.context_callsite)
		end
		end
		end