trace2: Implement trace2 hook that exports pack-object metrics

This commit implement trace2 hook that exports pack-object metrics. This
hook uses the existing trace2 infrastructure. It hooks into the
trace2 tree for the following events:
- data:pack-objects:write_pack_file/wrote
- data:pack-objects:loosen_unused_packed_objects/loosened
- data:pack-objects:stdin_packs_found
- data:pack-objects:stdin_packs_hints
- pack-objects:enumerate-objects
- pack-objects:prepare-pack
- pack-objects:write-pack-file

When run into such traces, the hook increases the corresponding
Prometheus' histograms. In addition, it also dumps equivalent fields to
command stats. Eventually, Gitaly outputs logs having associated fields.

3 files changed, 704 insertions, 0 deletions

diff --git a/internal/git/trace2hooks/packobjects_metrics.go b/internal/git/trace2hooks/packobjects_metrics.go
new file mode 100644
index 000000000..e2339f39d
--- /dev/null
+++ b/internal/git/trace2hooks/packobjects_metrics.go
@@ -0,0 +1,93 @@
+package trace2hooks
+
+import (
+	"context"
+	"strconv"
+
+	"github.com/prometheus/client_golang/prometheus"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/command"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/git/trace2"
+)
+
+var statsIntData = map[string]string{
+	"data:pack-objects:write_pack_file/wrote":                 "pack_objects.written_object_count",
+	"data:pack-objects:loosen_unused_packed_objects/loosened": "pack_objects.loosened_unused_packed_objects",
+	"data:pack-objects:stdin_packs_found":                     "pack_objects.stdin_packs_found",
+	"data:pack-objects:stdin_packs_hints":                     "pack_objects.stdin_packs_hints",
+}
+
+var statsElapsedTimes = map[string]string{
+	"pack-objects:enumerate-objects": "pack_objects.enumerate_objects_ms",
+	"pack-objects:prepare-pack":      "pack_objects.prepare_pack_ms",
+	"pack-objects:write-pack-file":   "pack_objects.write_pack_file_ms",
+}
+
+var histogramStageNames = map[string]string{
+	"pack-objects:enumerate-objects": "enumerate-objects",
+	"pack-objects:prepare-pack":      "prepare-pack",
+	"pack-objects:write-pack-file":   "write-pack-file",
+}
+
+// PackObjectsMetrics is a trace2 hook that export pack-objects Prometheus metrics and stats log
+// fields. This information is extracted by traversing the trace2 event tree.
+type PackObjectsMetrics struct {
+	metrics *prometheus.HistogramVec
+}
+
+// NewPackObjectsMetrics is the initializer for PackObjectsMetrics
+func NewPackObjectsMetrics() *PackObjectsMetrics {
+	return &PackObjectsMetrics{
+		metrics: prometheus.NewHistogramVec(
+			prometheus.HistogramOpts{
+				Name: "gitaly_pack_objects_stages_seconds",
+				Help: "Time of pack-objects command on different stage",
+			},
+			[]string{"stage"},
+		),
+	}
+}
+
+// Name returns the name of the hooks
+func (p *PackObjectsMetrics) Name() string {
+	return "pack_objects_metrics"
+}
+
+// Handle traverses input trace2 event tree for data nodes containing relevant pack-objects data.
+// When it finds one, it updates Prometheus objects and log fields accordingly.
+func (p *PackObjectsMetrics) Handle(rootCtx context.Context, trace *trace2.Trace) error {
+	trace.Walk(rootCtx, func(ctx context.Context, trace *trace2.Trace) context.Context {
+		stats := command.StatsFromContext(ctx)
+		if stats != nil {
+			if field, ok := statsIntData[trace.Name]; ok {
+				data, err := strconv.Atoi(trace.Metadata["data"])
+				if err == nil {
+					stats.RecordSum(field, data)
+				}
+			}
+
+			if field, ok := statsElapsedTimes[trace.Name]; ok {
+				elapsedTime := trace.FinishTime.Sub(trace.StartTime).Milliseconds()
+				stats.RecordSum(field, int(elapsedTime))
+			}
+
+			if stage, ok := histogramStageNames[trace.Name]; ok {
+				elapsedTime := trace.FinishTime.Sub(trace.StartTime).Seconds()
+				p.metrics.WithLabelValues(stage).Observe(elapsedTime)
+			}
+
+			return ctx
+		}
+		return ctx
+	})
+	return nil
+}
+
+// Describe describes Prometheus metrics exposed by the PackObjectsMetrics structure.
+func (p *PackObjectsMetrics) Describe(descs chan<- *prometheus.Desc) {
+	prometheus.DescribeByCollect(p, descs)
+}
+
+// Collect collects Prometheus metrics exposed by the PackObjectsMetrics structure.
+func (p *PackObjectsMetrics) Collect(c chan<- prometheus.Metric) {
+	p.metrics.Collect(c)
+}
diff --git a/internal/git/trace2hooks/packobjects_metrics_ext_test.go b/internal/git/trace2hooks/packobjects_metrics_ext_test.go
new file mode 100644
index 000000000..0785e4cd8
--- /dev/null
+++ b/internal/git/trace2hooks/packobjects_metrics_ext_test.go
@@ -0,0 +1,213 @@
+package trace2hooks_test
+
+import (
+	"bytes"
+	"context"
+	"fmt"
+	"testing"
+
+	"github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/require"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/command"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/git"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/git/gittest"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/git/trace2"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/git/trace2hooks"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/gitaly/config"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/testhelper"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/testhelper/testcfg"
+	"gitlab.com/gitlab-org/gitaly/v15/proto/go/gitalypb"
+)
+
+func TestMain(m *testing.M) {
+	testhelper.Run(m)
+}
+
+func TestPackObjectsMetrics(t *testing.T) {
+	t.Parallel()
+
+	for _, tc := range []struct {
+		desc      string
+		setupRepo func(ctx context.Context) (*gitalypb.Repository, config.Cfg, bytes.Buffer)
+		assert    func(*testing.T, logrus.Fields)
+	}{
+		{
+			desc: "pack blobs",
+			setupRepo: func(ctx context.Context) (*gitalypb.Repository, config.Cfg, bytes.Buffer) {
+				cfg := testcfg.Build(t)
+				repoProto, repoPath := gittest.CreateRepository(t, ctx, cfg,
+					gittest.CreateRepositoryConfig{SkipCreationViaService: true},
+				)
+
+				var input bytes.Buffer
+				for i := 0; i <= 10; i++ {
+					content := fmt.Sprintf("hello %d", i)
+					input.WriteString(gittest.WriteBlob(t, cfg, repoPath, []byte(content)).String())
+					input.WriteString("\n")
+				}
+
+				return repoProto, cfg, input
+			},
+			assert: func(t *testing.T, statFields logrus.Fields) {
+				require.Equal(t, 11, statFields["pack_objects.written_object_count"])
+			},
+		},
+		{
+			desc: "pack commits",
+			setupRepo: func(ctx context.Context) (*gitalypb.Repository, config.Cfg, bytes.Buffer) {
+				cfg := testcfg.Build(t)
+				repoProto, repoPath := gittest.CreateRepository(t, ctx, cfg,
+					gittest.CreateRepositoryConfig{SkipCreationViaService: true},
+				)
+
+				var input bytes.Buffer
+				input.WriteString(gittest.WriteCommit(t, cfg, repoPath, gittest.WithMessage("reachable"), gittest.WithBranch("reachable")).String())
+				input.WriteString("\n")
+				input.WriteString(gittest.WriteCommit(t, cfg, repoPath, gittest.WithMessage("unreachable")).String())
+				input.WriteString("\n")
+
+				return repoProto, cfg, input
+			},
+			assert: func(t *testing.T, statFields logrus.Fields) {
+				require.Equal(t, 3, statFields["pack_objects.written_object_count"])
+			},
+		},
+		{
+			desc: "pack refs",
+			setupRepo: func(ctx context.Context) (*gitalypb.Repository, config.Cfg, bytes.Buffer) {
+				cfg := testcfg.Build(t)
+				repoProto, repoPath := gittest.CreateRepository(t, ctx, cfg,
+					gittest.CreateRepositoryConfig{SkipCreationViaService: true},
+				)
+
+				var input bytes.Buffer
+				commit := gittest.WriteCommit(t, cfg, repoPath, gittest.WithMessage("commit"), gittest.WithBranch("main"))
+				for i := 0; i <= 10; i++ {
+					ref := fmt.Sprintf("ref-%d", i)
+					gittest.WriteRef(t, cfg, repoPath, git.ReferenceName(ref), commit)
+					input.WriteString(ref)
+					input.WriteString("\n")
+				}
+
+				return repoProto, cfg, input
+			},
+			assert: func(t *testing.T, statFields logrus.Fields) {
+				require.Equal(t, 2, statFields["pack_objects.written_object_count"])
+			},
+		},
+		{
+			desc: "pack tags",
+			setupRepo: func(ctx context.Context) (*gitalypb.Repository, config.Cfg, bytes.Buffer) {
+				cfg := testcfg.Build(t)
+				repoProto, repoPath := gittest.CreateRepository(t, ctx, cfg,
+					gittest.CreateRepositoryConfig{SkipCreationViaService: true},
+				)
+
+				var input bytes.Buffer
+				commit := gittest.WriteCommit(t, cfg, repoPath, gittest.WithMessage("commit"), gittest.WithBranch("main"))
+				for i := 0; i <= 10; i++ {
+					tag := fmt.Sprintf("tag-%d", i)
+					gittest.WriteTag(t, cfg, repoPath, tag, commit.Revision())
+					input.WriteString(tag)
+					input.WriteString("\n")
+				}
+
+				return repoProto, cfg, input
+			},
+			assert: func(t *testing.T, statFields logrus.Fields) {
+				require.Equal(t, 2, statFields["pack_objects.written_object_count"])
+			},
+		},
+		{
+			desc: "pack tree",
+			setupRepo: func(ctx context.Context) (*gitalypb.Repository, config.Cfg, bytes.Buffer) {
+				cfg := testcfg.Build(t)
+				repoProto, repoPath := gittest.CreateRepository(t, ctx, cfg,
+					gittest.CreateRepositoryConfig{SkipCreationViaService: true},
+				)
+
+				var input bytes.Buffer
+				tree := gittest.WriteTree(t, cfg, repoPath, []gittest.TreeEntry{
+					{
+						Mode:    "100644",
+						Path:    "file1",
+						Content: "file1",
+					},
+					{
+						Mode:    "100644",
+						Path:    "file2",
+						Content: "file2",
+					},
+					{
+						Mode:    "100644",
+						Path:    "file3",
+						Content: "file3",
+					},
+					{
+						OID: gittest.WriteTree(t, cfg, repoPath, []gittest.TreeEntry{
+							{
+								Mode:    "100644",
+								Path:    "subfile1",
+								Content: "subfile1",
+							},
+							{
+								Mode:    "100644",
+								Path:    "subfile2",
+								Content: "subfile2",
+							},
+						}),
+						Mode: "040000",
+						Path: "subdir",
+					},
+				})
+				input.WriteString(tree.String())
+				input.WriteString("\n")
+
+				return repoProto, cfg, input
+			},
+			assert: func(t *testing.T, statFields logrus.Fields) {
+				require.Equal(t, 7, statFields["pack_objects.written_object_count"])
+			},
+		},
+	} {
+		tc := tc
+
+		t.Run(tc.desc, func(t *testing.T) {
+			t.Parallel()
+
+			ctx := command.InitContextStats(testhelper.Context(t))
+			repoProto, cfg, input := tc.setupRepo(ctx)
+			gitCmdFactory, cleanup, err := git.NewExecCommandFactory(cfg, git.WithTrace2Hooks([]trace2.Hook{
+				trace2hooks.NewPackObjectsMetrics(),
+			}))
+			require.NoError(t, err)
+			defer cleanup()
+
+			cmd, err := gitCmdFactory.New(ctx, repoProto, git.Command{
+				Name: "pack-objects",
+				Flags: []git.Option{
+					git.Flag{Name: "--compression=0"},
+					git.Flag{Name: "--stdout"},
+					git.Flag{Name: "--unpack-unreachable"},
+					git.Flag{Name: "-q"},
+				},
+			}, git.WithStdin(&input))
+			require.NoError(t, err)
+
+			err = cmd.Wait()
+			require.NoError(t, err)
+
+			stats := command.StatsFromContext(ctx)
+			require.NotNil(t, stats)
+
+			statFields := stats.Fields()
+			require.Equal(t, "true", statFields["trace2.activated"])
+			require.Equal(t, "pack_objects_metrics", statFields["trace2.hooks"])
+			require.Contains(t, statFields, "pack_objects.enumerate_objects_ms")
+			require.Contains(t, statFields, "pack_objects.prepare_pack_ms")
+			require.Contains(t, statFields, "pack_objects.write_pack_file_ms")
+
+			tc.assert(t, statFields)
+		})
+	}
+}
diff --git a/internal/git/trace2hooks/packobjects_metrics_test.go b/internal/git/trace2hooks/packobjects_metrics_test.go
new file mode 100644
index 000000000..ded1fa95e
--- /dev/null
+++ b/internal/git/trace2hooks/packobjects_metrics_test.go
@@ -0,0 +1,398 @@
+package trace2hooks
+
+import (
+	"bytes"
+	"testing"
+	"time"
+
+	"github.com/prometheus/client_golang/prometheus/testutil"
+	"github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/require"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/command"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/git/trace2"
+	"gitlab.com/gitlab-org/gitaly/v15/internal/testhelper"
+)
+
+func TestPackObjectsMetrics_Handle(t *testing.T) {
+	t.Parallel()
+
+	// Pin a timestamp for trace tree generation below. This way enables asserting the time
+	// frames of spans correctly.
+	current, err := time.Parse("2006-01-02T15:04:05Z", "2023-01-01T00:00:00Z")
+	require.NoError(t, err)
+
+	for _, tc := range []struct {
+		desc            string
+		inputTrace      *trace2.Trace
+		expectedMetrics string
+		expectedStats   logrus.Fields
+	}{
+		{
+			desc:            "empty trace",
+			inputTrace:      nil,
+			expectedStats:   logrus.Fields{},
+			expectedMetrics: ``,
+		},
+		{
+			desc: "receives trace consisting of root only",
+			inputTrace: &trace2.Trace{
+				Thread:     "main",
+				Name:       "root",
+				StartTime:  current,
+				FinishTime: time.Time{},
+			},
+			expectedStats:   logrus.Fields{},
+			expectedMetrics: ``,
+		},
+		{
+			desc: "receives a complete trace",
+			inputTrace: connectChildren(&trace2.Trace{
+				Thread:     "main",
+				Name:       "root",
+				StartTime:  current,
+				FinishTime: current.Add(9 * time.Second),
+				Children: []*trace2.Trace{
+					{
+						Thread:     "main",
+						Name:       "version",
+						StartTime:  current,
+						FinishTime: current.Add(1 * time.Second),
+					},
+					{
+						Thread:     "main",
+						Name:       "start",
+						StartTime:  current.Add(1 * time.Second),
+						FinishTime: current.Add(2 * time.Second),
+						Metadata:   map[string]string{"argv": "git pack-objects toon --compression=0"},
+					},
+					{
+						Thread:     "main",
+						Name:       "def_repo",
+						StartTime:  current.Add(2 * time.Second),
+						FinishTime: current.Add(3 * time.Second),
+					},
+					connectChildren(&trace2.Trace{
+						Thread:     "main",
+						Name:       "pack-objects:enumerate-objects",
+						StartTime:  current.Add(3 * time.Second),
+						FinishTime: current.Add(5 * time.Second),
+						Children: []*trace2.Trace{
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:stdin_packs_hints",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "999",
+								},
+								StartTime:  current.Add(3 * time.Second),
+								FinishTime: current.Add(4 * time.Second),
+							},
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:stdin_packs_found",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "998",
+								},
+								StartTime:  current.Add(4 * time.Second),
+								FinishTime: current.Add(5 * time.Second),
+							},
+						},
+					}),
+					connectChildren(&trace2.Trace{
+						Thread:     "main",
+						Name:       "pack-objects:prepare-pack",
+						StartTime:  current.Add(5 * time.Second),
+						FinishTime: current.Add(7 * time.Second),
+						Children: []*trace2.Trace{
+							{
+								Thread:     "main",
+								Name:       "progress:Counting objects",
+								ChildID:    "0",
+								StartTime:  current.Add(5 * time.Second),
+								FinishTime: current.Add(6 * time.Second),
+							},
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:loosen_unused_packed_objects/loosened",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "1234",
+								},
+								StartTime:  current.Add(6 * time.Second),
+								FinishTime: current.Add(7 * time.Second),
+							},
+						},
+					},
+					),
+					connectChildren(&trace2.Trace{
+						Thread:     "main",
+						Name:       "pack-objects:write-pack-file",
+						StartTime:  current.Add(7 * time.Second),
+						FinishTime: current.Add(9 * time.Second),
+						Children: []*trace2.Trace{
+							{
+								Thread:     "main",
+								Name:       "progress:Writing objects",
+								ChildID:    "0",
+								StartTime:  current.Add(7 * time.Second),
+								FinishTime: current.Add(8 * time.Second),
+							},
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:write_pack_file/wrote",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "99",
+								},
+								StartTime:  current.Add(8 * time.Second),
+								FinishTime: current.Add(9 * time.Second),
+							},
+						},
+					},
+					),
+				},
+			}),
+			expectedStats: logrus.Fields{
+				"pack_objects.written_object_count":           99,
+				"pack_objects.loosened_unused_packed_objects": 1234,
+				"pack_objects.stdin_packs_hints":              999,
+				"pack_objects.stdin_packs_found":              998,
+				"pack_objects.enumerate_objects_ms":           2000,
+				"pack_objects.prepare_pack_ms":                2000,
+				"pack_objects.write_pack_file_ms":             2000,
+			},
+			expectedMetrics: `# HELP gitaly_pack_objects_stages_seconds Time of pack-objects command on different stage
+# TYPE gitaly_pack_objects_stages_seconds histogram
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.005"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.01"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.025"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.05"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.25"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.5"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="2.5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="10"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="+Inf"} 1
+gitaly_pack_objects_stages_seconds_sum{stage="enumerate-objects"} 2
+gitaly_pack_objects_stages_seconds_count{stage="enumerate-objects"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.005"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.01"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.025"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.05"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.25"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.5"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="2.5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="10"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="+Inf"} 1
+gitaly_pack_objects_stages_seconds_sum{stage="prepare-pack"} 2
+gitaly_pack_objects_stages_seconds_count{stage="prepare-pack"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.005"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.01"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.025"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.05"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.25"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.5"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="2.5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="10"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="+Inf"} 1
+gitaly_pack_objects_stages_seconds_sum{stage="write-pack-file"} 2
+gitaly_pack_objects_stages_seconds_count{stage="write-pack-file"} 1
+
+`,
+		},
+		{
+			desc: "tree contains multiple relative fields",
+			inputTrace: connectChildren(&trace2.Trace{
+				Thread:     "main",
+				Name:       "root",
+				StartTime:  current,
+				FinishTime: current.Add(9 * time.Second),
+				Children: []*trace2.Trace{
+					connectChildren(&trace2.Trace{
+						Thread:     "main",
+						Name:       "pack-objects:enumerate-objects",
+						StartTime:  current.Add(3 * time.Second),
+						FinishTime: current.Add(5 * time.Second),
+						Children: []*trace2.Trace{
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:stdin_packs_hints",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "999",
+								},
+								StartTime:  current.Add(3 * time.Second),
+								FinishTime: current.Add(4 * time.Second),
+							},
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:stdin_packs_found",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "998",
+								},
+								StartTime:  current.Add(4 * time.Second),
+								FinishTime: current.Add(5 * time.Second),
+							},
+						},
+					}),
+					connectChildren(&trace2.Trace{
+						Thread:     "main",
+						Name:       "pack-objects:prepare-pack",
+						StartTime:  current,
+						FinishTime: current.Add(5 * time.Second),
+						Children: []*trace2.Trace{
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:loosen_unused_packed_objects/loosened",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "1234",
+								},
+							},
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:loosen_unused_packed_objects/loosened",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "3456",
+								},
+							},
+						},
+					},
+					),
+					connectChildren(&trace2.Trace{
+						Thread:     "main",
+						Name:       "pack-objects:prepare-pack",
+						StartTime:  current.Add(5 * time.Second),
+						FinishTime: current.Add(7 * time.Second),
+						Children:   []*trace2.Trace{},
+					},
+					),
+					connectChildren(&trace2.Trace{
+						Thread:     "main",
+						Name:       "pack-objects:write-pack-file",
+						StartTime:  current.Add(7 * time.Second),
+						FinishTime: current.Add(8 * time.Second),
+						Children: []*trace2.Trace{
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:write_pack_file/wrote",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "99",
+								},
+							},
+						},
+					},
+					),
+					connectChildren(&trace2.Trace{
+						Thread:     "main",
+						Name:       "pack-objects:write-pack-file",
+						StartTime:  current.Add(8 * time.Second),
+						FinishTime: current.Add(9 * time.Second),
+						Children: []*trace2.Trace{
+							{
+								Thread:  "main",
+								Name:    "data:pack-objects:write_pack_file/wrote",
+								ChildID: "0",
+								Metadata: map[string]string{
+									"data": "2",
+								},
+							},
+						},
+					},
+					),
+				},
+			}),
+			expectedStats: logrus.Fields{
+				"pack_objects.written_object_count":           101,
+				"pack_objects.loosened_unused_packed_objects": 4690,
+				"pack_objects.stdin_packs_hints":              999,
+				"pack_objects.stdin_packs_found":              998,
+				"pack_objects.enumerate_objects_ms":           2000,
+				"pack_objects.prepare_pack_ms":                7000,
+				"pack_objects.write_pack_file_ms":             2000,
+			},
+			expectedMetrics: `# HELP gitaly_pack_objects_stages_seconds Time of pack-objects command on different stage
+# TYPE gitaly_pack_objects_stages_seconds histogram
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.005"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.01"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.025"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.05"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.25"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="0.5"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="2.5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="10"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="enumerate-objects",le="+Inf"} 1
+gitaly_pack_objects_stages_seconds_sum{stage="enumerate-objects"} 2
+gitaly_pack_objects_stages_seconds_count{stage="enumerate-objects"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.005"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.01"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.025"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.05"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.25"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="0.5"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="2.5"} 1
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="5"} 2
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="10"} 2
+gitaly_pack_objects_stages_seconds_bucket{stage="prepare-pack",le="+Inf"} 2
+gitaly_pack_objects_stages_seconds_sum{stage="prepare-pack"} 7
+gitaly_pack_objects_stages_seconds_count{stage="prepare-pack"} 2
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.005"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.01"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.025"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.05"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.1"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.25"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="0.5"} 0
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="1"} 2
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="2.5"} 2
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="5"} 2
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="10"} 2
+gitaly_pack_objects_stages_seconds_bucket{stage="write-pack-file",le="+Inf"} 2
+gitaly_pack_objects_stages_seconds_sum{stage="write-pack-file"} 2
+gitaly_pack_objects_stages_seconds_count{stage="write-pack-file"} 2
+
+`,
+		},
+	} {
+		tc := tc
+
+		t.Run(tc.desc, func(t *testing.T) {
+			t.Parallel()
+			ctx := command.InitContextStats(testhelper.Context(t))
+
+			exporter := NewPackObjectsMetrics()
+
+			err := exporter.Handle(ctx, tc.inputTrace)
+			require.NoError(t, err)
+
+			require.NoError(
+				t,
+				testutil.CollectAndCompare(
+					exporter,
+					bytes.NewBufferString(tc.expectedMetrics),
+				),
+			)
+
+			stats := command.StatsFromContext(ctx)
+			require.NotNil(t, stats)
+			require.Equal(t, tc.expectedStats, stats.Fields())
+		})
+	}
+}