Stabilize API test log capture

This commit is contained in:
rcourtman
2026-08-31 19:47:01 +01:00
parent 8eccd24bff
commit 0c76b5d756
6 changed files with 85 additions and 65 deletions
+4 -34
View File
@@ -1,48 +1,20 @@
package api
import (
"bytes"
"encoding/json"
"net/http/httptest"
"strings"
"sync"
"testing"
"time"
"github.com/rs/zerolog"
"github.com/rs/zerolog/log"
)
// lockedLogBuffer keeps log capture safe when another package goroutine logs
// while an auth-denial test owns the process-wide zerolog logger. bytes.Buffer
// is not safe for concurrent writes or for a read racing a write.
type lockedLogBuffer struct {
mu sync.Mutex
buf bytes.Buffer
}
func (b *lockedLogBuffer) Write(p []byte) (int, error) {
b.mu.Lock()
defer b.mu.Unlock()
return b.buf.Write(p)
}
func (b *lockedLogBuffer) String() string {
b.mu.Lock()
defer b.mu.Unlock()
return b.buf.String()
}
// captureAuthDenialLogs swaps the global logger for a buffer at debug level and
// resets the denial tracker, so each case starts from a known window.
// captureAuthDenialLogs resets the denial tracker and captures logs through the
// process-wide synchronized test sink, so each case starts from a known window.
func captureAuthDenialLogs(t *testing.T) *lockedLogBuffer {
t.Helper()
var buf lockedLogBuffer
prevLogger := log.Logger
prevLevel := zerolog.GlobalLevel()
log.Logger = zerolog.New(&buf).Level(zerolog.DebugLevel)
zerolog.SetGlobalLevel(zerolog.DebugLevel)
buf := captureTestLogs(t)
authDenialMu.Lock()
authDenials = make(map[string]*authDenialCounter)
@@ -50,15 +22,13 @@ func captureAuthDenialLogs(t *testing.T) *lockedLogBuffer {
prevNow := authDenialNow
t.Cleanup(func() {
log.Logger = prevLogger
zerolog.SetGlobalLevel(prevLevel)
authDenialNow = prevNow
authDenialMu.Lock()
authDenials = make(map[string]*authDenialCounter)
authDenialMu.Unlock()
})
return &buf
return buf
}
func countLogEvents(t *testing.T, buf *lockedLogBuffer, level, message string) int {
+1 -8
View File
@@ -66,7 +66,6 @@ import (
"github.com/rcourtman/pulse-go-rewrite/pkg/proxmox"
"github.com/rcourtman/pulse-go-rewrite/pkg/reporting"
"github.com/rs/zerolog"
"github.com/rs/zerolog/log"
tmock "github.com/stretchr/testify/mock"
)
@@ -24487,19 +24486,13 @@ func TestContract_AuthorizationRefusalKeepsStatusWhileLoggingAtDebug(t *testing.
// Capture only the request phase — router construction emits unrelated
// startup warnings that have nothing to do with authorization.
var logBuf bytes.Buffer
prevLogger := log.Logger
prevLevel := zerolog.GlobalLevel()
log.Logger = zerolog.New(&logBuf).Level(zerolog.DebugLevel)
zerolog.SetGlobalLevel(zerolog.DebugLevel)
logBuf := captureTestLogs(t)
authDenialMu.Lock()
authDenials = make(map[string]*authDenialCounter)
authDenialMu.Unlock()
t.Cleanup(func() {
log.Logger = prevLogger
zerolog.SetGlobalLevel(prevLevel)
authDenialMu.Lock()
authDenials = make(map[string]*authDenialCounter)
authDenialMu.Unlock()
+2 -1
View File
@@ -19,7 +19,8 @@ func TestMain(m *testing.M) {
_ = os.Setenv("PULSE_UPDATE_SERVER", "http://127.0.0.1:1")
_ = os.Setenv("PULSE_DATA_DIR", dataDir)
allowLoopbackSSOFetch = true
log.Logger = zerolog.Nop()
log.Logger = zerolog.New(testLogSink).Level(zerolog.DebugLevel)
zerolog.SetGlobalLevel(zerolog.DebugLevel)
code := m.Run()
_ = os.RemoveAll(dataDir)
os.Exit(code)
+2 -7
View File
@@ -16,17 +16,12 @@ import (
"github.com/rcourtman/pulse-go-rewrite/internal/monitoring"
"github.com/rcourtman/pulse-go-rewrite/internal/unifiedresources"
"github.com/rcourtman/pulse-go-rewrite/pkg/metrics"
"github.com/rs/zerolog"
"github.com/rs/zerolog/log"
)
// suppressBenchLogs disables zerolog for the duration of a benchmark to prevent
// log I/O from skewing results.
// TestMain installs a discard-by-default sink, so benchmarks avoid log I/O
// without mutating zerolog's process-global logger.
func suppressBenchLogs(b *testing.B) {
b.Helper()
orig := log.Logger
log.Logger = zerolog.Nop()
b.Cleanup(func() { log.Logger = orig })
}
// setBenchUnexportedField sets an unexported field on a struct via reflection.
@@ -8,8 +8,6 @@ import (
"github.com/rcourtman/pulse-go-rewrite/internal/config"
"github.com/rcourtman/pulse-go-rewrite/internal/monitoring"
"github.com/rs/zerolog"
"github.com/rs/zerolog/log"
)
// TestReloadSystemSettings_AppliesWebhookCIDRsToNewMonitor verifies the fix
@@ -99,22 +97,11 @@ func TestReloadSystemSettings_AppliesWebhookCIDRsToNewMonitor(t *testing.T) {
}
}
// captureRouterSettingsLogs swaps the global logger for a locked buffer so
// captureRouterSettingsLogs uses the synchronized process-wide test sink so
// tests can assert on warnings emitted by system-settings load failures.
func captureRouterSettingsLogs(t *testing.T) *lockedLogBuffer {
t.Helper()
var buf lockedLogBuffer
prevLogger := log.Logger
prevLevel := zerolog.GlobalLevel()
log.Logger = zerolog.New(&buf).Level(zerolog.DebugLevel)
zerolog.SetGlobalLevel(zerolog.DebugLevel)
t.Cleanup(func() {
log.Logger = prevLogger
zerolog.SetGlobalLevel(prevLevel)
})
return &buf
return captureTestLogs(t)
}
// unreadableSystemSettings returns a ConfigPersistence whose LoadSystemSettings
+74
View File
@@ -0,0 +1,74 @@
package api
import (
"bytes"
"sync"
"testing"
)
// lockedLogBuffer permits assertions while unrelated package goroutines are
// still emitting log records.
type lockedLogBuffer struct {
mu sync.Mutex
buf bytes.Buffer
}
func (b *lockedLogBuffer) Write(p []byte) (int, error) {
b.mu.Lock()
defer b.mu.Unlock()
return b.buf.Write(p)
}
func (b *lockedLogBuffer) String() string {
b.mu.Lock()
defer b.mu.Unlock()
return b.buf.String()
}
// synchronizedTestLogSink remains installed for the lifetime of the test
// process. Tests change only its protected destination, never zerolog's
// process-global logger, so background monitor goroutines can log safely.
type synchronizedTestLogSink struct {
mu sync.Mutex
target *lockedLogBuffer
}
func (s *synchronizedTestLogSink) Write(p []byte) (int, error) {
s.mu.Lock()
defer s.mu.Unlock()
if s.target == nil {
return len(p), nil
}
return s.target.Write(p)
}
var (
testLogSink = &synchronizedTestLogSink{}
testLogCaptureGate = func() chan struct{} {
gate := make(chan struct{}, 1)
gate <- struct{}{}
return gate
}()
)
// captureTestLogs serializes the small number of tests that need exact log
// assertions, while all other test logging continues through the stable sink.
func captureTestLogs(t testing.TB) *lockedLogBuffer {
t.Helper()
<-testLogCaptureGate
buf := &lockedLogBuffer{}
testLogSink.mu.Lock()
testLogSink.target = buf
testLogSink.mu.Unlock()
t.Cleanup(func() {
testLogSink.mu.Lock()
if testLogSink.target == buf {
testLogSink.target = nil
}
testLogSink.mu.Unlock()
testLogCaptureGate <- struct{}{}
})
return buf
}