Control Gorouter log level using debugserver reconfigurable sink

src/code.cloudfoundry.org/gorouter/cmd/gorouter/main.go

@@ -8,10 +8,12 @@ import (
 	"log/slog"
 	"os"
 	"runtime"
+	"strings"
 	"syscall"
 	"time"
 
 	"code.cloudfoundry.org/gorouter/metrics_prometheus"
+	"go.uber.org/zap/zapcore"
 
 	"code.cloudfoundry.org/clock"
 	"code.cloudfoundry.org/debugserver"
@@ -50,13 +52,81 @@ var (
 	h          *health.Health
 )
 
+// zapLevelSink is a lager sink that uses a slog.Logger for logging.
+// It implements the lager.Sink interface, allowing it to be used with
+// lager's logging system. The Log method logs the message and source
+// using the slog.Logger, and the LogLevel method returns the current
+// logging level.
+
+type zapLevelSink struct {
+	logger *slog.Logger
+}
+
+func (z *zapLevelSink) Log(lf lager.LogFormat) {
+	z.logger.Info("zapLevelSink Log()", slog.String("Zap Level Sink log invoked", lf.Message),
+		slog.String("source", lf.Source))
+}
+
+func (z *zapLevelSink) LogLevel() lager.LogLevel {
+	switch strings.ToLower(grlog.GetLoggingLevel()) {
+	case "debug":
+		return lager.DEBUG
+	case "info":
+		return lager.INFO
+	case "error":
+		return lager.ERROR
+	case "fatal":
+		return lager.FATAL
+	default:
+		return lager.INFO
+	}
+}
+
+// The SetMinLevel method updates the logging level of the
+// zapLevelSink based on the provided lager.LogLevel, mapping it to
+// the corresponding zapcore.Level. The logger is expected to be set
+// before using this sink, and it will log an info message when the
+// logging level is updated.
+
+func (z *zapLevelSink) SetMinLevel(level lager.LogLevel) {
+	var zapLevel zapcore.Level
+	switch level {
+	case lager.DEBUG:
+		zapLevel = zapcore.DebugLevel
+	case lager.INFO:
+		zapLevel = zapcore.InfoLevel
+	case lager.ERROR, lager.FATAL:
+		// For lager.ERROR and lager.FATAL, we use zapcore.ErrorLevel.
+		// This is because zapcore.ErrorLevel captures both error and fatal logs.
+		// Using zapcore.FatalLevel would cause the application to exit immediately.
+		// Because zapcore.FatalLevel calls os.Exit(1) after logging the message.
+		zapLevel = zapcore.ErrorLevel
+	default:
+		zapLevel = zapcore.InfoLevel
+	}
+
+	grlog.SetLoggingLevel(zapLevel.String())
+
+	// Print the new log level to the logger to confirm the change.
+	// This is useful for debugging and confirming that the log level has been updated.
+	if z.logger != nil {
+		// We cannot use z.logger.Info() directly here because it won't print the
+		// log level when it is set to zapcore.ErrorLevel or zapcore.FatalLevel.
+		// Instead, we use slog.New() to log the message. This ensures that the
+		// log level change is always logged, regardless of the current log level.
+		tmpLogger := slog.New(slog.NewTextHandler(os.Stdout, nil))
+		tmpLogger.Info("Gorouter logger -> zapcore log level updated.", slog.String("new-level", z.LogLevel().String()))
+	}
+}
+
 func main() {
 	flag.StringVar(&configFile, "c", "", "Configuration File")
 	flag.Parse()
 
 	prefix := "gorouter.stdout"
 	coreLogger := grlog.CreateLogger()
 	grlog.SetLoggingLevel("INFO")
+	coreLogger.Info("gorouter-startup-test-log", slog.String("test", "true"))
 
 	c, err := config.DefaultConfig()
 	if err != nil {
@@ -101,12 +171,31 @@ func main() {
 		runtime.GOMAXPROCS(c.GoMaxProcs)
 	}
 
+	// start the debugserver
 	if c.DebugAddr != "" {
-		reconfigurableSink := lager.ReconfigurableSink{}
-		_, err = debugserver.Run(c.DebugAddr, &reconfigurableSink)
+		logLevel, logErr := lager.LogLevelFromString(c.Logging.Level)
+		if logErr != nil {
+			logger.Error("invalid-log-level", grlog.ErrAttr(logErr))
+		}
+
+		// create a zapLevelSink that uses the logger
+		sink := &zapLevelSink{logger: logger}
+
+		// create a reconfigurable sink that can change log levels at runtime
+		reconfigurableSink := lager.NewReconfigurableSink(sink, logLevel)
+
+		// start the debugserver with the reconfigurable sink
+		_, err = debugserver.Run(c.DebugAddr, sink)
 		if err != nil {
 			logger.Error("failed-to-start-debug-server", grlog.ErrAttr(err))
 		}
+
+		logger.Info("debugserver-started",
+			slog.String("address", c.DebugAddr),
+			slog.String("log_level", c.Logging.Level),
+			slog.String("log_format", c.Logging.Format.Timestamp),
+			slog.String("log_level_from_sink", reconfigurableSink.GetMinLevel().String()),
+		)
 	}
 
 	logger.Info("setting-up-nats-connection")

src/code.cloudfoundry.org/gorouter/integration/main_test.go

@@ -2,6 +2,7 @@ package integration
 
 import (
 	"bufio"
+	"bytes"
 	"crypto/tls"
 	"encoding/json"
 	"errors"
@@ -618,6 +619,78 @@ var _ = Describe("Router Integration", func() {
 		Consistently(contentsFunc).ShouldNot(ContainSubstring("Component Router registered successfully"))
 	})
 
+	Context("It starts up a debugserver", func() {
+		var (
+			testState    *testState
+			contentsFunc func() string = func() string {
+				return string(gorouterSession.Out.Contents())
+			}
+		)
+
+		BeforeEach(func() {
+
+			testState = NewTestState()
+			testState.cfg.DebugAddr = "127.0.0.1:17017"
+			gorouterSession = testState.StartGorouter()
+		})
+
+		It("can change the debugserver's logging level", func() {
+
+			Consistently(contentsFunc).ShouldNot(ContainSubstring(`{log_level":0,"timestamp"`))
+
+			request, err := http.NewRequest("POST", fmt.Sprintf("http://%s/log-level", testState.cfg.DebugAddr), bytes.NewBufferString("debug"))
+			Expect(err).NotTo(HaveOccurred())
+
+			response, err := http.DefaultClient.Do(request)
+			Expect(err).NotTo(HaveOccurred())
+
+			Expect(response.StatusCode).To(Equal(http.StatusOK))
+			response.Body.Close()
+
+			Consistently(contentsFunc).Should(ContainSubstring(`{"log_level":0,"timestamp"`))
+
+			// And back to info level
+			gorouterSession.Out.Clear()
+			request, err = http.NewRequest("POST", fmt.Sprintf("http://%s/log-level", testState.cfg.DebugAddr), bytes.NewBufferString("info"))
+			Expect(err).NotTo(HaveOccurred())
+
+			response, err = http.DefaultClient.Do(request)
+			Expect(err).NotTo(HaveOccurred())
+
+			Expect(response.StatusCode).To(Equal(http.StatusOK))
+			response.Body.Close()
+
+			//Terminate everything just to generate some info logs
+			testState.StopAndCleanup()
+
+			Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":0,"timestamp"`))
+			Eventually(contentsFunc).Should(ContainSubstring(`{"log_level":1,"timestamp"`))
+
+		})
+
+		It("Does not accept invalid debug levels", func() {
+
+			Consistently(contentsFunc).ShouldNot(ContainSubstring(`{log_level":0,"timestamp"`))
+
+			gorouterSession.Out.Clear()
+
+			request, err := http.NewRequest("POST", fmt.Sprintf("http://%s/log-level", testState.cfg.DebugAddr), bytes.NewBufferString("meow"))
+			Expect(err).NotTo(HaveOccurred())
+
+			response, err := http.DefaultClient.Do(request)
+			Expect(err).NotTo(HaveOccurred())
+
+			Expect(response.StatusCode).ToNot(Equal(http.StatusOK))
+			response.Body.Close()
+
+			Expect(gorouterSession.ExitCode()).To(Equal(-1))
+
+			Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":0,"timestamp"`))
+			Eventually(contentsFunc).Should(ContainSubstring(`{"log_level":1,"timestamp"`))
+		})
+
+	})
+
 	Describe("loggregator metrics emitted", func() {
 		var (
 			fakeMetron test_util.FakeMetron

src/code.cloudfoundry.org/gorouter/logger/logger.go

@@ -98,6 +98,14 @@ func SetLoggingLevel(level string) {
 	conf.level.SetLevel(zapLevel)
 }
 
+/*
+GetLoggingLevel returns the current logging level.
+*/
+func GetLoggingLevel() string {
+	return conf.level.String()
+}
+
+// Logger is an interface that can be used to mock the logger in tests.
 type Logger interface {
 }