Verified Commit 016ad99c authored by Hercules Merscher's avatar Hercules Merscher 🌴
Browse files

feat: User Experience SLI observed

parent d28543d7
Loading
Loading
Loading
Loading
+53 −0
Original line number Diff line number Diff line
@@ -203,6 +203,59 @@ RSpec::Matchers.define :complete_user_experience do |user_experience_id, error:
  end
end

# Matcher for verifying UserExperience observed metrics instrumentation.
#
# Usage:
#   expect { subject }.to observed_user_experience('rails_request')
#
# This matcher verifies that the following metrics are incremented with specific labels:
# - gitlab_user_experience_checkpoint_total (with checkpoint=start)
# - gitlab_user_experience_checkpoint_total (with checkpoint=end)
# - gitlab_user_experience_total (with error=false)
# - gitlab_user_experience_apdex_total (with success=true)
#
# Parameters:
# - user_experience_id: Required. The ID of the user experience (e.g., 'rails_request')
# - error: Optional. The expected error flag for gitlab_user_experience_total (false by default)
# - success: Optional. The expected success flag for gitlab_user_experience_apdex_total (true by default)
RSpec::Matchers.define :observed_user_experience do |user_experience_id, error: false, success: true|
  include Labkit::RSpec::Matchers::UserExperience

  description { "observe user experience '#{user_experience_id}'" }
  supports_block_expectations

  match do |actual|
    labels = attributes(user_experience_id)

    start_before = checkpoint_counter&.get(labels.merge(checkpoint: "start")).to_i
    end_before = checkpoint_counter&.get(labels.merge(checkpoint: "end")).to_i
    total_before = total_counter&.get(labels.merge(error: error)).to_i
    apdex_before = apdex_counter&.get(labels.merge(success: success)).to_i

    actual.call

    start_after = checkpoint_counter&.get(labels.merge(checkpoint: "start")).to_i
    end_after = checkpoint_counter&.get(labels.merge(checkpoint: "end")).to_i
    total_after = total_counter&.get(labels.merge(error: error)).to_i
    apdex_after = apdex_counter&.get(labels.merge(success: success)).to_i

    @start_change = start_after - start_before
    @end_change = end_after - end_before
    @total_change = total_after - total_before
    @apdex_change = apdex_after - apdex_before

    @start_change == 1 && @end_change == 1 && @total_change == 1 && @apdex_change == (error ? 0 : 1)
  end

  failure_message do
    "Failed to observe user experience '#{user_experience_id}':\n" \
      "expected checkpoint='start' counter to increase by 1, but increased by #{@start_change}\n" \
      "expected checkpoint='end' counter to increase by 1, but increased by #{@end_change}\n" \
      "expected total='error: #{error}' counter to increase by 1, but increased by #{@total_change}\n" \
      "expected apdex='success: #{success}' counter to increase by #{error ? 0 : 1}, but increased by #{@apdex_change}"
  end
end

# Backward compatibility matchers for CoveredExperience
RSpec::Matchers.alias_matcher :start_covered_experience, :start_user_experience
RSpec::Matchers.alias_matcher :checkpoint_covered_experience, :checkpoint_user_experience
+12 −0
Original line number Diff line number Diff line
@@ -97,6 +97,18 @@ module Labkit
        get(experience_id).start(**extra, &)
      end

      # Records a past user experience by its duration atomically.
      #
      # @param experience_id [String, Symbol] The ID of the experience.
      # @param duration_s [Numeric] Elapsed duration in seconds.
      # @param extra [Hash] Additional data to include in the log events.
      # @return [Experience, Null] The observed experience or a Null object if not found (in production/staging).
      def observed(experience_id, duration_s:, **extra)
        definition = registry[experience_id]
        experience = definition ? Experience.new(definition) : raise_or_null(experience_id)
        experience.observed(duration_s: duration_s, **extra)
      end

      # Resumes a user experience using the experience_id.
      #
      # @param experience_id [String, Symbol] The ID of the experience to resume.
+23 −0
Original line number Diff line number Diff line
@@ -136,6 +136,28 @@ module Labkit
        self
      end

      # Records a past User Experience by its duration.
      #
      # @param duration_s [Numeric] The elapsed duration in seconds.
      # @param error [Boolean] Whether the experience ended in an error.
      # @param extra [Hash] Additional data to include in the log events.
      # @return [self]
      def observed(duration_s:, error: false, **extra)
        @start_time = @end_time = Time.now.utc
        @observed_duration_s = duration_s
        error!("observed_error") if error

        checkpoint_counter.increment(checkpoint: "start", **base_labels)
        log_event("start", **extra)

        checkpoint_counter.increment(checkpoint: "end", **base_labels)
        total_counter.increment(error: has_error?, **base_labels)
        apdex_counter.increment(success: apdex_success?, **base_labels) unless has_error?
        log_event("end", **extra)

        self
      end

      # Marks the experience as failed with an error
      #
      # @param error [StandardError, String] The error that caused the experience to fail.
@@ -193,6 +215,7 @@ module Labkit
      end

      def elapsed_time
        return @observed_duration_s unless @observed_duration_s.nil?
        return 0 unless @start_time

        last_time = @end_time || @checkpoint_time || @start_time
+1 −0
Original line number Diff line number Diff line
@@ -20,6 +20,7 @@ module Labkit
        self
      end

      def observed(**_kwargs) = self
      def push_attributes!(*_args) = self
      def checkpoint(*_args) = self
      def complete(*_args) = self
+86 −0
Original line number Diff line number Diff line
@@ -390,6 +390,92 @@ RSpec.describe Labkit::UserExperienceSli::Experience, :with_metrics_config do
    end
  end

  describe '#observed' do
    let(:duration_s) { 1.5 }

    subject(:observed) { experience.observed(duration_s: duration_s) }

    it { is_expected.to be(experience) }

    it 'fires start and end checkpoints, total, and apdex' do
      expect { observed }.to observed_user_experience(:testing_sample)
    end

    it 'sets start_time and end_time to the same timestamp' do
      observed

      expect(experience.start_time).to eq(experience.instance_variable_get(:@end_time))
    end

    it 'sets elapsed_time_s equal to duration_s' do
      expect(Labkit::UserExperienceSli.configuration.logger).to receive(:info)
        .with(hash_including(checkpoint: 'start', elapsed_time_s: duration_s))
        .ordered
        .and_call_original

      expect(Labkit::UserExperienceSli.configuration.logger).to receive(:info)
        .with(hash_including(checkpoint: 'end', elapsed_time_s: duration_s))
        .ordered
        .and_call_original

      observed
    end

    it 'does not add the experience to Current context' do
      observed

      expect(Labkit::UserExperienceSli::Current.active_experiences).not_to have_key(experience.id)
    end

    it 'includes extra parameters in both log events' do
      extra_info = { session_id: 'abc', worker: 'MyWorker' }

      expect(Labkit::UserExperienceSli.configuration.logger).to receive(:info)
        .with(hash_including(checkpoint: 'start', **extra_info))
        .ordered
        .and_call_original

      expect(Labkit::UserExperienceSli.configuration.logger).to receive(:info)
        .with(hash_including(checkpoint: 'end', **extra_info))
        .ordered
        .and_call_original

      experience.observed(duration_s: duration_s, **extra_info)
    end

    context 'when error: true' do
      subject(:observed) { experience.observed(duration_s: duration_s, error: true) }

      it 'fires total with error=true and skips apdex' do
        expect { observed }.to observed_user_experience(:testing_sample, error: true)
      end
    end

    context 'when duration exceeds urgency threshold' do
      let(:duration_s) { 999 }

      it 'reports apdex failure' do
        expect { observed }.to observed_user_experience(:testing_sample, success: false)
      end
    end

    context 'with reserved keyword validation' do
      %w[test development].each do |env|
        context "when RAILS_ENV is #{env}" do
          before do
            stub_env('RAILS_ENV', env)
          end

          it 'raises error when reserved keywords are used in extra' do
            expect { experience.observed(duration_s: duration_s, urgency: 'fake') }.to raise_error(
              Labkit::UserExperienceSli::ReservedKeywordError
            )
          end
        end
      end
    end
  end

  describe '#error!' do
    let(:exception) { Labkit::UserExperienceSli::UserExperienceError.new('boom!') }

Loading