Merge branch 'sh-disable-health-check-logging-default' into 'master'

log: Disable gRPC HealthCheck message logging

Closes #3428

See merge request gitlab-org/gitaly!4363

6 files changed, 81 insertions, 2 deletions

diff --git a/doc/configuration/README.md b/doc/configuration/README.md
index 70cf84498..0f7658bf1 100644
--- a/doc/configuration/README.md
+++ b/doc/configuration/README.md
@@ -164,3 +164,18 @@ level = "warn"
 |sentry_dsn|string|no|Sentry DSN for exception monitoring|
 |sentry_environment|string|no|Sentry Environment for exception monitoring|
 |ruby_sentry_dsn|string|no|Sentry DSN for gitaly-ruby exception monitoring|
+
+#### Environment variables
+
+|name|default|notes|
+|----|-------|-----|
+|GITALY_LOG_REQUEST_METHOD_ALLOW_PATTERN||Regular expression that controls which gRPC methods should be logged|
+|GITALY_LOG_REQUEST_METHOD_DENY_PATTERN|`^/grpc.health.v1.Health/Check$`|Regular expression that controls which gRPC methods should be filtered out|
+
+Note that `GITALY_LOG_REQUEST_METHOD_ALLOW_PATTERN` takes precedence
+over `GITALY_LOG_REQUEST_METHOD_DENY_PATTERN`. If a pattern matches in
+allow pattern, then it will be logged, even if it also matches the deny
+pattern. All error messages are logged unconditionally.
+
+By default, health check gRPC messages are not logged. To enable them,
+set `GITALY_LOG_REQUEST_METHOD_ALLOW_PATTERN` to `.`.
diff --git a/internal/gitaly/server/server_factory_test.go b/internal/gitaly/server/server_factory_test.go
index 661835098..c2afcd7c6 100644
--- a/internal/gitaly/server/server_factory_test.go
+++ b/internal/gitaly/server/server_factory_test.go
@@ -147,6 +147,8 @@ func TestGitalyServerFactory(t *testing.T) {
 	})
 
 	t.Run("logging check", func(t *testing.T) {
+		testhelper.ModifyEnvironment(t, "GITALY_LOG_REQUEST_METHOD_ALLOW_PATTERN", ".")
+
 		cfg := testcfg.Build(t)
 		logger, hook := test.NewNullLogger()
 		sf := NewGitalyServerFactory(
diff --git a/internal/helper/env/env.go b/internal/helper/env/env.go
index a988b3abf..e8fb5c70b 100644
--- a/internal/helper/env/env.go
+++ b/internal/helper/env/env.go
@@ -4,6 +4,7 @@ import (
 	"fmt"
 	"os"
 	"strconv"
+	"strings"
 	"time"
 )
 
@@ -51,3 +52,16 @@ func GetDuration(name string, fallback time.Duration) (time.Duration, error) {
 	}
 	return v, nil
 }
+
+// GetString fetches a given name from the environment and falls back to a
+// default value if the name is not available. The value is stripped of
+// leading and trailing whitespace.
+func GetString(name string, fallback string) string {
+	value := os.Getenv(name)
+
+	if value == "" {
+		return fallback
+	}
+
+	return strings.TrimSpace(value)
+}
diff --git a/internal/helper/env/env_test.go b/internal/helper/env/env_test.go
index 89a43f02e..10e68c143 100644
--- a/internal/helper/env/env_test.go
+++ b/internal/helper/env/env_test.go
@@ -171,3 +171,37 @@ func TestGetDuration(t *testing.T) {
 		})
 	}
 }
+
+func TestGetString(t *testing.T) {
+	for _, tc := range []struct {
+		value    string
+		fallback string
+		expected string
+	}{
+		{
+			value:    "Hello",
+			expected: "Hello",
+		},
+		{
+			value:    "hello ",
+			expected: "hello",
+		},
+		{
+			fallback: "fallback value",
+			expected: "fallback value",
+		},
+		{
+			value:    " ",
+			fallback: "fallback value",
+			expected: "",
+		},
+	} {
+		t.Run(fmt.Sprintf("value=%s,fallback=%s", tc.value, tc.fallback), func(t *testing.T) {
+			testhelper.ModifyEnvironment(t, "TEST_STRING", tc.value)
+
+			result := env.GetString("TEST_STRING", tc.fallback)
+
+			assert.Equal(t, tc.expected, result)
+		})
+	}
+}
diff --git a/internal/log/log.go b/internal/log/log.go
index b987283b2..42cb2bd94 100644
--- a/internal/log/log.go
+++ b/internal/log/log.go
@@ -9,6 +9,7 @@ import (
 	grpcmwlogrus "github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus"
 	"github.com/grpc-ecosystem/go-grpc-middleware/logging/logrus/ctxlogrus"
 	"github.com/sirupsen/logrus"
+	"gitlab.com/gitlab-org/gitaly/v14/internal/helper/env"
 	"google.golang.org/grpc"
 	"google.golang.org/grpc/codes"
 	"google.golang.org/grpc/stats"
@@ -21,6 +22,9 @@ const (
 	LogTimestampFormat = "2006-01-02T15:04:05.000"
 	// LogTimestampFormatUTC defines the utc timestamp format in log files
 	LogTimestampFormatUTC = "2006-01-02T15:04:05.000Z"
+
+	defaultLogRequestMethodAllowPattern = ""
+	defaultLogRequestMethodDenyPattern  = "^/grpc.health.v1.Health/Check$"
 )
 
 type utcFormatter struct {
@@ -116,7 +120,9 @@ func DeciderOption() grpcmwlogrus.Option {
 }
 
 func methodNameMatcherFromEnv() func(string) bool {
-	if pattern := os.Getenv("GITALY_LOG_REQUEST_METHOD_ALLOW_PATTERN"); pattern != "" {
+	if pattern :=
+		env.GetString("GITALY_LOG_REQUEST_METHOD_ALLOW_PATTERN",
+			defaultLogRequestMethodAllowPattern); pattern != "" {
 		methodRegex := regexp.MustCompile(pattern)
 
 		return func(fullMethodName string) bool {
@@ -124,7 +130,9 @@ func methodNameMatcherFromEnv() func(string) bool {
 		}
 	}
 
-	if pattern := os.Getenv("GITALY_LOG_REQUEST_METHOD_DENY_PATTERN"); pattern != "" {
+	if pattern :=
+		env.GetString("GITALY_LOG_REQUEST_METHOD_DENY_PATTERN",
+			defaultLogRequestMethodDenyPattern); pattern != "" {
 		methodRegex := regexp.MustCompile(pattern)
 
 		return func(fullMethodName string) bool {
diff --git a/internal/log/log_test.go b/internal/log/log_test.go
index a6b32b93b..224ea8389 100644
--- a/internal/log/log_test.go
+++ b/internal/log/log_test.go
@@ -462,6 +462,12 @@ func TestLogDeciderOption_logByRegexpMatch(t *testing.T) {
 			desc:             "default setting",
 			skip:             "",
 			only:             "",
+			shouldLogMethods: []string{"InfoRefsUploadPack", "PostUploadPackWithSidechannel"},
+		},
+		{
+			desc:             "allow all",
+			skip:             "",
+			only:             ".",
 			shouldLogMethods: []string{"Check", "InfoRefsUploadPack", "PostUploadPackWithSidechannel"},
 		},
 		{