diff options
Diffstat (limited to 'modules/log')
28 files changed, 2519 insertions, 0 deletions
diff --git a/modules/log/color.go b/modules/log/color.go new file mode 100644 index 0000000..dcbba5f --- /dev/null +++ b/modules/log/color.go @@ -0,0 +1,115 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "fmt" + "strconv" +) + +const escape = "\033" + +// ColorAttribute defines a single SGR Code +type ColorAttribute int + +// Base ColorAttributes +const ( + Reset ColorAttribute = iota + Bold + Faint + Italic + Underline + BlinkSlow + BlinkRapid + ReverseVideo + Concealed + CrossedOut +) + +// Foreground text colors +const ( + FgBlack ColorAttribute = iota + 30 + FgRed + FgGreen + FgYellow + FgBlue + FgMagenta + FgCyan + FgWhite +) + +// Foreground Hi-Intensity text colors +const ( + FgHiBlack ColorAttribute = iota + 90 + FgHiRed + FgHiGreen + FgHiYellow + FgHiBlue + FgHiMagenta + FgHiCyan + FgHiWhite +) + +// Background text colors +const ( + BgBlack ColorAttribute = iota + 40 + BgRed + BgGreen + BgYellow + BgBlue + BgMagenta + BgCyan + BgWhite +) + +// Background Hi-Intensity text colors +const ( + BgHiBlack ColorAttribute = iota + 100 + BgHiRed + BgHiGreen + BgHiYellow + BgHiBlue + BgHiMagenta + BgHiCyan + BgHiWhite +) + +var ( + resetBytes = ColorBytes(Reset) + fgCyanBytes = ColorBytes(FgCyan) + fgGreenBytes = ColorBytes(FgGreen) +) + +type ColoredValue struct { + v any + colors []ColorAttribute +} + +func (c *ColoredValue) Format(f fmt.State, verb rune) { + _, _ = f.Write(ColorBytes(c.colors...)) + s := fmt.Sprintf(fmt.FormatString(f, verb), c.v) + _, _ = f.Write([]byte(s)) + _, _ = f.Write(resetBytes) +} + +func NewColoredValue(v any, color ...ColorAttribute) *ColoredValue { + return &ColoredValue{v: v, colors: color} +} + +// ColorBytes converts a list of ColorAttributes to a byte array +func ColorBytes(attrs ...ColorAttribute) []byte { + bytes := make([]byte, 0, 20) + bytes = append(bytes, escape[0], '[') + if len(attrs) > 0 { + bytes = append(bytes, strconv.Itoa(int(attrs[0]))...) + for _, a := range attrs[1:] { + bytes = append(bytes, ';') + bytes = append(bytes, strconv.Itoa(int(a))...) + } + } else { + bytes = append(bytes, strconv.Itoa(int(Bold))...) + } + bytes = append(bytes, 'm') + return bytes +} diff --git a/modules/log/color_console.go b/modules/log/color_console.go new file mode 100644 index 0000000..82b5ce1 --- /dev/null +++ b/modules/log/color_console.go @@ -0,0 +1,17 @@ +// Copyright 2014 The Gogs Authors. All rights reserved. +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +// CanColorStdout reports if we can use ANSI escape sequences on stdout +var CanColorStdout = true + +// CanColorStderr reports if we can use ANSI escape sequences on stderr +var CanColorStderr = true + +// JournaldOnStdout reports whether stdout is attached to journald +var JournaldOnStdout = false + +// JournaldOnStderr reports whether stderr is attached to journald +var JournaldOnStderr = false diff --git a/modules/log/color_console_other.go b/modules/log/color_console_other.go new file mode 100644 index 0000000..c08b38c --- /dev/null +++ b/modules/log/color_console_other.go @@ -0,0 +1,69 @@ +// Copyright 2022 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +//go:build !windows + +package log + +import ( + "os" + "strconv" + "strings" + "syscall" + + "github.com/mattn/go-isatty" +) + +func journaldDevIno() (uint64, uint64, bool) { + journaldStream := os.Getenv("JOURNAL_STREAM") + if len(journaldStream) == 0 { + return 0, 0, false + } + deviceStr, inodeStr, ok := strings.Cut(journaldStream, ":") + device, err1 := strconv.ParseUint(deviceStr, 10, 64) + inode, err2 := strconv.ParseUint(inodeStr, 10, 64) + if !ok || err1 != nil || err2 != nil { + return 0, 0, false + } + return device, inode, true +} + +func fileStatDevIno(file *os.File) (uint64, uint64, bool) { + info, err := file.Stat() + if err != nil { + return 0, 0, false + } + + stat, ok := info.Sys().(*syscall.Stat_t) + if !ok { + return 0, 0, false + } + + // Do a type conversion to uint64, because Dev isn't always uint64 + // on every operating system + architecture combination. + return uint64(stat.Dev), stat.Ino, true //nolint:unconvert +} + +func fileIsDevIno(file *os.File, dev, ino uint64) bool { + fileDev, fileIno, ok := fileStatDevIno(file) + return ok && dev == fileDev && ino == fileIno +} + +func init() { + // When forgejo is running under service supervisor (e.g. systemd) with logging + // set to console, the output streams are typically captured into some logging + // system (e.g. journald or syslog) instead of going to the terminal. Disable + // usage of ANSI escape sequences if that's the case to avoid spamming + // the journal or syslog with garbled mess e.g. `#033[0m#033[32mcmd/web.go:102:#033[32m`. + CanColorStdout = isatty.IsTerminal(os.Stdout.Fd()) + CanColorStderr = isatty.IsTerminal(os.Stderr.Fd()) + + // Furthermore, check if we are running under journald specifically so that + // further output adjustments can be applied. Specifically, this changes + // the console logger defaults to disable duplication of date/time info and + // enable emission of special control sequences understood by journald + // instead of ANSI colors. + journalDev, journalIno, ok := journaldDevIno() + JournaldOnStdout = ok && !CanColorStdout && fileIsDevIno(os.Stdout, journalDev, journalIno) + JournaldOnStderr = ok && !CanColorStderr && fileIsDevIno(os.Stderr, journalDev, journalIno) +} diff --git a/modules/log/color_console_windows.go b/modules/log/color_console_windows.go new file mode 100644 index 0000000..3f59e93 --- /dev/null +++ b/modules/log/color_console_windows.go @@ -0,0 +1,42 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "os" + + "github.com/mattn/go-isatty" + "golang.org/x/sys/windows" +) + +func enableVTMode(console windows.Handle) bool { + mode := uint32(0) + err := windows.GetConsoleMode(console, &mode) + if err != nil { + return false + } + + // EnableVirtualTerminalProcessing is the console mode to allow ANSI code + // interpretation on the console. See: + // https://docs.microsoft.com/en-us/windows/console/setconsolemode + // It only works on Windows 10. Earlier terminals will fail with an err which we will + // handle to say don't color + mode |= windows.ENABLE_VIRTUAL_TERMINAL_PROCESSING + err = windows.SetConsoleMode(console, mode) + return err == nil +} + +func init() { + if isatty.IsTerminal(os.Stdout.Fd()) { + CanColorStdout = enableVTMode(windows.Stdout) + } else { + CanColorStdout = isatty.IsCygwinTerminal(os.Stderr.Fd()) + } + + if isatty.IsTerminal(os.Stderr.Fd()) { + CanColorStderr = enableVTMode(windows.Stderr) + } else { + CanColorStderr = isatty.IsCygwinTerminal(os.Stderr.Fd()) + } +} diff --git a/modules/log/color_router.go b/modules/log/color_router.go new file mode 100644 index 0000000..80e7e02 --- /dev/null +++ b/modules/log/color_router.go @@ -0,0 +1,87 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "fmt" + "time" +) + +var statusToColor = map[int][]ColorAttribute{ + 100: {Bold}, + 200: {FgGreen}, + 300: {FgYellow}, + 304: {FgCyan}, + 400: {Bold, FgRed}, + 401: {Bold, FgMagenta}, + 403: {Bold, FgMagenta}, + 500: {Bold, BgRed}, +} + +// ColoredStatus adds colors for HTTP status +func ColoredStatus(status int, s ...string) *ColoredValue { + color, ok := statusToColor[status] + if !ok { + color, ok = statusToColor[(status/100)*100] + } + if !ok { + color = []ColorAttribute{Bold} + } + if len(s) > 0 { + return NewColoredValue(s[0], color...) + } + return NewColoredValue(status, color...) +} + +var methodToColor = map[string][]ColorAttribute{ + "GET": {FgBlue}, + "POST": {FgGreen}, + "DELETE": {FgRed}, + "PATCH": {FgCyan}, + "PUT": {FgYellow, Faint}, + "HEAD": {FgBlue, Faint}, +} + +// ColoredMethod adds colors for HTTP methods on log +func ColoredMethod(method string) *ColoredValue { + color, ok := methodToColor[method] + if !ok { + return NewColoredValue(method, Bold) + } + return NewColoredValue(method, color...) +} + +var ( + durations = []time.Duration{ + 10 * time.Millisecond, + 100 * time.Millisecond, + 1 * time.Second, + 5 * time.Second, + 10 * time.Second, + } + + durationColors = [][]ColorAttribute{ + {FgGreen}, + {Bold}, + {FgYellow}, + {FgRed, Bold}, + {BgRed}, + } + + wayTooLong = BgMagenta +) + +// ColoredTime converts the provided time to a ColoredValue for logging. The duration is always formatted in milliseconds. +func ColoredTime(duration time.Duration) *ColoredValue { + // the output of duration in Millisecond is more readable: + // * before: "100.1ms" "100.1μs" "100.1s" + // * better: "100.1ms" "0.1ms" "100100.0ms", readers can compare the values at first glance. + str := fmt.Sprintf("%.1fms", float64(duration.Microseconds())/1000) + for i, k := range durations { + if duration < k { + return NewColoredValue(str, durationColors[i]...) + } + } + return NewColoredValue(str, wayTooLong) +} diff --git a/modules/log/event_format.go b/modules/log/event_format.go new file mode 100644 index 0000000..df6b083 --- /dev/null +++ b/modules/log/event_format.go @@ -0,0 +1,253 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "bytes" + "fmt" + "strings" + "time" +) + +type Event struct { + Time time.Time + + GoroutinePid string + Caller string + Filename string + Line int + + Level Level + + MsgSimpleText string + + msgFormat string // the format and args is only valid in the caller's goroutine + msgArgs []any // they are discarded before the event is passed to the writer's channel + + Stacktrace string +} + +type EventFormatted struct { + Origin *Event + Msg any // the message formatted by the writer's formatter, the writer knows its type +} + +type EventFormatter func(mode *WriterMode, event *Event, msgFormat string, msgArgs ...any) []byte + +type logStringFormatter struct { + v LogStringer +} + +var _ fmt.Formatter = logStringFormatter{} + +func (l logStringFormatter) Format(f fmt.State, verb rune) { + if f.Flag('#') && verb == 'v' { + _, _ = fmt.Fprintf(f, "%#v", l.v) + return + } + _, _ = f.Write([]byte(l.v.LogString())) +} + +// Copy of cheap integer to fixed-width decimal to ascii from logger. +// TODO: legacy bugs: doesn't support negative number, overflow if wid it too large. +func itoa(buf []byte, i, wid int) []byte { + var s [20]byte + bp := len(s) - 1 + for i >= 10 || wid > 1 { + wid-- + q := i / 10 + s[bp] = byte('0' + i - q*10) + bp-- + i = q + } + // i < 10 + s[bp] = byte('0' + i) + return append(buf, s[bp:]...) +} + +func colorSprintf(colorize bool, format string, args ...any) string { + hasColorValue := false + for _, v := range args { + if _, hasColorValue = v.(*ColoredValue); hasColorValue { + break + } + } + if colorize || !hasColorValue { + return fmt.Sprintf(format, args...) + } + + noColors := make([]any, len(args)) + copy(noColors, args) + for i, v := range args { + if cv, ok := v.(*ColoredValue); ok { + noColors[i] = cv.v + } + } + return fmt.Sprintf(format, noColors...) +} + +// EventFormatTextMessage makes the log message for a writer with its mode. This function is a copy of the original package +func EventFormatTextMessage(mode *WriterMode, event *Event, msgFormat string, msgArgs ...any) []byte { + buf := make([]byte, 0, 1024) + t := event.Time + flags := mode.Flags.Bits() + + // if log level prefixes are enabled, the message must begin with the prefix, see sd_daemon(3) + // "A line that is not prefixed will be logged at the default log level SD_INFO" + if flags&Llevelprefix != 0 { + prefix := event.Level.JournalPrefix() + buf = append(buf, prefix...) + } + + buf = append(buf, mode.Prefix...) + if flags&(Ldate|Ltime|Lmicroseconds) != 0 { + if mode.Colorize { + buf = append(buf, fgCyanBytes...) + } + if flags&LUTC != 0 { + t = t.UTC() + } + if flags&Ldate != 0 { + year, month, day := t.Date() + buf = itoa(buf, year, 4) + buf = append(buf, '/') + buf = itoa(buf, int(month), 2) + buf = append(buf, '/') + buf = itoa(buf, day, 2) + buf = append(buf, ' ') + } + if flags&(Ltime|Lmicroseconds) != 0 { + hour, min, sec := t.Clock() + buf = itoa(buf, hour, 2) + buf = append(buf, ':') + buf = itoa(buf, min, 2) + buf = append(buf, ':') + buf = itoa(buf, sec, 2) + if flags&Lmicroseconds != 0 { + buf = append(buf, '.') + buf = itoa(buf, t.Nanosecond()/1e3, 6) + } + buf = append(buf, ' ') + } + if mode.Colorize { + buf = append(buf, resetBytes...) + } + } + if flags&(Lshortfile|Llongfile) != 0 { + if mode.Colorize { + buf = append(buf, fgGreenBytes...) + } + file := event.Filename + if flags&Lmedfile == Lmedfile { + startIndex := len(file) - 20 + if startIndex > 0 { + file = "..." + file[startIndex:] + } + } else if flags&Lshortfile != 0 { + startIndex := strings.LastIndexByte(file, '/') + if startIndex > 0 && startIndex < len(file) { + file = file[startIndex+1:] + } + } + buf = append(buf, file...) + buf = append(buf, ':') + buf = itoa(buf, event.Line, -1) + if flags&(Lfuncname|Lshortfuncname) != 0 { + buf = append(buf, ':') + } else { + if mode.Colorize { + buf = append(buf, resetBytes...) + } + buf = append(buf, ' ') + } + } + if flags&(Lfuncname|Lshortfuncname) != 0 { + if mode.Colorize { + buf = append(buf, fgGreenBytes...) + } + funcname := event.Caller + if flags&Lshortfuncname != 0 { + lastIndex := strings.LastIndexByte(funcname, '.') + if lastIndex > 0 && len(funcname) > lastIndex+1 { + funcname = funcname[lastIndex+1:] + } + } + buf = append(buf, funcname...) + if mode.Colorize { + buf = append(buf, resetBytes...) + } + buf = append(buf, ' ') + } + + if flags&(Llevel|Llevelinitial) != 0 { + level := strings.ToUpper(event.Level.String()) + if mode.Colorize { + buf = append(buf, ColorBytes(levelToColor[event.Level]...)...) + } + buf = append(buf, '[') + if flags&Llevelinitial != 0 { + buf = append(buf, level[0]) + } else { + buf = append(buf, level...) + } + buf = append(buf, ']') + if mode.Colorize { + buf = append(buf, resetBytes...) + } + buf = append(buf, ' ') + } + + var msg []byte + + // if the log needs colorizing, do it + if mode.Colorize && len(msgArgs) > 0 { + hasColorValue := false + for _, v := range msgArgs { + if _, hasColorValue = v.(*ColoredValue); hasColorValue { + break + } + } + if hasColorValue { + msg = []byte(fmt.Sprintf(msgFormat, msgArgs...)) + } + } + // try to reuse the pre-formatted simple text message + if len(msg) == 0 { + msg = []byte(event.MsgSimpleText) + } + // if still no message, do the normal Sprintf for the message + if len(msg) == 0 { + msg = []byte(colorSprintf(mode.Colorize, msgFormat, msgArgs...)) + } + // remove at most one trailing new line + if len(msg) > 0 && msg[len(msg)-1] == '\n' { + 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 { + lines := bytes.Split([]byte(event.Stacktrace), []byte("\n")) + for _, line := range lines { + buf = append(buf, "\n\t"...) + buf = append(buf, line...) + } + buf = append(buf, '\n') + } + buf = append(buf, '\n') + return buf +} diff --git a/modules/log/event_format_test.go b/modules/log/event_format_test.go new file mode 100644 index 0000000..0c6061e --- /dev/null +++ b/modules/log/event_format_test.go @@ -0,0 +1,114 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +func TestItoa(t *testing.T) { + b := itoa(nil, 0, 0) + assert.Equal(t, "0", string(b)) + + b = itoa(nil, 0, 1) + assert.Equal(t, "0", string(b)) + + b = itoa(nil, 0, 2) + assert.Equal(t, "00", string(b)) +} + +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", + }, + "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 + 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", + }, + "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)) +} + +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", + }, + "msg format: %v %v", "arg0", NewColoredValue("arg1", FgBlue), + ) + + assert.Equal(t, `[PREFIX] 2020/01/02 03:04:05 filename:123:caller [E] msg format: arg0 arg1 + stacktrace + +`, string(res)) + + 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", + }, + "msg format: %v %v", "arg0", NewColoredValue("arg1", FgBlue), + ) + + assert.Equal(t, "[PREFIX] \x1b[36m2020/01/02 03:04:05 \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 TestEventFormatTextMessageJournal(t *testing.T) { + // TODO: it makes no sense to emit \n-containing messages to journal as they will get mangled + // 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", + }, + "msg format: %v %v", "arg0", NewColoredValue("arg1", FgBlue), + ) + + assert.Equal(t, `<3>[PREFIX] msg format: arg0 arg1 + stacktrace + +`, string(res)) +} diff --git a/modules/log/event_writer.go b/modules/log/event_writer.go new file mode 100644 index 0000000..4b77e48 --- /dev/null +++ b/modules/log/event_writer.go @@ -0,0 +1,54 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "fmt" +) + +// EventWriter is the general interface for all event writers +// EventWriterBase is only used as its base interface +// A writer implementation could override the default EventWriterBase functions +// eg: a writer can override the Run to handle events in its own way with its own goroutine +type EventWriter interface { + EventWriterBase +} + +// WriterMode is the mode for creating a new EventWriter, it contains common options for all writers +// Its WriterOption field is the specified options for a writer, it should be passed by value but not by pointer +type WriterMode struct { + BufferLen int + + Level Level + Prefix string + Colorize bool + Flags Flags + + Expression string + + StacktraceLevel Level + + WriterOption any +} + +// EventWriterProvider is the function for creating a new EventWriter +type EventWriterProvider func(writerName string, writerMode WriterMode) EventWriter + +var eventWriterProviders = map[string]EventWriterProvider{} + +func RegisterEventWriter(writerType string, p EventWriterProvider) { + eventWriterProviders[writerType] = p +} + +func HasEventWriter(writerType string) bool { + _, ok := eventWriterProviders[writerType] + return ok +} + +func NewEventWriter(name, writerType string, mode WriterMode) (EventWriter, error) { + if p, ok := eventWriterProviders[writerType]; ok { + return p(name, mode), nil + } + return nil, fmt.Errorf("unknown event writer type %q for writer %q", writerType, name) +} diff --git a/modules/log/event_writer_base.go b/modules/log/event_writer_base.go new file mode 100644 index 0000000..c327c48 --- /dev/null +++ b/modules/log/event_writer_base.go @@ -0,0 +1,169 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "context" + "fmt" + "io" + "regexp" + "runtime/pprof" + "time" +) + +// EventWriterBase is the base interface for most event writers +// It provides default implementations for most methods +type EventWriterBase interface { + Base() *EventWriterBaseImpl + GetWriterType() string + GetWriterName() string + GetLevel() Level + + Run(ctx context.Context) +} + +type EventWriterBaseImpl struct { + writerType string + + Name string + Mode *WriterMode + Queue chan *EventFormatted + + FormatMessage EventFormatter // format the Event to a message and write it to output + OutputWriteCloser io.WriteCloser // it will be closed when the event writer is stopped + GetPauseChan func() chan struct{} + + shared bool + stopped chan struct{} +} + +var _ EventWriterBase = (*EventWriterBaseImpl)(nil) + +func (b *EventWriterBaseImpl) Base() *EventWriterBaseImpl { + return b +} + +func (b *EventWriterBaseImpl) GetWriterType() string { + return b.writerType +} + +func (b *EventWriterBaseImpl) GetWriterName() string { + return b.Name +} + +func (b *EventWriterBaseImpl) GetLevel() Level { + return b.Mode.Level +} + +// Run is the default implementation for EventWriter.Run +func (b *EventWriterBaseImpl) Run(ctx context.Context) { + defer b.OutputWriteCloser.Close() + + var exprRegexp *regexp.Regexp + if b.Mode.Expression != "" { + var err error + if exprRegexp, err = regexp.Compile(b.Mode.Expression); err != nil { + FallbackErrorf("unable to compile expression %q for writer %q: %v", b.Mode.Expression, b.Name, err) + } + } + + handlePaused := func() { + if pause := b.GetPauseChan(); pause != nil { + select { + case <-pause: + case <-ctx.Done(): + } + } + } + + for { + select { + case <-ctx.Done(): + return + case event, ok := <-b.Queue: + if !ok { + return + } + + handlePaused() + + if exprRegexp != nil { + fileLineCaller := fmt.Sprintf("%s:%d:%s", event.Origin.Filename, event.Origin.Line, event.Origin.Caller) + matched := exprRegexp.MatchString(fileLineCaller) || exprRegexp.MatchString(event.Origin.MsgSimpleText) + if !matched { + continue + } + } + + var err error + switch msg := event.Msg.(type) { + case string: + _, err = b.OutputWriteCloser.Write([]byte(msg)) + case []byte: + _, err = b.OutputWriteCloser.Write(msg) + case io.WriterTo: + _, err = msg.WriteTo(b.OutputWriteCloser) + default: + _, err = b.OutputWriteCloser.Write([]byte(fmt.Sprint(msg))) + } + if err != nil { + FallbackErrorf("unable to write log message of %q (%v): %v", b.Name, err, event.Msg) + } + } + } +} + +func NewEventWriterBase(name, writerType string, mode WriterMode) *EventWriterBaseImpl { + if mode.BufferLen == 0 { + mode.BufferLen = 1000 + } + if mode.Level == UNDEFINED { + mode.Level = INFO + } + if mode.StacktraceLevel == UNDEFINED { + mode.StacktraceLevel = NONE + } + b := &EventWriterBaseImpl{ + writerType: writerType, + + Name: name, + Mode: &mode, + Queue: make(chan *EventFormatted, mode.BufferLen), + + GetPauseChan: GetManager().GetPauseChan, // by default, use the global pause channel + FormatMessage: EventFormatTextMessage, + } + return b +} + +// eventWriterStartGo use "go" to start an event worker's Run method +func eventWriterStartGo(ctx context.Context, w EventWriter, shared bool) { + if w.Base().stopped != nil { + return // already started + } + w.Base().shared = shared + w.Base().stopped = make(chan struct{}) + + ctxDesc := "Logger: EventWriter: " + w.GetWriterName() + if shared { + ctxDesc = "Logger: EventWriter (shared): " + w.GetWriterName() + } + writerCtx, writerCancel := newProcessTypedContext(ctx, ctxDesc) + go func() { + defer writerCancel() + defer close(w.Base().stopped) + pprof.SetGoroutineLabels(writerCtx) + w.Run(writerCtx) + }() +} + +// eventWriterStopWait stops an event writer and waits for it to finish flushing (with a timeout) +func eventWriterStopWait(w EventWriter) { + close(w.Base().Queue) + select { + case <-w.Base().stopped: + case <-time.After(2 * time.Second): + FallbackErrorf("unable to stop log writer %q in time, skip", w.GetWriterName()) + } +} diff --git a/modules/log/event_writer_conn.go b/modules/log/event_writer_conn.go new file mode 100644 index 0000000..022206a --- /dev/null +++ b/modules/log/event_writer_conn.go @@ -0,0 +1,111 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "io" + "net" +) + +type WriterConnOption struct { + Addr string + Protocol string + Reconnect bool + ReconnectOnMsg bool +} + +type eventWriterConn struct { + *EventWriterBaseImpl + connWriter connWriter +} + +var _ EventWriter = (*eventWriterConn)(nil) + +func NewEventWriterConn(writerName string, writerMode WriterMode) EventWriter { + w := &eventWriterConn{EventWriterBaseImpl: NewEventWriterBase(writerName, "conn", writerMode)} + opt := writerMode.WriterOption.(WriterConnOption) + w.connWriter = connWriter{ + ReconnectOnMsg: opt.ReconnectOnMsg, + Reconnect: opt.Reconnect, + Net: opt.Protocol, + Addr: opt.Addr, + } + w.OutputWriteCloser = &w.connWriter + return w +} + +func init() { + RegisterEventWriter("conn", NewEventWriterConn) +} + +// below is copied from old code + +type connWriter struct { + innerWriter io.WriteCloser + + ReconnectOnMsg bool + Reconnect bool + Net string `json:"net"` + Addr string `json:"addr"` +} + +var _ io.WriteCloser = (*connWriter)(nil) + +// Close the inner writer +func (i *connWriter) Close() error { + if i.innerWriter != nil { + return i.innerWriter.Close() + } + return nil +} + +// Write the data to the connection +func (i *connWriter) Write(p []byte) (int, error) { + if i.neededConnectOnMsg() { + if err := i.connect(); err != nil { + return 0, err + } + } + + if i.ReconnectOnMsg { + defer i.innerWriter.Close() + } + + return i.innerWriter.Write(p) +} + +func (i *connWriter) neededConnectOnMsg() bool { + if i.Reconnect { + i.Reconnect = false + return true + } + + if i.innerWriter == nil { + return true + } + + return i.ReconnectOnMsg +} + +func (i *connWriter) connect() error { + if i.innerWriter != nil { + _ = i.innerWriter.Close() + i.innerWriter = nil + } + + conn, err := net.Dial(i.Net, i.Addr) + if err != nil { + return err + } + + if tcpConn, ok := conn.(*net.TCPConn); ok { + err = tcpConn.SetKeepAlive(true) + if err != nil { + return err + } + } + + i.innerWriter = conn + return nil +} diff --git a/modules/log/event_writer_conn_test.go b/modules/log/event_writer_conn_test.go new file mode 100644 index 0000000..de8694f --- /dev/null +++ b/modules/log/event_writer_conn_test.go @@ -0,0 +1,76 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "context" + "fmt" + "io" + "net" + "strings" + "sync" + "testing" + "time" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func listenReadAndClose(t *testing.T, l net.Listener, expected string) { + conn, err := l.Accept() + require.NoError(t, err) + defer conn.Close() + written, err := io.ReadAll(conn) + + require.NoError(t, err) + assert.Equal(t, expected, string(written)) +} + +func TestConnLogger(t *testing.T) { + protocol := "tcp" + address := ":3099" + + l, err := net.Listen(protocol, address) + if err != nil { + t.Fatal(err) + } + defer l.Close() + + prefix := "TestPrefix " + level := INFO + flags := LstdFlags | LUTC | Lfuncname + + logger := NewLoggerWithWriters(context.Background(), "test", NewEventWriterConn("test-conn", WriterMode{ + Level: level, + Prefix: prefix, + Flags: FlagsFromBits(flags), + WriterOption: WriterConnOption{Addr: address, Protocol: protocol, Reconnect: true, ReconnectOnMsg: true}, + })) + + location, _ := time.LoadLocation("EST") + + date := time.Date(2019, time.January, 13, 22, 3, 30, 15, location) + + dateString := date.UTC().Format("2006/01/02 15:04:05") + + event := Event{ + Level: INFO, + MsgSimpleText: "TEST MSG", + Caller: "CALLER", + Filename: "FULL/FILENAME", + Line: 1, + Time: date, + } + expected := fmt.Sprintf("%s%s %s:%d:%s [%c] %s\n", prefix, dateString, event.Filename, event.Line, event.Caller, strings.ToUpper(event.Level.String())[0], event.MsgSimpleText) + var wg sync.WaitGroup + wg.Add(1) + go func() { + defer wg.Done() + listenReadAndClose(t, l, expected) + }() + logger.SendLogEvent(&event) + wg.Wait() + + logger.Close() +} diff --git a/modules/log/event_writer_console.go b/modules/log/event_writer_console.go new file mode 100644 index 0000000..78183de --- /dev/null +++ b/modules/log/event_writer_console.go @@ -0,0 +1,40 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "io" + "os" +) + +type WriterConsoleOption struct { + Stderr bool +} + +type eventWriterConsole struct { + *EventWriterBaseImpl +} + +var _ EventWriter = (*eventWriterConsole)(nil) + +type nopCloser struct { + io.Writer +} + +func (nopCloser) Close() error { return nil } + +func NewEventWriterConsole(name string, mode WriterMode) EventWriter { + w := &eventWriterConsole{EventWriterBaseImpl: NewEventWriterBase(name, "console", mode)} + opt := mode.WriterOption.(WriterConsoleOption) + if opt.Stderr { + w.OutputWriteCloser = nopCloser{os.Stderr} + } else { + w.OutputWriteCloser = nopCloser{os.Stdout} + } + return w +} + +func init() { + RegisterEventWriter("console", NewEventWriterConsole) +} diff --git a/modules/log/event_writer_file.go b/modules/log/event_writer_file.go new file mode 100644 index 0000000..fd73d7d --- /dev/null +++ b/modules/log/event_writer_file.go @@ -0,0 +1,53 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "io" + + "code.gitea.io/gitea/modules/util/rotatingfilewriter" +) + +type WriterFileOption struct { + FileName string + MaxSize int64 + LogRotate bool + DailyRotate bool + MaxDays int + Compress bool + CompressionLevel int +} + +type eventWriterFile struct { + *EventWriterBaseImpl + fileWriter io.WriteCloser +} + +var _ EventWriter = (*eventWriterFile)(nil) + +func NewEventWriterFile(name string, mode WriterMode) EventWriter { + w := &eventWriterFile{EventWriterBaseImpl: NewEventWriterBase(name, "file", mode)} + opt := mode.WriterOption.(WriterFileOption) + var err error + w.fileWriter, err = rotatingfilewriter.Open(opt.FileName, &rotatingfilewriter.Options{ + Rotate: opt.LogRotate, + MaximumSize: opt.MaxSize, + RotateDaily: opt.DailyRotate, + KeepDays: opt.MaxDays, + Compress: opt.Compress, + CompressionLevel: opt.CompressionLevel, + }) + if err != nil { + // if the log file can't be opened, what should it do? panic/exit? ignore logs? fallback to stderr? + // it seems that "fallback to stderr" is slightly better than others .... + FallbackErrorf("unable to open log file %q: %v", opt.FileName, err) + w.fileWriter = nopCloser{Writer: LoggerToWriter(FallbackErrorf)} + } + w.OutputWriteCloser = w.fileWriter + return w +} + +func init() { + RegisterEventWriter("file", NewEventWriterFile) +} diff --git a/modules/log/flags.go b/modules/log/flags.go new file mode 100644 index 0000000..cadf54f --- /dev/null +++ b/modules/log/flags.go @@ -0,0 +1,138 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "sort" + "strings" + + "code.gitea.io/gitea/modules/json" +) + +// These flags define which text to prefix to each log entry generated +// by the Logger. Bits are or'ed together to control what's printed. +// There is no control over the order they appear (the order listed +// here) or the format they present (as described in the comments). +// The prefix is followed by a colon only if more than time is stated +// is specified. For example, flags Ldate | Ltime +// produce, 2009/01/23 01:23:23 message. +// The standard is: +// 2009/01/23 01:23:23 ...a/logger/c/d.go:23:runtime.Caller() [I]: message +const ( + Ldate uint32 = 1 << iota // the date in the local time zone: 2009/01/23 + Ltime // the time in the local time zone: 01:23:23 + Lmicroseconds // microsecond resolution: 01:23:23.123123. assumes Ltime. + Llongfile // full file name and line number: /a/logger/c/d.go:23 + Lshortfile // final file name element and line number: d.go:23. overrides Llongfile + Lfuncname // function name of the caller: runtime.Caller() + Lshortfuncname // last part of the function name + 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 + LstdFlags = Ldate | Ltime | Lmedfile | Lshortfuncname | Llevelinitial // default + LjournaldFlags = Llevelprefix +) + +const Ldefault = LstdFlags + +type Flags struct { + defined bool + flags uint32 +} + +var flagFromString = map[string]uint32{ + "date": Ldate, + "time": Ltime, + "microseconds": Lmicroseconds, + "longfile": Llongfile, + "shortfile": Lshortfile, + "funcname": Lfuncname, + "shortfuncname": Lshortfuncname, + "utc": LUTC, + "levelinitial": Llevelinitial, + "level": Llevel, + "levelprefix": Llevelprefix, + "gopid": Lgopid, + + "medfile": Lmedfile, + "stdflags": LstdFlags, + "journaldflags": LjournaldFlags, +} + +var flagComboToString = []struct { + flag uint32 + name string +}{ + // name with more bits comes first + {LstdFlags, "stdflags"}, + {Lmedfile, "medfile"}, + + {Ldate, "date"}, + {Ltime, "time"}, + {Lmicroseconds, "microseconds"}, + {Llongfile, "longfile"}, + {Lshortfile, "shortfile"}, + {Lfuncname, "funcname"}, + {Lshortfuncname, "shortfuncname"}, + {LUTC, "utc"}, + {Llevelinitial, "levelinitial"}, + {Llevel, "level"}, + {Lgopid, "gopid"}, +} + +func (f Flags) Bits() uint32 { + if !f.defined { + return Ldefault + } + return f.flags +} + +func (f Flags) String() string { + flags := f.Bits() + var flagNames []string + for _, it := range flagComboToString { + if flags&it.flag == it.flag { + flags &^= it.flag + flagNames = append(flagNames, it.name) + } + } + if len(flagNames) == 0 { + return "none" + } + sort.Strings(flagNames) + return strings.Join(flagNames, ",") +} + +func (f *Flags) UnmarshalJSON(bytes []byte) error { + var s string + if err := json.Unmarshal(bytes, &s); err != nil { + return err + } + *f = FlagsFromString(s) + return nil +} + +func (f Flags) MarshalJSON() ([]byte, error) { + return []byte(`"` + f.String() + `"`), nil +} + +func FlagsFromString(from string, def ...uint32) Flags { + from = strings.TrimSpace(from) + if from == "" && len(def) > 0 { + return Flags{defined: true, flags: def[0]} + } + flags := uint32(0) + for _, flag := range strings.Split(strings.ToLower(from), ",") { + flags |= flagFromString[strings.TrimSpace(flag)] + } + return Flags{defined: true, flags: flags} +} + +func FlagsFromBits(flags uint32) Flags { + return Flags{defined: true, flags: flags} +} diff --git a/modules/log/flags_test.go b/modules/log/flags_test.go new file mode 100644 index 0000000..a101c42 --- /dev/null +++ b/modules/log/flags_test.go @@ -0,0 +1,31 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "testing" + + "code.gitea.io/gitea/modules/json" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func TestFlags(t *testing.T) { + assert.EqualValues(t, Ldefault, Flags{}.Bits()) + assert.EqualValues(t, 0, FlagsFromString("").Bits()) + assert.EqualValues(t, Lgopid, FlagsFromString("", Lgopid).Bits()) + assert.EqualValues(t, 0, FlagsFromString("none", Lgopid).Bits()) + assert.EqualValues(t, Ldate|Ltime, FlagsFromString("date,time", Lgopid).Bits()) + + assert.EqualValues(t, "stdflags", FlagsFromString("stdflags").String()) + assert.EqualValues(t, "medfile", FlagsFromString("medfile").String()) + + bs, err := json.Marshal(FlagsFromString("utc,level")) + require.NoError(t, err) + assert.EqualValues(t, `"level,utc"`, string(bs)) + var flags Flags + require.NoError(t, json.Unmarshal(bs, &flags)) + assert.EqualValues(t, LUTC|Llevel, flags.Bits()) +} diff --git a/modules/log/groutinelabel.go b/modules/log/groutinelabel.go new file mode 100644 index 0000000..56d7af4 --- /dev/null +++ b/modules/log/groutinelabel.go @@ -0,0 +1,19 @@ +// 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_test.go b/modules/log/groutinelabel_test.go new file mode 100644 index 0000000..34e9965 --- /dev/null +++ b/modules/log/groutinelabel_test.go @@ -0,0 +1,33 @@ +// 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"]) + } + }) + }) +} diff --git a/modules/log/init.go b/modules/log/init.go new file mode 100644 index 0000000..3fb5200 --- /dev/null +++ b/modules/log/init.go @@ -0,0 +1,44 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "context" + "runtime" + "strings" + + "code.gitea.io/gitea/modules/process" + "code.gitea.io/gitea/modules/util/rotatingfilewriter" +) + +var projectPackagePrefix string + +func init() { + _, filename, _, _ := runtime.Caller(0) + projectPackagePrefix = strings.TrimSuffix(filename, "modules/log/init.go") + if projectPackagePrefix == filename { + // in case the source code file is moved, we can not trim the suffix, the code above should also be updated. + panic("unable to detect correct package prefix, please update file: " + filename) + } + + rotatingfilewriter.ErrorPrintf = FallbackErrorf + + process.TraceCallback = func(skip int, start bool, pid process.IDType, description string, parentPID process.IDType, typ string) { + if start && parentPID != "" { + Log(skip+1, TRACE, "Start %s: %s (from %s) (%s)", NewColoredValue(pid, FgHiYellow), description, NewColoredValue(parentPID, FgYellow), NewColoredValue(typ, Reset)) + } else if start { + Log(skip+1, TRACE, "Start %s: %s (%s)", NewColoredValue(pid, FgHiYellow), description, NewColoredValue(typ, Reset)) + } else { + Log(skip+1, TRACE, "Done %s: %s", NewColoredValue(pid, FgHiYellow), NewColoredValue(description, Reset)) + } + } +} + +func newProcessTypedContext(parent context.Context, desc string) (ctx context.Context, cancel context.CancelFunc) { + // the "process manager" also calls "log.Trace()" to output logs, so if we want to create new contexts by the manager, we need to disable the trace temporarily + process.TraceLogDisable(true) + defer process.TraceLogDisable(false) + ctx, _, cancel = process.GetManager().AddTypedContext(parent, desc, process.SystemProcessType, false) + return ctx, cancel +} diff --git a/modules/log/level.go b/modules/log/level.go new file mode 100644 index 0000000..47f7b83 --- /dev/null +++ b/modules/log/level.go @@ -0,0 +1,136 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "bytes" + "strings" + + "code.gitea.io/gitea/modules/json" +) + +// Level is the level of the logger +type Level int + +const ( + UNDEFINED Level = iota + TRACE + DEBUG + INFO + WARN + ERROR + FATAL + NONE +) + +const CRITICAL = ERROR // most logger frameworks doesn't support CRITICAL, and it doesn't seem useful + +var toString = map[Level]string{ + UNDEFINED: "undefined", + + TRACE: "trace", + DEBUG: "debug", + INFO: "info", + WARN: "warn", + ERROR: "error", + + FATAL: "fatal", + NONE: "none", +} + +// Machine-readable log level prefixes as defined in sd-daemon(3). +// +// "If a systemd service definition file is configured with StandardError=journal +// or StandardError=kmsg (and similar with StandardOutput=), these prefixes can +// be used to encode a log level in lines printed. <...> To use these prefixes +// simply prefix every line with one of these strings. A line that is not prefixed +// will be logged at the default log level SD_INFO." +var toJournalPrefix = map[Level]string{ + TRACE: "<7>", // SD_DEBUG + DEBUG: "<6>", // SD_INFO + INFO: "<5>", // SD_NOTICE + WARN: "<4>", // SD_WARNING + ERROR: "<3>", // SD_ERR + FATAL: "<2>", // SD_CRIT +} + +var toLevel = map[string]Level{ + "undefined": UNDEFINED, + + "trace": TRACE, + "debug": DEBUG, + "info": INFO, + "warn": WARN, + "warning": WARN, + "error": ERROR, + + "fatal": FATAL, + "none": NONE, +} + +var levelToColor = map[Level][]ColorAttribute{ + TRACE: {Bold, FgCyan}, + DEBUG: {Bold, FgBlue}, + INFO: {Bold, FgGreen}, + WARN: {Bold, FgYellow}, + ERROR: {Bold, FgRed}, + FATAL: {Bold, BgRed}, + NONE: {Reset}, +} + +func (l Level) String() string { + s, ok := toString[l] + if ok { + return s + } + return "info" +} + +func (l Level) JournalPrefix() string { + return toJournalPrefix[l] +} + +func (l Level) ColorAttributes() []ColorAttribute { + color, ok := levelToColor[l] + if ok { + return color + } + none := levelToColor[NONE] + return none +} + +// MarshalJSON takes a Level and turns it into text +func (l Level) MarshalJSON() ([]byte, error) { + buffer := bytes.NewBufferString(`"`) + buffer.WriteString(toString[l]) + buffer.WriteString(`"`) + return buffer.Bytes(), nil +} + +// UnmarshalJSON takes text and turns it into a Level +func (l *Level) UnmarshalJSON(b []byte) error { + var tmp any + err := json.Unmarshal(b, &tmp) + if err != nil { + return err + } + + switch v := tmp.(type) { + case string: + *l = LevelFromString(v) + case int: + *l = LevelFromString(Level(v).String()) + default: + *l = INFO + } + return nil +} + +// LevelFromString takes a level string and returns a Level +func LevelFromString(level string) Level { + if l, ok := toLevel[strings.ToLower(level)]; ok { + return l + } + return INFO +} diff --git a/modules/log/level_test.go b/modules/log/level_test.go new file mode 100644 index 0000000..9831ca5 --- /dev/null +++ b/modules/log/level_test.go @@ -0,0 +1,56 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "fmt" + "testing" + + "code.gitea.io/gitea/modules/json" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +type testLevel struct { + Level Level `json:"level"` +} + +func TestLevelMarshalUnmarshalJSON(t *testing.T) { + levelBytes, err := json.Marshal(testLevel{ + Level: INFO, + }) + require.NoError(t, err) + assert.Equal(t, string(makeTestLevelBytes(INFO.String())), string(levelBytes)) + + var testLevel testLevel + err = json.Unmarshal(levelBytes, &testLevel) + require.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + err = json.Unmarshal(makeTestLevelBytes(`FOFOO`), &testLevel) + require.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + err = json.Unmarshal([]byte(fmt.Sprintf(`{"level":%d}`, 2)), &testLevel) + require.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + err = json.Unmarshal([]byte(fmt.Sprintf(`{"level":%d}`, 10012)), &testLevel) + require.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + err = json.Unmarshal([]byte(`{"level":{}}`), &testLevel) + require.NoError(t, err) + assert.Equal(t, INFO, testLevel.Level) + + assert.Equal(t, INFO.String(), Level(1001).String()) + + err = json.Unmarshal([]byte(`{"level":{}`), &testLevel.Level) + require.Error(t, err) +} + +func makeTestLevelBytes(level string) []byte { + return []byte(fmt.Sprintf(`{"level":"%s"}`, level)) +} diff --git a/modules/log/logger.go b/modules/log/logger.go new file mode 100644 index 0000000..a833b6e --- /dev/null +++ b/modules/log/logger.go @@ -0,0 +1,50 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +// Package log provides logging capabilities for Gitea. +// Concepts: +// +// * Logger: a Logger provides logging functions and dispatches log events to all its writers +// +// * EventWriter: written log Event to a destination (eg: file, console) +// - EventWriterBase: the base struct of a writer, it contains common fields and functions for all writers +// - WriterType: the type name of a writer, eg: console, file +// - WriterName: aka Mode Name in document, the name of a writer instance, it's usually defined by the config file. +// It is called "mode name" because old code use MODE as config key, to keep compatibility, keep this concept. +// +// * WriterMode: the common options for all writers, eg: log level. +// - WriterConsoleOption and others: the specified options for a writer, eg: file path, remote address. +// +// Call graph: +// -> log.Info() +// -> LoggerImpl.Log() +// -> LoggerImpl.SendLogEvent, then the event goes into writer's goroutines +// -> EventWriter.Run() handles the events +package log + +// BaseLogger provides the basic logging functions +type BaseLogger interface { + Log(skip int, level Level, format string, v ...any) + GetLevel() Level +} + +// LevelLogger provides level-related logging functions +type LevelLogger interface { + LevelEnabled(level Level) bool + + Trace(format string, v ...any) + Debug(format string, v ...any) + Info(format string, v ...any) + Warn(format string, v ...any) + Error(format string, v ...any) + Critical(format string, v ...any) +} + +type Logger interface { + BaseLogger + LevelLogger +} + +type LogStringer interface { //nolint:revive + LogString() string +} diff --git a/modules/log/logger_global.go b/modules/log/logger_global.go new file mode 100644 index 0000000..994acfe --- /dev/null +++ b/modules/log/logger_global.go @@ -0,0 +1,83 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "fmt" + "os" +) + +// FallbackErrorf is the last chance to show an error if the logger has internal errors +func FallbackErrorf(format string, args ...any) { + _, _ = fmt.Fprintf(os.Stderr, format+"\n", args...) +} + +func GetLevel() Level { + return GetLogger(DEFAULT).GetLevel() +} + +func Log(skip int, level Level, format string, v ...any) { + GetLogger(DEFAULT).Log(skip+1, level, format, v...) +} + +func Trace(format string, v ...any) { + Log(1, TRACE, format, v...) +} + +func IsTrace() bool { + return GetLevel() <= TRACE +} + +func Debug(format string, v ...any) { + Log(1, DEBUG, format, v...) +} + +func IsDebug() bool { + return GetLevel() <= DEBUG +} + +func Info(format string, v ...any) { + Log(1, INFO, format, v...) +} + +func Warn(format string, v ...any) { + Log(1, WARN, format, v...) +} + +func Error(format string, v ...any) { + Log(1, ERROR, format, v...) +} + +func ErrorWithSkip(skip int, format string, v ...any) { + Log(skip+1, ERROR, format, v...) +} + +func Critical(format string, v ...any) { + Log(1, ERROR, format, v...) +} + +// Fatal records fatal log and exit process +func Fatal(format string, v ...any) { + Log(1, FATAL, format, v...) + GetManager().Close() + os.Exit(1) +} + +func GetLogger(name string) Logger { + return GetManager().GetLogger(name) +} + +func IsLoggerEnabled(name string) bool { + return GetManager().GetLogger(name).IsEnabled() +} + +func SetConsoleLogger(loggerName, writerName string, level Level) { + writer := NewEventWriterConsole(writerName, WriterMode{ + Level: level, + Flags: FlagsFromBits(LstdFlags), + Colorize: CanColorStdout, + WriterOption: WriterConsoleOption{}, + }) + GetManager().GetLogger(loggerName).ReplaceAllWriters(writer) +} diff --git a/modules/log/logger_impl.go b/modules/log/logger_impl.go new file mode 100644 index 0000000..d38c651 --- /dev/null +++ b/modules/log/logger_impl.go @@ -0,0 +1,240 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "context" + "runtime" + "strings" + "sync" + "sync/atomic" + "time" + + "code.gitea.io/gitea/modules/json" + "code.gitea.io/gitea/modules/util" +) + +type LoggerImpl struct { + LevelLogger + + ctx context.Context + ctxCancel context.CancelFunc + + level atomic.Int32 + stacktraceLevel atomic.Int32 + + eventWriterMu sync.RWMutex + eventWriters map[string]EventWriter +} + +var ( + _ BaseLogger = (*LoggerImpl)(nil) + _ LevelLogger = (*LoggerImpl)(nil) +) + +// SendLogEvent sends a log event to all writers +func (l *LoggerImpl) SendLogEvent(event *Event) { + l.eventWriterMu.RLock() + defer l.eventWriterMu.RUnlock() + + if len(l.eventWriters) == 0 { + FallbackErrorf("[no logger writer]: %s", event.MsgSimpleText) + return + } + + // the writers have their own goroutines, the message arguments (with Stringer) shouldn't be used in other goroutines + // so the event message must be formatted here + msgFormat, msgArgs := event.msgFormat, event.msgArgs + event.msgFormat, event.msgArgs = "(already processed by formatters)", nil + + for _, w := range l.eventWriters { + if event.Level < w.GetLevel() { + continue + } + formatted := &EventFormatted{ + Origin: event, + Msg: w.Base().FormatMessage(w.Base().Mode, event, msgFormat, msgArgs...), + } + select { + case w.Base().Queue <- formatted: + default: + bs, _ := json.Marshal(event) + FallbackErrorf("log writer %q queue is full, event: %v", w.GetWriterName(), string(bs)) + } + } +} + +// syncLevelInternal syncs the level of the logger with the levels of the writers +func (l *LoggerImpl) syncLevelInternal() { + lowestLevel := NONE + for _, w := range l.eventWriters { + if w.GetLevel() < lowestLevel { + lowestLevel = w.GetLevel() + } + } + l.level.Store(int32(lowestLevel)) + + lowestLevel = NONE + for _, w := range l.eventWriters { + if w.Base().Mode.StacktraceLevel < lowestLevel { + lowestLevel = w.GetLevel() + } + } + l.stacktraceLevel.Store(int32(lowestLevel)) +} + +// removeWriterInternal removes a writer from the logger, and stops it if it's not shared +func (l *LoggerImpl) removeWriterInternal(w EventWriter) { + if !w.Base().shared { + eventWriterStopWait(w) // only stop non-shared writers, shared writers are managed by the manager + } + delete(l.eventWriters, w.GetWriterName()) +} + +// AddWriters adds writers to the logger, and starts them. Existing writers will be replaced by new ones. +func (l *LoggerImpl) AddWriters(writer ...EventWriter) { + l.eventWriterMu.Lock() + defer l.eventWriterMu.Unlock() + l.addWritersInternal(writer...) +} + +func (l *LoggerImpl) addWritersInternal(writer ...EventWriter) { + for _, w := range writer { + if old, ok := l.eventWriters[w.GetWriterName()]; ok { + l.removeWriterInternal(old) + } + } + + for _, w := range writer { + l.eventWriters[w.GetWriterName()] = w + eventWriterStartGo(l.ctx, w, false) + } + + l.syncLevelInternal() +} + +// RemoveWriter removes a writer from the logger, and the writer is closed and flushed if it is not shared +func (l *LoggerImpl) RemoveWriter(modeName string) error { + l.eventWriterMu.Lock() + defer l.eventWriterMu.Unlock() + + w, ok := l.eventWriters[modeName] + if !ok { + return util.ErrNotExist + } + + l.removeWriterInternal(w) + l.syncLevelInternal() + return nil +} + +// ReplaceAllWriters replaces all writers from the logger, non-shared writers are closed and flushed +func (l *LoggerImpl) ReplaceAllWriters(writer ...EventWriter) { + l.eventWriterMu.Lock() + defer l.eventWriterMu.Unlock() + + for _, w := range l.eventWriters { + l.removeWriterInternal(w) + } + l.eventWriters = map[string]EventWriter{} + l.addWritersInternal(writer...) +} + +// DumpWriters dumps the writers as a JSON map, it's used for debugging and display purposes. +func (l *LoggerImpl) DumpWriters() map[string]any { + l.eventWriterMu.RLock() + defer l.eventWriterMu.RUnlock() + + writers := make(map[string]any, len(l.eventWriters)) + for k, w := range l.eventWriters { + bs, err := json.Marshal(w.Base().Mode) + if err != nil { + FallbackErrorf("marshal writer %q to dump failed: %v", k, err) + continue + } + m := map[string]any{} + _ = json.Unmarshal(bs, &m) + m["WriterType"] = w.GetWriterType() + writers[k] = m + } + return writers +} + +// Close closes the logger, non-shared writers are closed and flushed +func (l *LoggerImpl) Close() { + l.ReplaceAllWriters() + l.ctxCancel() +} + +// IsEnabled returns true if the logger is enabled: it has a working level and has writers +// Fatal is not considered as enabled, because it's a special case and the process just exits +func (l *LoggerImpl) IsEnabled() bool { + l.eventWriterMu.RLock() + defer l.eventWriterMu.RUnlock() + return l.level.Load() < int32(FATAL) && len(l.eventWriters) > 0 +} + +// Log prepares the log event, if the level matches, the event will be sent to the writers +func (l *LoggerImpl) Log(skip int, level Level, format string, logArgs ...any) { + if Level(l.level.Load()) > level { + return + } + + event := &Event{ + Time: time.Now(), + Level: level, + Caller: "?()", + } + + pc, filename, line, ok := runtime.Caller(skip + 1) + if ok { + fn := runtime.FuncForPC(pc) + if fn != nil { + event.Caller = fn.Name() + "()" + } + } + event.Filename, event.Line = strings.TrimPrefix(filename, projectPackagePrefix), line + + if l.stacktraceLevel.Load() <= int32(level) { + 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) + + // handle LogStringer values + for i, v := range msgArgs { + if cv, ok := v.(*ColoredValue); ok { + if s, ok := cv.v.(LogStringer); ok { + cv.v = logStringFormatter{v: s} + } + } else if s, ok := v.(LogStringer); ok { + msgArgs[i] = logStringFormatter{v: s} + } + } + + event.MsgSimpleText = colorSprintf(false, format, msgArgs...) + event.msgFormat = format + event.msgArgs = msgArgs + l.SendLogEvent(event) +} + +func (l *LoggerImpl) GetLevel() Level { + return Level(l.level.Load()) +} + +func NewLoggerWithWriters(ctx context.Context, name string, writer ...EventWriter) *LoggerImpl { + l := &LoggerImpl{} + l.ctx, l.ctxCancel = newProcessTypedContext(ctx, "Logger: "+name) + l.LevelLogger = BaseLoggerToGeneralLogger(l) + l.eventWriters = map[string]EventWriter{} + l.AddWriters(writer...) + return l +} diff --git a/modules/log/logger_test.go b/modules/log/logger_test.go new file mode 100644 index 0000000..0de14eb --- /dev/null +++ b/modules/log/logger_test.go @@ -0,0 +1,146 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "context" + "sync" + "testing" + "time" + + "github.com/stretchr/testify/assert" +) + +type dummyWriter struct { + *EventWriterBaseImpl + + delay time.Duration + + mu sync.Mutex + logs []string +} + +func (d *dummyWriter) Write(p []byte) (n int, err error) { + if d.delay > 0 { + time.Sleep(d.delay) + } + d.mu.Lock() + defer d.mu.Unlock() + d.logs = append(d.logs, string(p)) + return len(p), nil +} + +func (d *dummyWriter) Close() error { + return nil +} + +func (d *dummyWriter) GetLogs() []string { + d.mu.Lock() + defer d.mu.Unlock() + logs := make([]string, len(d.logs)) + copy(logs, d.logs) + return logs +} + +func newDummyWriter(name string, level Level, delay time.Duration) *dummyWriter { + w := &dummyWriter{ + EventWriterBaseImpl: NewEventWriterBase(name, "dummy", WriterMode{Level: level, Flags: FlagsFromBits(0)}), + } + w.delay = delay + w.Base().OutputWriteCloser = w + return w +} + +func TestLogger(t *testing.T) { + logger := NewLoggerWithWriters(context.Background(), "test") + + dump := logger.DumpWriters() + assert.Empty(t, dump) + assert.EqualValues(t, NONE, logger.GetLevel()) + assert.False(t, logger.IsEnabled()) + + w1 := newDummyWriter("dummy-1", DEBUG, 0) + logger.AddWriters(w1) + assert.EqualValues(t, DEBUG, logger.GetLevel()) + + w2 := newDummyWriter("dummy-2", WARN, 200*time.Millisecond) + logger.AddWriters(w2) + assert.EqualValues(t, DEBUG, logger.GetLevel()) + + dump = logger.DumpWriters() + assert.Len(t, dump, 2) + + logger.Trace("trace-level") // this level is not logged + logger.Debug("debug-level") + logger.Error("error-level") + + // w2 is slow, so only w1 has logs + time.Sleep(100 * time.Millisecond) + assert.Equal(t, []string{"debug-level\n", "error-level\n"}, w1.GetLogs()) + assert.Equal(t, []string{}, w2.GetLogs()) + + logger.Close() + + // after Close, all logs are flushed + assert.Equal(t, []string{"debug-level\n", "error-level\n"}, w1.GetLogs()) + assert.Equal(t, []string{"error-level\n"}, w2.GetLogs()) +} + +func TestLoggerPause(t *testing.T) { + logger := NewLoggerWithWriters(context.Background(), "test") + + w1 := newDummyWriter("dummy-1", DEBUG, 0) + logger.AddWriters(w1) + + GetManager().PauseAll() + time.Sleep(50 * time.Millisecond) + + logger.Info("info-level") + time.Sleep(100 * time.Millisecond) + assert.Equal(t, []string{}, w1.GetLogs()) + + GetManager().ResumeAll() + + time.Sleep(100 * time.Millisecond) + assert.Equal(t, []string{"info-level\n"}, w1.GetLogs()) + + logger.Close() +} + +type testLogString struct { + Field string +} + +func (t testLogString) LogString() string { + return "log-string" +} + +func TestLoggerLogString(t *testing.T) { + logger := NewLoggerWithWriters(context.Background(), "test") + + w1 := newDummyWriter("dummy-1", DEBUG, 0) + w1.Mode.Colorize = true + logger.AddWriters(w1) + + logger.Info("%s %s %#v %v", testLogString{}, &testLogString{}, testLogString{Field: "detail"}, NewColoredValue(testLogString{}, FgRed)) + logger.Close() + + assert.Equal(t, []string{"log-string log-string log.testLogString{Field:\"detail\"} \x1b[31mlog-string\x1b[0m\n"}, w1.GetLogs()) +} + +func TestLoggerExpressionFilter(t *testing.T) { + logger := NewLoggerWithWriters(context.Background(), "test") + + w1 := newDummyWriter("dummy-1", DEBUG, 0) + w1.Mode.Expression = "foo.*" + logger.AddWriters(w1) + + logger.Info("foo") + logger.Info("bar") + logger.Info("foo bar") + logger.SendLogEvent(&Event{Level: INFO, Filename: "foo.go", MsgSimpleText: "by filename"}) + logger.Close() + + assert.Equal(t, []string{"foo\n", "foo bar\n", "by filename\n"}, w1.GetLogs()) +} diff --git a/modules/log/manager.go b/modules/log/manager.go new file mode 100644 index 0000000..0417bbe --- /dev/null +++ b/modules/log/manager.go @@ -0,0 +1,142 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "context" + "fmt" + "sync" + "sync/atomic" +) + +const DEFAULT = "default" + +// LoggerManager manages loggers and shared event writers +type LoggerManager struct { + ctx context.Context + ctxCancel context.CancelFunc + + mu sync.Mutex + writers map[string]EventWriter + loggers map[string]*LoggerImpl + defaultLogger atomic.Pointer[LoggerImpl] + + pauseMu sync.RWMutex + pauseChan chan struct{} +} + +// GetLogger returns a logger with the given name. If the logger doesn't exist, a new empty one will be created. +func (m *LoggerManager) GetLogger(name string) *LoggerImpl { + if name == DEFAULT { + if logger := m.defaultLogger.Load(); logger != nil { + return logger + } + } + + m.mu.Lock() + defer m.mu.Unlock() + + logger := m.loggers[name] + if logger == nil { + logger = NewLoggerWithWriters(m.ctx, name) + m.loggers[name] = logger + if name == DEFAULT { + m.defaultLogger.Store(logger) + } + } + + return logger +} + +// PauseAll pauses all event writers +func (m *LoggerManager) PauseAll() { + m.pauseMu.Lock() + m.pauseChan = make(chan struct{}) + m.pauseMu.Unlock() +} + +// ResumeAll resumes all event writers +func (m *LoggerManager) ResumeAll() { + m.pauseMu.Lock() + close(m.pauseChan) + m.pauseChan = nil + m.pauseMu.Unlock() +} + +// GetPauseChan returns a channel for writer pausing +func (m *LoggerManager) GetPauseChan() chan struct{} { + m.pauseMu.RLock() + defer m.pauseMu.RUnlock() + return m.pauseChan +} + +// Close closes the logger manager, all loggers and writers will be closed, the messages are flushed. +func (m *LoggerManager) Close() { + m.mu.Lock() + defer m.mu.Unlock() + + for _, logger := range m.loggers { + logger.Close() + } + m.loggers = map[string]*LoggerImpl{} + + for _, writer := range m.writers { + eventWriterStopWait(writer) + } + m.writers = map[string]EventWriter{} + + m.ctxCancel() +} + +// DumpLoggers returns a map of all loggers and their event writers, for debugging and display purposes. +func (m *LoggerManager) DumpLoggers() map[string]any { + m.mu.Lock() + defer m.mu.Unlock() + + dump := map[string]any{} + for name, logger := range m.loggers { + loggerDump := map[string]any{ + "IsEnabled": logger.IsEnabled(), + "EventWriters": logger.DumpWriters(), + } + dump[name] = loggerDump + } + return dump +} + +// NewSharedWriter creates a new shared event writer, it can be used by multiple loggers, and a shared writer won't be closed if a logger is closed. +func (m *LoggerManager) NewSharedWriter(writerName, writerType string, mode WriterMode) (writer EventWriter, err error) { + m.mu.Lock() + defer m.mu.Unlock() + + if _, ok := m.writers[writerName]; ok { + return nil, fmt.Errorf("log event writer %q has been added before", writerName) + } + + if writer, err = NewEventWriter(writerName, writerType, mode); err != nil { + return nil, err + } + + m.writers[writerName] = writer + eventWriterStartGo(m.ctx, writer, true) + return writer, nil +} + +func (m *LoggerManager) GetSharedWriter(writerName string) EventWriter { + m.mu.Lock() + defer m.mu.Unlock() + return m.writers[writerName] +} + +var loggerManager = NewManager() + +func GetManager() *LoggerManager { + return loggerManager +} + +func NewManager() *LoggerManager { + m := &LoggerManager{writers: map[string]EventWriter{}, loggers: map[string]*LoggerImpl{}} + m.ctx, m.ctxCancel = newProcessTypedContext(context.Background(), "LoggerManager") + return m +} diff --git a/modules/log/manager_test.go b/modules/log/manager_test.go new file mode 100644 index 0000000..3839080 --- /dev/null +++ b/modules/log/manager_test.go @@ -0,0 +1,43 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func TestSharedWorker(t *testing.T) { + RegisterEventWriter("dummy", func(writerName string, writerMode WriterMode) EventWriter { + return newDummyWriter(writerName, writerMode.Level, 0) + }) + + m := NewManager() + _, err := m.NewSharedWriter("dummy-1", "dummy", WriterMode{Level: DEBUG, Flags: FlagsFromBits(0)}) + require.NoError(t, err) + + w := m.GetSharedWriter("dummy-1") + assert.NotNil(t, w) + loggerTest := m.GetLogger("test") + loggerTest.AddWriters(w) + loggerTest.Info("msg-1") + loggerTest.ReplaceAllWriters() // the shared writer is not closed here + loggerTest.Info("never seen") + + // the shared writer can still be used later + w = m.GetSharedWriter("dummy-1") + assert.NotNil(t, w) + loggerTest.AddWriters(w) + loggerTest.Info("msg-2") + + m.GetLogger("test-another").AddWriters(w) + m.GetLogger("test-another").Info("msg-3") + + m.Close() + + logs := w.(*dummyWriter).GetLogs() + assert.Equal(t, []string{"msg-1\n", "msg-2\n", "msg-3\n"}, logs) +} diff --git a/modules/log/misc.go b/modules/log/misc.go new file mode 100644 index 0000000..ae4ce04 --- /dev/null +++ b/modules/log/misc.go @@ -0,0 +1,78 @@ +// Copyright 2023 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "io" +) + +type baseToLogger struct { + base BaseLogger +} + +// BaseLoggerToGeneralLogger wraps a BaseLogger (which only has Log() function) to a Logger (which has Info() function) +func BaseLoggerToGeneralLogger(b BaseLogger) Logger { + l := &baseToLogger{base: b} + return l +} + +var _ Logger = (*baseToLogger)(nil) + +func (s *baseToLogger) Log(skip int, level Level, format string, v ...any) { + s.base.Log(skip+1, level, format, v...) +} + +func (s *baseToLogger) GetLevel() Level { + return s.base.GetLevel() +} + +func (s *baseToLogger) LevelEnabled(level Level) bool { + return s.base.GetLevel() <= level +} + +func (s *baseToLogger) Trace(format string, v ...any) { + s.base.Log(1, TRACE, format, v...) +} + +func (s *baseToLogger) Debug(format string, v ...any) { + s.base.Log(1, DEBUG, format, v...) +} + +func (s *baseToLogger) Info(format string, v ...any) { + s.base.Log(1, INFO, format, v...) +} + +func (s *baseToLogger) Warn(format string, v ...any) { + s.base.Log(1, WARN, format, v...) +} + +func (s *baseToLogger) Error(format string, v ...any) { + s.base.Log(1, ERROR, format, v...) +} + +func (s *baseToLogger) Critical(format string, v ...any) { + s.base.Log(1, CRITICAL, format, v...) +} + +type PrintfLogger struct { + Logf func(format string, args ...any) +} + +func (p *PrintfLogger) Printf(format string, args ...any) { + p.Logf(format, args...) +} + +type loggerToWriter struct { + logf func(format string, args ...any) +} + +func (p *loggerToWriter) Write(bs []byte) (int, error) { + p.logf("%s", string(bs)) + return len(bs), nil +} + +// LoggerToWriter wraps a log function to an io.Writer +func LoggerToWriter(logf func(format string, args ...any)) io.Writer { + return &loggerToWriter{logf: logf} +} diff --git a/modules/log/stack.go b/modules/log/stack.go new file mode 100644 index 0000000..9b22e92 --- /dev/null +++ b/modules/log/stack.go @@ -0,0 +1,80 @@ +// Copyright 2019 The Gitea Authors. All rights reserved. +// SPDX-License-Identifier: MIT + +package log + +import ( + "bytes" + "fmt" + "os" + "runtime" +) + +var unknown = []byte("???") + +// Stack will skip back the provided number of frames and return a stack trace with source code. +// Although we could just use debug.Stack(), this routine will return the source code and +// skip back the provided number of frames - i.e. allowing us to ignore preceding function calls. +// A skip of 0 returns the stack trace for the calling function, not including this call. +// If the problem is a lack of memory of course all this is not going to work... +func Stack(skip int) string { + buf := new(bytes.Buffer) + + // Store the last file we opened as its probable that the preceding stack frame + // will be in the same file + var lines [][]byte + var lastFilename string + for i := skip + 1; ; i++ { // Skip over frames + programCounter, filename, lineNumber, ok := runtime.Caller(i) + // If we can't retrieve the information break - basically we're into go internals at this point. + if !ok { + break + } + + // Print equivalent of debug.Stack() + _, _ = fmt.Fprintf(buf, "%s:%d (0x%x)\n", filename, lineNumber, programCounter) + // Now try to print the offending line + if filename != lastFilename { + data, err := os.ReadFile(filename) + if err != nil { + // can't read this source file + // likely we don't have the sourcecode available + continue + } + lines = bytes.Split(data, []byte{'\n'}) + lastFilename = filename + } + _, _ = fmt.Fprintf(buf, "\t%s: %s\n", functionName(programCounter), source(lines, lineNumber)) + } + return buf.String() +} + +// functionName converts the provided programCounter into a function name +func functionName(programCounter uintptr) []byte { + function := runtime.FuncForPC(programCounter) + if function == nil { + return unknown + } + name := []byte(function.Name()) + + // Because we provide the filename we can drop the preceding package name. + if lastslash := bytes.LastIndex(name, []byte("/")); lastslash >= 0 { + name = name[lastslash+1:] + } + // And the current package name. + if period := bytes.Index(name, []byte(".")); period >= 0 { + name = name[period+1:] + } + // And we should just replace the interpunct with a dot + name = bytes.ReplaceAll(name, []byte("·"), []byte(".")) + return name +} + +// source returns a space-trimmed slice of the n'th line. +func source(lines [][]byte, n int) []byte { + n-- // in stack trace, lines are 1-indexed but our array is 0-indexed + if n < 0 || n >= len(lines) { + return unknown + } + return bytes.TrimSpace(lines[n]) +} |