Skip to content

Commit 4b7547b

Browse files
committed
fix
1 parent 65e45fd commit 4b7547b

19 files changed

+378
-47
lines changed

models/db/engine_hook.go

+15-5
Original file line numberDiff line numberDiff line change
@@ -7,23 +7,33 @@ 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+
span.SetAttributeString(gtprof.TraceAttrDbSQL, c.SQL)
33+
span.End()
34+
} else {
35+
setting.PanicInDevOrTesting("span in database engine hook is nil")
36+
}
2737
if c.ExecuteTime >= h.Threshold {
2838
// 8 is the amount of skips passed to runtime.Caller, so that in the log the correct function
2939
// 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
}
@@ -289,15 +290,20 @@ func (c *Command) run(skip int, opts *RunOpts) error {
289290
timeout = defaultCommandExecutionTimeout
290291
}
291292

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

302+
_, span := gtprof.GetTracer().Start(c.parentContext, gtprof.TraceSpanGitRun)
303+
defer span.End()
304+
span.SetAttributeString(gtprof.TraceAttrFuncCaller, callerInfo)
305+
span.SetAttributeString(gtprof.TraceAttrGitCommand, cmdLogString)
306+
301307
var ctx context.Context
302308
var cancel context.CancelFunc
303309
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/trace.go

+119
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,119 @@
1+
// Copyright 2024 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+
end()
27+
}
28+
29+
type TraceSpan struct {
30+
// immutable
31+
parent *TraceSpan
32+
internalSpans []traceSpanInternal
33+
34+
// mutable, must be protected by mutex
35+
mu sync.RWMutex
36+
name string
37+
startTime time.Time
38+
endTime time.Time
39+
attributes []TraceAttribute
40+
children []*TraceSpan
41+
}
42+
43+
type TraceAttribute struct {
44+
Key string
45+
Value TraceValue
46+
}
47+
48+
type TraceValue struct {
49+
v any
50+
}
51+
52+
func (t *TraceValue) AsString() string {
53+
return fmt.Sprint(t.v)
54+
}
55+
56+
func (t *TraceValue) AsInt64() int64 {
57+
v, _ := util.ToInt64(t.v)
58+
return v
59+
}
60+
61+
func (t *TraceValue) AsFloat64() float64 {
62+
v, _ := util.ToFloat64(t.v)
63+
return v
64+
}
65+
66+
var globalTraceStarters []traceStarter
67+
68+
type Tracer struct {
69+
starters []traceStarter
70+
}
71+
72+
func (s *TraceSpan) SetAttributeString(key, value string) *TraceSpan {
73+
s.mu.Lock()
74+
defer s.mu.Unlock()
75+
76+
s.attributes = append(s.attributes, TraceAttribute{Key: key, Value: TraceValue{v: value}})
77+
return s
78+
}
79+
80+
func (t *Tracer) Start(ctx context.Context, spanName string) (context.Context, *TraceSpan) {
81+
starters := t.starters
82+
if starters == nil {
83+
starters = globalTraceStarters
84+
}
85+
ts := &TraceSpan{name: spanName, startTime: time.Now()}
86+
existingCtxSpan, _ := ctx.Value(ContextKeySpan).(*TraceSpan)
87+
if existingCtxSpan != nil {
88+
existingCtxSpan.mu.Lock()
89+
existingCtxSpan.children = append(existingCtxSpan.children, ts)
90+
existingCtxSpan.mu.Unlock()
91+
ts.parent = existingCtxSpan
92+
}
93+
for internalSpanIdx, tsp := range starters {
94+
var internalSpan traceSpanInternal
95+
ctx, internalSpan = tsp.start(ctx, ts, internalSpanIdx)
96+
ts.internalSpans = append(ts.internalSpans, internalSpan)
97+
}
98+
ctx = context.WithValue(ctx, ContextKeySpan, ts)
99+
return ctx, ts
100+
}
101+
102+
func (s *TraceSpan) End() {
103+
s.mu.Lock()
104+
s.endTime = time.Now()
105+
s.mu.Unlock()
106+
107+
for _, tsp := range s.internalSpans {
108+
tsp.end()
109+
}
110+
}
111+
112+
func GetTracer() *Tracer {
113+
return &Tracer{}
114+
}
115+
116+
func GetContextSpan(ctx context.Context) *TraceSpan {
117+
ts, _ := ctx.Value(ContextKeySpan).(*TraceSpan)
118+
return ts
119+
}

modules/gtprof/trace_builtin.go

+66
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,66 @@
1+
// Copyright 2024 The Gitea Authors. All rights reserved.
2+
// SPDX-License-Identifier: MIT
3+
4+
package gtprof
5+
6+
import (
7+
"context"
8+
"fmt"
9+
"strings"
10+
"time"
11+
12+
"code.gitea.io/gitea/modules/tailmsg"
13+
)
14+
15+
type traceBuiltinStarter struct{}
16+
17+
type traceBuiltinSpan struct {
18+
ts *TraceSpan
19+
20+
internalSpanIdx int
21+
}
22+
23+
func (t *traceBuiltinSpan) toString(out *strings.Builder, indent int) {
24+
t.ts.mu.RLock()
25+
defer t.ts.mu.RUnlock()
26+
27+
out.WriteString(strings.Repeat(" ", indent))
28+
out.WriteString(t.ts.name)
29+
if t.ts.endTime.IsZero() {
30+
out.WriteString(" duration: (not ended)")
31+
} else {
32+
out.WriteString(fmt.Sprintf(" duration: %.4fs", t.ts.endTime.Sub(t.ts.startTime).Seconds()))
33+
}
34+
out.WriteString("\n")
35+
for _, a := range t.ts.attributes {
36+
out.WriteString(strings.Repeat(" ", indent+2))
37+
out.WriteString(a.Key)
38+
out.WriteString(": ")
39+
out.WriteString(a.Value.AsString())
40+
out.WriteString("\n")
41+
}
42+
for _, c := range t.ts.children {
43+
span := c.internalSpans[t.internalSpanIdx].(*traceBuiltinSpan)
44+
span.toString(out, indent+2)
45+
}
46+
}
47+
48+
func (t *traceBuiltinSpan) end() {
49+
if t.ts.parent == nil {
50+
// FIXME: debug purpose only
51+
// FIXME: it should distinguish between http response network lag and actual processing time
52+
if len(t.ts.children) > 3 || t.ts.endTime.Sub(t.ts.startTime) > 100*time.Millisecond {
53+
sb := &strings.Builder{}
54+
t.toString(sb, 0)
55+
tailmsg.GetManager().GetTraceRecorder().Record(sb.String())
56+
}
57+
}
58+
}
59+
60+
func (t *traceBuiltinStarter) start(ctx context.Context, traceSpan *TraceSpan, internalSpanIdx int) (context.Context, traceSpanInternal) {
61+
return ctx, &traceBuiltinSpan{ts: traceSpan, internalSpanIdx: internalSpanIdx}
62+
}
63+
64+
func init() {
65+
globalTraceStarters = append(globalTraceStarters, &traceBuiltinStarter{})
66+
}

modules/gtprof/trace_const.go

+19
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,19 @@
1+
// Copyright 2024 The Gitea Authors. All rights reserved.
2+
// SPDX-License-Identifier: MIT
3+
4+
package gtprof
5+
6+
// Some interesting names could be found in https://github.com/open-telemetry/opentelemetry-go/tree/main/semconv
7+
8+
const (
9+
TraceSpanHTTP = "http"
10+
TraceSpanGitRun = "git-run"
11+
TraceSpanDatabase = "database"
12+
)
13+
14+
const (
15+
TraceAttrFuncCaller = "func.caller"
16+
TraceAttrDbSQL = "db.sql"
17+
TraceAttrGitCommand = "git.command"
18+
TraceAttrHTTPRoute = "http.route"
19+
)

modules/tailmsg/taillog.go

+73
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,73 @@
1+
// Copyright 2024 The Gitea Authors. All rights reserved.
2+
// SPDX-License-Identifier: MIT
3+
4+
package tailmsg
5+
6+
import (
7+
"sync"
8+
"time"
9+
)
10+
11+
type MsgRecord struct {
12+
Time time.Time
13+
Content string
14+
}
15+
16+
type MsgRecorder interface {
17+
Record(content string)
18+
GetRecords() []*MsgRecord
19+
}
20+
21+
type memoryMsgRecorder struct {
22+
mu sync.RWMutex
23+
msgs []*MsgRecord
24+
limit int
25+
}
26+
27+
// TODO: use redis for a clustered environment
28+
29+
func (m *memoryMsgRecorder) Record(content string) {
30+
m.mu.Lock()
31+
defer m.mu.Unlock()
32+
m.msgs = append(m.msgs, &MsgRecord{
33+
Time: time.Now(),
34+
Content: content,
35+
})
36+
if len(m.msgs) > m.limit {
37+
m.msgs = m.msgs[len(m.msgs)-m.limit:]
38+
}
39+
}
40+
41+
func (m *memoryMsgRecorder) GetRecords() []*MsgRecord {
42+
m.mu.RLock()
43+
defer m.mu.RUnlock()
44+
ret := make([]*MsgRecord, len(m.msgs))
45+
copy(ret, m.msgs)
46+
return ret
47+
}
48+
49+
func NewMsgRecorder(limit int) MsgRecorder {
50+
return &memoryMsgRecorder{
51+
limit: limit,
52+
}
53+
}
54+
55+
type Manager struct {
56+
traceRecorder MsgRecorder
57+
logRecorder MsgRecorder
58+
}
59+
60+
func (m *Manager) GetTraceRecorder() MsgRecorder {
61+
return m.traceRecorder
62+
}
63+
64+
func (m *Manager) GetLogRecorder() MsgRecorder {
65+
return m.logRecorder
66+
}
67+
68+
var GetManager = sync.OnceValue(func() *Manager {
69+
return &Manager{
70+
traceRecorder: NewMsgRecorder(100),
71+
logRecorder: NewMsgRecorder(1000),
72+
}
73+
})

options/locale/locale_en-US.ini

+2-1
Original file line numberDiff line numberDiff line change
@@ -3355,6 +3355,8 @@ monitor.previous = Previous Time
33553355
monitor.execute_times = Executions
33563356
monitor.process = Running Processes
33573357
monitor.stacktrace = Stacktrace
3358+
monitor.trace = Trace
3359+
monitor.performance_logs = Performance Logs
33583360
monitor.processes_count = %d Processes
33593361
monitor.download_diagnosis_report = Download diagnosis report
33603362
monitor.desc = Description
@@ -3363,7 +3365,6 @@ monitor.execute_time = Execution Time
33633365
monitor.last_execution_result = Result
33643366
monitor.process.cancel = Cancel process
33653367
monitor.process.cancel_desc = Cancelling a process may cause data loss
3366-
monitor.process.cancel_notices = Cancel: <strong>%s</strong>?
33673368
monitor.process.children = Children
33683369
33693370
monitor.queues = Queues

0 commit comments

Comments
 (0)