Skip to content

Commit 7069369

Browse files
Support performance trace (#32973)
1. Add a OpenTelemetry-like shim-layer to collect traces 2. Add a simple builtin trace collector and exporter, end users could download the diagnosis report to get the traces. This PR's design is quite lightweight, no hard-dependency, and it is easy to improve or remove. We can try it on gitea.com first to see whether it works well, and fine tune the details. --------- Co-authored-by: silverwind <[email protected]>
1 parent 2cb3946 commit 7069369

24 files changed

+628
-52
lines changed

cmd/web.go

+4
Original file line numberDiff line numberDiff line change
@@ -18,10 +18,12 @@ import (
1818

1919
"code.gitea.io/gitea/modules/container"
2020
"code.gitea.io/gitea/modules/graceful"
21+
"code.gitea.io/gitea/modules/gtprof"
2122
"code.gitea.io/gitea/modules/log"
2223
"code.gitea.io/gitea/modules/process"
2324
"code.gitea.io/gitea/modules/public"
2425
"code.gitea.io/gitea/modules/setting"
26+
"code.gitea.io/gitea/modules/util"
2527
"code.gitea.io/gitea/routers"
2628
"code.gitea.io/gitea/routers/install"
2729

@@ -218,6 +220,8 @@ func serveInstalled(ctx *cli.Context) error {
218220
}
219221
}
220222

223+
gtprof.EnableBuiltinTracer(util.Iif(setting.IsProd, 2000*time.Millisecond, 100*time.Millisecond))
224+
221225
// Set up Chi routes
222226
webRoutes := routers.NormalRoutes()
223227
err := listen(webRoutes, true)

models/db/engine_hook.go

+18-5
Original file line numberDiff line numberDiff line change
@@ -7,23 +7,36 @@ import (
77
"context"
88
"time"
99

10+
"code.gitea.io/gitea/modules/gtprof"
1011
"code.gitea.io/gitea/modules/log"
12+
"code.gitea.io/gitea/modules/setting"
1113

1214
"xorm.io/xorm/contexts"
1315
)
1416

15-
type SlowQueryHook struct {
17+
type EngineHook struct {
1618
Threshold time.Duration
1719
Logger log.Logger
1820
}
1921

20-
var _ contexts.Hook = (*SlowQueryHook)(nil)
22+
var _ contexts.Hook = (*EngineHook)(nil)
2123

22-
func (*SlowQueryHook) BeforeProcess(c *contexts.ContextHook) (context.Context, error) {
23-
return c.Ctx, nil
24+
func (*EngineHook) BeforeProcess(c *contexts.ContextHook) (context.Context, error) {
25+
ctx, _ := gtprof.GetTracer().Start(c.Ctx, gtprof.TraceSpanDatabase)
26+
return ctx, nil
2427
}
2528

26-
func (h *SlowQueryHook) AfterProcess(c *contexts.ContextHook) error {
29+
func (h *EngineHook) AfterProcess(c *contexts.ContextHook) error {
30+
span := gtprof.GetContextSpan(c.Ctx)
31+
if span != nil {
32+
// Do not record SQL parameters here:
33+
// * It shouldn't expose the parameters because they contain sensitive information, end users need to report the trace details safely.
34+
// * Some parameters contain quite long texts, waste memory and are difficult to display.
35+
span.SetAttributeString(gtprof.TraceAttrDbSQL, c.SQL)
36+
span.End()
37+
} else {
38+
setting.PanicInDevOrTesting("span in database engine hook is nil")
39+
}
2740
if c.ExecuteTime >= h.Threshold {
2841
// 8 is the amount of skips passed to runtime.Caller, so that in the log the correct function
2942
// is being displayed (the function that ultimately wants to execute the query in the code)

models/db/engine_init.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -72,7 +72,7 @@ func InitEngine(ctx context.Context) error {
7272
xe.SetDefaultContext(ctx)
7373

7474
if setting.Database.SlowQueryThreshold > 0 {
75-
xe.AddHook(&SlowQueryHook{
75+
xe.AddHook(&EngineHook{
7676
Threshold: setting.Database.SlowQueryThreshold,
7777
Logger: log.GetLogger("xorm"),
7878
})

modules/git/command.go

+9-3
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@ import (
1818
"time"
1919

2020
"code.gitea.io/gitea/modules/git/internal" //nolint:depguard // only this file can use the internal type CmdArg, other files and packages should use AddXxx functions
21+
"code.gitea.io/gitea/modules/gtprof"
2122
"code.gitea.io/gitea/modules/log"
2223
"code.gitea.io/gitea/modules/process"
2324
"code.gitea.io/gitea/modules/util"
@@ -54,7 +55,7 @@ func logArgSanitize(arg string) string {
5455
} else if filepath.IsAbs(arg) {
5556
base := filepath.Base(arg)
5657
dir := filepath.Dir(arg)
57-
return filepath.Join(filepath.Base(dir), base)
58+
return ".../" + filepath.Join(filepath.Base(dir), base)
5859
}
5960
return arg
6061
}
@@ -295,15 +296,20 @@ func (c *Command) run(skip int, opts *RunOpts) error {
295296
timeout = defaultCommandExecutionTimeout
296297
}
297298

298-
var desc string
299+
cmdLogString := c.LogString()
299300
callerInfo := util.CallerFuncName(1 /* util */ + 1 /* this */ + skip /* parent */)
300301
if pos := strings.LastIndex(callerInfo, "/"); pos >= 0 {
301302
callerInfo = callerInfo[pos+1:]
302303
}
303304
// these logs are for debugging purposes only, so no guarantee of correctness or stability
304-
desc = fmt.Sprintf("git.Run(by:%s, repo:%s): %s", callerInfo, logArgSanitize(opts.Dir), c.LogString())
305+
desc := fmt.Sprintf("git.Run(by:%s, repo:%s): %s", callerInfo, logArgSanitize(opts.Dir), cmdLogString)
305306
log.Debug("git.Command: %s", desc)
306307

308+
_, span := gtprof.GetTracer().Start(c.parentContext, gtprof.TraceSpanGitRun)
309+
defer span.End()
310+
span.SetAttributeString(gtprof.TraceAttrFuncCaller, callerInfo)
311+
span.SetAttributeString(gtprof.TraceAttrGitCommand, cmdLogString)
312+
307313
var ctx context.Context
308314
var cancel context.CancelFunc
309315
var finished context.CancelFunc

modules/git/command_test.go

+1-1
Original file line numberDiff line numberDiff line change
@@ -58,5 +58,5 @@ func TestCommandString(t *testing.T) {
5858
assert.EqualValues(t, cmd.prog+` a "-m msg" "it's a test" "say \"hello\""`, cmd.LogString())
5959

6060
cmd = NewCommandContextNoGlobals(context.Background(), "url: https://a:b@c/", "/root/dir-a/dir-b")
61-
assert.EqualValues(t, cmd.prog+` "url: https://sanitized-credential@c/" dir-a/dir-b`, cmd.LogString())
61+
assert.EqualValues(t, cmd.prog+` "url: https://sanitized-credential@c/" .../dir-a/dir-b`, cmd.LogString())
6262
}

modules/gtprof/event.go

+32
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,32 @@
1+
// Copyright 2025 The Gitea Authors. All rights reserved.
2+
// SPDX-License-Identifier: MIT
3+
4+
package gtprof
5+
6+
type EventConfig struct {
7+
attributes []*TraceAttribute
8+
}
9+
10+
type EventOption interface {
11+
applyEvent(*EventConfig)
12+
}
13+
14+
type applyEventFunc func(*EventConfig)
15+
16+
func (f applyEventFunc) applyEvent(cfg *EventConfig) {
17+
f(cfg)
18+
}
19+
20+
func WithAttributes(attrs ...*TraceAttribute) EventOption {
21+
return applyEventFunc(func(cfg *EventConfig) {
22+
cfg.attributes = append(cfg.attributes, attrs...)
23+
})
24+
}
25+
26+
func eventConfigFromOptions(options ...EventOption) *EventConfig {
27+
cfg := &EventConfig{}
28+
for _, opt := range options {
29+
opt.applyEvent(cfg)
30+
}
31+
return cfg
32+
}

modules/gtprof/trace.go

+175
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,175 @@
1+
// Copyright 2025 The Gitea Authors. All rights reserved.
2+
// SPDX-License-Identifier: MIT
3+
4+
package gtprof
5+
6+
import (
7+
"context"
8+
"fmt"
9+
"sync"
10+
"time"
11+
12+
"code.gitea.io/gitea/modules/util"
13+
)
14+
15+
type contextKey struct {
16+
name string
17+
}
18+
19+
var contextKeySpan = &contextKey{"span"}
20+
21+
type traceStarter interface {
22+
start(ctx context.Context, traceSpan *TraceSpan, internalSpanIdx int) (context.Context, traceSpanInternal)
23+
}
24+
25+
type traceSpanInternal interface {
26+
addEvent(name string, cfg *EventConfig)
27+
recordError(err error, cfg *EventConfig)
28+
end()
29+
}
30+
31+
type TraceSpan struct {
32+
// immutable
33+
parent *TraceSpan
34+
internalSpans []traceSpanInternal
35+
internalContexts []context.Context
36+
37+
// mutable, must be protected by mutex
38+
mu sync.RWMutex
39+
name string
40+
statusCode uint32
41+
statusDesc string
42+
startTime time.Time
43+
endTime time.Time
44+
attributes []*TraceAttribute
45+
children []*TraceSpan
46+
}
47+
48+
type TraceAttribute struct {
49+
Key string
50+
Value TraceValue
51+
}
52+
53+
type TraceValue struct {
54+
v any
55+
}
56+
57+
func (t *TraceValue) AsString() string {
58+
return fmt.Sprint(t.v)
59+
}
60+
61+
func (t *TraceValue) AsInt64() int64 {
62+
v, _ := util.ToInt64(t.v)
63+
return v
64+
}
65+
66+
func (t *TraceValue) AsFloat64() float64 {
67+
v, _ := util.ToFloat64(t.v)
68+
return v
69+
}
70+
71+
var globalTraceStarters []traceStarter
72+
73+
type Tracer struct {
74+
starters []traceStarter
75+
}
76+
77+
func (s *TraceSpan) SetName(name string) {
78+
s.mu.Lock()
79+
defer s.mu.Unlock()
80+
s.name = name
81+
}
82+
83+
func (s *TraceSpan) SetStatus(code uint32, desc string) {
84+
s.mu.Lock()
85+
defer s.mu.Unlock()
86+
s.statusCode, s.statusDesc = code, desc
87+
}
88+
89+
func (s *TraceSpan) AddEvent(name string, options ...EventOption) {
90+
cfg := eventConfigFromOptions(options...)
91+
for _, tsp := range s.internalSpans {
92+
tsp.addEvent(name, cfg)
93+
}
94+
}
95+
96+
func (s *TraceSpan) RecordError(err error, options ...EventOption) {
97+
cfg := eventConfigFromOptions(options...)
98+
for _, tsp := range s.internalSpans {
99+
tsp.recordError(err, cfg)
100+
}
101+
}
102+
103+
func (s *TraceSpan) SetAttributeString(key, value string) *TraceSpan {
104+
s.mu.Lock()
105+
defer s.mu.Unlock()
106+
107+
s.attributes = append(s.attributes, &TraceAttribute{Key: key, Value: TraceValue{v: value}})
108+
return s
109+
}
110+
111+
func (t *Tracer) Start(ctx context.Context, spanName string) (context.Context, *TraceSpan) {
112+
starters := t.starters
113+
if starters == nil {
114+
starters = globalTraceStarters
115+
}
116+
ts := &TraceSpan{name: spanName, startTime: time.Now()}
117+
parentSpan := GetContextSpan(ctx)
118+
if parentSpan != nil {
119+
parentSpan.mu.Lock()
120+
parentSpan.children = append(parentSpan.children, ts)
121+
parentSpan.mu.Unlock()
122+
ts.parent = parentSpan
123+
}
124+
125+
parentCtx := ctx
126+
for internalSpanIdx, tsp := range starters {
127+
var internalSpan traceSpanInternal
128+
if parentSpan != nil {
129+
parentCtx = parentSpan.internalContexts[internalSpanIdx]
130+
}
131+
ctx, internalSpan = tsp.start(parentCtx, ts, internalSpanIdx)
132+
ts.internalContexts = append(ts.internalContexts, ctx)
133+
ts.internalSpans = append(ts.internalSpans, internalSpan)
134+
}
135+
ctx = context.WithValue(ctx, contextKeySpan, ts)
136+
return ctx, ts
137+
}
138+
139+
type mutableContext interface {
140+
context.Context
141+
SetContextValue(key, value any)
142+
GetContextValue(key any) any
143+
}
144+
145+
// StartInContext starts a trace span in Gitea's mutable context (usually the web request context).
146+
// Due to the design limitation of Gitea's web framework, it can't use `context.WithValue` to bind a new span into a new context.
147+
// So here we use our "reqctx" framework to achieve the same result: web request context could always see the latest "span".
148+
func (t *Tracer) StartInContext(ctx mutableContext, spanName string) (*TraceSpan, func()) {
149+
curTraceSpan := GetContextSpan(ctx)
150+
_, newTraceSpan := GetTracer().Start(ctx, spanName)
151+
ctx.SetContextValue(contextKeySpan, newTraceSpan)
152+
return newTraceSpan, func() {
153+
newTraceSpan.End()
154+
ctx.SetContextValue(contextKeySpan, curTraceSpan)
155+
}
156+
}
157+
158+
func (s *TraceSpan) End() {
159+
s.mu.Lock()
160+
s.endTime = time.Now()
161+
s.mu.Unlock()
162+
163+
for _, tsp := range s.internalSpans {
164+
tsp.end()
165+
}
166+
}
167+
168+
func GetTracer() *Tracer {
169+
return &Tracer{}
170+
}
171+
172+
func GetContextSpan(ctx context.Context) *TraceSpan {
173+
ts, _ := ctx.Value(contextKeySpan).(*TraceSpan)
174+
return ts
175+
}

0 commit comments

Comments
 (0)