Vault-39164/Handle log_requests_level empty-string or off with SIGHUP (#9056) (#10197)

* handle log_requests_level empty string or off with SIGHUP

* Update vault/core.go



* add unit test and update comment on ReloadLogRequest to indicate different than first config read

* test coverage for FinalizeInFlightReqData changes

* changelog

---------

Co-authored-by: Angel Garbarino <Monkeychip@users.noreply.github.com>
Co-authored-by: Copilot <175728472+Copilot@users.noreply.github.com>

changelog/_9056.txt

@@ -0,0 +1,3 @@
+```release-note:bug
+logging: Fixed an issue where the `log_requests_level` configuration was not respected on a SIGHUP reload when set to "off" or removed from the config file.
+```

vault/core.go

@@ -4265,13 +4265,18 @@ func (c *Core) StoreInFlightReqData(reqID string, data InFlightReqData) {
 	c.inFlightReqData.InFlightReqCount.Inc()
 }
 
-// FinalizeInFlightReqData is going log the completed request if the
-// corresponding server config option is enabled. It also removes the
-// request from the inFlightReqMap and decrement the number of in-flight
-// requests by one.
+// FinalizeInFlightReqData logs the completed request if the logRequestsLevel is configured
+// to a value other than `Off`. It then removes the request from the in-flight map
+// and decrements the counter.
 func (c *Core) FinalizeInFlightReqData(reqID string, statusCode int) {
-	if c.logRequestsLevel != nil && c.logRequestsLevel.Load() != 0 {
-		c.LogCompletedRequests(reqID, statusCode)
+	// Only log the request if a log level is set and it's not explicitly `Off`.
+	if c.logRequestsLevel != nil {
+		logLevel := c.logRequestsLevel.Load()
+
+		// Check for valid logging levels, excluding "Off"
+		if logLevel != int32(log.Off) && logLevel > int32(log.NoLevel) {
+			c.LogCompletedRequests(reqID, statusCode)
+		}
 	}
 
 	c.inFlightReqData.InFlightReqMap.Delete(reqID)
@@ -4326,6 +4331,10 @@ func (c *Core) LogCompletedRequests(reqID string, statusCode int) {
 		"request_method", reqData.Method)
 }
 
+// ReloadLogRequestsLevel reloads the request logging level. Note that unlike the
+// initial configuration, an empty or missing log level is explicitly treated as
+// `Off` during a reload. This is a defensive measure to ensure that request
+// logging is reliably disabled if the configuration is removed.
 func (c *Core) ReloadLogRequestsLevel() {
 	conf := c.rawConfig.Load()
 	if conf == nil {
@@ -4333,12 +4342,20 @@ func (c *Core) ReloadLogRequestsLevel() {
 	}
 
 	infoLevel := conf.(*server.Config).LogRequestsLevel
-	switch {
-	case log.LevelFromString(infoLevel) > log.NoLevel && log.LevelFromString(infoLevel) < log.Off:
-		c.logRequestsLevel.Store(int32(log.LevelFromString(infoLevel)))
-	case infoLevel != "":
-		c.logger.Warn("invalid log_requests_level", "level", infoLevel)
+	configLogLevel := log.LevelFromString(infoLevel)
+
+	// Accept "off" or empty string as valid disables
+	if configLogLevel == log.Off || infoLevel == "" {
+		c.logRequestsLevel.Store(int32(log.Off))
+		return
 	}
+	// Accept valid levels only
+	if configLogLevel > log.NoLevel && configLogLevel < log.Off {
+		c.logRequestsLevel.Store(int32(configLogLevel))
+		return
+	}
+	// Warn on invalid values
+	c.logger.Warn("invalid log_requests_level", "level", infoLevel)
 }
 
 func (c *Core) ReloadIntrospectionEndpointEnabled() {

vault/core_test.go

@@ -38,6 +38,7 @@ import (
 	"github.com/sasha-s/go-deadlock"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
+	uberatomic "go.uber.org/atomic"
 )
 
 // invalidKey is used to test Unseal
@@ -260,6 +261,138 @@ func TestNewCore_configureLogRequestLevel(t *testing.T) {
 	}
 }
 
+// TestCore_FinalizeInFlightReqData validates that the core server
+// correctly finalizes a completed request. It verifies that the request is
+// removed from the in-flight map and the counter is decremented.
+func TestCore_FinalizeInFlightReqData(t *testing.T) {
+	core := &Core{
+		logger:           corehelpers.NewTestLogger(t),
+		logRequestsLevel: uberatomic.NewInt32(int32(log.Info)), // Set to a valid log level
+		inFlightReqData: &InFlightRequests{
+			InFlightReqMap:   &sync.Map{},
+			InFlightReqCount: uberatomic.NewUint64(1),
+		},
+	}
+
+	reqID := "test-req"
+	reqData := InFlightReqData{
+		StartTime:        time.Now(),
+		ClientRemoteAddr: "127.0.0.1",
+		ReqPath:          "/test",
+		Method:           "GET",
+		ClientID:         "client-1",
+	}
+	core.inFlightReqData.InFlightReqMap.Store(reqID, reqData)
+
+	core.FinalizeInFlightReqData(reqID, 200)
+
+	_, ok := core.inFlightReqData.InFlightReqMap.Load(reqID)
+	if ok {
+		t.Errorf("Expected request to be deleted from map")
+	}
+
+	if got := core.inFlightReqData.InFlightReqCount.Load(); got != 0 {
+		t.Errorf("Expected counter to be 0, got %d", got)
+	}
+}
+
+// TestCore_FinalizeInFlightReqData_LogLevelVariants checks that request
+// logging is conditional on the configured log level. It asserts that logging
+// only occurs when a valid log level is set and not for "off" or invalid levels.
+func TestCore_FinalizeInFlightReqData_LogLevelVariants(t *testing.T) {
+	tests := []struct {
+		name         string
+		logLevel     int32
+		expectLogged bool // For manual inspection only
+	}{
+		{"log level off", int32(log.Off), false},
+		{"log level no level (empty)", int32(log.NoLevel), false},
+		{"log level info", int32(log.Info), true},
+		{"log level invalid", int32(-99), false},
+	}
+
+	for _, tc := range tests {
+		t.Run(tc.name, func(t *testing.T) {
+			core := &Core{
+				logger:           corehelpers.NewTestLogger(t),
+				logRequestsLevel: uberatomic.NewInt32(tc.logLevel),
+				inFlightReqData: &InFlightRequests{
+					InFlightReqMap:   &sync.Map{},
+					InFlightReqCount: uberatomic.NewUint64(1),
+				},
+			}
+			reqID := "test-req"
+			reqData := InFlightReqData{
+				StartTime:        time.Now(),
+				ClientRemoteAddr: "127.0.0.1",
+				ReqPath:          "/test",
+				Method:           "GET",
+				ClientID:         "client-1",
+			}
+			core.inFlightReqData.InFlightReqMap.Store(reqID, reqData)
+
+			core.FinalizeInFlightReqData(reqID, 200)
+
+			_, ok := core.inFlightReqData.InFlightReqMap.Load(reqID)
+			if ok {
+				t.Errorf("Expected request to be deleted from map")
+			}
+
+			if got := core.inFlightReqData.InFlightReqCount.Load(); got != 0 {
+				t.Errorf("Expected counter to be 0, got %d", got)
+			}
+		})
+	}
+}
+
+// TestCore_ReloadLogRequestsLevel ensures the log level for completed
+// requests is correctly updated when the server config is reloaded via SIGHUP,
+// including handling empty or "off" values.
+func TestCore_ReloadLogRequestsLevel(t *testing.T) {
+	t.Parallel()
+
+	tests := []struct {
+		name          string
+		configLevel   string
+		expectedLevel log.Level
+	}{
+		{"none", "", log.Off},
+		{"off", "off", log.Off},
+		{"trace", "trace", log.Trace},
+		{"debug", "debug", log.Debug},
+		{"info", "info", log.Info},
+		{"warn", "warn", log.Warn},
+		{"error", "error", log.Error},
+		{"bad", "foo", log.NoLevel},
+	}
+
+	for _, tc := range tests {
+		t.Run(tc.name, func(t *testing.T) {
+			// Create an atomic.Value instance and initialize it
+			rawConfig := &atomic.Value{}
+			rawConfig.Store(&server.Config{
+				SharedConfig: &configutil.SharedConfig{},
+			})
+
+			core := &Core{
+				logger:           corehelpers.NewTestLogger(t),
+				logRequestsLevel: uberatomic.NewInt32(0),
+				rawConfig:        rawConfig,
+			}
+			// Simulate config reload
+			conf := &server.Config{
+				SharedConfig:     &configutil.SharedConfig{},
+				LogRequestsLevel: tc.configLevel,
+			}
+			core.rawConfig.Store(conf)
+
+			core.ReloadLogRequestsLevel()
+			got := log.Level(core.logRequestsLevel.Load())
+			require.Equal(t, tc.expectedLevel, got)
+		})
+	}
+}
+
 // TestNewCore_configureListeners tests that we are able to configure listeners
 // on a NewCore via config.
 func TestNewCore_configureListeners(t *testing.T) {