From b410d629ee8479fafb99f140c722b9b29fd6c909 Mon Sep 17 00:00:00 2001 From: Jeff Widman Date: Mon, 17 Aug 2026 20:32:06 +0000 Subject: [PATCH] Restore global logger state in tests --- internal/handlers/nuget_feed_test.go | 8 ++-- internal/handlers/oidc_handling_test.go | 4 +- internal/logging/logging_test.go | 7 ++-- internal/oidc/oidc_registry_test.go | 6 +-- internal/testhelpers/logging.go | 49 +++++++++++++++++++++++++ internal/testhelpers/logging_test.go | 40 ++++++++++++++++++++ logging_test.go | 5 ++- proxy_test.go | 10 +---- 8 files changed, 107 insertions(+), 22 deletions(-) create mode 100644 internal/testhelpers/logging.go create mode 100644 internal/testhelpers/logging_test.go diff --git a/internal/handlers/nuget_feed_test.go b/internal/handlers/nuget_feed_test.go index 6d5a979..8417b58 100644 --- a/internal/handlers/nuget_feed_test.go +++ b/internal/handlers/nuget_feed_test.go @@ -5,7 +5,6 @@ import ( "encoding/json" "fmt" "io" - "log" "net/http" "net/http/httptest" "net/url" @@ -19,6 +18,7 @@ import ( "github.com/stretchr/testify/require" "github.com/dependabot/proxy/internal/config" + "github.com/dependabot/proxy/internal/testhelpers" ) func TestNugetFeedHandler(t *testing.T) { @@ -113,7 +113,7 @@ func TestNugetFeedHandler(t *testing.T) { } var buf bytes.Buffer - log.SetOutput(&buf) + testhelpers.CaptureStandardLog(t, &buf) handler := NewNugetFeedHandler(credentials) discoverNugetFeed(t, handler, "https://corp.dependabot.com/nuget/", http.StatusOK, mustMarshalJSON(t, rsp)) @@ -313,7 +313,7 @@ func TestExtraAuthenticatedURLsAreReportedInTheLog(t *testing.T) { }` var buf bytes.Buffer - log.SetOutput(&buf) + testhelpers.CaptureStandardLog(t, &buf) handler := NewNugetFeedHandler(credentials) discoverNugetFeed(t, handler, "https://nuget.example.com/index.json", http.StatusOK, jsonResponse) logContents := buf.String() @@ -555,7 +555,7 @@ func TestNugetFeedHandlerIgnoresUnusableStaticCredentials(t *testing.T) { func TestNugetFeedHandlerLogsIgnoredDuplicateResourceURL(t *testing.T) { var buf bytes.Buffer - log.SetOutput(&buf) + testhelpers.CaptureStandardLog(t, &buf) handler := NewNugetFeedHandler(config.Credentials{ testNugetFeedCredential("https://first.example.com/index.json", "first-token"), testNugetFeedCredential("https://second.example.com/index.json", "second-token"), diff --git a/internal/handlers/oidc_handling_test.go b/internal/handlers/oidc_handling_test.go index 2f5b065..92d2df4 100644 --- a/internal/handlers/oidc_handling_test.go +++ b/internal/handlers/oidc_handling_test.go @@ -4,7 +4,6 @@ import ( "bytes" "fmt" "io" - "log" "net/http" "net/http/httptest" "strings" @@ -16,6 +15,7 @@ import ( "github.com/stretchr/testify/require" "github.com/dependabot/proxy/internal/config" + "github.com/dependabot/proxy/internal/testhelpers" ) type oidcHandler interface { @@ -1557,7 +1557,7 @@ func TestOIDCURLsAreAuthenticated(t *testing.T) { // create handler and capture log output var buf bytes.Buffer - log.SetOutput(&buf) + testhelpers.CaptureStandardLog(t, &buf) handler := tc.handlerFactory(tc.credentials) if tc.serviceIndexURL != "" { nugetHandler, ok := handler.(*NugetFeedHandler) diff --git a/internal/logging/logging_test.go b/internal/logging/logging_test.go index f4ef5dd..37eb179 100644 --- a/internal/logging/logging_test.go +++ b/internal/logging/logging_test.go @@ -3,12 +3,13 @@ package logging import ( "bytes" "fmt" - "log" "strings" "testing" "github.com/elazarl/goproxy" "github.com/stretchr/testify/assert" + + "github.com/dependabot/proxy/internal/testhelpers" ) func TestRequestLogf(t *testing.T) { @@ -60,7 +61,7 @@ func TestRequestLogf(t *testing.T) { for name, tc := range testCases { t.Run(name, func(t *testing.T) { var buf bytes.Buffer - log.SetOutput(&buf) + testhelpers.CaptureStandardLog(t, &buf) RequestLogf(proxyCtx, tc.format, tc.argv...) @@ -119,7 +120,7 @@ func TestRequestMultilineLogf(t *testing.T) { for name, tc := range testCases { t.Run(name, func(t *testing.T) { var buf bytes.Buffer - log.SetOutput(&buf) + testhelpers.CaptureStandardLog(t, &buf) RequestMultilineLogf(proxyCtx, tc.format, tc.argv...) diff --git a/internal/oidc/oidc_registry_test.go b/internal/oidc/oidc_registry_test.go index 6bad744..defbd5c 100644 --- a/internal/oidc/oidc_registry_test.go +++ b/internal/oidc/oidc_registry_test.go @@ -2,9 +2,7 @@ package oidc import ( "bytes" - "log" "net/http/httptest" - "os" "strconv" "strings" "sync" @@ -15,6 +13,7 @@ import ( "github.com/stretchr/testify/require" "github.com/dependabot/proxy/internal/config" + "github.com/dependabot/proxy/internal/testhelpers" ) func setupOIDCEnv(t *testing.T) { @@ -570,8 +569,7 @@ func TestOIDCRegistry_Register_NoDuplicateEntries(t *testing.T) { cred2 := azureCredWithURL("tenant-2", "client-2", "https://registry.example.com/packages") var logBuf bytes.Buffer - log.SetOutput(&logBuf) - defer log.SetOutput(os.Stderr) + testhelpers.CaptureStandardLog(t, &logBuf) oidcCred1, key1, ok1 := r.Register(cred1, []string{"url"}, "test registry") oidcCred2, key2, ok2 := r.Register(cred2, []string{"url"}, "test registry") diff --git a/internal/testhelpers/logging.go b/internal/testhelpers/logging.go new file mode 100644 index 0000000..a9f6d01 --- /dev/null +++ b/internal/testhelpers/logging.go @@ -0,0 +1,49 @@ +package testhelpers + +import ( + "io" + "log" + "testing" + + "github.com/sirupsen/logrus" +) + +// PreserveGlobalLoggerState restores the process-wide standard and Logrus +// logger configuration after the test completes. +func PreserveGlobalLoggerState(t testing.TB) { + t.Helper() + + standardOutput := log.Writer() + standardFlags := log.Flags() + standardPrefix := log.Prefix() + logrusLogger := logrus.StandardLogger() + logrusOutput := logrusLogger.Out + logrusFormatter := logrusLogger.Formatter + logrusLevel := logrusLogger.GetLevel() + logrusReportCaller := logrusLogger.ReportCaller + + t.Cleanup(func() { + log.SetOutput(standardOutput) + log.SetFlags(standardFlags) + log.SetPrefix(standardPrefix) + logrus.SetOutput(logrusOutput) + logrus.SetFormatter(logrusFormatter) + logrus.SetLevel(logrusLevel) + logrus.SetReportCaller(logrusReportCaller) + }) +} + +// CaptureStandardLog redirects the standard logger for the duration of a test. +func CaptureStandardLog(t testing.TB, output io.Writer) { + t.Helper() + PreserveGlobalLoggerState(t) + log.SetOutput(output) +} + +// CaptureGlobalLogs redirects the standard and Logrus loggers for a test. +func CaptureGlobalLogs(t testing.TB, output io.Writer) { + t.Helper() + PreserveGlobalLoggerState(t) + log.SetOutput(output) + logrus.SetOutput(output) +} diff --git a/internal/testhelpers/logging_test.go b/internal/testhelpers/logging_test.go new file mode 100644 index 0000000..a1619cc --- /dev/null +++ b/internal/testhelpers/logging_test.go @@ -0,0 +1,40 @@ +package testhelpers + +import ( + "io" + "log" + "testing" + + "github.com/sirupsen/logrus" + "github.com/stretchr/testify/assert" +) + +func TestPreserveGlobalLoggerState(t *testing.T) { + standardOutput := log.Writer() + standardFlags := log.Flags() + standardPrefix := log.Prefix() + logrusLogger := logrus.StandardLogger() + logrusOutput := logrusLogger.Out + logrusFormatter := logrusLogger.Formatter + logrusLevel := logrusLogger.GetLevel() + logrusReportCaller := logrusLogger.ReportCaller + + t.Run("mutate logger state", func(t *testing.T) { + PreserveGlobalLoggerState(t) + log.SetOutput(io.Discard) + log.SetFlags(0) + log.SetPrefix("test-prefix") + logrus.SetOutput(io.Discard) + logrus.SetFormatter(&logrus.JSONFormatter{}) + logrus.SetLevel(logrus.DebugLevel) + logrus.SetReportCaller(!logrusReportCaller) + }) + + assert.Equal(t, standardOutput, log.Writer()) + assert.Equal(t, standardFlags, log.Flags()) + assert.Equal(t, standardPrefix, log.Prefix()) + assert.Equal(t, logrusOutput, logrusLogger.Out) + assert.Equal(t, logrusFormatter, logrusLogger.Formatter) + assert.Equal(t, logrusLevel, logrusLogger.GetLevel()) + assert.Equal(t, logrusReportCaller, logrusLogger.ReportCaller) +} diff --git a/logging_test.go b/logging_test.go index be64ec8..3dc4993 100644 --- a/logging_test.go +++ b/logging_test.go @@ -20,6 +20,8 @@ import ( "github.com/sirupsen/logrus" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" + + "github.com/dependabot/proxy/internal/testhelpers" ) var timestamp = regexp.MustCompile(`\d{4}/\d{2}/{2} \d{2}:\d{2}:\d{2} `) @@ -155,7 +157,7 @@ func TestRequestLogger(t *testing.T) { } var buf bytes.Buffer - log.SetOutput(&buf) + testhelpers.CaptureStandardLog(t, &buf) l := NewRequestLogger() if tc.setup != nil { tc.setup(t, l) @@ -191,6 +193,7 @@ func TestRequestLogger(t *testing.T) { } func TestSetupLogging(t *testing.T) { + testhelpers.PreserveGlobalLoggerState(t) temp := t.TempDir() logFile := path.Join(temp, "test.log") logfilePath = &logFile diff --git a/proxy_test.go b/proxy_test.go index 50cda1e..4ad73bd 100644 --- a/proxy_test.go +++ b/proxy_test.go @@ -10,7 +10,6 @@ import ( "crypto/x509/pkix" "encoding/pem" "io" - "log" "math/big" "net" "net/http" @@ -20,11 +19,11 @@ import ( "testing" "time" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "github.com/dependabot/proxy/internal/config" + "github.com/dependabot/proxy/internal/testhelpers" ) var ( @@ -306,12 +305,7 @@ func TestProxyHTTPSConditionalNotModifiedPreservesCachedResponse(t *testing.T) { // identical request can still succeed. func TestProxyUpstreamCloseIsNotCachedAsBodylessResponse(t *testing.T) { var logOutput bytes.Buffer - originalLogOutput := log.Writer() - originalLogrusOutput := logrus.StandardLogger().Out - log.SetOutput(&logOutput) - logrus.SetOutput(&logOutput) - defer log.SetOutput(originalLogOutput) - defer logrus.SetOutput(originalLogrusOutput) + testhelpers.CaptureGlobalLogs(t, &logOutput) var upstreamRequests atomic.Int32 upstream := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {