Verified Commit c8fecfd0 authored by Hercules Merscher's avatar Hercules Merscher
Browse files

feat: Load experience from context when calling get

parent efcb7bdd

lib/labkit/covered_experience.rb

+1 −1
Original line number Diff line number Diff line
@@ -51,7 +51,7 @@ module Labkit 
        definition = registry[experience_id]



        if definition

          Experience.new(definition)

          Experience.load(definition)

        else

          raise_or_null(experience_id)

        end

lib/labkit/covered_experience/experience.rb

+20 −8
Original line number Diff line number Diff line
@@ -21,6 +21,21 @@ module Labkit 
      def initialize(definition)

        @definition = definition

      end

      private :initialize



      class << self

        # Factory method to create a new Covered Experience

        # It will also rehydrate the state from the current context

        # if it exists.

        #

        # @param definition [Labkit::CoveredExperience::Definition]

        # @return [Labkit::CoveredExperience::Experience]

        def load(definition)

          instance = new(definition)

          instance.instance_eval { load_from_context }

          instance

        end

      end



      # Start the Covered Experience.

      #
@@ -59,13 +74,13 @@ module Labkit 
        end

      end



      # Resume the Covered Experience from the context.

      # Resume 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

      def resume(**extra, &)

        load_from_context(**extra)

        ensure_started!

        checkpoint(checkpoint_category: 'resume', **extra)



        return self unless block_given?
@@ -242,7 +257,7 @@ module Labkit 
        Labkit::Context.push(Labkit::Context::COVERED_EXPERIENCE_AGG_KEY => covered_experiences)

      end



      def load_from_context(**extra)

      def load_from_context

        covered_experiences = aggregation_context

        experience_data = covered_experiences[@definition.covered_experience]
@@ -253,14 +268,11 @@ module Labkit 
          else experience_data || {}

          end



        if processed_data["start_time"].nil?

          warn("#{@definition.covered_experience} cannot not be resumed", covered_experiences: covered_experiences)

          return

        end

        return if processed_data["start_time"].nil?



        @start_time = Time.iso8601(processed_data["start_time"])

        checkpoint_counter.increment(checkpoint: "intermediate")

        log_event("intermediate", checkpoint_category: "resume", **extra)

        log_event("intermediate", checkpoint_category: "load_from_context")

      end



      def warn(err, **extra)

spec/labkit/covered_experience/experience_spec.rb

+108 −218
Original line number Diff line number Diff line
@@ -24,7 +24,7 @@ RSpec.describe Labkit::CoveredExperience::Experience, :with_metrics_config do 
  let(:project_id) { 456 }

  let(:context) { { user_id: user_id, project_id: project_id } }



  subject(:experience) { described_class.new(definition) }

  subject(:experience) { described_class.load(definition) }



  around do |example|

    Labkit::Context.with_context(**context) do
@@ -208,15 +208,9 @@ RSpec.describe Labkit::CoveredExperience::Experience, :with_metrics_config do 
  end



  describe '#resume' do

    context 'when experience data exists in context' do

      let(:start_time) { Time.now.utc - 1 }



    context 'when experience is started' do

      before do

        # Set up existing covered experience in context

        covered_experiences = {

          "testing_sample" => { "start_time" => start_time.iso8601(3) }

        }

        Labkit::Context.push("covered_experiences" => covered_experiences)

        experience.start

      end



      context 'when block is given' do
@@ -286,7 +280,7 @@ RSpec.describe Labkit::CoveredExperience::Experience, :with_metrics_config do 
        it { expect { resume }.to checkpoint_covered_experience(:testing_sample) }

        it { expect { resume }.not_to complete_covered_experience(:testing_sample) }



        it 'logs only resume event' do

        it 'logs resume event' do

          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(**event_info, checkpoint: 'intermediate', checkpoint_category: 'resume'))

            .and_call_original
@@ -294,12 +288,6 @@ RSpec.describe Labkit::CoveredExperience::Experience, :with_metrics_config do 
          resume

        end



        it 'loads start time from context' do

          resume



          expect(experience.start_time).to be_within(1).of(start_time)

        end



        it 'includes extra arguments in log event' do

          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(
@@ -342,208 +330,6 @@ RSpec.describe Labkit::CoveredExperience::Experience, :with_metrics_config do 
      end

    end



    context 'when experience was started in the same process' do

      let(:started_experience) { described_class.new(definition) }



      before do

        started_experience.start

      end



      context 'when block is given' do

        it 'returns itself' do

          expect(experience.resume { |_xp| 1 + 1 }).to be(experience)

        end



        it 'resumes and automatically completes the experience' do

          expect do |block|

            experience.resume(&block)

          end.to yield_with_args(experience)

          # When resuming from same process, we expect 2 checkpoint increments:

          # 1. From calling the proc (load_from_context)

          # 2. From the resume itself

          .and checkpoint_covered_experience(:testing_sample, by: 2)

          .and complete_covered_experience(:testing_sample)

        end



        it 'captures exceptions and marks as error' do

          expect do

            experience.resume { raise 'Something went wrong' }

          end.to raise_error(RuntimeError, 'Something went wrong')

          .and checkpoint_covered_experience(:testing_sample, by: 2)

          .and complete_covered_experience(:testing_sample, error: true)

        end



        it 'logs resume and end events' do

          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(**event_info, checkpoint: 'intermediate', checkpoint_category: 'push_to_context'))

            .ordered

            .and_call_original



          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(**event_info, checkpoint: 'intermediate', checkpoint_category: 'resume'))

            .ordered

            .and_call_original



          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(**event_info, checkpoint: 'end', end_time: a_kind_of(Time)))

            .ordered

            .and_call_original



          experience.resume { |_xp| 1 + 1 }

        end



        it 'includes extra arguments in log events' do

          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(

              **event_info,

              checkpoint: 'intermediate',

              checkpoint_category: 'push_to_context'

            ))

            .ordered

            .and_call_original



          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(

              **event_info,

              checkpoint: 'intermediate',

              checkpoint_category: 'resume',

              session_id: 'session-789'

            ))

            .ordered

            .and_call_original



          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(

              **event_info,

              checkpoint: 'end',

              end_time: a_kind_of(Time),

              session_id: 'session-789'

            ))

            .ordered

            .and_call_original



          experience.resume(session_id: 'session-789') { |_xp| 1 + 1 }

        end

      end



      context 'when block is not given' do

        subject(:resume) { experience.resume }



        it { is_expected.to be(experience) }

        it { expect { resume }.to checkpoint_covered_experience(:testing_sample, by: 2) }

        it { expect { resume }.not_to complete_covered_experience(:testing_sample) }



        it 'logs resume event after calling the proc' do

          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(**event_info, checkpoint: 'intermediate', checkpoint_category: 'push_to_context'))

            .ordered

            .and_call_original



          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(**event_info, checkpoint: 'intermediate', checkpoint_category: 'resume'))

            .ordered

            .and_call_original



          resume

        end



        it 'loads start time from the started experience' do

          resume



          original_start_time = started_experience.start_time

          expect(experience.start_time).to be_within(1).of(original_start_time)

        end



        it 'includes extra arguments in log event' do

          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(

              **event_info,

              checkpoint: 'intermediate',

              checkpoint_category: 'push_to_context'

            ))

            .ordered

            .and_call_original



          expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

            .with(hash_including(

              **event_info,

              checkpoint: 'intermediate',

              checkpoint_category: 'resume',

              resumed_by: 'worker-123'

            ))

            .ordered

            .and_call_original



          experience.resume(resumed_by: 'worker-123')

        end



        it 'calls the proc stored in context to get experience data' do

          # The proc should be called when loading from context

          covered_experiences = Labkit::Context.current.get_attribute("covered_experiences")

          proc_object = covered_experiences["testing_sample"]



          expect(proc_object).to receive(:call).and_call_original



          resume

        end

      end

    end



    context 'when no experience data exists in context' do

      before do

        # Ensure no covered experiences in context

        Labkit::Context.push("covered_experiences" => {})

      end



      context 'when RAILS_ENV is production' do

        before do

          stub_env('RAILS_ENV', 'production')

        end



        it 'does not raise error but does not log resume event' do

          expect(Labkit::CoveredExperience.configuration.logger).not_to receive(:info)

            .with(hash_including(checkpoint: 'resume'))



          expect { experience.resume }.not_to raise_error

        end



        it 'does not resume the experience' do

          expect { experience.resume }.not_to checkpoint_covered_experience(:testing_sample)

        end

      end



      context 'when RAILS_ENV is unset' do

        it 'does not raise error but does not log resume event' do

          expect(Labkit::CoveredExperience.configuration.logger).not_to receive(:info)

            .with(hash_including(checkpoint: 'resume'))



          expect { experience.resume }.not_to raise_error

        end

      end



      %w[test development].each do |env|

        context "when RAILS_ENV is #{env}" do

          before do

            stub_env('RAILS_ENV', env)

          end



          it 'raises UnstartedError' do

            expect { experience.resume }.to raise_error(

              Labkit::CoveredExperience::UnstartedError,

              "Covered Experience #{definition.covered_experience} not started"

            )

          end



          it 'raises UnstartedError even with block' do

            expect { experience.resume { |_xp| 1 + 1 } }.to raise_error(

              Labkit::CoveredExperience::UnstartedError,

              "Covered Experience #{definition.covered_experience} not started"

            )

          end

        end

      end

    end



    context 'when context is nil' do

      context 'when RAILS_ENV is production' do

        before do
@@ -850,4 +636,108 @@ 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 '.load' do

    context 'when experience data exists in context' do

      let(:start_time) { Time.now.utc - 5 }



      before do

        # Set up existing covered experience in context

        covered_experiences = {

          "testing_sample" => { "start_time" => start_time.iso8601(3) }

        }

        Labkit::Context.push("covered_experiences" => covered_experiences)

      end



      subject(:loaded_experience) { described_class.load(definition) }



      it 'returns an Experience instance' do

        expect(loaded_experience).to be_a(described_class)

      end



      it 'loads the start time from context' do

        expect(loaded_experience.start_time).to be_within(1).of(start_time)

      end



      it 'logs load_from_context event' do

        expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

          .with(hash_including(

            **event_info,

            checkpoint: 'intermediate',

            checkpoint_category: 'load_from_context'

          ))

          .and_call_original



        loaded_experience

      end



      it 'increments checkpoint counter' do

        expect { loaded_experience }.to checkpoint_covered_experience(:testing_sample)

      end

    end



    context 'when experience data exists as a Proc in context' do

      let(:start_time) { Time.now.utc - 3 }

      let(:proc_data) { proc { { "start_time" => start_time.iso8601(3) } } }



      before do

        # Set up existing covered experience as a Proc in context

        covered_experiences = {

          "testing_sample" => proc_data

        }

        Labkit::Context.push("covered_experiences" => covered_experiences)

      end



      subject(:loaded_experience) { described_class.load(definition) }



      it 'calls the proc to get experience data' do

        expect(proc_data).to receive(:call).and_call_original

        loaded_experience

      end



      it 'loads the start time from proc result' do

        expect(loaded_experience.start_time).to be_within(1).of(start_time)

      end



      it 'logs load_from_context event' do

        expect(Labkit::CoveredExperience.configuration.logger).to receive(:info)

          .with(hash_including(

            **event_info,

            checkpoint: 'intermediate',

            checkpoint_category: 'load_from_context'

          ))

          .and_call_original



        loaded_experience

      end

    end



    context 'when no experience data exists in context' do

      before do

        # Ensure no covered experiences in context

        Labkit::Context.push("covered_experiences" => nil)

      end



      subject(:loaded_experience) { described_class.load(definition) }



      it 'returns an Experience instance' do

        expect(loaded_experience).to be_a(described_class)

      end



      it 'does not set start_time' do

        expect(loaded_experience.start_time).to be_nil

      end



      it 'does not log load_from_context event' do

        expect(Labkit::CoveredExperience.configuration.logger).not_to receive(:info)

          .with(hash_including(checkpoint_category: 'load_from_context'))



        loaded_experience

      end



      it 'does not increment checkpoint counter' do

        expect { loaded_experience }.not_to checkpoint_covered_experience(:testing_sample)

      end

    end

  end

end

spec/labkit/covered_experience_spec.rb

+96 −66
Original line number Diff line number Diff line
@@ -174,17 +174,10 @@ RSpec.describe Labkit::CoveredExperience, :with_metrics_config do 


    context 'with extra attributes' do

      let(:extra_attrs) { { user_id: 789, request_id: 'req-123' } }

      let(:logger) { instance_double(Labkit::Logging::JsonLogger) }



      before do

        described_class.configure { |config| config.logger = logger }

        allow(logger).to receive(:info)

      end



      it 'logs extra attributes in start event' do

        described_class.start('testing_sample', **extra_attrs)



        expect(logger).to have_received(:info).with(

        expect(described_class.configuration.logger).to receive(:info)

          .with(

            hash_including(

              checkpoint: 'start',

              covered_experience: 'testing_sample',
@@ -192,12 +185,26 @@ RSpec.describe Labkit::CoveredExperience, :with_metrics_config do 
              request_id: 'req-123'

            )

          )

          .and_call_original



        described_class.start('testing_sample', **extra_attrs)

      end



      it 'logs extra attributes in complete event when using block' do

        described_class.start('testing_sample', **extra_attrs) { 42 }

        expect(described_class.configuration.logger).to receive(:info)

          .with(

            hash_including(

              checkpoint: 'start',

              covered_experience: 'testing_sample',

              user_id: 789,

              request_id: 'req-123'

            )

          )

          .ordered

          .and_call_original



        expect(logger).to have_received(:info).with(

        expect(described_class.configuration.logger).to receive(:info)

          .with(

            hash_including(

              checkpoint: 'end',

              covered_experience: 'testing_sample',
@@ -205,6 +212,10 @@ RSpec.describe Labkit::CoveredExperience, :with_metrics_config do 
              request_id: 'req-123'

            )

          )

          .ordered

          .and_call_original



        described_class.start('testing_sample', **extra_attrs) { 42 }

      end

    end

  end
@@ -233,17 +244,6 @@ RSpec.describe Labkit::CoveredExperience, :with_metrics_config do 
          .and checkpoint_covered_experience(:testing_sample)

          .and complete_covered_experience(:testing_sample, error: true)

        end



        it 'passes extra attributes to the experience' do

          extra_attrs = { user_id: 123, feature_flag: 'enabled' }

          experience = nil



          described_class.resume('testing_sample', **extra_attrs) do |exp|

            experience = exp

          end



          expect(experience).to be_a(Labkit::CoveredExperience::Experience)

        end

      end



      context 'when block is not given' do
@@ -252,28 +252,25 @@ RSpec.describe Labkit::CoveredExperience, :with_metrics_config do 
        it { expect(resume_experience).to be_a(Labkit::CoveredExperience::Experience) }

        it { expect { resume_experience }.to checkpoint_covered_experience(:testing_sample) }

        it { expect { resume_experience }.not_to complete_covered_experience(:testing_sample) }



        it 'passes extra attributes to the experience' do

          extra_attrs = { user_id: 456, session_id: 'abc123' }

          experience = described_class.resume('testing_sample', **extra_attrs)



          expect(experience).to be_a(Labkit::CoveredExperience::Experience)

        end

      end



      context 'with extra attributes' do

        let(:extra_attrs) { { user_id: 789, request_id: 'req-123' } }

        let(:logger) { instance_double(Labkit::Logging::JsonLogger) }



        before do

          described_class.configure { |config| config.logger = logger }

          allow(logger).to receive(:info)

        end



        it 'logs extra attributes in resume event' do

          described_class.resume('testing_sample', **extra_attrs)

          expect(described_class.configuration.logger).to receive(:info)

            .with(

              hash_including(

                checkpoint: 'intermediate',

                checkpoint_category: 'load_from_context',

                covered_experience: 'testing_sample',

              )

            )

            .ordered

            .and_call_original



          expect(logger).to have_received(:info).with(

          expect(described_class.configuration.logger).to receive(:info)

            .with(

              hash_including(

                checkpoint: 'intermediate',

                checkpoint_category: 'resume',
@@ -282,12 +279,39 @@ RSpec.describe Labkit::CoveredExperience, :with_metrics_config do 
                request_id: 'req-123'

              )

            )

            .ordered

            .and_call_original



          described_class.resume('testing_sample', **extra_attrs)

        end



        it 'logs extra attributes in complete event when using block' do

          described_class.resume('testing_sample', **extra_attrs) { 42 }

          expect(described_class.configuration.logger).to receive(:info)

            .with(

              hash_including(

                checkpoint: 'intermediate',

                checkpoint_category: 'load_from_context',

                covered_experience: 'testing_sample',

              )

            )

            .ordered

            .and_call_original



          expect(logger).to have_received(:info).with(

          expect(described_class.configuration.logger).to receive(:info)

            .with(

              hash_including(

                checkpoint: 'intermediate',

                checkpoint_category: 'resume',

                covered_experience: 'testing_sample',

                user_id: 789,

                request_id: 'req-123'

              )

            )

            .ordered

            .and_call_original



          expect(described_class.configuration.logger).to receive(:info)

            .with(

              hash_including(

                checkpoint: 'end',

                covered_experience: 'testing_sample',
@@ -295,6 +319,10 @@ RSpec.describe Labkit::CoveredExperience, :with_metrics_config do 
                request_id: 'req-123'

              )

            )

            .ordered

            .and_call_original



          described_class.resume('testing_sample', **extra_attrs) { 42 }

        end

      end

    end
@@ -322,9 +350,11 @@ RSpec.describe Labkit::CoveredExperience, :with_metrics_config do 
          expect do |block|

            described_class.resume('testing_sample', &block)

          end.to yield_with_args(Labkit::CoveredExperience::Experience)



          expect do

            described_class.resume('testing_sample') { 42 }

          end.not_to checkpoint_covered_experience(:testing_sample)



          expect do

            described_class.resume('testing_sample') { 42 }

          end.not_to complete_covered_experience(:testing_sample)