Skip to content

[FIXED] SetLoggerV2 deadlocks when prev logger errors on close - #8430

Open
palkan wants to merge 1 commit into
nats-io:mainfrom
palkan:fix/set-logger-deadlock
Open

[FIXED] SetLoggerV2 deadlocks when prev logger errors on close#8430
palkan wants to merge 1 commit into
nats-io:mainfrom
palkan:fix/set-logger-deadlock

Conversation

@palkan

@palkan palkan commented Jul 29, 2026

Copy link
Copy Markdown

Calling s.Errorf(...) within s.logging.Lock(); ...; s.logging.Unlock() would result in a deadlock, 'cause s.Errorf() tries to acquire the same mutex (s.logging).

Reproduction:

// failingCloseLogger implements both server.Logger and io.Closer.
type failingCloseLogger struct{}

func (l *failingCloseLogger) Noticef(format string, v ...any) {}
// ... other server.Logger functions
func (l *failingCloseLogger) Close() error {
	return errors.New("simulated close error")
}

func main() {
	opts := &server.Options{
		Host:   "127.0.0.1",
		Port:   -1,
		NoLog:  true,
		NoSigs: true,
	}

	s, err := server.NewServer(opts)
	if err != nil {
		os.Exit(1)
	}

	s.SetLogger(&failingCloseLogger{}, false, false)
	fmt.Println("First logger installed.")

	done := make(chan struct{})
	go func() {
		s.SetLogger(&failingCloseLogger{}, false, false)
		close(done)
	}()

	select {
	case <-done:
		fmt.Println("Second logger installed.")
	case <-time.After(3 * time.Second):
		buf := make([]byte, 64<<10)
		numBytes := runtime.Stack(buf, true)
		fmt.Println(string(buf[:numBytes]))
		panic("deadlocked")
	}
}

Results in:

$ go run main.go

First logger installed.
goroutine 1 [running]:
main.main()
	eadlock-repro/main.go:54 +0x200

goroutine 5 [sync.RWMutex.RLock]:
sync.runtime_SemacquireRWMutexR(0x8adc4b17ee8?, 0xdc?, 0x10?)
	/opt/homebrew/Cellar/go/1.26.1/libexec/src/runtime/sema.go:100 +0x28
sync.(*RWMutex).RLock(...)
	/opt/homebrew/Cellar/go/1.26.1/libexec/src/sync/rwmutex.go:74
github.com/nats-io/nats-server/v2/server.(*Server).executeLogCall(0x8adc4c5a008, 0x104daab70, {0x1046cccfc, 0x18}, {0x8adc4ad2b20, 0x1, 0x1})
	nats-server/server/log.go:288 +0x90
github.com/nats-io/nats-server/v2/server.(*Server).Errorf(...)
	nats-server/server/log.go:189
github.com/nats-io/nats-server/v2/server.(*Server).SetLoggerV2(0x8adc4c5a008, {0x104db8088, 0x104e64e00}, 0x0?, 0x0?, 0x0?)
	nats-server/server/log.go:139 +0x1e4
github.com/nats-io/nats-server/v2/server.(*Server).SetLogger(...)
	nats-server/server/log.go:112
main.main.func1()
	main.go:45 +0x44
created by main.main in goroutine 1
	main.go:44 +0x150

The issue was found with mulint, so it's kinda hypothetical. Potential real-world scenarios when it might occur is log rotation (ReOpenLogs(...) w/ a broken old logger) and embedded servers calling SetLogger multiple times.

@palkan
palkan requested a review from a team as a code owner July 29, 2026 03:03
@github-actions

Copy link
Copy Markdown

Please review the CONTRIBUTING.md guide as some commits are missing Signed-off-by: in their commit messages.

To correct, please amend the following commits and force-push:

Calling s.Errorf() tries to acquire the same s.logging mutex which we're already holding, so we should call it after Unlock()

Signed-off-by: Vladimir Dementyev <dementiev.vm@gmail.com>
@palkan
palkan force-pushed the fix/set-logger-deadlock branch from 9ac5776 to efa55d5 Compare July 29, 2026 03:06
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant