Refactor pprof labels and process desc (#32909)

* Deprecate "gopid" in log, it is not useful and requires very hacky
approach
* Remove "git.Command.SetDescription" because it is not useful and only
makes the logs too flexible
This commit is contained in:
wxiaoguang 2024-12-20 12:17:14 +08:00 committed by GitHub
parent c66de245c4
commit 52b319bc00
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
31 changed files with 182 additions and 247 deletions

View File

@ -7,10 +7,8 @@ import (
"bufio"
"bytes"
"context"
"fmt"
"io"
"math"
"runtime"
"strconv"
"strings"
@ -32,7 +30,6 @@ type WriteCloserError interface {
func ensureValidGitRepository(ctx context.Context, repoPath string) error {
stderr := strings.Builder{}
err := NewCommand(ctx, "rev-parse").
SetDescription(fmt.Sprintf("%s rev-parse [repo_path: %s]", GitExecutable, repoPath)).
Run(&RunOpts{
Dir: repoPath,
Stderr: &stderr,
@ -62,13 +59,9 @@ func catFileBatchCheck(ctx context.Context, repoPath string) (WriteCloserError,
cancel()
}()
_, filename, line, _ := runtime.Caller(2)
filename = strings.TrimPrefix(filename, callerPrefix)
go func() {
stderr := strings.Builder{}
err := NewCommand(ctx, "cat-file", "--batch-check").
SetDescription(fmt.Sprintf("%s cat-file --batch-check [repo_path: %s] (%s:%d)", GitExecutable, repoPath, filename, line)).
Run(&RunOpts{
Dir: repoPath,
Stdin: batchStdinReader,
@ -114,13 +107,9 @@ func catFileBatch(ctx context.Context, repoPath string) (WriteCloserError, *bufi
cancel()
}()
_, filename, line, _ := runtime.Caller(2)
filename = strings.TrimPrefix(filename, callerPrefix)
go func() {
stderr := strings.Builder{}
err := NewCommand(ctx, "cat-file", "--batch").
SetDescription(fmt.Sprintf("%s cat-file --batch [repo_path: %s] (%s:%d)", GitExecutable, repoPath, filename, line)).
Run(&RunOpts{
Dir: repoPath,
Stdin: batchStdinReader,
@ -320,13 +309,6 @@ func ParseTreeLine(objectFormat ObjectFormat, rd *bufio.Reader, modeBuf, fnameBu
return mode, fname, sha, n, err
}
var callerPrefix string
func init() {
_, filename, _, _ := runtime.Caller(0)
callerPrefix = strings.TrimSuffix(filename, "modules/git/batch_reader.go")
}
func DiscardFull(rd *bufio.Reader, discard int64) error {
if discard > math.MaxInt32 {
n, err := rd.Discard(math.MaxInt32)

View File

@ -7,7 +7,6 @@ import (
"bufio"
"bytes"
"context"
"fmt"
"io"
"os"
@ -142,9 +141,7 @@ func CreateBlameReader(ctx context.Context, objectFormat ObjectFormat, repoPath
// There is no equivalent on Windows. May be implemented if Gitea uses an external git backend.
cmd.AddOptionValues("--ignore-revs-file", *ignoreRevsFile)
}
cmd.AddDynamicArguments(commit.ID.String()).
AddDashesAndList(file).
SetDescription(fmt.Sprintf("GetBlame [repo_path: %s]", repoPath))
cmd.AddDynamicArguments(commit.ID.String()).AddDashesAndList(file)
reader, stdout, err := os.Pipe()
if err != nil {
if ignoreRevsFile != nil {

View File

@ -12,6 +12,7 @@ import (
"io"
"os"
"os/exec"
"path/filepath"
"runtime"
"strings"
"time"
@ -43,18 +44,24 @@ type Command struct {
prog string
args []string
parentContext context.Context
desc string
globalArgsLength int
brokenArgs []string
}
func (c *Command) String() string {
return c.toString(false)
func logArgSanitize(arg string) string {
if strings.Contains(arg, "://") && strings.Contains(arg, "@") {
return util.SanitizeCredentialURLs(arg)
} else if filepath.IsAbs(arg) {
base := filepath.Base(arg)
dir := filepath.Dir(arg)
return filepath.Join(filepath.Base(dir), base)
}
return arg
}
func (c *Command) toString(sanitizing bool) string {
func (c *Command) LogString() string {
// WARNING: this function is for debugging purposes only. It's much better than old code (which only joins args with space),
// It's impossible to make a simple and 100% correct implementation of argument quoting for different platforms.
// It's impossible to make a simple and 100% correct implementation of argument quoting for different platforms here.
debugQuote := func(s string) string {
if strings.ContainsAny(s, " `'\"\t\r\n") {
return fmt.Sprintf("%q", s)
@ -63,12 +70,11 @@ func (c *Command) toString(sanitizing bool) string {
}
a := make([]string, 0, len(c.args)+1)
a = append(a, debugQuote(c.prog))
for _, arg := range c.args {
if sanitizing && (strings.Contains(arg, "://") && strings.Contains(arg, "@")) {
a = append(a, debugQuote(util.SanitizeCredentialURLs(arg)))
} else {
a = append(a, debugQuote(arg))
}
if c.globalArgsLength > 0 {
a = append(a, "...global...")
}
for i := c.globalArgsLength; i < len(c.args); i++ {
a = append(a, debugQuote(logArgSanitize(c.args[i])))
}
return strings.Join(a, " ")
}
@ -112,12 +118,6 @@ func (c *Command) SetParentContext(ctx context.Context) *Command {
return c
}
// SetDescription sets the description for this command which be returned on c.String()
func (c *Command) SetDescription(desc string) *Command {
c.desc = desc
return c
}
// isSafeArgumentValue checks if the argument is safe to be used as a value (not an option)
func isSafeArgumentValue(s string) bool {
return s == "" || s[0] != '-'
@ -271,8 +271,12 @@ var ErrBrokenCommand = errors.New("git command is broken")
// Run runs the command with the RunOpts
func (c *Command) Run(opts *RunOpts) error {
return c.run(1, opts)
}
func (c *Command) run(skip int, opts *RunOpts) error {
if len(c.brokenArgs) != 0 {
log.Error("git command is broken: %s, broken args: %s", c.String(), strings.Join(c.brokenArgs, " "))
log.Error("git command is broken: %s, broken args: %s", c.LogString(), strings.Join(c.brokenArgs, " "))
return ErrBrokenCommand
}
if opts == nil {
@ -285,20 +289,14 @@ func (c *Command) Run(opts *RunOpts) error {
timeout = defaultCommandExecutionTimeout
}
if len(opts.Dir) == 0 {
log.Debug("git.Command.Run: %s", c)
} else {
log.Debug("git.Command.RunDir(%s): %s", opts.Dir, c)
}
desc := c.desc
if desc == "" {
if opts.Dir == "" {
desc = fmt.Sprintf("git: %s", c.toString(true))
} else {
desc = fmt.Sprintf("git(dir:%s): %s", opts.Dir, c.toString(true))
}
var desc string
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())
log.Debug("git.Command: %s", desc)
var ctx context.Context
var cancel context.CancelFunc
@ -401,7 +399,7 @@ func IsErrorExitCode(err error, code int) bool {
// RunStdString runs the command with options and returns stdout/stderr as string. and store stderr to returned error (err combined with stderr).
func (c *Command) RunStdString(opts *RunOpts) (stdout, stderr string, runErr RunStdError) {
stdoutBytes, stderrBytes, err := c.RunStdBytes(opts)
stdoutBytes, stderrBytes, err := c.runStdBytes(opts)
stdout = util.UnsafeBytesToString(stdoutBytes)
stderr = util.UnsafeBytesToString(stderrBytes)
if err != nil {
@ -413,6 +411,10 @@ func (c *Command) RunStdString(opts *RunOpts) (stdout, stderr string, runErr Run
// RunStdBytes runs the command with options and returns stdout/stderr as bytes. and store stderr to returned error (err combined with stderr).
func (c *Command) RunStdBytes(opts *RunOpts) (stdout, stderr []byte, runErr RunStdError) {
return c.runStdBytes(opts)
}
func (c *Command) runStdBytes(opts *RunOpts) (stdout, stderr []byte, runErr RunStdError) {
if opts == nil {
opts = &RunOpts{}
}
@ -435,7 +437,7 @@ func (c *Command) RunStdBytes(opts *RunOpts) (stdout, stderr []byte, runErr RunS
PipelineFunc: opts.PipelineFunc,
}
err := c.Run(newOpts)
err := c.run(2, newOpts)
stderr = stderrBuf.Bytes()
if err != nil {
return nil, stderr, &runStdError{err: err, stderr: util.UnsafeBytesToString(stderr)}

View File

@ -55,8 +55,8 @@ func TestGitArgument(t *testing.T) {
func TestCommandString(t *testing.T) {
cmd := NewCommandContextNoGlobals(context.Background(), "a", "-m msg", "it's a test", `say "hello"`)
assert.EqualValues(t, cmd.prog+` a "-m msg" "it's a test" "say \"hello\""`, cmd.String())
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/")
assert.EqualValues(t, cmd.prog+` "url: https://sanitized-credential@c/"`, cmd.toString(true))
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())
}

View File

@ -18,7 +18,6 @@ import (
"time"
"code.gitea.io/gitea/modules/proxy"
"code.gitea.io/gitea/modules/util"
)
// GPGSettings represents the default GPG settings for this repository
@ -160,12 +159,6 @@ func CloneWithArgs(ctx context.Context, args TrustedCmdArgs, from, to string, op
}
cmd.AddDashesAndList(from, to)
if strings.Contains(from, "://") && strings.Contains(from, "@") {
cmd.SetDescription(fmt.Sprintf("clone branch %s from %s to %s (shared: %t, mirror: %t, depth: %d)", opts.Branch, util.SanitizeCredentialURLs(from), to, opts.Shared, opts.Mirror, opts.Depth))
} else {
cmd.SetDescription(fmt.Sprintf("clone branch %s from %s to %s (shared: %t, mirror: %t, depth: %d)", opts.Branch, from, to, opts.Shared, opts.Mirror, opts.Depth))
}
if opts.Timeout <= 0 {
opts.Timeout = -1
}
@ -213,12 +206,6 @@ func Push(ctx context.Context, repoPath string, opts PushOptions) error {
}
cmd.AddDashesAndList(remoteBranchArgs...)
if strings.Contains(opts.Remote, "://") && strings.Contains(opts.Remote, "@") {
cmd.SetDescription(fmt.Sprintf("push branch %s to %s (force: %t, mirror: %t)", opts.Branch, util.SanitizeCredentialURLs(opts.Remote), opts.Force, opts.Mirror))
} else {
cmd.SetDescription(fmt.Sprintf("push branch %s to %s (force: %t, mirror: %t)", opts.Branch, opts.Remote, opts.Force, opts.Mirror))
}
stdout, stderr, err := cmd.RunStdString(&RunOpts{Env: opts.Env, Timeout: opts.Timeout, Dir: repoPath})
if err != nil {
if strings.Contains(stderr, "non-fast-forward") {

View File

@ -9,6 +9,7 @@ import (
"sync"
"time"
"code.gitea.io/gitea/modules/gtprof"
"code.gitea.io/gitea/modules/log"
"code.gitea.io/gitea/modules/process"
"code.gitea.io/gitea/modules/setting"
@ -136,7 +137,7 @@ func (g *Manager) doShutdown() {
}
g.lock.Lock()
g.shutdownCtxCancel()
atShutdownCtx := pprof.WithLabels(g.hammerCtx, pprof.Labels(LifecyclePProfLabel, "post-shutdown"))
atShutdownCtx := pprof.WithLabels(g.hammerCtx, pprof.Labels(gtprof.LabelGracefulLifecycle, "post-shutdown"))
pprof.SetGoroutineLabels(atShutdownCtx)
for _, fn := range g.toRunAtShutdown {
go fn()
@ -167,7 +168,7 @@ func (g *Manager) doHammerTime(d time.Duration) {
default:
log.Warn("Setting Hammer condition")
g.hammerCtxCancel()
atHammerCtx := pprof.WithLabels(g.terminateCtx, pprof.Labels(LifecyclePProfLabel, "post-hammer"))
atHammerCtx := pprof.WithLabels(g.terminateCtx, pprof.Labels(gtprof.LabelGracefulLifecycle, "post-hammer"))
pprof.SetGoroutineLabels(atHammerCtx)
}
g.lock.Unlock()
@ -183,7 +184,7 @@ func (g *Manager) doTerminate() {
default:
log.Warn("Terminating")
g.terminateCtxCancel()
atTerminateCtx := pprof.WithLabels(g.managerCtx, pprof.Labels(LifecyclePProfLabel, "post-terminate"))
atTerminateCtx := pprof.WithLabels(g.managerCtx, pprof.Labels(gtprof.LabelGracefulLifecycle, "post-terminate"))
pprof.SetGoroutineLabels(atTerminateCtx)
for _, fn := range g.toRunAtTerminate {

View File

@ -8,6 +8,8 @@ import (
"runtime/pprof"
"sync"
"time"
"code.gitea.io/gitea/modules/gtprof"
)
// FIXME: it seems that there is a bug when using systemd Type=notify: the "Install Page" (INSTALL_LOCK=false) doesn't notify properly.
@ -22,12 +24,6 @@ const (
watchdogMsg systemdNotifyMsg = "WATCHDOG=1"
)
// LifecyclePProfLabel is a label marking manager lifecycle phase
// Making it compliant with prometheus key regex https://prometheus.io/docs/concepts/data_model/#metric-names-and-labels
// would enable someone interested to be able to to continuously gather profiles into pyroscope.
// Other labels for pprof (in "modules/process" package) should also follow this rule.
const LifecyclePProfLabel = "graceful_lifecycle"
func statusMsg(msg string) systemdNotifyMsg {
return systemdNotifyMsg("STATUS=" + msg)
}
@ -71,10 +67,10 @@ func (g *Manager) prepare(ctx context.Context) {
g.hammerCtx, g.hammerCtxCancel = context.WithCancel(ctx)
g.managerCtx, g.managerCtxCancel = context.WithCancel(ctx)
g.terminateCtx = pprof.WithLabels(g.terminateCtx, pprof.Labels(LifecyclePProfLabel, "with-terminate"))
g.shutdownCtx = pprof.WithLabels(g.shutdownCtx, pprof.Labels(LifecyclePProfLabel, "with-shutdown"))
g.hammerCtx = pprof.WithLabels(g.hammerCtx, pprof.Labels(LifecyclePProfLabel, "with-hammer"))
g.managerCtx = pprof.WithLabels(g.managerCtx, pprof.Labels(LifecyclePProfLabel, "with-manager"))
g.terminateCtx = pprof.WithLabels(g.terminateCtx, pprof.Labels(gtprof.LabelGracefulLifecycle, "with-terminate"))
g.shutdownCtx = pprof.WithLabels(g.shutdownCtx, pprof.Labels(gtprof.LabelGracefulLifecycle, "with-shutdown"))
g.hammerCtx = pprof.WithLabels(g.hammerCtx, pprof.Labels(gtprof.LabelGracefulLifecycle, "with-hammer"))
g.managerCtx = pprof.WithLabels(g.managerCtx, pprof.Labels(gtprof.LabelGracefulLifecycle, "with-manager"))
if !g.setStateTransition(stateInit, stateRunning) {
panic("invalid graceful manager state: transition from init to running failed")

25
modules/gtprof/gtprof.go Normal file
View File

@ -0,0 +1,25 @@
// Copyright 2024 The Gitea Authors. All rights reserved.
// SPDX-License-Identifier: MIT
package gtprof
// This is a Gitea-specific profiling package,
// the name is chosen to distinguish it from the standard pprof tool and "GNU gprof"
// LabelGracefulLifecycle is a label marking manager lifecycle phase
// Making it compliant with prometheus key regex https://prometheus.io/docs/concepts/data_model/#metric-names-and-labels
// would enable someone interested to be able to continuously gather profiles into pyroscope.
// Other labels for pprof should also follow this rule.
const LabelGracefulLifecycle = "graceful_lifecycle"
// LabelPid is a label set on goroutines that have a process attached
const LabelPid = "pid"
// LabelPpid is a label set on goroutines that have a process attached
const LabelPpid = "ppid"
// LabelProcessType is a label set on goroutines that have a process attached
const LabelProcessType = "process_type"
// LabelProcessDescription is a label set on goroutines that have a process attached
const LabelProcessDescription = "process_description"

View File

@ -13,10 +13,9 @@ import (
type Event struct {
Time time.Time
GoroutinePid string
Caller string
Filename string
Line int
Caller string
Filename string
Line int
Level Level
@ -218,17 +217,16 @@ func EventFormatTextMessage(mode *WriterMode, event *Event, msgFormat string, ms
}
if flags&Lgopid == Lgopid {
if event.GoroutinePid != "" {
buf = append(buf, '[')
if mode.Colorize {
buf = append(buf, ColorBytes(FgHiYellow)...)
}
buf = append(buf, event.GoroutinePid...)
if mode.Colorize {
buf = append(buf, resetBytes...)
}
buf = append(buf, ']', ' ')
deprecatedGoroutinePid := "no-gopid" // use a dummy value to avoid breaking the log format
buf = append(buf, '[')
if mode.Colorize {
buf = append(buf, ColorBytes(FgHiYellow)...)
}
buf = append(buf, deprecatedGoroutinePid...)
if mode.Colorize {
buf = append(buf, resetBytes...)
}
buf = append(buf, ']', ' ')
}
buf = append(buf, msg...)

View File

@ -24,34 +24,32 @@ func TestItoa(t *testing.T) {
func TestEventFormatTextMessage(t *testing.T) {
res := EventFormatTextMessage(&WriterMode{Prefix: "[PREFIX] ", Colorize: false, Flags: Flags{defined: true, flags: 0xffffffff}},
&Event{
Time: time.Date(2020, 1, 2, 3, 4, 5, 6, time.UTC),
Caller: "caller",
Filename: "filename",
Line: 123,
GoroutinePid: "pid",
Level: ERROR,
Stacktrace: "stacktrace",
Time: time.Date(2020, 1, 2, 3, 4, 5, 6, time.UTC),
Caller: "caller",
Filename: "filename",
Line: 123,
Level: ERROR,
Stacktrace: "stacktrace",
},
"msg format: %v %v", "arg0", NewColoredValue("arg1", FgBlue),
)
assert.Equal(t, `[PREFIX] 2020/01/02 03:04:05.000000 filename:123:caller [E] [pid] msg format: arg0 arg1
assert.Equal(t, `[PREFIX] 2020/01/02 03:04:05.000000 filename:123:caller [E] [no-gopid] msg format: arg0 arg1
stacktrace
`, string(res))
res = EventFormatTextMessage(&WriterMode{Prefix: "[PREFIX] ", Colorize: true, Flags: Flags{defined: true, flags: 0xffffffff}},
&Event{
Time: time.Date(2020, 1, 2, 3, 4, 5, 6, time.UTC),
Caller: "caller",
Filename: "filename",
Line: 123,
GoroutinePid: "pid",
Level: ERROR,
Stacktrace: "stacktrace",
Time: time.Date(2020, 1, 2, 3, 4, 5, 6, time.UTC),
Caller: "caller",
Filename: "filename",
Line: 123,
Level: ERROR,
Stacktrace: "stacktrace",
},
"msg format: %v %v", "arg0", NewColoredValue("arg1", FgBlue),
)
assert.Equal(t, "[PREFIX] \x1b[36m2020/01/02 03:04:05.000000 \x1b[0m\x1b[32mfilename:123:\x1b[32mcaller\x1b[0m \x1b[1;31m[E]\x1b[0m [\x1b[93mpid\x1b[0m] msg format: arg0 \x1b[34marg1\x1b[0m\n\tstacktrace\n\n", string(res))
assert.Equal(t, "[PREFIX] \x1b[36m2020/01/02 03:04:05.000000 \x1b[0m\x1b[32mfilename:123:\x1b[32mcaller\x1b[0m \x1b[1;31m[E]\x1b[0m [\x1b[93mno-gopid\x1b[0m] msg format: arg0 \x1b[34marg1\x1b[0m\n\tstacktrace\n\n", string(res))
}

View File

@ -30,7 +30,7 @@ const (
LUTC // if Ldate or Ltime is set, use UTC rather than the local time zone
Llevelinitial // Initial character of the provided level in brackets, eg. [I] for info
Llevel // Provided level in brackets [INFO]
Lgopid // the Goroutine-PID of the context
Lgopid // the Goroutine-PID of the context, deprecated and it is always a const value
Lmedfile = Lshortfile | Llongfile // last 20 characters of the filename
LstdFlags = Ldate | Ltime | Lmedfile | Lshortfuncname | Llevelinitial // default

View File

@ -1,19 +0,0 @@
// Copyright 2022 The Gitea Authors. All rights reserved.
// SPDX-License-Identifier: MIT
package log
import "unsafe"
//go:linkname runtime_getProfLabel runtime/pprof.runtime_getProfLabel
func runtime_getProfLabel() unsafe.Pointer //nolint
type labelMap map[string]string
func getGoroutineLabels() map[string]string {
l := (*labelMap)(runtime_getProfLabel())
if l == nil {
return nil
}
return *l
}

View File

@ -1,33 +0,0 @@
// Copyright 2022 The Gitea Authors. All rights reserved.
// SPDX-License-Identifier: MIT
package log
import (
"context"
"runtime/pprof"
"testing"
"github.com/stretchr/testify/assert"
)
func Test_getGoroutineLabels(t *testing.T) {
pprof.Do(context.Background(), pprof.Labels(), func(ctx context.Context) {
currentLabels := getGoroutineLabels()
pprof.ForLabels(ctx, func(key, value string) bool {
assert.EqualValues(t, value, currentLabels[key])
return true
})
pprof.Do(ctx, pprof.Labels("Test_getGoroutineLabels", "Test_getGoroutineLabels_child1"), func(ctx context.Context) {
currentLabels := getGoroutineLabels()
pprof.ForLabels(ctx, func(key, value string) bool {
assert.EqualValues(t, value, currentLabels[key])
return true
})
if assert.NotNil(t, currentLabels) {
assert.EqualValues(t, "Test_getGoroutineLabels_child1", currentLabels["Test_getGoroutineLabels"])
}
})
})
}

View File

@ -200,11 +200,6 @@ func (l *LoggerImpl) Log(skip int, level Level, format string, logArgs ...any) {
event.Stacktrace = Stack(skip + 1)
}
labels := getGoroutineLabels()
if labels != nil {
event.GoroutinePid = labels["pid"]
}
// get a simple text message without color
msgArgs := make([]any, len(logArgs))
copy(msgArgs, logArgs)

View File

@ -11,6 +11,8 @@ import (
"sync"
"sync/atomic"
"time"
"code.gitea.io/gitea/modules/gtprof"
)
// TODO: This packages still uses a singleton for the Manager.
@ -25,18 +27,6 @@ var (
DefaultContext = context.Background()
)
// DescriptionPProfLabel is a label set on goroutines that have a process attached
const DescriptionPProfLabel = "process_description"
// PIDPProfLabel is a label set on goroutines that have a process attached
const PIDPProfLabel = "pid"
// PPIDPProfLabel is a label set on goroutines that have a process attached
const PPIDPProfLabel = "ppid"
// ProcessTypePProfLabel is a label set on goroutines that have a process attached
const ProcessTypePProfLabel = "process_type"
// IDType is a pid type
type IDType string
@ -187,7 +177,12 @@ func (pm *Manager) Add(ctx context.Context, description string, cancel context.C
Trace(true, pid, description, parentPID, processType)
pprofCtx := pprof.WithLabels(ctx, pprof.Labels(DescriptionPProfLabel, description, PPIDPProfLabel, string(parentPID), PIDPProfLabel, string(pid), ProcessTypePProfLabel, processType))
pprofCtx := pprof.WithLabels(ctx, pprof.Labels(
gtprof.LabelProcessDescription, description,
gtprof.LabelPpid, string(parentPID),
gtprof.LabelPid, string(pid),
gtprof.LabelProcessType, processType,
))
if currentlyRunning {
pprof.SetGoroutineLabels(pprofCtx)
}

View File

@ -10,6 +10,8 @@ import (
"sort"
"time"
"code.gitea.io/gitea/modules/gtprof"
"github.com/google/pprof/profile"
)
@ -202,7 +204,7 @@ func (pm *Manager) ProcessStacktraces(flat, noSystem bool) ([]*Process, int, int
// Add the non-process associated labels from the goroutine sample to the Stack
for name, value := range sample.Label {
if name == DescriptionPProfLabel || name == PIDPProfLabel || (!flat && name == PPIDPProfLabel) || name == ProcessTypePProfLabel {
if name == gtprof.LabelProcessDescription || name == gtprof.LabelPid || (!flat && name == gtprof.LabelPpid) || name == gtprof.LabelProcessType {
continue
}
@ -224,7 +226,7 @@ func (pm *Manager) ProcessStacktraces(flat, noSystem bool) ([]*Process, int, int
var process *Process
// Try to get the PID from the goroutine labels
if pidvalue, ok := sample.Label[PIDPProfLabel]; ok && len(pidvalue) == 1 {
if pidvalue, ok := sample.Label[gtprof.LabelPid]; ok && len(pidvalue) == 1 {
pid := IDType(pidvalue[0])
// Now try to get the process from our map
@ -238,20 +240,20 @@ func (pm *Manager) ProcessStacktraces(flat, noSystem bool) ([]*Process, int, int
// get the parent PID
ppid := IDType("")
if value, ok := sample.Label[PPIDPProfLabel]; ok && len(value) == 1 {
if value, ok := sample.Label[gtprof.LabelPpid]; ok && len(value) == 1 {
ppid = IDType(value[0])
}
// format the description
description := "(dead process)"
if value, ok := sample.Label[DescriptionPProfLabel]; ok && len(value) == 1 {
if value, ok := sample.Label[gtprof.LabelProcessDescription]; ok && len(value) == 1 {
description = value[0] + " " + description
}
// override the type of the process to "code" but add the old type as a label on the first stack
ptype := NoneProcessType
if value, ok := sample.Label[ProcessTypePProfLabel]; ok && len(value) == 1 {
stack.Labels = append(stack.Labels, &Label{Name: ProcessTypePProfLabel, Value: value[0]})
if value, ok := sample.Label[gtprof.LabelProcessType]; ok && len(value) == 1 {
stack.Labels = append(stack.Labels, &Label{Name: gtprof.LabelProcessType, Value: value[0]})
}
process = &Process{
PID: pid,

View File

@ -6,6 +6,7 @@ package queue
import (
"context"
"fmt"
"runtime/pprof"
"sync"
"sync/atomic"
"time"
@ -241,6 +242,9 @@ func NewWorkerPoolQueueWithContext[T any](ctx context.Context, name string, queu
w.origHandler = handler
w.safeHandler = func(t ...T) (unhandled []T) {
defer func() {
// FIXME: there is no ctx support in the handler, so process manager is unable to restore the labels
// so here we explicitly set the "queue ctx" labels again after the handler is done
pprof.SetGoroutineLabels(w.ctxRun)
err := recover()
if err != nil {
log.Error("Recovered from panic in queue %q handler: %v\n%s", name, err, log.Stack(2))

13
modules/util/runtime.go Normal file
View File

@ -0,0 +1,13 @@
// Copyright 2024 The Gitea Authors. All rights reserved.
// SPDX-License-Identifier: MIT
package util
import "runtime"
func CallerFuncName(skip int) string {
pc := make([]uintptr, 1)
runtime.Callers(skip+1, pc)
funcName := runtime.FuncForPC(pc[0]).Name()
return funcName
}

View File

@ -0,0 +1,32 @@
// Copyright 2024 The Gitea Authors. All rights reserved.
// SPDX-License-Identifier: MIT
package util
import (
"fmt"
"testing"
"github.com/stretchr/testify/assert"
)
func TestCallerFuncName(t *testing.T) {
s := CallerFuncName(1)
assert.Equal(t, "code.gitea.io/gitea/modules/util.TestCallerFuncName", s)
}
func BenchmarkCallerFuncName(b *testing.B) {
// BenchmarkCaller/sprintf-12 12744829 95.49 ns/op
b.Run("sprintf", func(b *testing.B) {
for i := 0; i < b.N; i++ {
_ = fmt.Sprintf("aaaaaaaaaaaaaaaa %s %s %s", "bbbbbbbbbbbbbbbbbbb", b.Name(), "ccccccccccccccccccccc")
}
})
// BenchmarkCaller/caller-12 10625133 113.6 ns/op
// It is almost as fast as fmt.Sprintf
b.Run("caller", func(b *testing.B) {
for i := 0; i < b.N; i++ {
CallerFuncName(1)
}
})
}

View File

@ -458,7 +458,6 @@ func serviceRPC(ctx *context.Context, h *serviceHandler, service string) {
var stderr bytes.Buffer
cmd.AddArguments("--stateless-rpc").AddDynamicArguments(h.getRepoDir())
cmd.SetDescription(fmt.Sprintf("%s %s %s [repo_path: %s]", git.GitExecutable, service, "--stateless-rpc", h.getRepoDir()))
if err := cmd.Run(&git.RunOpts{
Dir: h.getRepoDir(),
Env: append(os.Environ(), h.environ...),

View File

@ -1156,7 +1156,6 @@ func GetDiff(ctx context.Context, gitRepo *git.Repository, opts *DiffOptions, fi
go func() {
stderr := &bytes.Buffer{}
cmdDiff.SetDescription(fmt.Sprintf("GetDiffRange [repo_path: %s]", repoPath))
if err := cmdDiff.Run(&git.RunOpts{
Timeout: time.Duration(setting.Git.Timeout.Default) * time.Second,
Dir: repoPath,

View File

@ -46,11 +46,6 @@ func UpdateAddress(ctx context.Context, m *repo_model.Mirror, addr string) error
}
cmd := git.NewCommand(ctx, "remote", "add").AddDynamicArguments(remoteName).AddArguments("--mirror=fetch").AddDynamicArguments(addr)
if strings.Contains(addr, "://") && strings.Contains(addr, "@") {
cmd.SetDescription(fmt.Sprintf("remote add %s --mirror=fetch %s [repo_path: %s]", remoteName, util.SanitizeCredentialURLs(addr), repoPath))
} else {
cmd.SetDescription(fmt.Sprintf("remote add %s --mirror=fetch %s [repo_path: %s]", remoteName, addr, repoPath))
}
_, _, err = cmd.RunStdString(&git.RunOpts{Dir: repoPath})
if err != nil && !strings.HasPrefix(err.Error(), "exit status 128 - fatal: No such remote ") {
return err
@ -66,11 +61,6 @@ func UpdateAddress(ctx context.Context, m *repo_model.Mirror, addr string) error
}
cmd = git.NewCommand(ctx, "remote", "add").AddDynamicArguments(remoteName).AddArguments("--mirror=fetch").AddDynamicArguments(wikiRemotePath)
if strings.Contains(wikiRemotePath, "://") && strings.Contains(wikiRemotePath, "@") {
cmd.SetDescription(fmt.Sprintf("remote add %s --mirror=fetch %s [repo_path: %s]", remoteName, util.SanitizeCredentialURLs(wikiRemotePath), wikiPath))
} else {
cmd.SetDescription(fmt.Sprintf("remote add %s --mirror=fetch %s [repo_path: %s]", remoteName, wikiRemotePath, wikiPath))
}
_, _, err = cmd.RunStdString(&git.RunOpts{Dir: wikiPath})
if err != nil && !strings.HasPrefix(err.Error(), "exit status 128 - fatal: No such remote ") {
return err
@ -197,7 +187,6 @@ func pruneBrokenReferences(ctx context.Context,
stderrBuilder.Reset()
stdoutBuilder.Reset()
pruneErr := git.NewCommand(ctx, "remote", "prune").AddDynamicArguments(m.GetRemoteName()).
SetDescription(fmt.Sprintf("Mirror.runSync %ssPrune references: %s ", wiki, m.Repo.FullName())).
Run(&git.RunOpts{
Timeout: timeout,
Dir: repoPath,
@ -248,15 +237,13 @@ func runSync(ctx context.Context, m *repo_model.Mirror) ([]*mirrorSyncResult, bo
stdoutBuilder := strings.Builder{}
stderrBuilder := strings.Builder{}
if err := cmd.
SetDescription(fmt.Sprintf("Mirror.runSync: %s", m.Repo.FullName())).
Run(&git.RunOpts{
Timeout: timeout,
Dir: repoPath,
Env: envs,
Stdout: &stdoutBuilder,
Stderr: &stderrBuilder,
}); err != nil {
if err := cmd.Run(&git.RunOpts{
Timeout: timeout,
Dir: repoPath,
Env: envs,
Stdout: &stdoutBuilder,
Stderr: &stderrBuilder,
}); err != nil {
stdout := stdoutBuilder.String()
stderr := stderrBuilder.String()
@ -275,14 +262,12 @@ func runSync(ctx context.Context, m *repo_model.Mirror) ([]*mirrorSyncResult, bo
// Successful prune - reattempt mirror
stderrBuilder.Reset()
stdoutBuilder.Reset()
if err = cmd.
SetDescription(fmt.Sprintf("Mirror.runSync: %s", m.Repo.FullName())).
Run(&git.RunOpts{
Timeout: timeout,
Dir: repoPath,
Stdout: &stdoutBuilder,
Stderr: &stderrBuilder,
}); err != nil {
if err = cmd.Run(&git.RunOpts{
Timeout: timeout,
Dir: repoPath,
Stdout: &stdoutBuilder,
Stderr: &stderrBuilder,
}); err != nil {
stdout := stdoutBuilder.String()
stderr := stderrBuilder.String()
@ -346,7 +331,6 @@ func runSync(ctx context.Context, m *repo_model.Mirror) ([]*mirrorSyncResult, bo
stderrBuilder.Reset()
stdoutBuilder.Reset()
if err := git.NewCommand(ctx, "remote", "update", "--prune").AddDynamicArguments(m.GetRemoteName()).
SetDescription(fmt.Sprintf("Mirror.runSync Wiki: %s ", m.Repo.FullName())).
Run(&git.RunOpts{
Timeout: timeout,
Dir: wikiPath,
@ -373,7 +357,6 @@ func runSync(ctx context.Context, m *repo_model.Mirror) ([]*mirrorSyncResult, bo
stdoutBuilder.Reset()
if err = git.NewCommand(ctx, "remote", "update", "--prune").AddDynamicArguments(m.GetRemoteName()).
SetDescription(fmt.Sprintf("Mirror.runSync Wiki: %s ", m.Repo.FullName())).
Run(&git.RunOpts{
Timeout: timeout,
Dir: wikiPath,

View File

@ -9,7 +9,6 @@ import (
"fmt"
"io"
"regexp"
"strings"
"time"
"code.gitea.io/gitea/models/db"
@ -31,11 +30,6 @@ var stripExitStatus = regexp.MustCompile(`exit status \d+ - `)
func AddPushMirrorRemote(ctx context.Context, m *repo_model.PushMirror, addr string) error {
addRemoteAndConfig := func(addr, path string) error {
cmd := git.NewCommand(ctx, "remote", "add", "--mirror=push").AddDynamicArguments(m.RemoteName, addr)
if strings.Contains(addr, "://") && strings.Contains(addr, "@") {
cmd.SetDescription(fmt.Sprintf("remote add %s --mirror=push %s [repo_path: %s]", m.RemoteName, util.SanitizeCredentialURLs(addr), path))
} else {
cmd.SetDescription(fmt.Sprintf("remote add %s --mirror=push %s [repo_path: %s]", m.RemoteName, addr, path))
}
if _, _, err := cmd.RunStdString(&git.RunOpts{Dir: path}); err != nil {
return err
}

View File

@ -326,7 +326,6 @@ func DeleteReleaseByID(ctx context.Context, repo *repo_model.Repository, rel *re
}
if stdout, _, err := git.NewCommand(ctx, "tag", "-d").AddDashesAndList(rel.TagName).
SetDescription(fmt.Sprintf("DeleteReleaseByID (git tag -d): %d", rel.ID)).
RunStdString(&git.RunOpts{Dir: repo.RepoPath()}); err != nil && !strings.Contains(err.Error(), "not found") {
log.Error("DeleteReleaseByID (git tag -d): %d in %v Failed:\nStdout: %s\nError: %v", rel.ID, repo, stdout, err)
return fmt.Errorf("git tag -d: %w", err)

View File

@ -92,7 +92,6 @@ func AdoptRepository(ctx context.Context, doer, u *user_model.User, opts CreateR
}
if stdout, _, err := git.NewCommand(ctx, "update-server-info").
SetDescription(fmt.Sprintf("CreateRepository(git update-server-info): %s", repoPath)).
RunStdString(&git.RunOpts{Dir: repoPath}); err != nil {
log.Error("CreateRepository(git update-server-info) in %v: Stdout: %s\nError: %v", repo, stdout, err)
return fmt.Errorf("CreateRepository(git update-server-info): %w", err)

View File

@ -86,8 +86,7 @@ func GitGcRepos(ctx context.Context, timeout time.Duration, args git.TrustedCmdA
// GitGcRepo calls 'git gc' to remove unnecessary files and optimize the local repository
func GitGcRepo(ctx context.Context, repo *repo_model.Repository, timeout time.Duration, args git.TrustedCmdArgs) error {
log.Trace("Running git gc on %-v", repo)
command := git.NewCommand(ctx, "gc").AddArguments(args...).
SetDescription(fmt.Sprintf("Repository Garbage Collection: %s", repo.FullName()))
command := git.NewCommand(ctx, "gc").AddArguments(args...)
var stdout string
var err error
stdout, _, err = command.RunStdString(&git.RunOpts{Timeout: timeout, Dir: repo.RepoPath()})

View File

@ -68,7 +68,6 @@ func prepareRepoCommit(ctx context.Context, repo *repo_model.Repository, tmpDir,
// Clone to temporary path and do the init commit.
if stdout, _, err := git.NewCommand(ctx, "clone").AddDynamicArguments(repoPath, tmpDir).
SetDescription(fmt.Sprintf("prepareRepoCommit (git clone): %s to %s", repoPath, tmpDir)).
RunStdString(&git.RunOpts{Dir: "", Env: env}); err != nil {
log.Error("Failed to clone from %v into %s: stdout: %s\nError: %v", repo, tmpDir, stdout, err)
return fmt.Errorf("git clone: %w", err)
@ -301,7 +300,6 @@ func CreateRepositoryDirectly(ctx context.Context, doer, u *user_model.User, opt
}
if stdout, _, err := git.NewCommand(ctx, "update-server-info").
SetDescription(fmt.Sprintf("CreateRepository(git update-server-info): %s", repoPath)).
RunStdString(&git.RunOpts{Dir: repoPath}); err != nil {
log.Error("CreateRepository(git update-server-info) in %v: Stdout: %s\nError: %v", repo, stdout, err)
rollbackRepo = repo
@ -314,9 +312,7 @@ func CreateRepositoryDirectly(ctx context.Context, doer, u *user_model.User, opt
if len(opts.License) > 0 {
licenses = append(licenses, ConvertLicenseName(opts.License))
stdout, _, err := git.NewCommand(ctx, "rev-parse", "HEAD").
SetDescription(fmt.Sprintf("CreateRepository(git rev-parse HEAD): %s", repoPath)).
RunStdString(&git.RunOpts{Dir: repoPath})
stdout, _, err := git.NewCommand(ctx, "rev-parse", "HEAD").RunStdString(&git.RunOpts{Dir: repoPath})
if err != nil {
log.Error("CreateRepository(git rev-parse HEAD) in %v: Stdout: %s\nError: %v", repo, stdout, err)
rollbackRepo = repo

View File

@ -158,7 +158,6 @@ func ForkRepository(ctx context.Context, doer, owner *user_model.User, opts Fork
}
repoPath := repo_model.RepoPath(owner.Name, repo.Name)
if stdout, _, err := cloneCmd.AddDynamicArguments(oldRepoPath, repoPath).
SetDescription(fmt.Sprintf("ForkRepository(git clone): %s to %s", opts.BaseRepo.FullName(), repo.FullName())).
RunStdBytes(&git.RunOpts{Timeout: 10 * time.Minute}); err != nil {
log.Error("Fork Repository (git clone) Failed for %v (from %v):\nStdout: %s\nError: %v", repo, opts.BaseRepo, stdout, err)
return fmt.Errorf("git clone: %w", err)
@ -169,7 +168,6 @@ func ForkRepository(ctx context.Context, doer, owner *user_model.User, opts Fork
}
if stdout, _, err := git.NewCommand(txCtx, "update-server-info").
SetDescription(fmt.Sprintf("ForkRepository(git update-server-info): %s", repo.FullName())).
RunStdString(&git.RunOpts{Dir: repoPath}); err != nil {
log.Error("Fork Repository (git update-server-info) failed for %v:\nStdout: %s\nError: %v", repo, stdout, err)
return fmt.Errorf("git update-server-info: %w", err)

View File

@ -237,7 +237,6 @@ func generateRepoCommit(ctx context.Context, repo, templateRepo, generateRepo *r
repoPath := repo.RepoPath()
if stdout, _, err := git.NewCommand(ctx, "remote", "add", "origin").AddDynamicArguments(repoPath).
SetDescription(fmt.Sprintf("generateRepoCommit (git remote add): %s to %s", templateRepoPath, tmpDir)).
RunStdString(&git.RunOpts{Dir: tmpDir, Env: env}); err != nil {
log.Error("Unable to add %v as remote origin to temporary repo to %s: stdout %s\nError: %v", repo, tmpDir, stdout, err)
return fmt.Errorf("git remote add: %w", err)
@ -369,7 +368,6 @@ func generateRepository(ctx context.Context, doer, owner *user_model.User, templ
}
if stdout, _, err := git.NewCommand(ctx, "update-server-info").
SetDescription(fmt.Sprintf("GenerateRepository(git update-server-info): %s", repoPath)).
RunStdString(&git.RunOpts{Dir: repoPath}); err != nil {
log.Error("GenerateRepository(git update-server-info) in %v: Stdout: %s\nError: %v", generateRepo, stdout, err)
return generateRepo, fmt.Errorf("error in GenerateRepository(git update-server-info): %w", err)

View File

@ -34,7 +34,6 @@ func initRepoCommit(ctx context.Context, tmpPath string, repo *repo_model.Reposi
committerEmail := sig.Email
if stdout, _, err := git.NewCommand(ctx, "add", "--all").
SetDescription(fmt.Sprintf("initRepoCommit (git add): %s", tmpPath)).
RunStdString(&git.RunOpts{Dir: tmpPath}); err != nil {
log.Error("git add --all failed: Stdout: %s\nError: %v", stdout, err)
return fmt.Errorf("git add --all: %w", err)
@ -62,9 +61,8 @@ func initRepoCommit(ctx context.Context, tmpPath string, repo *repo_model.Reposi
)
if stdout, _, err := cmd.
SetDescription(fmt.Sprintf("initRepoCommit (git commit): %s", tmpPath)).
RunStdString(&git.RunOpts{Dir: tmpPath, Env: env}); err != nil {
log.Error("Failed to commit: %v: Stdout: %s\nError: %v", cmd.String(), stdout, err)
log.Error("Failed to commit: %v: Stdout: %s\nError: %v", cmd.LogString(), stdout, err)
return fmt.Errorf("git commit: %w", err)
}
@ -73,7 +71,6 @@ func initRepoCommit(ctx context.Context, tmpPath string, repo *repo_model.Reposi
}
if stdout, _, err := git.NewCommand(ctx, "push", "origin").AddDynamicArguments("HEAD:" + defaultBranch).
SetDescription(fmt.Sprintf("initRepoCommit (git push): %s", tmpPath)).
RunStdString(&git.RunOpts{Dir: tmpPath, Env: repo_module.InternalPushingEnvironment(u, repo)}); err != nil {
log.Error("Failed to push back to HEAD: Stdout: %s\nError: %v", stdout, err)
return fmt.Errorf("git push: %w", err)

View File

@ -122,7 +122,6 @@ func MigrateRepositoryGitData(ctx context.Context, u *user_model.User,
}
if stdout, _, err := git.NewCommand(ctx, "update-server-info").
SetDescription(fmt.Sprintf("MigrateRepositoryGitData(git update-server-info): %s", repoPath)).
RunStdString(&git.RunOpts{Dir: repoPath}); err != nil {
log.Error("MigrateRepositoryGitData(git update-server-info) in %v: Stdout: %s\nError: %v", repo, stdout, err)
return repo, fmt.Errorf("error in MigrateRepositoryGitData(git update-server-info): %w", err)