Add feature to tune log levels for individual subsystems

.changelog/16665.txt

@@ -0,0 +1,7 @@
+```release-note:improvement
+logging: Allow setting independent log levels for subsystems using -log-sublevels
+```
+
+```release-note:improvement
+monitor: Allow setting independent log levels for subsystems using -log-sublevels
+```

agent/agent_endpoint.go

@@ -11,14 +11,13 @@ import (
 	"strings"
 	"time"
 
-	"github.com/hashicorp/consul/envoyextensions/xdscommon"
+	"github.com/hashicorp/go-bexpr"
 	"github.com/hashicorp/go-hclog"
+	iradix "github.com/hashicorp/go-immutable-radix/v2"
 	"github.com/hashicorp/go-memdb"
-	"github.com/mitchellh/hashstructure"
-
-	"github.com/hashicorp/go-bexpr"
 	"github.com/hashicorp/serf/coordinate"
 	"github.com/hashicorp/serf/serf"
+	"github.com/mitchellh/hashstructure"
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/promhttp"
 
@@ -29,6 +28,7 @@ import (
 	"github.com/hashicorp/consul/agent/structs"
 	token_store "github.com/hashicorp/consul/agent/token"
 	"github.com/hashicorp/consul/api"
+	"github.com/hashicorp/consul/envoyextensions/xdscommon"
 	"github.com/hashicorp/consul/ipaddr"
 	"github.com/hashicorp/consul/lib"
 	"github.com/hashicorp/consul/logging"
@@ -1415,6 +1415,27 @@ func (s *HTTPHandlers) AgentMonitor(resp http.ResponseWriter, req *http.Request)
 		return nil, HTTPError{StatusCode: http.StatusBadRequest, Reason: fmt.Sprintf("Unknown log level: %s", logLevel)}
 	}
 
+	// Set up a prefix tree of LogSublevels so we can override
+	// log levels for named subcomponents.
+	var tree *iradix.Tree[hclog.Level]
+	if sublevels, ok := req.URL.Query()["logsublevels"]; ok && len(sublevels) > 0 {
+		tree = iradix.New[hclog.Level]()
+		for _, v := range sublevels {
+			key, level, ok := strings.Cut(v, ":")
+			if !ok {
+				return nil, HTTPError{StatusCode: http.StatusBadRequest, Reason: "Expected sublevel to be `<subsystem>:<log-level>` format"}
+			}
+			if !logging.ValidateLogLevel(level) {
+				return nil, HTTPError{StatusCode: http.StatusBadRequest, Reason: fmt.Sprintf("Unknown log level: %s", level)}
+			}
+			// Note for keen-eyed developers comparing this code with a similar one in logging.Setup:
+			// There is no special case required here for the root logger name because monitor.New
+			// will create a new logger to be used as a SinkAdapter for the agent logger. We must not
+			// change the agent logger level here.
+			tree, _, _ = tree.Insert([]byte(key), logging.LevelFromString(level))
+		}
+	}
+
 	flusher, ok := resp.(http.Flusher)
 	if !ok {
 		return nil, fmt.Errorf("Streaming not supported")
@@ -1424,8 +1445,10 @@ func (s *HTTPHandlers) AgentMonitor(resp http.ResponseWriter, req *http.Request)
 		BufferSize: 512,
 		Logger:     s.agent.logger,
 		LoggerOptions: &hclog.LoggerOptions{
-			Level:      logging.LevelFromString(logLevel),
-			JSONFormat: logJSON,
+			Level:             logging.LevelFromString(logLevel),
+			JSONFormat:        logJSON,
+			SubloggerHook:     logging.MakeSubloggerHook(tree),
+			IndependentLevels: true, // required so the sublogger hook doesn't modify parent logger level
 		},
 	})
 	logsCh := monitor.Start()

agent/agent_endpoint_test.go

@@ -21,7 +21,6 @@ import (
 	"time"
 
 	"github.com/armon/go-metrics"
-	"github.com/hashicorp/consul/api"
 	"github.com/hashicorp/go-hclog"
 	"github.com/hashicorp/go-uuid"
 	"github.com/hashicorp/serf/serf"
@@ -40,7 +39,7 @@ import (
 	"github.com/hashicorp/consul/agent/local"
 	"github.com/hashicorp/consul/agent/structs"
 	"github.com/hashicorp/consul/agent/token"
-	tokenStore "github.com/hashicorp/consul/agent/token"
+	"github.com/hashicorp/consul/api"
 	"github.com/hashicorp/consul/envoyextensions/xdscommon"
 	"github.com/hashicorp/consul/lib"
 	"github.com/hashicorp/consul/sdk/testutil"
@@ -1601,7 +1600,7 @@ func TestAgent_Metrics_ACLDeny(t *testing.T) {
 
 func TestHTTPHandlers_AgentMetricsStream_ACLDeny(t *testing.T) {
 	bd := BaseDeps{}
-	bd.Tokens = new(tokenStore.Store)
+	bd.Tokens = new(token.Store)
 	sink := metrics.NewInmemSink(30*time.Millisecond, time.Second)
 	bd.MetricsConfig = &lib.MetricsConfig{
 		Handler: sink,
@@ -1630,7 +1629,7 @@ func TestHTTPHandlers_AgentMetricsStream_ACLDeny(t *testing.T) {
 
 func TestHTTPHandlers_AgentMetricsStream(t *testing.T) {
 	bd := BaseDeps{}
-	bd.Tokens = new(tokenStore.Store)
+	bd.Tokens = new(token.Store)
 	sink := metrics.NewInmemSink(20*time.Millisecond, time.Second)
 	bd.MetricsConfig = &lib.MetricsConfig{
 		Handler: sink,
@@ -6115,6 +6114,50 @@ func TestAgent_Monitor(t *testing.T) {
 			t.Fatalf("got %q and did not find %q", got, want)
 		}
 	})
+
+	t.Run("logsublevel invalid format", func(t *testing.T) {
+		req, _ := http.NewRequest("GET", "/v1/agent/monitor?loglevel=warn&logsublevels=debug", nil)
+
+		resp := httptest.NewRecorder()
+		a.srv.h.ServeHTTP(resp, req)
+		require.Equal(t, http.StatusBadRequest, resp.Code)
+
+		expect := "Expected sublevel to be `<subsystem>:<log-level>` format"
+		require.Contains(t, resp.Body.String(), expect)
+	})
+
+	t.Run("logsublevel valid format", func(t *testing.T) {
+		cancelCtx, cancelFunc := context.WithCancel(context.Background())
+		req, _ := http.NewRequestWithContext(cancelCtx, "GET", "/v1/agent/monitor?loglevel=warn&logsublevels=TestAgent.http:debug", nil)
+
+		resp := httptest.NewRecorder()
+		go a.srv.h.ServeHTTP(resp, req)
+
+		args := &structs.ServiceDefinition{
+			Name: "monitor",
+			Port: 8000,
+			Check: structs.CheckType{
+				TTL: 15 * time.Second,
+			},
+		}
+
+		registerReq, _ := http.NewRequest("PUT", "/v1/agent/service/register", jsonReader(args))
+		res := httptest.NewRecorder()
+		a.srv.h.ServeHTTP(res, registerReq)
+		if http.StatusOK != res.Code {
+			t.Fatalf("expected 200 but got %v", res.Code)
+		}
+
+		require.Eventually(t, func() bool {
+			return len(resp.Body.Bytes()) > 0
+		}, 3*time.Second, 100*time.Millisecond)
+		expect := "TestAgent.http: Request finished: method=PUT url=/v1/agent/service/register"
+		require.Contains(t, resp.Body.String(), expect, "expected debug level message but got none")
+		notExpect := "Synced service: service=monitor"
+		require.NotContains(t, resp.Body.String(), notExpect, "got info level message but expected none")
+
+		cancelFunc()
+	})
 }
 
 func TestAgent_Monitor_ACLDeny(t *testing.T) {
@@ -6294,15 +6337,15 @@ func TestAgent_Token(t *testing.T) {
 
 	type tokens struct {
 		user                string
-		userSource          tokenStore.TokenSource
+		userSource          token.TokenSource
 		agent               string
-		agentSource         tokenStore.TokenSource
+		agentSource         token.TokenSource
 		agentRecovery       string
-		agentRecoverySource tokenStore.TokenSource
+		agentRecoverySource token.TokenSource
 		repl                string
-		replSource          tokenStore.TokenSource
+		replSource          token.TokenSource
 		registration        string
-		registrationSource  tokenStore.TokenSource
+		registrationSource  token.TokenSource
 	}
 
 	resetTokens := func(init tokens) {
@@ -6353,7 +6396,7 @@ func TestAgent_Token(t *testing.T) {
 			url:       "acl_token",
 			body:      body("U"),
 			code:      http.StatusOK,
-			raw:       tokens{user: "U", userSource: tokenStore.TokenSourceAPI},
+			raw:       tokens{user: "U", userSource: token.TokenSourceAPI},
 			effective: tokens{user: "U", agent: "U"},
 		},
 		{
@@ -6362,7 +6405,7 @@ func TestAgent_Token(t *testing.T) {
 			url:       "default",
 			body:      body("U"),
 			code:      http.StatusOK,
-			raw:       tokens{user: "U", userSource: tokenStore.TokenSourceAPI},
+			raw:       tokens{user: "U", userSource: token.TokenSourceAPI},
 			effective: tokens{user: "U", agent: "U"},
 		},
 		{
@@ -6372,7 +6415,7 @@ func TestAgent_Token(t *testing.T) {
 			body:      body("A"),
 			code:      http.StatusOK,
 			init:      tokens{user: "U", agent: "U"},
-			raw:       tokens{user: "U", agent: "A", agentSource: tokenStore.TokenSourceAPI},
+			raw:       tokens{user: "U", agent: "A", agentSource: token.TokenSourceAPI},
 			effective: tokens{user: "U", agent: "A"},
 		},
 		{
@@ -6382,7 +6425,7 @@ func TestAgent_Token(t *testing.T) {
 			body:      body("A"),
 			code:      http.StatusOK,
 			init:      tokens{user: "U", agent: "U"},
-			raw:       tokens{user: "U", agent: "A", agentSource: tokenStore.TokenSourceAPI},
+			raw:       tokens{user: "U", agent: "A", agentSource: token.TokenSourceAPI},
 			effective: tokens{user: "U", agent: "A"},
 		},
 		{
@@ -6391,7 +6434,7 @@ func TestAgent_Token(t *testing.T) {
 			url:       "acl_agent_master_token",
 			body:      body("M"),
 			code:      http.StatusOK,
-			raw:       tokens{agentRecovery: "M", agentRecoverySource: tokenStore.TokenSourceAPI},
+			raw:       tokens{agentRecovery: "M", agentRecoverySource: token.TokenSourceAPI},
 			effective: tokens{agentRecovery: "M"},
 		},
 		{
@@ -6400,7 +6443,7 @@ func TestAgent_Token(t *testing.T) {
 			url:       "agent_master",
 			body:      body("M"),
 			code:      http.StatusOK,
-			raw:       tokens{agentRecovery: "M", agentRecoverySource: tokenStore.TokenSourceAPI},
+			raw:       tokens{agentRecovery: "M", agentRecoverySource: token.TokenSourceAPI},
 			effective: tokens{agentRecovery: "M"},
 		},
 		{
@@ -6409,16 +6452,16 @@ func TestAgent_Token(t *testing.T) {
 			url:       "agent_recovery",
 			body:      body("R"),
 			code:      http.StatusOK,
-			raw:       tokens{agentRecovery: "R", agentRecoverySource: tokenStore.TokenSourceAPI},
-			effective: tokens{agentRecovery: "R", agentRecoverySource: tokenStore.TokenSourceAPI},
+			raw:       tokens{agentRecovery: "R", agentRecoverySource: token.TokenSourceAPI},
+			effective: tokens{agentRecovery: "R", agentRecoverySource: token.TokenSourceAPI},
 		},
 		{
 			name:      "set repl legacy",
 			method:    "PUT",
 			url:       "acl_replication_token",
 			body:      body("R"),
 			code:      http.StatusOK,
-			raw:       tokens{repl: "R", replSource: tokenStore.TokenSourceAPI},
+			raw:       tokens{repl: "R", replSource: token.TokenSourceAPI},
 			effective: tokens{repl: "R"},
 		},
 		{
@@ -6427,7 +6470,7 @@ func TestAgent_Token(t *testing.T) {
 			url:       "replication",
 			body:      body("R"),
 			code:      http.StatusOK,
-			raw:       tokens{repl: "R", replSource: tokenStore.TokenSourceAPI},
+			raw:       tokens{repl: "R", replSource: token.TokenSourceAPI},
 			effective: tokens{repl: "R"},
 		},
 		{
@@ -6436,7 +6479,7 @@ func TestAgent_Token(t *testing.T) {
 			url:       "config_file_service_registration",
 			body:      body("G"),
 			code:      http.StatusOK,
-			raw:       tokens{registration: "G", registrationSource: tokenStore.TokenSourceAPI},
+			raw:       tokens{registration: "G", registrationSource: token.TokenSourceAPI},
 			effective: tokens{registration: "G"},
 		},
 		{
@@ -6446,7 +6489,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{user: "U"},
-			raw:    tokens{userSource: tokenStore.TokenSourceAPI},
+			raw:    tokens{userSource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear default",
@@ -6455,7 +6498,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{user: "U"},
-			raw:    tokens{userSource: tokenStore.TokenSourceAPI},
+			raw:    tokens{userSource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear agent legacy",
@@ -6464,7 +6507,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{agent: "A"},
-			raw:    tokens{agentSource: tokenStore.TokenSourceAPI},
+			raw:    tokens{agentSource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear agent",
@@ -6473,7 +6516,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{agent: "A"},
-			raw:    tokens{agentSource: tokenStore.TokenSourceAPI},
+			raw:    tokens{agentSource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear master legacy",
@@ -6482,7 +6525,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{agentRecovery: "M"},
-			raw:    tokens{agentRecoverySource: tokenStore.TokenSourceAPI},
+			raw:    tokens{agentRecoverySource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear master",
@@ -6491,7 +6534,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{agentRecovery: "M"},
-			raw:    tokens{agentRecoverySource: tokenStore.TokenSourceAPI},
+			raw:    tokens{agentRecoverySource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear recovery",
@@ -6500,7 +6543,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{agentRecovery: "R"},
-			raw:    tokens{agentRecoverySource: tokenStore.TokenSourceAPI},
+			raw:    tokens{agentRecoverySource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear repl legacy",
@@ -6509,7 +6552,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{repl: "R"},
-			raw:    tokens{replSource: tokenStore.TokenSourceAPI},
+			raw:    tokens{replSource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear repl",
@@ -6518,7 +6561,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{repl: "R"},
-			raw:    tokens{replSource: tokenStore.TokenSourceAPI},
+			raw:    tokens{replSource: token.TokenSourceAPI},
 		},
 		{
 			name:   "clear registration",
@@ -6527,7 +6570,7 @@ func TestAgent_Token(t *testing.T) {
 			body:   body(""),
 			code:   http.StatusOK,
 			init:   tokens{registration: "G"},
-			raw:    tokens{registrationSource: tokenStore.TokenSourceAPI},
+			raw:    tokens{registrationSource: token.TokenSourceAPI},
 		},
 	}
 	for _, tt := range tests {

agent/config/builder.go

@@ -1030,6 +1030,7 @@ func (b *builder) build() (rt RuntimeConfig, err error) {
 
 		Logging: logging.Config{
 			LogLevel:          stringVal(c.LogLevel),
+			LogSublevels:      c.LogSublevels,
 			LogJSON:           boolVal(c.LogJSON),
 			LogFilePath:       stringVal(c.LogFile),
 			EnableSyslog:      boolVal(c.EnableSyslog),

agent/config/config.go

@@ -191,6 +191,7 @@ type Config struct {
 	Limits                           Limits              `mapstructure:"limits" json:"-"`
 	Locality                         *Locality           `mapstructure:"locality" json:"-"`
 	LogLevel                         *string             `mapstructure:"log_level" json:"log_level,omitempty"`
+	LogSublevels                     map[string]string   `mapstructure:"log_sublevels" json:"log_sublevels,omitempty"`
 	LogJSON                          *bool               `mapstructure:"log_json" json:"log_json,omitempty"`
 	LogFile                          *string             `mapstructure:"log_file" json:"log_file,omitempty"`
 	LogRotateDuration                *string             `mapstructure:"log_rotate_duration" json:"log_rotate_duration,omitempty"`

agent/config/flags.go

@@ -62,7 +62,8 @@ func AddFlags(fs *flag.FlagSet, f *LoadOpts) {
 	add(&f.FlagValues.Ports.HTTPS, "https-port", "Sets the HTTPS API port to listen on.")
 	add(&f.FlagValues.StartJoinAddrsLAN, "join", "(deprecated) An alias for -retry-join. The -join flag will be removed in a future release.")
 	add(&f.FlagValues.StartJoinAddrsWAN, "join-wan", "(deprecated) An alias for -retry-join-wan. The -join-wan flag will be removed in a future release.")
-	add(&f.FlagValues.LogLevel, "log-level", "Log level of the agent.")
+	add(&f.FlagValues.LogLevel, "log-level", "Log level of the agent. This value is inherited by subsystem loggers but may be overridden by -log-sublevels.")
+	add(&f.FlagValues.LogSublevels, "log-sublevels", "Sets the log level of a subsystem in `<subsystem>:<log-level>` format (e.g. `agent.leader:warn`). Can be specified multiple times.")
 	add(&f.FlagValues.LogJSON, "log-json", "Output logs in JSON format.")
 	add(&f.FlagValues.LogFile, "log-file", "Path to the file the logs get written to")
 	add(&f.FlagValues.LogRotateBytes, "log-rotate-bytes", "Maximum number of bytes that should be written to a log file")