From a9d09e5019a1635b9a988dfd75b017b78d9a1a73 Mon Sep 17 00:00:00 2001 From: Gusted Date: Sun, 10 Aug 2025 22:54:29 +0200 Subject: [PATCH] chore: remove goroutine PID logging (#8851) - It was possible for Forgejo adminstrators to configure the logger to log the goroutine PID that made the `Log` call. - The need for the goroutine PID to be logged is that it might give insight which request or otherwise process made the log call by correlating the PID with other logs. However even for a single request I cannot make correlations between the goroutine PIDs and it seems that this particular need cannot be fulfilled by the current implementation. - The gathering of this PID is discouraged, https://go.dev/doc/faq#no_goroutine_id, and the current implementation is a hack and can break in future Go releases; it has broken before in 61e21d7ded198653a91a49f945d2c2a6dee0e73c. - If the need arise, we instead should make the logger implementation context aware and use a PID that's associated with the context, which is guarantees to be consistent (this is also the more idiomatic way to achieve this functionality). ## Release notes - Other changes without a feature or bug label - [PR](https://codeberg.org/forgejo/forgejo/pulls/8851): chore: remove goroutine PID logging Reviewed-on: https://codeberg.org/forgejo/forgejo/pulls/8851 Reviewed-by: Earl Warren Reviewed-by: Michael Kriese Co-authored-by: Gusted Co-committed-by: Gusted --- modules/log/event_format.go | 20 ++------- modules/log/event_format_test.go | 69 +++++++++++++---------------- modules/log/flags.go | 3 -- modules/log/flags_test.go | 4 +- modules/log/groutinelabel.go | 21 --------- modules/log/groutinelabel_go1.24.go | 38 ---------------- modules/log/groutinelabel_test.go | 33 -------------- modules/log/logger_impl.go | 5 --- 8 files changed, 36 insertions(+), 157 deletions(-) delete mode 100644 modules/log/groutinelabel.go delete mode 100644 modules/log/groutinelabel_go1.24.go delete mode 100644 modules/log/groutinelabel_test.go diff --git a/modules/log/event_format.go b/modules/log/event_format.go index df6b083a92..6835a4ca5b 100644 --- a/modules/log/event_format.go +++ b/modules/log/event_format.go @@ -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 @@ -225,19 +224,6 @@ func EventFormatTextMessage(mode *WriterMode, event *Event, msgFormat string, ms msg = msg[:len(msg)-1] } - 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, ']', ' ') - } - } buf = append(buf, msg...) if event.Stacktrace != "" && mode.StacktraceLevel <= event.Level { diff --git a/modules/log/event_format_test.go b/modules/log/event_format_test.go index 0c6061eaea..f6f9754300 100644 --- a/modules/log/event_format_test.go +++ b/modules/log/event_format_test.go @@ -24,48 +24,45 @@ 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, `<3>[PREFIX] 2020/01/02 03:04:05.000000 filename:123:caller [E] [pid] msg format: arg0 arg1 + assert.Equal(t, `<3>[PREFIX] 2020/01/02 03:04:05.000000 filename:123:caller [E] 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, "<3>[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, "<3>[PREFIX] \x1b[36m2020/01/02 03:04:05.000000 \x1b[0m\x1b[32mfilename:123:\x1b[32mcaller\x1b[0m \x1b[1;31m[E]\x1b[0m msg format: arg0 \x1b[34marg1\x1b[0m\n\tstacktrace\n\n", string(res)) } func TestEventFormatTextMessageStd(t *testing.T) { res := EventFormatTextMessage(&WriterMode{Prefix: "[PREFIX] ", Colorize: false, Flags: Flags{defined: true, flags: LstdFlags}}, &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), ) @@ -77,13 +74,12 @@ func TestEventFormatTextMessageStd(t *testing.T) { res = EventFormatTextMessage(&WriterMode{Prefix: "[PREFIX] ", Colorize: true, Flags: Flags{defined: true, flags: LstdFlags}}, &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), ) @@ -96,13 +92,12 @@ func TestEventFormatTextMessageJournal(t *testing.T) { // the proper way here is to attach the backtrace as structured metadata, but we can't do that via stderr res := EventFormatTextMessage(&WriterMode{Prefix: "[PREFIX] ", Colorize: false, Flags: Flags{defined: true, flags: LjournaldFlags}}, &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), ) diff --git a/modules/log/flags.go b/modules/log/flags.go index afce30680d..1e4fe830c1 100644 --- a/modules/log/flags.go +++ b/modules/log/flags.go @@ -30,7 +30,6 @@ 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 Llevelprefix // printk-style logging prefixes as documented in sd-daemon(3), used by journald Lmedfile = Lshortfile | Llongfile // last 20 characters of the filename @@ -57,7 +56,6 @@ var flagFromString = map[string]uint32{ "levelinitial": Llevelinitial, "level": Llevel, "levelprefix": Llevelprefix, - "gopid": Lgopid, "medfile": Lmedfile, "stdflags": LstdFlags, @@ -82,7 +80,6 @@ var flagComboToString = []struct { {LUTC, "utc"}, {Llevelinitial, "levelinitial"}, {Llevel, "level"}, - {Lgopid, "gopid"}, } func (f Flags) Bits() uint32 { diff --git a/modules/log/flags_test.go b/modules/log/flags_test.go index 1af9a58ed6..f39fe440e2 100644 --- a/modules/log/flags_test.go +++ b/modules/log/flags_test.go @@ -15,9 +15,7 @@ import ( func TestFlags(t *testing.T) { assert.Equal(t, Ldefault, Flags{}.Bits()) assert.EqualValues(t, 0, FlagsFromString("").Bits()) - assert.Equal(t, Lgopid, FlagsFromString("", Lgopid).Bits()) - assert.EqualValues(t, 0, FlagsFromString("none", Lgopid).Bits()) - assert.Equal(t, Ldate|Ltime, FlagsFromString("date,time", Lgopid).Bits()) + assert.Equal(t, Ldate|Ltime, FlagsFromString("date,time").Bits()) assert.Equal(t, "stdflags", FlagsFromString("stdflags").String()) assert.Equal(t, "medfile", FlagsFromString("medfile").String()) diff --git a/modules/log/groutinelabel.go b/modules/log/groutinelabel.go deleted file mode 100644 index cd5fb96d52..0000000000 --- a/modules/log/groutinelabel.go +++ /dev/null @@ -1,21 +0,0 @@ -//go:build !go1.24 - -// 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 -} diff --git a/modules/log/groutinelabel_go1.24.go b/modules/log/groutinelabel_go1.24.go deleted file mode 100644 index e849811bc2..0000000000 --- a/modules/log/groutinelabel_go1.24.go +++ /dev/null @@ -1,38 +0,0 @@ -//go:build go1.24 - -// Copyright 2024 The Forgejo 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 - -// Struct definitions copied from: https://github.com/golang/go/blob/ca63101df47a4467bc80faa654fc19d68e583952/src/runtime/pprof/label.go -type label struct { - key string - value string -} - -type LabelSet struct { - list []label -} - -type labelMap struct { - LabelSet -} - -func getGoroutineLabels() map[string]string { - l := (*labelMap)(runtime_getProfLabel()) - if l == nil { - return nil - } - - m := make(map[string]string, len(l.list)) - for _, label := range l.list { - m[label.key] = label.value - } - return m -} diff --git a/modules/log/groutinelabel_test.go b/modules/log/groutinelabel_test.go deleted file mode 100644 index 98d7b4e129..0000000000 --- a/modules/log/groutinelabel_test.go +++ /dev/null @@ -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(t.Context(), pprof.Labels(), func(ctx context.Context) { - currentLabels := getGoroutineLabels() - pprof.ForLabels(ctx, func(key, value string) bool { - assert.Equal(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.Equal(t, value, currentLabels[key]) - return true - }) - if assert.NotNil(t, currentLabels) { - assert.Equal(t, "Test_getGoroutineLabels_child1", currentLabels["Test_getGoroutineLabels"]) - } - }) - }) -} diff --git a/modules/log/logger_impl.go b/modules/log/logger_impl.go index b21e800f52..76d7e6a821 100644 --- a/modules/log/logger_impl.go +++ b/modules/log/logger_impl.go @@ -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)