From 7069369e0390ab1110a41bcf36a8b7e0ac294226 Mon Sep 17 00:00:00 2001 From: wxiaoguang Date: Wed, 22 Jan 2025 02:57:07 +0800 Subject: [PATCH] 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 --- cmd/web.go | 4 + models/db/engine_hook.go | 23 +++- models/db/engine_init.go | 2 +- modules/git/command.go | 12 +- modules/git/command_test.go | 2 +- modules/gtprof/event.go | 32 +++++ modules/gtprof/trace.go | 175 ++++++++++++++++++++++++++++ modules/gtprof/trace_builtin.go | 96 +++++++++++++++ modules/gtprof/trace_const.go | 19 +++ modules/gtprof/trace_test.go | 93 +++++++++++++++ modules/tailmsg/talimsg.go | 73 ++++++++++++ modules/web/routing/context.go | 11 +- options/locale/locale_en-US.ini | 3 +- routers/common/middleware.go | 15 ++- routers/web/admin/admin.go | 1 + routers/web/admin/diagnosis.go | 18 ++- routers/web/admin/perftrace.go | 18 +++ routers/web/admin/stacktrace.go | 11 +- routers/web/web.go | 1 + templates/admin/navbar.tmpl | 6 +- templates/admin/perftrace.tmpl | 13 +++ templates/admin/stacktrace-row.tmpl | 5 +- templates/admin/stacktrace.tmpl | 28 +---- templates/admin/trace_tabs.tmpl | 19 +++ 24 files changed, 628 insertions(+), 52 deletions(-) create mode 100644 modules/gtprof/event.go create mode 100644 modules/gtprof/trace.go create mode 100644 modules/gtprof/trace_builtin.go create mode 100644 modules/gtprof/trace_const.go create mode 100644 modules/gtprof/trace_test.go create mode 100644 modules/tailmsg/talimsg.go create mode 100644 routers/web/admin/perftrace.go create mode 100644 templates/admin/perftrace.tmpl create mode 100644 templates/admin/trace_tabs.tmpl diff --git a/cmd/web.go b/cmd/web.go index f8217758e5..dc5c6de48a 100644 --- a/cmd/web.go +++ b/cmd/web.go @@ -18,10 +18,12 @@ import ( "code.gitea.io/gitea/modules/container" "code.gitea.io/gitea/modules/graceful" + "code.gitea.io/gitea/modules/gtprof" "code.gitea.io/gitea/modules/log" "code.gitea.io/gitea/modules/process" "code.gitea.io/gitea/modules/public" "code.gitea.io/gitea/modules/setting" + "code.gitea.io/gitea/modules/util" "code.gitea.io/gitea/routers" "code.gitea.io/gitea/routers/install" @@ -218,6 +220,8 @@ func serveInstalled(ctx *cli.Context) error { } } + gtprof.EnableBuiltinTracer(util.Iif(setting.IsProd, 2000*time.Millisecond, 100*time.Millisecond)) + // Set up Chi routes webRoutes := routers.NormalRoutes() err := listen(webRoutes, true) diff --git a/models/db/engine_hook.go b/models/db/engine_hook.go index b4c543c3dd..2c9fc09c99 100644 --- a/models/db/engine_hook.go +++ b/models/db/engine_hook.go @@ -7,23 +7,36 @@ import ( "context" "time" + "code.gitea.io/gitea/modules/gtprof" "code.gitea.io/gitea/modules/log" + "code.gitea.io/gitea/modules/setting" "xorm.io/xorm/contexts" ) -type SlowQueryHook struct { +type EngineHook struct { Threshold time.Duration Logger log.Logger } -var _ contexts.Hook = (*SlowQueryHook)(nil) +var _ contexts.Hook = (*EngineHook)(nil) -func (*SlowQueryHook) BeforeProcess(c *contexts.ContextHook) (context.Context, error) { - return c.Ctx, nil +func (*EngineHook) BeforeProcess(c *contexts.ContextHook) (context.Context, error) { + ctx, _ := gtprof.GetTracer().Start(c.Ctx, gtprof.TraceSpanDatabase) + return ctx, nil } -func (h *SlowQueryHook) AfterProcess(c *contexts.ContextHook) error { +func (h *EngineHook) AfterProcess(c *contexts.ContextHook) error { + span := gtprof.GetContextSpan(c.Ctx) + if span != nil { + // Do not record SQL parameters here: + // * It shouldn't expose the parameters because they contain sensitive information, end users need to report the trace details safely. + // * Some parameters contain quite long texts, waste memory and are difficult to display. + span.SetAttributeString(gtprof.TraceAttrDbSQL, c.SQL) + span.End() + } else { + setting.PanicInDevOrTesting("span in database engine hook is nil") + } if c.ExecuteTime >= h.Threshold { // 8 is the amount of skips passed to runtime.Caller, so that in the log the correct function // is being displayed (the function that ultimately wants to execute the query in the code) diff --git a/models/db/engine_init.go b/models/db/engine_init.go index da85018957..edca697934 100644 --- a/models/db/engine_init.go +++ b/models/db/engine_init.go @@ -72,7 +72,7 @@ func InitEngine(ctx context.Context) error { xe.SetDefaultContext(ctx) if setting.Database.SlowQueryThreshold > 0 { - xe.AddHook(&SlowQueryHook{ + xe.AddHook(&EngineHook{ Threshold: setting.Database.SlowQueryThreshold, Logger: log.GetLogger("xorm"), }) diff --git a/modules/git/command.go b/modules/git/command.go index 2584e3cc57..602d00f027 100644 --- a/modules/git/command.go +++ b/modules/git/command.go @@ -18,6 +18,7 @@ import ( "time" "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 + "code.gitea.io/gitea/modules/gtprof" "code.gitea.io/gitea/modules/log" "code.gitea.io/gitea/modules/process" "code.gitea.io/gitea/modules/util" @@ -54,7 +55,7 @@ func logArgSanitize(arg string) string { } else if filepath.IsAbs(arg) { base := filepath.Base(arg) dir := filepath.Dir(arg) - return filepath.Join(filepath.Base(dir), base) + return ".../" + filepath.Join(filepath.Base(dir), base) } return arg } @@ -295,15 +296,20 @@ func (c *Command) run(skip int, opts *RunOpts) error { timeout = defaultCommandExecutionTimeout } - var desc string + cmdLogString := c.LogString() callerInfo := util.CallerFuncName(1 /* util */ + 1 /* this */ + skip /* parent */) if pos := strings.LastIndex(callerInfo, "/"); pos >= 0 { callerInfo = callerInfo[pos+1:] } // these logs are for debugging purposes only, so no guarantee of correctness or stability - desc = fmt.Sprintf("git.Run(by:%s, repo:%s): %s", callerInfo, logArgSanitize(opts.Dir), c.LogString()) + desc := fmt.Sprintf("git.Run(by:%s, repo:%s): %s", callerInfo, logArgSanitize(opts.Dir), cmdLogString) log.Debug("git.Command: %s", desc) + _, span := gtprof.GetTracer().Start(c.parentContext, gtprof.TraceSpanGitRun) + defer span.End() + span.SetAttributeString(gtprof.TraceAttrFuncCaller, callerInfo) + span.SetAttributeString(gtprof.TraceAttrGitCommand, cmdLogString) + var ctx context.Context var cancel context.CancelFunc var finished context.CancelFunc diff --git a/modules/git/command_test.go b/modules/git/command_test.go index 0823afd7f7..e988714db7 100644 --- a/modules/git/command_test.go +++ b/modules/git/command_test.go @@ -58,5 +58,5 @@ func TestCommandString(t *testing.T) { assert.EqualValues(t, cmd.prog+` a "-m msg" "it's a test" "say \"hello\""`, cmd.LogString()) cmd = NewCommandContextNoGlobals(context.Background(), "url: https://a:b@c/", "/root/dir-a/dir-b") - assert.EqualValues(t, cmd.prog+` "url: https://sanitized-credential@c/" dir-a/dir-b`, cmd.LogString()) + assert.EqualValues(t, cmd.prog+` "url: https://sanitized-credential@c/" .../dir-a/dir-b`, cmd.LogString()) } diff --git a/modules/gtprof/event.go b/modules/gtprof/event.go new file mode 100644 index 0000000000..da4a0faff9 --- /dev/null +++ b/modules/gtprof/event.go @@ -0,0 +1,32 @@ +// Copyright 2025 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package gtprof + +type EventConfig struct { + attributes []*TraceAttribute +} + +type EventOption interface { + applyEvent(*EventConfig) +} + +type applyEventFunc func(*EventConfig) + +func (f applyEventFunc) applyEvent(cfg *EventConfig) { + f(cfg) +} + +func WithAttributes(attrs ...*TraceAttribute) EventOption { + return applyEventFunc(func(cfg *EventConfig) { + cfg.attributes = append(cfg.attributes, attrs...) + }) +} + +func eventConfigFromOptions(options ...EventOption) *EventConfig { + cfg := &EventConfig{} + for _, opt := range options { + opt.applyEvent(cfg) + } + return cfg +} diff --git a/modules/gtprof/trace.go b/modules/gtprof/trace.go new file mode 100644 index 0000000000..ad67c226dc --- /dev/null +++ b/modules/gtprof/trace.go @@ -0,0 +1,175 @@ +// Copyright 2025 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package gtprof + +import ( + "context" + "fmt" + "sync" + "time" + + "code.gitea.io/gitea/modules/util" +) + +type contextKey struct { + name string +} + +var contextKeySpan = &contextKey{"span"} + +type traceStarter interface { + start(ctx context.Context, traceSpan *TraceSpan, internalSpanIdx int) (context.Context, traceSpanInternal) +} + +type traceSpanInternal interface { + addEvent(name string, cfg *EventConfig) + recordError(err error, cfg *EventConfig) + end() +} + +type TraceSpan struct { + // immutable + parent *TraceSpan + internalSpans []traceSpanInternal + internalContexts []context.Context + + // mutable, must be protected by mutex + mu sync.RWMutex + name string + statusCode uint32 + statusDesc string + startTime time.Time + endTime time.Time + attributes []*TraceAttribute + children []*TraceSpan +} + +type TraceAttribute struct { + Key string + Value TraceValue +} + +type TraceValue struct { + v any +} + +func (t *TraceValue) AsString() string { + return fmt.Sprint(t.v) +} + +func (t *TraceValue) AsInt64() int64 { + v, _ := util.ToInt64(t.v) + return v +} + +func (t *TraceValue) AsFloat64() float64 { + v, _ := util.ToFloat64(t.v) + return v +} + +var globalTraceStarters []traceStarter + +type Tracer struct { + starters []traceStarter +} + +func (s *TraceSpan) SetName(name string) { + s.mu.Lock() + defer s.mu.Unlock() + s.name = name +} + +func (s *TraceSpan) SetStatus(code uint32, desc string) { + s.mu.Lock() + defer s.mu.Unlock() + s.statusCode, s.statusDesc = code, desc +} + +func (s *TraceSpan) AddEvent(name string, options ...EventOption) { + cfg := eventConfigFromOptions(options...) + for _, tsp := range s.internalSpans { + tsp.addEvent(name, cfg) + } +} + +func (s *TraceSpan) RecordError(err error, options ...EventOption) { + cfg := eventConfigFromOptions(options...) + for _, tsp := range s.internalSpans { + tsp.recordError(err, cfg) + } +} + +func (s *TraceSpan) SetAttributeString(key, value string) *TraceSpan { + s.mu.Lock() + defer s.mu.Unlock() + + s.attributes = append(s.attributes, &TraceAttribute{Key: key, Value: TraceValue{v: value}}) + return s +} + +func (t *Tracer) Start(ctx context.Context, spanName string) (context.Context, *TraceSpan) { + starters := t.starters + if starters == nil { + starters = globalTraceStarters + } + ts := &TraceSpan{name: spanName, startTime: time.Now()} + parentSpan := GetContextSpan(ctx) + if parentSpan != nil { + parentSpan.mu.Lock() + parentSpan.children = append(parentSpan.children, ts) + parentSpan.mu.Unlock() + ts.parent = parentSpan + } + + parentCtx := ctx + for internalSpanIdx, tsp := range starters { + var internalSpan traceSpanInternal + if parentSpan != nil { + parentCtx = parentSpan.internalContexts[internalSpanIdx] + } + ctx, internalSpan = tsp.start(parentCtx, ts, internalSpanIdx) + ts.internalContexts = append(ts.internalContexts, ctx) + ts.internalSpans = append(ts.internalSpans, internalSpan) + } + ctx = context.WithValue(ctx, contextKeySpan, ts) + return ctx, ts +} + +type mutableContext interface { + context.Context + SetContextValue(key, value any) + GetContextValue(key any) any +} + +// StartInContext starts a trace span in Gitea's mutable context (usually the web request context). +// 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. +// So here we use our "reqctx" framework to achieve the same result: web request context could always see the latest "span". +func (t *Tracer) StartInContext(ctx mutableContext, spanName string) (*TraceSpan, func()) { + curTraceSpan := GetContextSpan(ctx) + _, newTraceSpan := GetTracer().Start(ctx, spanName) + ctx.SetContextValue(contextKeySpan, newTraceSpan) + return newTraceSpan, func() { + newTraceSpan.End() + ctx.SetContextValue(contextKeySpan, curTraceSpan) + } +} + +func (s *TraceSpan) End() { + s.mu.Lock() + s.endTime = time.Now() + s.mu.Unlock() + + for _, tsp := range s.internalSpans { + tsp.end() + } +} + +func GetTracer() *Tracer { + return &Tracer{} +} + +func GetContextSpan(ctx context.Context) *TraceSpan { + ts, _ := ctx.Value(contextKeySpan).(*TraceSpan) + return ts +} diff --git a/modules/gtprof/trace_builtin.go b/modules/gtprof/trace_builtin.go new file mode 100644 index 0000000000..41743a25e4 --- /dev/null +++ b/modules/gtprof/trace_builtin.go @@ -0,0 +1,96 @@ +// Copyright 2025 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package gtprof + +import ( + "context" + "fmt" + "strings" + "sync/atomic" + "time" + + "code.gitea.io/gitea/modules/tailmsg" +) + +type traceBuiltinStarter struct{} + +type traceBuiltinSpan struct { + ts *TraceSpan + + internalSpanIdx int +} + +func (t *traceBuiltinSpan) addEvent(name string, cfg *EventConfig) { + // No-op because builtin tracer doesn't need it. + // In the future we might use it to mark the time point between backend logic and network response. +} + +func (t *traceBuiltinSpan) recordError(err error, cfg *EventConfig) { + // No-op because builtin tracer doesn't need it. + // Actually Gitea doesn't handle err this way in most cases +} + +func (t *traceBuiltinSpan) toString(out *strings.Builder, indent int) { + t.ts.mu.RLock() + defer t.ts.mu.RUnlock() + + out.WriteString(strings.Repeat(" ", indent)) + out.WriteString(t.ts.name) + if t.ts.endTime.IsZero() { + out.WriteString(" duration: (not ended)") + } else { + out.WriteString(fmt.Sprintf(" duration=%.4fs", t.ts.endTime.Sub(t.ts.startTime).Seconds())) + } + for _, a := range t.ts.attributes { + out.WriteString(" ") + out.WriteString(a.Key) + out.WriteString("=") + value := a.Value.AsString() + if strings.ContainsAny(value, " \t\r\n") { + quoted := false + for _, c := range "\"'`" { + if quoted = !strings.Contains(value, string(c)); quoted { + value = string(c) + value + string(c) + break + } + } + if !quoted { + value = fmt.Sprintf("%q", value) + } + } + out.WriteString(value) + } + out.WriteString("\n") + for _, c := range t.ts.children { + span := c.internalSpans[t.internalSpanIdx].(*traceBuiltinSpan) + span.toString(out, indent+2) + } +} + +func (t *traceBuiltinSpan) end() { + if t.ts.parent == nil { + // TODO: debug purpose only + // TODO: it should distinguish between http response network lag and actual processing time + threshold := time.Duration(traceBuiltinThreshold.Load()) + if threshold != 0 && t.ts.endTime.Sub(t.ts.startTime) > threshold { + sb := &strings.Builder{} + t.toString(sb, 0) + tailmsg.GetManager().GetTraceRecorder().Record(sb.String()) + } + } +} + +func (t *traceBuiltinStarter) start(ctx context.Context, traceSpan *TraceSpan, internalSpanIdx int) (context.Context, traceSpanInternal) { + return ctx, &traceBuiltinSpan{ts: traceSpan, internalSpanIdx: internalSpanIdx} +} + +func init() { + globalTraceStarters = append(globalTraceStarters, &traceBuiltinStarter{}) +} + +var traceBuiltinThreshold atomic.Int64 + +func EnableBuiltinTracer(threshold time.Duration) { + traceBuiltinThreshold.Store(int64(threshold)) +} diff --git a/modules/gtprof/trace_const.go b/modules/gtprof/trace_const.go new file mode 100644 index 0000000000..af9ce9223f --- /dev/null +++ b/modules/gtprof/trace_const.go @@ -0,0 +1,19 @@ +// Copyright 2025 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package gtprof + +// Some interesting names could be found in https://github.com/open-telemetry/opentelemetry-go/tree/main/semconv + +const ( + TraceSpanHTTP = "http" + TraceSpanGitRun = "git-run" + TraceSpanDatabase = "database" +) + +const ( + TraceAttrFuncCaller = "func.caller" + TraceAttrDbSQL = "db.sql" + TraceAttrGitCommand = "git.command" + TraceAttrHTTPRoute = "http.route" +) diff --git a/modules/gtprof/trace_test.go b/modules/gtprof/trace_test.go new file mode 100644 index 0000000000..7e1743c88d --- /dev/null +++ b/modules/gtprof/trace_test.go @@ -0,0 +1,93 @@ +// Copyright 2025 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package gtprof + +import ( + "context" + "testing" + + "github.com/stretchr/testify/assert" +) + +// "vendor span" is a simple demo for a span from a vendor library + +var vendorContextKey any = "vendorContextKey" + +type vendorSpan struct { + name string + children []*vendorSpan +} + +func vendorTraceStart(ctx context.Context, name string) (context.Context, *vendorSpan) { + span := &vendorSpan{name: name} + parentSpan, ok := ctx.Value(vendorContextKey).(*vendorSpan) + if ok { + parentSpan.children = append(parentSpan.children, span) + } + ctx = context.WithValue(ctx, vendorContextKey, span) + return ctx, span +} + +// below "testTrace*" integrate the vendor span into our trace system + +type testTraceSpan struct { + vendorSpan *vendorSpan +} + +func (t *testTraceSpan) addEvent(name string, cfg *EventConfig) {} + +func (t *testTraceSpan) recordError(err error, cfg *EventConfig) {} + +func (t *testTraceSpan) end() {} + +type testTraceStarter struct{} + +func (t *testTraceStarter) start(ctx context.Context, traceSpan *TraceSpan, internalSpanIdx int) (context.Context, traceSpanInternal) { + ctx, span := vendorTraceStart(ctx, traceSpan.name) + return ctx, &testTraceSpan{span} +} + +func TestTraceStarter(t *testing.T) { + globalTraceStarters = []traceStarter{&testTraceStarter{}} + + ctx := context.Background() + ctx, span := GetTracer().Start(ctx, "root") + defer span.End() + + func(ctx context.Context) { + ctx, span := GetTracer().Start(ctx, "span1") + defer span.End() + func(ctx context.Context) { + _, span := GetTracer().Start(ctx, "spanA") + defer span.End() + }(ctx) + func(ctx context.Context) { + _, span := GetTracer().Start(ctx, "spanB") + defer span.End() + }(ctx) + }(ctx) + + func(ctx context.Context) { + _, span := GetTracer().Start(ctx, "span2") + defer span.End() + }(ctx) + + var spanFullNames []string + var collectSpanNames func(parentFullName string, s *vendorSpan) + collectSpanNames = func(parentFullName string, s *vendorSpan) { + fullName := parentFullName + "/" + s.name + spanFullNames = append(spanFullNames, fullName) + for _, c := range s.children { + collectSpanNames(fullName, c) + } + } + collectSpanNames("", span.internalSpans[0].(*testTraceSpan).vendorSpan) + assert.Equal(t, []string{ + "/root", + "/root/span1", + "/root/span1/spanA", + "/root/span1/spanB", + "/root/span2", + }, spanFullNames) +} diff --git a/modules/tailmsg/talimsg.go b/modules/tailmsg/talimsg.go new file mode 100644 index 0000000000..aafc98e2d2 --- /dev/null +++ b/modules/tailmsg/talimsg.go @@ -0,0 +1,73 @@ +// Copyright 2025 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package tailmsg + +import ( + "sync" + "time" +) + +type MsgRecord struct { + Time time.Time + Content string +} + +type MsgRecorder interface { + Record(content string) + GetRecords() []*MsgRecord +} + +type memoryMsgRecorder struct { + mu sync.RWMutex + msgs []*MsgRecord + limit int +} + +// TODO: use redis for a clustered environment + +func (m *memoryMsgRecorder) Record(content string) { + m.mu.Lock() + defer m.mu.Unlock() + m.msgs = append(m.msgs, &MsgRecord{ + Time: time.Now(), + Content: content, + }) + if len(m.msgs) > m.limit { + m.msgs = m.msgs[len(m.msgs)-m.limit:] + } +} + +func (m *memoryMsgRecorder) GetRecords() []*MsgRecord { + m.mu.RLock() + defer m.mu.RUnlock() + ret := make([]*MsgRecord, len(m.msgs)) + copy(ret, m.msgs) + return ret +} + +func NewMsgRecorder(limit int) MsgRecorder { + return &memoryMsgRecorder{ + limit: limit, + } +} + +type Manager struct { + traceRecorder MsgRecorder + logRecorder MsgRecorder +} + +func (m *Manager) GetTraceRecorder() MsgRecorder { + return m.traceRecorder +} + +func (m *Manager) GetLogRecorder() MsgRecorder { + return m.logRecorder +} + +var GetManager = sync.OnceValue(func() *Manager { + return &Manager{ + traceRecorder: NewMsgRecorder(100), + logRecorder: NewMsgRecorder(1000), + } +}) diff --git a/modules/web/routing/context.go b/modules/web/routing/context.go index fbf371b839..d3eb98f83d 100644 --- a/modules/web/routing/context.go +++ b/modules/web/routing/context.go @@ -6,6 +6,9 @@ package routing import ( "context" "net/http" + + "code.gitea.io/gitea/modules/gtprof" + "code.gitea.io/gitea/modules/reqctx" ) type contextKeyType struct{} @@ -14,10 +17,12 @@ var contextKey contextKeyType // RecordFuncInfo records a func info into context func RecordFuncInfo(ctx context.Context, funcInfo *FuncInfo) (end func()) { - // TODO: reqCtx := reqctx.FromContext(ctx), add trace support end = func() {} - - // save the func info into the context record + if reqCtx := reqctx.FromContext(ctx); reqCtx != nil { + var traceSpan *gtprof.TraceSpan + traceSpan, end = gtprof.GetTracer().StartInContext(reqCtx, "http.func") + traceSpan.SetAttributeString("func", funcInfo.shortName) + } if record, ok := ctx.Value(contextKey).(*requestRecord); ok { record.lock.Lock() record.funcInfo = funcInfo diff --git a/options/locale/locale_en-US.ini b/options/locale/locale_en-US.ini index 533eb136f9..85d2c71ec7 100644 --- a/options/locale/locale_en-US.ini +++ b/options/locale/locale_en-US.ini @@ -3368,6 +3368,8 @@ monitor.previous = Previous Time monitor.execute_times = Executions monitor.process = Running Processes monitor.stacktrace = Stacktrace +monitor.trace = Trace +monitor.performance_logs = Performance Logs monitor.processes_count = %d Processes monitor.download_diagnosis_report = Download diagnosis report monitor.desc = Description @@ -3376,7 +3378,6 @@ monitor.execute_time = Execution Time monitor.last_execution_result = Result monitor.process.cancel = Cancel process monitor.process.cancel_desc = Cancelling a process may cause data loss -monitor.process.cancel_notices = Cancel: %s? monitor.process.children = Children monitor.queues = Queues diff --git a/routers/common/middleware.go b/routers/common/middleware.go index de59b78583..2ba02de8ed 100644 --- a/routers/common/middleware.go +++ b/routers/common/middleware.go @@ -9,6 +9,7 @@ import ( "strings" "code.gitea.io/gitea/modules/cache" + "code.gitea.io/gitea/modules/gtprof" "code.gitea.io/gitea/modules/httplib" "code.gitea.io/gitea/modules/reqctx" "code.gitea.io/gitea/modules/setting" @@ -52,6 +53,14 @@ func RequestContextHandler() func(h http.Handler) http.Handler { ctx, finished := reqctx.NewRequestContext(req.Context(), profDesc) defer finished() + ctx, span := gtprof.GetTracer().Start(ctx, gtprof.TraceSpanHTTP) + req = req.WithContext(ctx) + defer func() { + chiCtx := chi.RouteContext(req.Context()) + span.SetAttributeString(gtprof.TraceAttrHTTPRoute, chiCtx.RoutePattern()) + span.End() + }() + defer func() { if err := recover(); err != nil { RenderPanicErrorPage(respWriter, req, err) // it should never panic @@ -75,11 +84,11 @@ func ChiRoutePathHandler() func(h http.Handler) http.Handler { // make sure chi uses EscapedPath(RawPath) as RoutePath, then "%2f" could be handled correctly return func(next http.Handler) http.Handler { return http.HandlerFunc(func(resp http.ResponseWriter, req *http.Request) { - ctx := chi.RouteContext(req.Context()) + chiCtx := chi.RouteContext(req.Context()) if req.URL.RawPath == "" { - ctx.RoutePath = req.URL.EscapedPath() + chiCtx.RoutePath = req.URL.EscapedPath() } else { - ctx.RoutePath = req.URL.RawPath + chiCtx.RoutePath = req.URL.RawPath } next.ServeHTTP(resp, req) }) diff --git a/routers/web/admin/admin.go b/routers/web/admin/admin.go index 3902a1efb1..0cd13acf60 100644 --- a/routers/web/admin/admin.go +++ b/routers/web/admin/admin.go @@ -37,6 +37,7 @@ const ( tplSelfCheck templates.TplName = "admin/self_check" tplCron templates.TplName = "admin/cron" tplQueue templates.TplName = "admin/queue" + tplPerfTrace templates.TplName = "admin/perftrace" tplStacktrace templates.TplName = "admin/stacktrace" tplQueueManage templates.TplName = "admin/queue_manage" tplStats templates.TplName = "admin/stats" diff --git a/routers/web/admin/diagnosis.go b/routers/web/admin/diagnosis.go index 020554a35a..d040dbe0ba 100644 --- a/routers/web/admin/diagnosis.go +++ b/routers/web/admin/diagnosis.go @@ -10,13 +10,15 @@ import ( "time" "code.gitea.io/gitea/modules/httplib" + "code.gitea.io/gitea/modules/tailmsg" + "code.gitea.io/gitea/modules/util" "code.gitea.io/gitea/services/context" ) func MonitorDiagnosis(ctx *context.Context) { seconds := ctx.FormInt64("seconds") - if seconds <= 5 { - seconds = 5 + if seconds <= 1 { + seconds = 1 } if seconds > 300 { seconds = 300 @@ -65,4 +67,16 @@ func MonitorDiagnosis(ctx *context.Context) { return } _ = pprof.Lookup("heap").WriteTo(f, 0) + + f, err = zipWriter.CreateHeader(&zip.FileHeader{Name: "perftrace.txt", Method: zip.Deflate, Modified: time.Now()}) + if err != nil { + ctx.ServerError("Failed to create zip file", err) + return + } + for _, record := range tailmsg.GetManager().GetTraceRecorder().GetRecords() { + _, _ = f.Write(util.UnsafeStringToBytes(record.Time.Format(time.RFC3339))) + _, _ = f.Write([]byte(" ")) + _, _ = f.Write(util.UnsafeStringToBytes((record.Content))) + _, _ = f.Write([]byte("\n\n")) + } } diff --git a/routers/web/admin/perftrace.go b/routers/web/admin/perftrace.go new file mode 100644 index 0000000000..51ee57da10 --- /dev/null +++ b/routers/web/admin/perftrace.go @@ -0,0 +1,18 @@ +// Copyright 2025 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package admin + +import ( + "net/http" + + "code.gitea.io/gitea/modules/tailmsg" + "code.gitea.io/gitea/services/context" +) + +func PerfTrace(ctx *context.Context) { + monitorTraceCommon(ctx) + ctx.Data["PageIsAdminMonitorPerfTrace"] = true + ctx.Data["PerfTraceRecords"] = tailmsg.GetManager().GetTraceRecorder().GetRecords() + ctx.HTML(http.StatusOK, tplPerfTrace) +} diff --git a/routers/web/admin/stacktrace.go b/routers/web/admin/stacktrace.go index ff751be621..2b8c2fb4af 100644 --- a/routers/web/admin/stacktrace.go +++ b/routers/web/admin/stacktrace.go @@ -12,10 +12,17 @@ import ( "code.gitea.io/gitea/services/context" ) +func monitorTraceCommon(ctx *context.Context) { + ctx.Data["Title"] = ctx.Tr("admin.monitor") + ctx.Data["PageIsAdminMonitorTrace"] = true + // Hide the performance trace tab in production, because it shows a lot of SQLs and is not that useful for end users. + // To avoid confusing end users, do not let them know this tab. End users should "download diagnosis report" instead. + ctx.Data["ShowAdminPerformanceTraceTab"] = !setting.IsProd +} + // Stacktrace show admin monitor goroutines page func Stacktrace(ctx *context.Context) { - ctx.Data["Title"] = ctx.Tr("admin.monitor") - ctx.Data["PageIsAdminMonitorStacktrace"] = true + monitorTraceCommon(ctx) ctx.Data["GoroutineCount"] = runtime.NumGoroutine() diff --git a/routers/web/web.go b/routers/web/web.go index c1790398f8..ef26dd9a74 100644 --- a/routers/web/web.go +++ b/routers/web/web.go @@ -720,6 +720,7 @@ func registerRoutes(m *web.Router) { m.Group("/monitor", func() { m.Get("/stats", admin.MonitorStats) m.Get("/cron", admin.CronTasks) + m.Get("/perftrace", admin.PerfTrace) m.Get("/stacktrace", admin.Stacktrace) m.Post("/stacktrace/cancel/{pid}", admin.StacktraceCancel) m.Get("/queue", admin.Queues) diff --git a/templates/admin/navbar.tmpl b/templates/admin/navbar.tmpl index 4116357d1d..72584ec799 100644 --- a/templates/admin/navbar.tmpl +++ b/templates/admin/navbar.tmpl @@ -95,7 +95,7 @@ {{ctx.Locale.Tr "admin.notices"}} -
+
{{ctx.Locale.Tr "admin.monitor"}}
@@ -107,8 +107,8 @@ {{ctx.Locale.Tr "admin.monitor.queues"}} - - {{ctx.Locale.Tr "admin.monitor.stacktrace"}} + + {{ctx.Locale.Tr "admin.monitor.trace"}}
diff --git a/templates/admin/perftrace.tmpl b/templates/admin/perftrace.tmpl new file mode 100644 index 0000000000..2e09f14e46 --- /dev/null +++ b/templates/admin/perftrace.tmpl @@ -0,0 +1,13 @@ +{{template "admin/layout_head" (dict "ctxData" . "pageClass" "admin monitor")}} + +
+ {{template "admin/trace_tabs" .}} + + {{range $record := .PerfTraceRecords}} +
+ 
{{$record.Content}}
+
+ {{end}} +
+ +{{template "admin/layout_footer" .}} diff --git a/templates/admin/stacktrace-row.tmpl b/templates/admin/stacktrace-row.tmpl index 97c361ff90..db7ed81c79 100644 --- a/templates/admin/stacktrace-row.tmpl +++ b/templates/admin/stacktrace-row.tmpl @@ -17,7 +17,10 @@
{{if or (eq .Process.Type "request") (eq .Process.Type "normal")}} - {{svg "octicon-trash" 16 "text-red"}} + {{svg "octicon-trash" 16 "text-red"}} {{end}}
diff --git a/templates/admin/stacktrace.tmpl b/templates/admin/stacktrace.tmpl index ce03d80555..c5dde6b30c 100644 --- a/templates/admin/stacktrace.tmpl +++ b/templates/admin/stacktrace.tmpl @@ -1,22 +1,7 @@ {{template "admin/layout_head" (dict "ctxData" . "pageClass" "admin monitor")}}
-
-
-
- {{ctx.Locale.Tr "admin.monitor.process"}} - {{ctx.Locale.Tr "admin.monitor.stacktrace"}} -
-
-
-
- - {{ctx.Locale.Tr "tool.raw_seconds"}} -
-
-
- -
+ {{template "admin/trace_tabs" .}}

{{printf "%d Goroutines" .GoroutineCount}}{{/* Goroutine is non-translatable*/}} @@ -34,15 +19,4 @@ {{end}}

-
-
- {{ctx.Locale.Tr "admin.monitor.process.cancel"}} -
-
-

{{ctx.Locale.Tr "admin.monitor.process.cancel_notices" (``|SafeHTML)}}

-

{{ctx.Locale.Tr "admin.monitor.process.cancel_desc"}}

-
- {{template "base/modal_actions_confirm" .}} -
- {{template "admin/layout_footer" .}} diff --git a/templates/admin/trace_tabs.tmpl b/templates/admin/trace_tabs.tmpl new file mode 100644 index 0000000000..5066c9c41b --- /dev/null +++ b/templates/admin/trace_tabs.tmpl @@ -0,0 +1,19 @@ +
+
+
+ {{if .ShowAdminPerformanceTraceTab}} + {{ctx.Locale.Tr "admin.monitor.performance_logs"}} + {{end}} + {{ctx.Locale.Tr "admin.monitor.process"}} + {{ctx.Locale.Tr "admin.monitor.stacktrace"}} +
+
+
+
+ + {{ctx.Locale.Tr "tool.raw_seconds"}} +
+
+
+ +