feat: Consolidate logging offenses originating from the application context (9b3c7f21) · Commits · GitLab.org / ruby / gems / labkit-ruby

lib/labkit/logging/field_validator/log_interceptor.rb

+32 −0

Original line number	Diff line number	Diff line
		@@ -15,6 +15,8 @@ module Labkit
		%r{/.*logger\.rb$}
		].freeze

		DEFAULT_CONTEXT_CALLSITE = "Labkit::Context"

		class << self
		def register_wrapper_pattern(pattern)
		wrapper_patterns << pattern
		@@ -33,6 +35,23 @@ module Labkit
		def combined_ignore_pattern
		@combined_ignore_pattern \|\|= Regexp.union(IGNORE_PATHS + wrapper_patterns)
		end

		# The callsite name used for offenses originating from the Labkit context
		# (e.g. ApplicationContext) rather than from the log caller directly.
		# Override this in your application to point to the actual context provider file:
		# Labkit::Logging::FieldValidator::LogInterceptor.context_callsite =
		# "lib/gitlab/application_context.rb"
		def context_callsite
		@context_callsite \|\| DEFAULT_CONTEXT_CALLSITE
		end

		def context_callsite=(callsite)
		@context_callsite = callsite
		end

		def reset_context_callsite!
		@context_callsite = nil
		end
		end

		def format_data(severity, timestamp, progname, message)
		@@ -46,6 +65,12 @@ module Labkit

		logger_class = self.class.name \|\| 'AnonymousLogger'

		# Keys the caller explicitly passed in the log message. Any deprecated field
		# present in `data` but absent here arrived via Labkit::Context (e.g.
		# 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

		deprecated_lookup = Labkit::Fields::Deprecated.all
		if data.is_a?(Hash)
		data.each_key do \|key\|
		@@ -53,11 +78,18 @@ module Labkit
		standard_field = deprecated_lookup[key_str]
		next unless standard_field

		if direct_keys.include?(key_str)
		Registry.instance.record_offense(callsite_path, location.lineno, key_str, standard_field, logger_class)
		else
		Registry.instance.record_offense(
		LogInterceptor.context_callsite, 0, key_str, standard_field, logger_class
		)
		end
		end
		end

		Registry.instance.check_for_removed_offenses(callsite_path, data, logger_class)
		Registry.instance.check_for_removed_offenses(LogInterceptor.context_callsite, data, logger_class)

		data
		end

spec/labkit/logging/field_validator/log_interceptor_spec.rb

+108 −1

Original line number	Diff line number	Diff line
		@@ -98,14 +98,78 @@ RSpec.describe Labkit::Logging::FieldValidator::LogInterceptor do
		end
		end

		context 'when deprecated field originates from Labkit context (not 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, not the log callsite' do
		Labkit::Context.with_context('meta.user_id' => 456) do
		test_logger.format_message('INFO', Time.now.utc, 'test', { message: 'hello' })
		end

		expect(registry.offenses).not_to be_empty
		offense = registry.offenses.first
		expect(offense['callsite']).to eq(Labkit::Logging::FieldValidator::LogInterceptor.context_callsite)
		expect(offense['deprecated_field']).to eq('meta.user_id')
		end

		it 'records lineno 0 for context-originated offenses' do
		Labkit::Context.with_context('meta.user_id' => 456) do
		test_logger.format_message('INFO', Time.now.utc, 'test', { message: 'hello' })
		end

		expect(registry.offenses.first['lineno']).to eq(0)
		end

		it 'produces a single offense entry regardless of how many log calls occur' do
		Labkit::Context.with_context('meta.user_id' => 456) do
		3.times { test_logger.format_message('INFO', Time.now.utc, 'test', { message: 'hello' }) }
		end

		context_offenses = registry.offenses.select do \|o\|
		o['callsite'] == Labkit::Logging::FieldValidator::LogInterceptor.context_callsite
		end
		expect(context_offenses.size).to eq(1)
		end
		end

		context 'when 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 })

		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')
		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 })
		end

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

		context 'when detecting removed offenses' do
		before do
		allow(test_logger).to receive(:determine_callsite).and_return(mock_location)
		end

		it 'calls check_for_removed_offenses with data hash' do
		it 'calls check_for_removed_offenses for both the callsite and the context callsite with the data hash' do
		expect(registry).to receive(:check_for_removed_offenses)
		.with('app/test.rb', hash_including('gl_user_id' => 123, 'message' => 'hello'), 'AnonymousLogger')
		expect(registry).to receive(:check_for_removed_offenses)
		.with(Labkit::Logging::FieldValidator::LogInterceptor.context_callsite,
		hash_including('gl_user_id' => 123, 'message' => 'hello'), 'AnonymousLogger')

		test_logger.format_message('INFO', Time.now.utc, 'test', { 'gl_user_id' => 123, 'message' => 'hello' })
		end
		@@ -164,6 +228,49 @@ RSpec.describe Labkit::Logging::FieldValidator::LogInterceptor do
		end
		end

		describe 'context callsite' do
		describe '.context_callsite' do
		after { described_class.reset_context_callsite! }

		it 'returns the default value' do
		expect(described_class.context_callsite).to eq(Labkit::Logging::FieldValidator::LogInterceptor::DEFAULT_CONTEXT_CALLSITE)
		end

		it 'returns a custom value when set' do
		described_class.context_callsite = 'lib/gitlab/application_context.rb'

		expect(described_class.context_callsite).to eq('lib/gitlab/application_context.rb')
		end
		end

		describe '.reset_context_callsite!' do
		it 'restores the default value after customization' do
		described_class.context_callsite = 'lib/gitlab/application_context.rb'

		described_class.reset_context_callsite!

		expect(described_class.context_callsite).to eq(Labkit::Logging::FieldValidator::LogInterceptor::DEFAULT_CONTEXT_CALLSITE)
		end
		end

		context 'when a custom context callsite is configured' do
		before do
		described_class.context_callsite = 'lib/gitlab/application_context.rb'
		allow(test_logger).to receive(:determine_callsite).and_return(mock_location)
		end

		after { described_class.reset_context_callsite! }

		it 'uses the custom callsite for context-originated offenses' do
		Labkit::Context.with_context('meta.user_id' => 456) do
		test_logger.format_message('INFO', Time.now.utc, 'test', { message: 'hello' })
		end

		expect(registry.offenses.first['callsite']).to eq('lib/gitlab/application_context.rb')
		end
		end
		end

		describe 'wrapper patterns' do
		describe '.register_wrapper_pattern' do
		after do