feat: add a EXCLUSION to the logger (#8212)

This feature is intended to help reduce noisy logs generated by routine Kubernetes probes and Prometheus scraping. While logs are essential, these specific requests (e.g., to /metrics and /api/healthz) generally don't provide useful information and tend to clutter the output.

The goal is to introduce functionality that effectively acts as the inverse of the existing EXPRESSION mode—allowing logging to be excluded based on a condition, rather than included.

Reviewed-on: https://codeberg.org/forgejo/forgejo/pulls/8212
Reviewed-by: Gusted <gusted@noreply.codeberg.org>
Co-authored-by: zokki <zokki.softwareschmiede@gmail.com>
Co-committed-by: zokki <zokki.softwareschmiede@gmail.com>

cmd/manager_logging.go

@@ -44,6 +44,11 @@ func defaultLoggingFlags() []cli.Flag {
 			Aliases: []string{"e"},
 			Usage:   "Matching expression for the logger",
 		},
+		&cli.StringFlag{
+			Name:    "exclusion",
+			Aliases: []string{"x"},
+			Usage:   "Exclusion for the logger",
+		},
 		&cli.StringFlag{
 			Name:    "prefix",
 			Aliases: []string{"p"},
@@ -286,6 +291,9 @@ func commonAddLogger(ctx context.Context, c *cli.Command, mode string, vals map[
 	if len(c.String("expression")) > 0 {
 		vals["expression"] = c.String("expression")
 	}
+	if len(c.String("exclusion")) > 0 {
+		vals["exclusion"] = c.String("exclusion")
+	}
 	if len(c.String("prefix")) > 0 {
 		vals["prefix"] = c.String("prefix")
 	}

custom/conf/app.example.ini

@@ -631,6 +631,7 @@ LEVEL = Info
 ;LEVEL=
 ;FLAGS = stdflags or journald
 ;EXPRESSION =
+;EXCLUSION =
 ;PREFIX =
 ;COLORIZE = false
 ;;

go.mod

@@ -24,7 +24,7 @@ require (
 	github.com/ProtonMail/go-crypto v1.3.0
 	github.com/PuerkitoBio/goquery v1.10.3
 	github.com/SaveTheRbtz/zstd-seekable-format-go/pkg v0.7.2
-	github.com/alecthomas/chroma/v2 v2.18.0
+	github.com/alecthomas/chroma/v2 v2.19.0
 	github.com/blakesmith/ar v0.0.0-20190502131153-809d4375e1fb
 	github.com/blevesearch/bleve/v2 v2.5.2
 	github.com/buildkite/terminal-to-html/v3 v3.16.8

go.sum

@@ -62,8 +62,8 @@ github.com/SaveTheRbtz/zstd-seekable-format-go/pkg v0.7.2/go.mod h1:JitQWJ8JuV4Y
 github.com/alecthomas/assert/v2 v2.11.0 h1:2Q9r3ki8+JYXvGsDyBXwH3LcJ+WK5D0gc5E8vS6K3D0=
 github.com/alecthomas/assert/v2 v2.11.0/go.mod h1:Bze95FyfUr7x34QZrjL+XP+0qgp/zg8yS+TtBj1WA3k=
 github.com/alecthomas/chroma/v2 v2.2.0/go.mod h1:vf4zrexSH54oEjJ7EdB65tGNHmH3pGZmVkgTP5RHvAs=
-github.com/alecthomas/chroma/v2 v2.18.0 h1:6h53Q4hW83SuF+jcsp7CVhLsMozzvQvO8HBbKQW+gn4=
-github.com/alecthomas/chroma/v2 v2.18.0/go.mod h1:RVX6AvYm4VfYe/zsk7mjHueLDZor3aWCNE14TFlepBk=
+github.com/alecthomas/chroma/v2 v2.19.0 h1:Im+SLRgT8maArxv81mULDWN8oKxkzboH07CHesxElq4=
+github.com/alecthomas/chroma/v2 v2.19.0/go.mod h1:RVX6AvYm4VfYe/zsk7mjHueLDZor3aWCNE14TFlepBk=
 github.com/alecthomas/repr v0.0.0-20220113201626-b1b626ac65ae/go.mod h1:2kn6fqh/zIyPLmm3ugklbEi5hg5wS435eygvNfaDQL8=
 github.com/alecthomas/repr v0.4.0 h1:GhI2A8MACjfegCPVq9f1FLvIBS+DrQ2KQBFZP1iFzXc=
 github.com/alecthomas/repr v0.4.0/go.mod h1:Fr0507jx4eOXV7AlPV6AVZLYrLIuIeSOWtW57eE/O/4=

modules/log/event_writer.go

@@ -26,6 +26,7 @@ type WriterMode struct {
 	Flags    Flags
 
 	Expression string
+	Exclusion  string
 
 	StacktraceLevel Level
 

modules/log/event_writer_base.go

@@ -68,6 +68,14 @@ func (b *EventWriterBaseImpl) Run(ctx context.Context) {
 		}
 	}
 
+	var exclusionRegexp *regexp.Regexp
+	if b.Mode.Exclusion != "" {
+		var err error
+		if exclusionRegexp, err = regexp.Compile(b.Mode.Exclusion); err != nil {
+			FallbackErrorf("unable to compile exclusion %q for writer %q: %v", b.Mode.Exclusion, b.Name, err)
+		}
+	}
+
 	handlePaused := func() {
 		if pause := b.GetPauseChan(); pause != nil {
 			select {
@@ -95,6 +103,13 @@ func (b *EventWriterBaseImpl) Run(ctx context.Context) {
 					continue
 				}
 			}
+			if exclusionRegexp != nil {
+				fileLineCaller := fmt.Sprintf("%s:%d:%s", event.Origin.Filename, event.Origin.Line, event.Origin.Caller)
+				matched := exclusionRegexp.MatchString(fileLineCaller) || exclusionRegexp.MatchString(event.Origin.MsgSimpleText)
+				if matched {
+					continue
+				}
+			}
 
 			var err error
 			switch msg := event.Msg.(type) {

modules/log/event_writer_buffer_test.go

@@ -31,3 +31,49 @@ func TestBufferLogger(t *testing.T) {
 	logger.Close()
 	assert.Contains(t, bufferWriter.Buffer.String(), expected)
 }
+
+func TestBufferLoggerWithExclusion(t *testing.T) {
+	prefix := "ExclusionPrefix "
+	level := log.INFO
+	message := "something"
+
+	bufferWriter := log.NewEventWriterBuffer("test-buffer", log.WriterMode{
+		Level:     level,
+		Prefix:    prefix,
+		Exclusion: message,
+	})
+
+	logger := log.NewLoggerWithWriters(t.Context(), "test", bufferWriter)
+
+	logger.SendLogEvent(&log.Event{
+		Level:         log.INFO,
+		MsgSimpleText: message,
+	})
+	logger.Close()
+	assert.NotContains(t, bufferWriter.Buffer.String(), message)
+}
+
+func TestBufferLoggerWithExpressionAndExclusion(t *testing.T) {
+	prefix := "BothPrefix "
+	level := log.INFO
+	expression := ".*foo.*"
+	exclusion := ".*bar.*"
+
+	bufferWriter := log.NewEventWriterBuffer("test-buffer", log.WriterMode{
+		Level:      level,
+		Prefix:     prefix,
+		Expression: expression,
+		Exclusion:  exclusion,
+	})
+
+	logger := log.NewLoggerWithWriters(t.Context(), "test", bufferWriter)
+
+	logger.SendLogEvent(&log.Event{Level: log.INFO, MsgSimpleText: "foo expression"})
+	logger.SendLogEvent(&log.Event{Level: log.INFO, MsgSimpleText: "bar exclusion"})
+	logger.SendLogEvent(&log.Event{Level: log.INFO, MsgSimpleText: "foo bar both"})
+	logger.SendLogEvent(&log.Event{Level: log.INFO, MsgSimpleText: "none"})
+	logger.Close()
+
+	assert.Contains(t, bufferWriter.Buffer.String(), "foo expression")
+	assert.NotContains(t, bufferWriter.Buffer.String(), "bar")
+}

modules/log/logger_test.go

@@ -143,3 +143,19 @@ func TestLoggerExpressionFilter(t *testing.T) {
 
 	assert.Equal(t, []string{"foo\n", "foo bar\n", "by filename\n"}, w1.GetLogs())
 }
+
+func TestLoggerExclusionFilter(t *testing.T) {
+	logger := NewLoggerWithWriters(t.Context(), "test")
+
+	w1 := newDummyWriter("dummy-1", DEBUG, 0)
+	w1.Mode.Exclusion = "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{"bar\n"}, w1.GetLogs())
+}

modules/setting/log.go

@@ -133,6 +133,7 @@ func loadLogModeByName(rootCfg ConfigProvider, loggerName, modeName string) (wri
 	writerMode.StacktraceLevel = log.LevelFromString(ConfigInheritedKeyString(sec, "STACKTRACE_LEVEL", Log.StacktraceLogLevel.String()))
 	writerMode.Prefix = ConfigInheritedKeyString(sec, "PREFIX")
 	writerMode.Expression = ConfigInheritedKeyString(sec, "EXPRESSION")
+	writerMode.Exclusion = ConfigInheritedKeyString(sec, "EXCLUSION")
 	// flags are updated and set below
 
 	switch writerType {

modules/setting/log_test.go

@@ -44,6 +44,7 @@ func TestLogConfigDefault(t *testing.T) {
 		"BufferLen": 10000,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "stdflags",
 		"Level": "info",
 		"Prefix": "",
@@ -83,6 +84,7 @@ logger.xorm.MODE =
 		"BufferLen": 10000,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "stdflags",
 		"Level": "info",
 		"Prefix": "",
@@ -121,6 +123,7 @@ MODE = console
 		"BufferLen": 10000,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "stdflags",
 		"Level": "info",
 		"Prefix": "",
@@ -168,6 +171,7 @@ ACCESS = file
 		"BufferLen": 10000,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "stdflags",
 		"Level": "info",
 		"Prefix": "",
@@ -191,6 +195,7 @@ ACCESS = file
 		"BufferLen": 10000,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "none",
 		"Level": "info",
 		"Prefix": "",
@@ -257,6 +262,7 @@ STDERR = true
 		"BufferLen": 10000,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "stdflags",
 		"Level": "warn",
 		"Prefix": "",
@@ -270,6 +276,7 @@ STDERR = true
 		"BufferLen": 10000,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "stdflags",
 		"Level": "error",
 		"Prefix": "",
@@ -287,6 +294,7 @@ STDERR = true
 		"BufferLen": 10000,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "none",
 		"Level": "warn",
 		"Prefix": "",
@@ -323,6 +331,7 @@ MODE = file
 LEVEL = error
 STACKTRACE_LEVEL = fatal
 EXPRESSION = filter
+EXCLUSION = not
 FLAGS = medfile
 PREFIX = "[Prefix] "
 FILE_NAME = file-xxx.log
@@ -341,6 +350,7 @@ COMPRESSION_LEVEL = 4
 		"BufferLen": 10,
 		"Colorize": false,
 		"Expression": "",
+		"Exclusion": "",
 		"Flags": "stdflags",
 		"Level": "info",
 		"Prefix": "",
@@ -360,6 +370,7 @@ COMPRESSION_LEVEL = 4
 		"BufferLen": 10,
 		"Colorize": false,
 		"Expression": "filter",
+		"Exclusion": "not",
 		"Flags": "medfile",
 		"Level": "error",
 		"Prefix": "[Prefix] ",

routers/private/manager.go

@@ -145,6 +145,7 @@ func AddLogger(ctx *context.PrivateContext) {
 
 	writerMode.Prefix, _ = opts.Config["prefix"].(string)
 	writerMode.Expression, _ = opts.Config["expression"].(string)
+	writerMode.Exclusion, _ = opts.Config["exclusion"].(string)
 
 	switch writerType {
 	case "console":

services/mailer/mail_actions.go

@@ -16,8 +16,8 @@ const (
 	tplActionNowDone base.TplName = "actions/now_done"
 )
 
-// requires !run.Status.IsSuccess() or !lastRun.Status.IsSuccess()
-func MailActionRun(run *actions_model.ActionRun, priorStatus actions_model.Status, lastRun *actions_model.ActionRun) error {
+var MailActionRun = mailActionRun // make it mockable
+func mailActionRun(run *actions_model.ActionRun, priorStatus actions_model.Status, lastRun *actions_model.ActionRun) error {
 	if setting.MailService == nil {
 		// No mail service configured
 		return nil

services/mailer/mail_actions_now_done_test.go

@@ -57,6 +57,91 @@ func assertTranslatedLocaleMailActionsNowDone(t *testing.T, msgBody string) {
 	AssertTranslatedLocale(t, msgBody, "mail.actions.successful_run_after_failure", "mail.actions.not_successful_run", "mail.actions.run_info_cur_status", "mail.actions.run_info_ref", "mail.actions.run_info_previous_status", "mail.actions.run_info_trigger", "mail.view_it_on")
 }
 
+func TestActionRunNowDoneStatusMatrix(t *testing.T) {
+	successStatuses := []actions_model.Status{
+		actions_model.StatusSuccess,
+		actions_model.StatusSkipped,
+		actions_model.StatusCancelled,
+	}
+	failureStatuses := []actions_model.Status{
+		actions_model.StatusFailure,
+	}
+
+	for _, testCase := range []struct {
+		name         string
+		statuses     []actions_model.Status
+		hasLastRun   bool
+		lastStatuses []actions_model.Status
+		run          bool
+	}{
+		{
+			name:     "FailureNoLastRun",
+			statuses: failureStatuses,
+			run:      true,
+		},
+		{
+			name:     "SuccessNoLastRun",
+			statuses: successStatuses,
+			run:      false,
+		},
+		{
+			name:         "FailureLastRunSuccess",
+			statuses:     failureStatuses,
+			hasLastRun:   true,
+			lastStatuses: successStatuses,
+			run:          true,
+		},
+		{
+			name:         "FailureLastRunFailure",
+			statuses:     failureStatuses,
+			hasLastRun:   true,
+			lastStatuses: failureStatuses,
+			run:          true,
+		},
+		{
+			name:         "SuccessLastRunFailure",
+			statuses:     successStatuses,
+			hasLastRun:   true,
+			lastStatuses: failureStatuses,
+			run:          true,
+		},
+		{
+			name:         "SuccessLastRunSuccess",
+			statuses:     successStatuses,
+			hasLastRun:   true,
+			lastStatuses: successStatuses,
+			run:          false,
+		},
+	} {
+		t.Run(testCase.name, func(t *testing.T) {
+			var called bool
+			defer test.MockVariableValue(&MailActionRun, func(run *actions_model.ActionRun, priorStatus actions_model.Status, lastRun *actions_model.ActionRun) error {
+				called = true
+				return nil
+			})()
+			for _, status := range testCase.statuses {
+				for _, lastStatus := range testCase.lastStatuses {
+					called = false
+					n := NewNotifier()
+					var lastRun *actions_model.ActionRun
+					if testCase.hasLastRun {
+						lastRun = &actions_model.ActionRun{
+							Status: lastStatus,
+						}
+					}
+					n.ActionRunNowDone(t.Context(),
+						&actions_model.ActionRun{
+							Status: status,
+						},
+						actions_model.StatusUnknown,
+						lastRun)
+					assert.Equal(t, testCase.run, called, "status = %s, lastStatus = %s", status, lastStatus)
+				}
+			}
+		})
+	}
+}
+
 func TestActionRunNowDoneNotificationMail(t *testing.T) {
 	ctx := t.Context()
 

services/mailer/notify.go

@@ -212,7 +212,7 @@ func (m *mailNotifier) NewUserSignUp(ctx context.Context, newUser *user_model.Us
 
 func (m *mailNotifier) ActionRunNowDone(ctx context.Context, run *actions_model.ActionRun, priorStatus actions_model.Status, lastRun *actions_model.ActionRun) {
 	// Only send a mail on a successful run when the workflow recovered (i.e., the run before failed).
-	if run.Status.IsSuccess() && (lastRun == nil || lastRun.Status.IsSuccess()) {
+	if !run.Status.IsFailure() && (lastRun == nil || !lastRun.Status.IsFailure()) {
 		return
 	}
 	if err := MailActionRun(run, priorStatus, lastRun); err != nil {

tests/e2e/webauthn.test.e2e.ts

@@ -42,7 +42,6 @@ test('WebAuthn register & login flow', async ({browser, request}, workerInfo) =>
     await page.locator('div[aria-label="Profile and settings…"]').click();
     await page.getByText('Sign out').click();
   }).toPass();
-  await page.waitForURL(`${workerInfo.project.use.baseURL}/`);
 
   // Login.
   response = await page.goto('/user/login');