diff --git a/packages/gorouter/spec b/packages/gorouter/spec index 0fe0f2da2..16c2dde03 100644 --- a/packages/gorouter/spec +++ b/packages/gorouter/spec @@ -35,6 +35,7 @@ files: - code.cloudfoundry.org/gorouter/handlers/*.go # gosub - code.cloudfoundry.org/gorouter/integration/*.go # gosub - code.cloudfoundry.org/gorouter/logger/*.go # gosub + - code.cloudfoundry.org/gorouter/logadapter/*.go # gosub - code.cloudfoundry.org/gorouter/mbus/*.go # gosub - code.cloudfoundry.org/gorouter/mbus/fakes/*.go # gosub - code.cloudfoundry.org/gorouter/metrics/*.go # gosub diff --git a/src/code.cloudfoundry.org/gorouter/cmd/gorouter/main.go b/src/code.cloudfoundry.org/gorouter/cmd/gorouter/main.go index 84b6ae354..534dd2bce 100644 --- a/src/code.cloudfoundry.org/gorouter/cmd/gorouter/main.go +++ b/src/code.cloudfoundry.org/gorouter/cmd/gorouter/main.go @@ -11,11 +11,11 @@ import ( "syscall" "time" + "code.cloudfoundry.org/gorouter/logadapter" "code.cloudfoundry.org/gorouter/metrics_prometheus" "code.cloudfoundry.org/clock" "code.cloudfoundry.org/debugserver" - "code.cloudfoundry.org/lager/v3" "code.cloudfoundry.org/tlsconfig" "github.com/cloudfoundry/dropsonde" "github.com/cloudfoundry/dropsonde/metric_sender" @@ -102,11 +102,16 @@ func main() { } if c.DebugAddr != "" { - reconfigurableSink := lager.ReconfigurableSink{} - _, err = debugserver.Run(c.DebugAddr, &reconfigurableSink) + sink := logadapter.NewZapLevelSink(logger) + _, 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), + ) } logger.Info("setting-up-nats-connection") diff --git a/src/code.cloudfoundry.org/gorouter/integration/main_test.go b/src/code.cloudfoundry.org/gorouter/integration/main_test.go index 319334d44..cdc0c79ea 100644 --- a/src/code.cloudfoundry.org/gorouter/integration/main_test.go +++ b/src/code.cloudfoundry.org/gorouter/integration/main_test.go @@ -2,7 +2,9 @@ package integration import ( "bufio" + "bytes" "crypto/tls" + "crypto/x509" "encoding/json" "errors" "fmt" @@ -41,6 +43,10 @@ import ( var _ = Describe("Router Integration", func() { + const ( + appHostname = "myapp-with-route-service.some.domain" + ) + var ( cfg *config.Config cfgFile string @@ -49,6 +55,8 @@ var _ = Describe("Router Integration", func() { natsRunner *test_util.NATSRunner gorouterSession *Session oauthServerURL string + testState *testState + testApp, routeService *httptest.Server ) BeforeEach(func() { @@ -618,6 +626,345 @@ var _ = Describe("Router Integration", func() { Consistently(contentsFunc).ShouldNot(ContainSubstring("Component Router registered successfully")) }) + Context("It starts up a debugserver", func() { + var ( + contentsFunc func() string = func() string { + return string(gorouterSession.Out.Contents()) + } + ) + + BeforeEach(func() { + testState = NewTestState() + testState.cfg.DebugAddr = "127.0.0.1:17017" + testState.StartGorouterOrFail() + gorouterSession = testState.gorouterSession + + // A test app is started that the gorouter can route to. + testApp = httptest.NewServer(http.HandlerFunc( + func(w http.ResponseWriter, r *http.Request) { + w.Header().Add("X-App-Instance", "app1") + w.WriteHeader(200) + _, err := w.Write([]byte("I'm the app")) + Expect(err).ToNot(HaveOccurred()) + })) + + // A test route service that the gorouter can route to. + // It will forward the request to the test app and return the response. + routeService = httptest.NewUnstartedServer( + http.HandlerFunc( + func(w http.ResponseWriter, r *http.Request) { + defer GinkgoRecover() + + forwardedURL := r.Header.Get("X-CF-Forwarded-Url") + sigHeader := r.Header.Get("X-Cf-Proxy-Signature") + metadata := r.Header.Get("X-Cf-Proxy-Metadata") + + req := testState.newGetRequest(forwardedURL) + + req.Header.Add("X-CF-Forwarded-Url", forwardedURL) + req.Header.Add("X-Cf-Proxy-Metadata", metadata) + req.Header.Add("X-Cf-Proxy-Signature", sigHeader) + + res, err := testState.routeServiceClient.Do(req) + Expect(err).ToNot(HaveOccurred()) + defer res.Body.Close() + })) + + // Start the route service. The routes check at the endpoint + // http://:@127.0.0.1:<>/routes would show something like below. + // {"internal-route-service-43749.localhost.routing.cf-app.com":[{ "address":"127.0.0.1:43749","availability_zone":"","protocol":"http1","tls":false,"ttl":10,"tags":null,"private_instance_id":"4b63c7ba"}]} + routeService.Start() + + testState.registerWithInternalRouteService( + testApp, + routeService, + appHostname, + testState.cfg.SSLPort, + ) + }) + + AfterEach(func() { + if routeService != nil { + routeService.Close() + } + if testApp != nil { + testApp.Close() + } + }) + + 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"`)) + + 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() + + gorouterSession.Out.Clear() + + Expect(gorouterSession.ExitCode()).To(Equal(-1)) + + // Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":0,"timestamp"`)) + // Eventually(contentsFunc).Should(ContainSubstring(`{"log_level":1,"timestamp"`)) + }) + + It("Accepts info as a valid log level", func() { + + 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() + + // clear the gorouter session output to avoid confusion with previous logs + gorouterSession.Out.Clear() + + // Stop the gorouter and it will generate some logs like below. + // {"log_level":1,"timestamp":1751405405.2474551,"message":"nats-connection-disconnected","source":"gorouter.stdout.nats","data":{"host":"localhost:25043","addr":"[::1]:25043"}} + // {"log_level":1,"timestamp":1751405405.346799,"message":"gorouter.stopping","source":"gorouter.stdout.router"} + testState.StopAndCleanup() + + // We don't expect the gorouter to exit, so we check the exit code + // is still -1 (indicating it is still running) + Expect(gorouterSession.ExitCode()).To(Equal(0)) + + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":0,"timestamp"`)) + Eventually(contentsFunc).Should(ContainSubstring(`{"log_level":1,"timestamp"`)) + }) + + It("Accepts warn as a valid log level", func() { + + // Clear the gorouter session output to avoid confusion with previous logs + gorouterSession.Out.Clear() + + request, err := http.NewRequest("POST", fmt.Sprintf("http://%s/log-level", testState.cfg.DebugAddr), bytes.NewBufferString("warn")) + Expect(err).NotTo(HaveOccurred()) + + response, err := http.DefaultClient.Do(request) + Expect(err).NotTo(HaveOccurred()) + + Expect(response.StatusCode).To(Equal(http.StatusOK)) + response.Body.Close() + + // Get an invalid certificate chain and rule to trigger a warning log + chain, rule, err := test_util.CreateInvalidCertAndRule("potato.com", []string{"spinach.com"}) + Expect(err).ToNot(HaveOccurred()) + + // Override the CA Subject to match the chain's issuer + // rule.CASubject = config.NewCertSubjectFromName(chain[0].Issuer) + rule.CASubject = config.CertSubject{ + CommonName: chain[0].Issuer.CommonName, + Organization: chain[0].Issuer.Organization, + } + + // Calling VerifyClientCertMetadata with the client certificate metadata rule should result in + // a warning log since the chain does not match the rule. The rule is set to require a common + // name of "spinach.com" but the chain's issuer common name is "potato.com". + testLogger := test_util.NewTestLogger("test") + err = config.VerifyClientCertMetadata([]config.VerifyClientCertificateMetadataRule{rule}, [][]*x509.Certificate{chain}, testLogger.Logger) + + // err = config.CheckClientCertificateMetadataRule(chain, logger, rule) + Expect(err).To(HaveOccurred()) + + // We don't expect the gorouter to exit, so we check the exit code + // is still -1 (indicating it is still running) + Expect(gorouterSession.ExitCode()).To(Equal(-1)) + + // A warning log should be generated like below. + // {"log_level":2,"timestamp":1751436459.3247795,"message":"invalid-subject","source":"test","data":{"issuer":"CN=theCA,O=xyz\\, Inc.","subject":"O=xyz\\, Inc.","allowed":{}}} + testLogs := string(testLogger.TestSink.Buffer.Contents()) + Expect(testLogs).Should(ContainSubstring(`"log_level":2,"timestamp"`)) + }) + + It("Accepts error as a valid log level", func() { + + request, err := http.NewRequest("POST", fmt.Sprintf("http://%s/log-level", testState.cfg.DebugAddr), bytes.NewBufferString("error")) + Expect(err).NotTo(HaveOccurred()) + + response, err := http.DefaultClient.Do(request) + Expect(err).NotTo(HaveOccurred()) + + Expect(response.StatusCode).To(Equal(http.StatusOK)) + response.Body.Close() + + // Stop the app and leave the route in place. This will generate + // some logs at error level since the app is no longer running. + // {"log_level":3,"timestamp":1751405779.235571,"message":"backend-endpoint-failed","source":"gorouter.stdout","data":{"route-endpoint":{"ApplicationId":"","Addr":"127.0.0.1:35913","Tags":null,"RouteServiceUrl":"https://internal-route-service-38401.localhost.routing.cf-app.com:25041","AZ":""},"attempt":1,"vcap_request_id":"a02f408e-ba00-44ea-71dd-a2ee6fd0fb07","num-endpoints":1,"got-connection":false,"wrote-headers":false,"conn-reused":false,"dns-lookup-time":0,"dial-time":0.000156212,"tls-handshake-time":0,"local-address":"","error":"incomplete request (dial tcp 127.0.0.1:35913: connect: connection refused)","retriable":true}} + // {"log_level":3,"timestamp":1751405779.235689,"message":"endpoint-marked-as-ineligible","source":"gorouter.stdout.registry","data":{"route-endpoint":{"ApplicationId":"","Addr":"127.0.0.1:35913","Tags":null,"RouteServiceUrl":"https://internal-route-service-38401.localhost.routing.cf-app.com:25041","AZ":""}}} + gorouterSession.Out.Clear() + testApp.Close() + + // Sending a request to the app hostname will generate logs + // at error level since the app is no longer running. + req := testState.newGetRequest(fmt.Sprintf("https://%s", appHostname)) + _, err = testState.client.Do(req) + Expect(err).To(BeNil()) + + // We don't expect the gorouter to exit, so we check the exit code + // is still -1 (indicating it is still running) + Expect(gorouterSession.ExitCode()).To(Equal(-1)) + + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":0,"timestamp"`)) + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":1,"timestamp"`)) + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":2,"timestamp"`)) + Eventually(contentsFunc).Should(ContainSubstring(`{"log_level":3,"timestamp"`)) + }) + + It("Accepts fatal as a valid log level", func() { + + gorouterSession.Out.Clear() + + request, err := http.NewRequest("POST", fmt.Sprintf("http://%s/log-level", testState.cfg.DebugAddr), bytes.NewBufferString("fatal")) + Expect(err).NotTo(HaveOccurred()) + + response, err := http.DefaultClient.Do(request) + Expect(err).NotTo(HaveOccurred()) + + Expect(response.StatusCode).To(Equal(http.StatusOK)) + response.Body.Close() + + // Stop the gorouter session and restart it with an invalid config to generate fatal log + testState.StopAndCleanup() + + // Note that Gorouter logger.Fatal() generates a log at Error level (3) like below. + // {"log_level":3,"timestamp":1751476408.1017516,"message":"Error loading config:","data":{"error":"router.client_cert_validation must be one of 'none', 'request' or 'require'."}} + writeConfig(&config.Config{EnableSSL: true}, cfgFile) + gorouterCmd := exec.Command(gorouterPath, "-c", cfgFile) + gorouterSession, _ = Start(gorouterCmd, GinkgoWriter, GinkgoWriter) + Eventually(gorouterSession, 5*time.Second).Should(Exit(1)) + + // Fatal logs are generated at Error level, so we check for log_level 3 + // and the message "Error loading config" in the gorouter session output. + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":1,"timestamp"`)) + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{"log_level":2,"timestamp"`)) + Eventually(contentsFunc).Should(ContainSubstring(`Error loading config`)) + Eventually(contentsFunc).Should(ContainSubstring(`{"log_level":3,"timestamp"`)) + + }) + + It("Does not accept empty log level", 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("{}")) + Expect(err).NotTo(HaveOccurred()) + + response, err := http.DefaultClient.Do(request) + Expect(err).NotTo(HaveOccurred()) + + Expect(response.StatusCode).ToNot(Equal(http.StatusOK)) + response.Body.Close() + + // We don't expect the gorouter to exit, so we check the exit code + // is still -1 (indicating it is still running) + Expect(gorouterSession.ExitCode()).To(Equal(-1)) + }) + + It("Does not accept GET on the log level", func() { + + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{log_level":0,"timestamp"`)) + + gorouterSession.Out.Clear() + + request, err := http.NewRequest("GET", fmt.Sprintf("http://%s/log-level", testState.cfg.DebugAddr), bytes.NewBufferString("fatal")) + Expect(err).NotTo(HaveOccurred()) + + response, err := http.DefaultClient.Do(request) + Expect(err).NotTo(HaveOccurred()) + + Expect(response.StatusCode).ToNot(Equal(http.StatusOK)) + response.Body.Close() + + // We don't expect the gorouter to exit, so we check the exit code + // is still -1 (indicating it is still running) + Expect(gorouterSession.ExitCode()).To(Equal(-1)) + }) + + It("Does not accept PUT on the log level", func() { + + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{log_level":0,"timestamp"`)) + + gorouterSession.Out.Clear() + + request, err := http.NewRequest("PUT", 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).ToNot(Equal(http.StatusOK)) + response.Body.Close() + + // We don't expect the gorouter to exit, so we check the exit code + // is still -1 (indicating it is still running) + Expect(gorouterSession.ExitCode()).To(Equal(-1)) + }) + + It("Does not accept DELETE on the log level", func() { + + Consistently(contentsFunc).ShouldNot(ContainSubstring(`{log_level":0,"timestamp"`)) + + gorouterSession.Out.Clear() + + request, err := http.NewRequest("DELETE", 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).ToNot(Equal(http.StatusOK)) + response.Body.Close() + + // We don't expect the gorouter to exit, so we check the exit code + // is still -1 (indicating it is still running) + Expect(gorouterSession.ExitCode()).To(Equal(-1)) + }) + }) + Describe("loggregator metrics emitted", func() { var ( fakeMetron test_util.FakeMetron @@ -1495,9 +1842,9 @@ func appRegistered(routesUri string, app registeredApp) bool { func routeExists(routesEndpoint, routeName string) (bool, error) { resp, err := http.Get(routesEndpoint) if err != nil { - fmt.Println("Failed to get from routes endpoint") return false, err } + switch resp.StatusCode { case http.StatusOK: bytes, err := io.ReadAll(resp.Body) @@ -1506,10 +1853,8 @@ func routeExists(routesEndpoint, routeName string) (bool, error) { routes := make(map[string]interface{}) err = json.Unmarshal(bytes, &routes) Expect(err).ToNot(HaveOccurred()) - _, found := routes[routeName] return found, nil - default: return false, errors.New("Didn't get an OK response") } diff --git a/src/code.cloudfoundry.org/gorouter/integration/test_utils_test.go b/src/code.cloudfoundry.org/gorouter/integration/test_utils_test.go index 6fd6e7d78..c8d8d0978 100644 --- a/src/code.cloudfoundry.org/gorouter/integration/test_utils_test.go +++ b/src/code.cloudfoundry.org/gorouter/integration/test_utils_test.go @@ -2,7 +2,6 @@ package integration import ( "crypto/tls" - "io" "os" "os/exec" "syscall" @@ -64,17 +63,9 @@ func startGorouterSession(cfgFile string) *Session { gorouterCmd := exec.Command(gorouterPath, "-c", cfgFile) session, err := Start(gorouterCmd, GinkgoWriter, GinkgoWriter) Expect(err).ToNot(HaveOccurred()) - var eventsSessionLogs []byte + Eventually(func() string { - logAdd, err := io.ReadAll(session.Out) - if err != nil { - if session.ExitCode() >= 0 { - Fail("gorouter quit early!") - } - return "" - } - eventsSessionLogs = append(eventsSessionLogs, logAdd...) - return string(eventsSessionLogs) + return string(session.Out.Contents()) }, 70*time.Second).Should(SatisfyAll( ContainSubstring(`starting`), MatchRegexp(`Successfully-connected-to-nats.*localhost:\d+`), diff --git a/src/code.cloudfoundry.org/gorouter/logadapter/logadapter.go b/src/code.cloudfoundry.org/gorouter/logadapter/logadapter.go new file mode 100644 index 000000000..f01d18271 --- /dev/null +++ b/src/code.cloudfoundry.org/gorouter/logadapter/logadapter.go @@ -0,0 +1,103 @@ +package logadapter + +import ( + grlog "code.cloudfoundry.org/gorouter/logger" + "code.cloudfoundry.org/lager/v3" + "go.uber.org/zap" + "go.uber.org/zap/zapcore" + "log/slog" + "os" + "strings" +) + +// 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 NewZapLevelSink(l *slog.Logger) *zapLevelSink { + return &zapLevelSink{logger: l} +} + +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 "warn": + // lager does not have a separate WARN level, it uses INFO for warnings. + return lager.INFO + 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: + zapLevel = zapcore.ErrorLevel + case lager.FATAL: + zapLevel = zapcore.FatalLevel + default: + // There is no lager.WARN level, so mapping it to zapcore.WarnLevel in default case. + zapLevel = zapcore.WarnLevel + } + + 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 := NewZapLoggerWithTimestamp() + tmpLogger.Info("Gorouter logger -> zapcore log level updated.", + zap.String("new log_level", zapLevel.String())) + } +} + +// NewZapLoggerWithTimestamp creates a new zap.Logger with a custom +// timestamp encoder that outputs the timestamp as a float64 representing +// the number of seconds since the Unix epoch. +func NewZapLoggerWithTimestamp() *zap.Logger { + cfg := zap.NewProductionEncoderConfig() + // customized keys for the JSON encoder + cfg.TimeKey = "timestamp" + cfg.LevelKey = "log_level" + cfg.MessageKey = "message" + // time encoded in RFC3339 format + cfg.EncodeTime = zapcore.RFC3339TimeEncoder + // Encode log level as int. zapcore.Level is 0-indexed, + // so add 1 to the level to match the gorouter's expected level. + cfg.EncodeLevel = func(l zapcore.Level, enc zapcore.PrimitiveArrayEncoder) { + enc.AppendInt(int(l + 1)) + } + core := zapcore.NewCore(zapcore.NewJSONEncoder(cfg), zapcore.AddSync(os.Stdout), zap.InfoLevel) + return zap.New(core) +} diff --git a/src/code.cloudfoundry.org/gorouter/logger/logger.go b/src/code.cloudfoundry.org/gorouter/logger/logger.go index 6cee94da1..d41c57144 100644 --- a/src/code.cloudfoundry.org/gorouter/logger/logger.go +++ b/src/code.cloudfoundry.org/gorouter/logger/logger.go @@ -20,9 +20,8 @@ var ( mutex sync.Mutex ) -/* -dynamicLoggingConfig holds dynamic configuration for the time encoding and logging level. -*/ +// dynamicLoggingConfig holds dynamic configuration for the time encoding and logging level. + type dynamicLoggingConfig struct { encoding string level zap.AtomicLevel @@ -98,6 +97,12 @@ 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 { } @@ -135,9 +140,7 @@ func initializeLogger() *slog.Logger { return slogFrontend } -/* -ErrAttr is creating an slog.String attribute with 'error' key and the provided error message as value. -*/ +// ErrAttr is creating an slog.String attribute with 'error' key and the provided error message as value. func ErrAttr(err error) slog.Attr { return slog.String("error", err.Error()) } @@ -150,9 +153,7 @@ func StructValue(obj any) StructWithLogValue { return StructWithLogValue{Value: obj} } -/* -StructWithLogValue implements LogValue(), which allows lazy execution. -*/ +// StructWithLogValue implements LogValue(), which allows lazy execution. type StructWithLogValue struct { Value any } @@ -211,9 +212,7 @@ func CreateLoggerWithSource(prefix string, component string) *slog.Logger { return baseLogger.With(slog.String("source", appendix)).WithGroup("data") } -/* -CreateLogger returns a copy of the logger. All subsequent log statements will be nested in the 'data' field. -*/ +// CreateLogger returns a copy of the logger. All subsequent log statements will be nested in the 'data' field. func CreateLogger() *slog.Logger { if baseLogger == nil { panic("logger is not initialized") diff --git a/src/code.cloudfoundry.org/gorouter/test_util/helpers.go b/src/code.cloudfoundry.org/gorouter/test_util/helpers.go index c0fb510d6..c98e341b8 100644 --- a/src/code.cloudfoundry.org/gorouter/test_util/helpers.go +++ b/src/code.cloudfoundry.org/gorouter/test_util/helpers.go @@ -691,3 +691,50 @@ func CreateCertAndAddCA(cn CertNames, cp *x509.CertPool) CertChain { cp.AddCert(certChain.CACert) return certChain } + +// CreateInvalidCertAndRule creates a certificate chain with a leaf and CA certificate, +// where the leaf certificate has a common name (CN) and the CA certificate is used to +// sign the leaf. The rule is built with mismatched valid subjects that do not match the +// leaf certificate's common name. +func CreateInvalidCertAndRule(cn string, invalidSubjects []string) ([]*x509.Certificate, config.VerifyClientCertificateMetadataRule, error) { + // Create signed cert + root CA + certChain := CreateSignedCertWithRootCA(CertNames{ + CommonName: cn, + }) + + // Parse the leaf certificate from PEM + block, _ := pem.Decode(certChain.CertPEM) + if block == nil { + return nil, config.VerifyClientCertificateMetadataRule{}, fmt.Errorf("failed to decode cert PEM") + } + x509Leaf, err := x509.ParseCertificate(block.Bytes) + if err != nil { + return nil, config.VerifyClientCertificateMetadataRule{}, fmt.Errorf("failed to parse leaf cert: %w", err) + } + x509Leaf.IsCA = false + + // Parse the CA certificate from PEM + block, _ = pem.Decode(certChain.CACertPEM) + if block == nil { + return nil, config.VerifyClientCertificateMetadataRule{}, fmt.Errorf("failed to decode CA cert PEM") + } + x509CA, err := x509.ParseCertificate(block.Bytes) + if err != nil { + return nil, config.VerifyClientCertificateMetadataRule{}, fmt.Errorf("failed to parse CA cert: %w", err) + } + + // Build rule with mismatched valid subjects + validSubjects := make([]config.CertSubject, len(invalidSubjects)) + for i, subj := range invalidSubjects { + validSubjects[i] = config.CertSubject{CommonName: subj} + } + + // Use actual CA subject to make the rule apply + rule := config.VerifyClientCertificateMetadataRule{ + CASubject: config.CertSubject{CommonName: x509CA.Subject.CommonName}, + ValidSubjects: validSubjects, + } + + // Return leaf + CA in chain + return []*x509.Certificate{x509Leaf, x509CA}, rule, nil +}