Observe duration of each pipeline creation step

This commit adds instrumentation to track and graph the duration in
seconds of each pipeline creation step in
`::Ci::CreatePipelineService::SEQUENCE`. Each class in the sequence is
tracked as a separate step.

https://gitlab.com/gitlab-org/gitlab/-/issues/332891

lib/gitlab/ci/pipeline/chain/command.rb

@@ -87,6 +87,13 @@ module Gitlab
             @metrics ||= ::Gitlab::Ci::Pipeline::Metrics
           end
 
+          def observe_step_duration(step_class, duration)
+            step = step_class.name.underscore.tr('/', '_')
+
+            metrics.pipeline_creation_step_duration_histogram(step)
+              .observe({}, duration.seconds)
+          end
+
           def observe_creation_duration(duration)
             metrics.pipeline_creation_duration_histogram
               .observe({}, duration.seconds)

lib/gitlab/ci/pipeline/chain/sequence.rb

@@ -14,9 +14,13 @@ module Gitlab
 
           def build!
             @sequence.each do |step_class|
+              step_start = Time.now
               step = step_class.new(@pipeline, @command)
 
               step.perform!
+
+              @command.observe_step_duration(step_class, Time.now - step_start)
+
               break if step.break?
             end
 

lib/gitlab/ci/pipeline/metrics.rb

@@ -13,6 +13,16 @@ module Gitlab
           ::Gitlab::Metrics.histogram(name, comment, labels, buckets)
         end
 
+        def self.pipeline_creation_step_duration_histogram(step)
+          name = "#{step}_duration_seconds".to_sym
+          description = step.gsub('gitlab_ci_', '').tr('_', ' ')
+          comment = "Duration of the #{description}"
+          labels = {}
+          buckets = [0.01, 0.05, 0.1, 0.5, 1.0, 2.0, 5.0, 20.0, 50.0, 240.0]
+
+          ::Gitlab::Metrics.histogram(name, comment, labels, buckets)
+        end
+
         def self.pipeline_security_orchestration_policy_processing_duration_histogram
           name = :gitlab_ci_pipeline_security_orchestration_policy_processing_duration_seconds
           comment = 'Pipeline security orchestration policy processing duration'

spec/lib/gitlab/ci/pipeline/chain/command_spec.rb

@@ -341,4 +341,21 @@ RSpec.describe Gitlab::Ci::Pipeline::Chain::Command do
       end
     end
   end
+
+  describe '#observe_step_duration' do
+    it 'adds the duration to the step duration histogram' do
+      histogram = double(:histogram)
+      duration = 2.hours.ago - 1.hour.ago
+
+      expect(histogram).to receive(:observe).with({}, duration.seconds)
+      expect(::Gitlab::Ci::Pipeline::Metrics).to receive(:pipeline_creation_step_duration_histogram)
+        .with('gitlab_ci_pipeline_chain_build')
+        .and_return(histogram)
+
+      described_class.new.observe_step_duration(
+        Gitlab::Ci::Pipeline::Chain::Build,
+        duration
+      )
+    end
+  end
 end

spec/lib/gitlab/ci/pipeline/chain/sequence_spec.rb

@@ -61,6 +61,23 @@ RSpec.describe Gitlab::Ci::Pipeline::Chain::Sequence do
       expect(histogram).to have_received(:observe)
     end
 
+    it 'adds step sequence duration to duration histogram' do
+      expect(command.metrics)
+        .to receive(:pipeline_creation_step_duration_histogram)
+        .with(first_step)
+        .ordered
+        .and_return(histogram)
+      expect(command.metrics)
+        .to receive(:pipeline_creation_step_duration_histogram)
+        .with(second_step)
+        .ordered
+        .and_return(histogram)
+
+      subject.build!
+
+      expect(histogram).to have_received(:observe).twice
+    end
+
     it 'records pipeline size by pipeline source in a histogram' do
       allow(command.metrics)
         .to receive(:pipeline_size_histogram)

spec/lib/gitlab/ci/pipeline/metrics_spec.rb

+# frozen_string_literal: true
+
+require 'spec_helper'
+
+RSpec.describe ::Gitlab::Ci::Pipeline::Metrics do
+  describe '.pipeline_creation_step_duration_histogram' do
+    it 'adds the step to the step duration histogram' do
+      step = 'gitlab_ci_pipeline_chain_build'
+
+      expect(::Gitlab::Metrics).to receive(:histogram)
+        .with(
+          :gitlab_ci_pipeline_chain_build_duration_seconds,
+          'Duration of the pipeline chain build',
+          {},
+          [0.01, 0.05, 0.1, 0.5, 1.0, 2.0, 5.0, 20.0, 50.0, 240.0]
+        )
+
+      described_class.pipeline_creation_step_duration_histogram(step)
+    end
+  end
+end