Welcome to mirror list, hosted at ThFree Co, Russian Federation.

gitlab.com/gitlab-org/gitaly.git - Unnamed repository; edit this file 'description' to name the repository.
summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorJohn Cai <jcai@gitlab.com>2023-03-29 22:01:09 +0300
committerJohn Cai <jcai@gitlab.com>2023-03-29 22:01:09 +0300
commit0b31e634f58b0495a20eaa00b588714dfdefefd7 (patch)
treecaab1cd611ad4796f58857ab4eae827a8677a73f
parentd41dacd832cc71860f8e069647b539880263392c (diff)
parent85249660e66b596d69d4c95d3fe8bb64af5c83ab (diff)
Merge branch 'qmnguyen0711/implement-trace2-pack-file-metrics' into 'master'
Trace2: Expose internal pack objects metrics with trace2 See merge request https://gitlab.com/gitlab-org/gitaly/-/merge_requests/5442 Merged-by: John Cai <jcai@gitlab.com> Approved-by: John Cai <jcai@gitlab.com> Reviewed-by: Patrick Steinhardt <psteinhardt@gitlab.com> Reviewed-by: Quang-Minh Nguyen <qmnguyen@gitlab.com> Co-authored-by: Quang-Minh Nguyen <qmnguyen@gitlab.com>
-rw-r--r--internal/git/command_factory.go5
-rw-r--r--internal/git/command_factory_test.go44
-rw-r--r--internal/git/trace2hooks/packobjects_metrics.go93
-rw-r--r--internal/git/trace2hooks/packobjects_metrics_ext_test.go213
-rw-r--r--internal/git/trace2hooks/packobjects_metrics_test.go398
-rw-r--r--internal/git/trace2hooks/tracingexporter.go6
-rw-r--r--internal/git/trace2hooks/tracingexporter_test.go2
-rw-r--r--internal/metadata/featureflag/ff_export_trace2_pack_objects_metrics.go10
-rw-r--r--internal/testhelper/testhelper.go3
9 files changed, 763 insertions, 11 deletions
diff --git a/internal/git/command_factory.go b/internal/git/command_factory.go
index d8115ddc5..61d62c74c 100644
--- a/internal/git/command_factory.go
+++ b/internal/git/command_factory.go
@@ -96,7 +96,10 @@ func WithTrace2Hooks(hooks []trace2.Hook) ExecCommandFactoryOption {
func DefaultTrace2HooksFor(ctx context.Context, subCmd string) []trace2.Hook {
var hooks []trace2.Hook
if featureflag.ExportTrace2Tracing.IsEnabled(ctx) && tracing.IsSampled(ctx) {
- hooks = append(hooks, &trace2hooks.TracingExporter{})
+ hooks = append(hooks, trace2hooks.NewTracingExporter())
+ }
+ if featureflag.ExportTrace2PackObjectsMetrics.IsEnabled(ctx) {
+ hooks = append(hooks, trace2hooks.NewPackObjectsMetrics())
}
return hooks
}
diff --git a/internal/git/command_factory_test.go b/internal/git/command_factory_test.go
index a4129be38..5a998da76 100644
--- a/internal/git/command_factory_test.go
+++ b/internal/git/command_factory_test.go
@@ -973,6 +973,9 @@ func testTrace2TracingExporter(t *testing.T, testCtx context.Context) {
},
} {
t.Run(tc.desc, func(t *testing.T) {
+ // Disable other hooks
+ testCtx := featureflag.ContextWithFeatureFlag(testCtx, featureflag.ExportTrace2PackObjectsMetrics, false)
+
reporter, cleanup := testhelper.StubTracingReporter(t, tc.tracerOptions...)
defer cleanup()
ctx := tc.setup(t, command.InitContextStats(testCtx))
@@ -1000,7 +1003,12 @@ func testTrace2TracingExporter(t *testing.T, testCtx context.Context) {
}
func TestDefaultTrace2HooksFor(t *testing.T) {
- featureSet := testhelper.NewFeatureSets(featureflag.ExportTrace2Tracing)
+ t.Parallel()
+
+ featureSet := testhelper.NewFeatureSets(
+ featureflag.ExportTrace2Tracing,
+ featureflag.ExportTrace2PackObjectsMetrics,
+ )
featureSet.Run(t, testDefaultTrace2HooksFor)
}
@@ -1015,29 +1023,41 @@ func testDefaultTrace2HooksFor(t *testing.T, ctx context.Context) {
{
desc: "there is no active span",
setup: func(t *testing.T) (context.Context, []trace2.Hook) {
- return testhelper.Context(t), nil
+ ctx := testhelper.Context(t)
+ var hooks []trace2.Hook
+ if featureflag.ExportTrace2PackObjectsMetrics.IsEnabled(ctx) {
+ hooks = append(hooks, trace2hooks.NewPackObjectsMetrics())
+ }
+ return ctx, hooks
},
},
{
desc: "active span is sampled",
setup: func(t *testing.T) (context.Context, []trace2.Hook) {
_, ctx = tracing.StartSpan(testhelper.Context(t), "root", nil)
+ var hooks []trace2.Hook
- if !featureflag.ExportTrace2Tracing.IsEnabled(ctx) {
- return ctx, nil
+ if featureflag.ExportTrace2Tracing.IsEnabled(ctx) {
+ hooks = append(hooks, &trace2hooks.TracingExporter{})
}
- return ctx, []trace2.Hook{
- &trace2hooks.TracingExporter{},
+ if featureflag.ExportTrace2PackObjectsMetrics.IsEnabled(ctx) {
+ hooks = append(hooks, trace2hooks.NewPackObjectsMetrics())
}
+
+ return ctx, hooks
},
},
{
desc: "active span is not sampled",
setup: func(t *testing.T) (context.Context, []trace2.Hook) {
_, ctx = tracing.StartSpan(testhelper.Context(t), "root", nil)
+ var hooks []trace2.Hook
+ if featureflag.ExportTrace2PackObjectsMetrics.IsEnabled(ctx) {
+ hooks = append(hooks, trace2hooks.NewPackObjectsMetrics())
+ }
- return ctx, nil
+ return ctx, hooks
},
tracerOptions: []testhelper.StubTracingReporterOption{testhelper.NeverSampled()},
},
@@ -1049,7 +1069,7 @@ func testDefaultTrace2HooksFor(t *testing.T, ctx context.Context) {
ctx, expectedHooks := tc.setup(t)
hooks := git.DefaultTrace2HooksFor(ctx, tc.subCmd)
- require.Equal(t, expectedHooks, hooks)
+ require.Equal(t, hookNames(expectedHooks), hookNames(hooks))
})
}
}
@@ -1083,3 +1103,11 @@ func performPackObjectGit(t *testing.T, ctx context.Context, opts ...git.ExecCom
err = cmd.Wait()
require.NoError(t, err)
}
+
+func hookNames(hooks []trace2.Hook) []string {
+ var names []string
+ for _, hook := range hooks {
+ names = append(names, hook.Name())
+ }
+ return names
+}
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())
+ })
+ }
+}
diff --git a/internal/git/trace2hooks/tracingexporter.go b/internal/git/trace2hooks/tracingexporter.go
index 1f7e9f3bd..94a00da93 100644
--- a/internal/git/trace2hooks/tracingexporter.go
+++ b/internal/git/trace2hooks/tracingexporter.go
@@ -9,6 +9,12 @@ import (
"gitlab.com/gitlab-org/gitaly/v15/internal/tracing"
)
+// NewTracingExporter initializes TracingExporter, which is a hook to convert Trace2 events to
+// corresponding distributed tracing
+func NewTracingExporter() *TracingExporter {
+ return &TracingExporter{}
+}
+
// TracingExporter is a trace2 hook that converts the trace2 tree to corresponding distributed
// tracing's spans. These spans are then collected if the process initializes labkit's tracing
// utility.
diff --git a/internal/git/trace2hooks/tracingexporter_test.go b/internal/git/trace2hooks/tracingexporter_test.go
index a506d7612..5c3afb03d 100644
--- a/internal/git/trace2hooks/tracingexporter_test.go
+++ b/internal/git/trace2hooks/tracingexporter_test.go
@@ -218,7 +218,7 @@ func TestTracingExporter_Handle(t *testing.T) {
reporter.Reset()
ctx, trace := tc.setup(t)
- exporter := TracingExporter{}
+ exporter := NewTracingExporter()
err := exporter.Handle(ctx, trace)
require.NoError(t, err)
diff --git a/internal/metadata/featureflag/ff_export_trace2_pack_objects_metrics.go b/internal/metadata/featureflag/ff_export_trace2_pack_objects_metrics.go
new file mode 100644
index 000000000..9ccfa3e97
--- /dev/null
+++ b/internal/metadata/featureflag/ff_export_trace2_pack_objects_metrics.go
@@ -0,0 +1,10 @@
+package featureflag
+
+// ExportTrace2PackObjectsMetrics allows Gitaly enables trace2 and export internal Git metrics
+// of pack-objects commands
+var ExportTrace2PackObjectsMetrics = NewFeatureFlag(
+ "export_trace2_pack_objects_metrics",
+ "v15.11.0",
+ "https://gitlab.com/gitlab-org/gitaly/-/issues/4997",
+ false,
+)
diff --git a/internal/testhelper/testhelper.go b/internal/testhelper/testhelper.go
index 9f810c58d..db19842c9 100644
--- a/internal/testhelper/testhelper.go
+++ b/internal/testhelper/testhelper.go
@@ -204,8 +204,9 @@ func ContextWithoutCancel(opts ...ContextOpt) context.Context {
// Randomly enable the use of the catfile cache in localrepo.ReadObject.
ctx = featureflag.ContextWithFeatureFlag(ctx, featureflag.LocalrepoReadObjectCached, rnd.Int()%2 == 0)
- // Randomly enable the use of trace2 tracing exporter.
+ // Randomly enable the use of trace2 flags
ctx = featureflag.ContextWithFeatureFlag(ctx, featureflag.ExportTrace2Tracing, rnd.Int()%2 == 0)
+ ctx = featureflag.ContextWithFeatureFlag(ctx, featureflag.ExportTrace2PackObjectsMetrics, rnd.Int()%2 == 0)
for _, opt := range opts {
ctx = opt(ctx)