feat: Accepts extra args for log events (460ce73e) · Commits · GitLab.org / ruby / gems / labkit-ruby

lib/labkit/covered_experience/experience.rb

+9 −6

Original line number	Diff line number	Diff line
		@@ -24,6 +24,7 @@ module Labkit
		# Start the Covered Experience.
		#
		# @yield [self] When a block is provided, the experience will be completed automatically.
		# @param extra [Hash] Additional data to include in the log event
		# @return [self]
		# @raise [CoveredExperienceError] If the block raises an error.
		#
		@@ -38,10 +39,10 @@ module Labkit
		# experience.start
		# experience.checkpoint
		# experience.complete
		def start
		def start(**extra)
		@start_time = Time.now.utc
		checkpoint_counter.increment(checkpoint: "start")
		log_event("start")
		log_event("start", **extra)

		return self unless block_given?

		@@ -58,23 +59,25 @@ module Labkit

		# Checkpoint the Covered Experience.
		#
		# @param extra [Hash] Additional data to include in the log event
		# @raise [UnstartedError] If the experience has not been started and RAILS_ENV is development or test.
		# @return [self]
		def checkpoint
		def checkpoint(**extra)
		return unless ensure_started!

		@checkpoint_time = Time.now.utc
		checkpoint_counter.increment(checkpoint: "intermediate")
		log_event("intermediate")
		log_event("intermediate", **extra)

		self
		end

		# Complete the Covered Experience.
		#
		# @param extra [Hash] Additional data to include in the log event
		# @raise [UnstartedError] If the experience has not been started and RAILS_ENV is development or test.
		# @return [self]
		def complete
		def complete(**extra)
		return unless ensure_started!

		begin
		@@ -83,7 +86,7 @@ module Labkit
		checkpoint_counter.increment(checkpoint: "end")
		total_counter.increment(error: has_error?)
		apdex_counter.increment(success: apdex_success?) unless has_error?
		log_event("end")
		log_event("end", **extra)
		end

		self

spec/labkit/covered_experience/experience_spec.rb

+86 −0

Original line number	Diff line number	Diff line
		@@ -157,4 +157,90 @@ RSpec.describe Labkit::CoveredExperience::Experience, :with_metrics_config do
		it { expect(experience.error).to be(exception) }
		it { expect(experience.error!('BOOM!').error).to be('BOOM!') }
		end

		describe 'extra arguments in log events' do
		let(:logger) { Labkit::Logging::JsonLogger.new(StringIO.new) }

		before do
		Labkit::CoveredExperience.configure do \|config\|
		config.logger = logger
		end
		end

		def log_entries
		log_output = logger.instance_variable_get(:@logdev).dev
		log_output.string.split("\n").filter_map do \|line\|
		next if line.strip.empty?

		JSON.parse(line, symbolize_names: true)
		rescue JSON::ParserError
		nil
		end
		end

		describe '#start with extra arguments' do
		it 'includes extra arguments in the log event' do
		experience.start(user_id: 123, request_id: 'abc-123')

		start_log = log_entries.find { \|entry\| entry[:checkpoint] == 'start' }
		expect(start_log).to include(
		user_id: 123,
		request_id: 'abc-123'
		)
		end

		it 'works with block and includes extra arguments' do
		experience.start(session_id: 'session-456') { \|_xp\| 1 + 1 }

		start_log = log_entries.find { \|entry\| entry[:checkpoint] == 'start' }
		end_log = log_entries.find { \|entry\| entry[:checkpoint] == 'end' }

		expect(start_log).to include(session_id: 'session-456')
		expect(end_log).not_to include(:session_id) # end doesn't get start's extra args
		end
		end

		describe '#checkpoint with extra arguments' do
		before do
		experience.start
		end

		it 'includes extra arguments in the log event' do
		experience.checkpoint(step: 'validation', items_processed: 50)

		checkpoint_log = log_entries.find { \|entry\| entry[:checkpoint] == 'intermediate' }
		expect(checkpoint_log).to include(
		step: 'validation',
		items_processed: 50
		)
		end
		end

		describe '#complete with extra arguments' do
		before do
		experience.start
		end

		it 'includes extra arguments in the log event' do
		experience.complete(total_items: 100, success_rate: 0.95)

		complete_log = log_entries.find { \|entry\| entry[:checkpoint] == 'end' }
		expect(complete_log).to include(
		total_items: 100,
		success_rate: 0.95
		)
		end

		it 'includes extra arguments even when there is an error' do
		experience.error!('Something went wrong')
		experience.complete(cleanup_performed: true)

		complete_log = log_entries.find { \|entry\| entry[:checkpoint] == 'end' }
		expect(complete_log).to include(
		cleanup_performed: true,
		error: true
		)
		end
		end
		end
		end