fix: prevent logger close recursion and unsafe writer closing

This commit is contained in:
2026-03-17 14:43:28 +03:00
parent 956755fe82
commit 6112a707c7
4 changed files with 227 additions and 24 deletions

28
io.go
View File

@@ -64,12 +64,18 @@ func (l *Logger) print(level LogLevel, m ...any) {
if l.level.n < level.n { if l.level.n < level.n {
return return
} }
if len(l.writers) == 0 {
return
}
tb := getFullTraceback(0) tb := getFullTraceback(0)
for _, writer := range l.writers { for _, writer := range l.writers {
if writer == nil {
continue
}
err := writer.Print(level, l.prefix, tb, m...) err := writer.Print(level, l.prefix, tb, m...)
if err != nil { if err != nil {
l.Error(err) l.reportWriterError(err)
} }
} }
} }
@@ -80,12 +86,28 @@ func (l *Logger) println(level LogLevel, m ...any) {
if l.level.n < level.n { if l.level.n < level.n {
return return
} }
if len(l.writers) == 0 {
return
}
tb := getFullTraceback(0) tb := getFullTraceback(0)
messages := append(append(make([]any, 0, len(m)+1), m...), "\n")
for _, writer := range l.writers { for _, writer := range l.writers {
err := writer.Print(level, l.prefix, tb, append(m, "\n")...) if writer == nil {
continue
}
err := writer.Print(level, l.prefix, tb, messages...)
if err != nil { if err != nil {
l.Error(err) l.reportWriterError(err)
} }
} }
} }
// reportWriterError writes internal writer failures directly to stderr to avoid
// re-entering the same logger path that just failed.
func (l *Logger) reportWriterError(err error) {
if err == nil {
return
}
_, _ = fmt.Fprintf(os.Stderr, "[%s] logger writer error: %v\n", l.prefix, err)
}

View File

@@ -1,6 +1,7 @@
package slog package slog
import ( import (
"errors"
"fmt" "fmt"
"io" "io"
"strings" "strings"
@@ -83,13 +84,18 @@ func (l *Logger) AddWriter(writer LoggerWriter) *Logger {
return l return l
} }
func (l *Logger) Close() error { func (l *Logger) Close() error {
var errs []error
for _, writer := range l.writers { for _, writer := range l.writers {
if writer == nil {
continue
}
err := writer.Close() err := writer.Close()
if err != nil { if err != nil {
l.Error(err) errs = append(errs, err)
} }
} }
return nil l.writers = nil
return errors.Join(errs...)
} }
func (l *Logger) CreateTextWriter(w io.Writer) *LoggerTextWriter { func (l *Logger) CreateTextWriter(w io.Writer) *LoggerTextWriter {

170
logger_test.go Normal file
View File

@@ -0,0 +1,170 @@
package slog
import (
"bytes"
"errors"
"os"
"testing"
)
type stubLoggerWriter struct {
printErr error
closeErr error
printCalls int
closeCalls int
}
func (w *stubLoggerWriter) Close() error {
w.closeCalls++
return w.closeErr
}
func (w *stubLoggerWriter) Write(p []byte) (int, error) {
return len(p), nil
}
func (w *stubLoggerWriter) Print(_ LogLevel, _ string, _ []*MethodTraceback, _ ...any) error {
w.printCalls++
return w.printErr
}
func TestLoggerCloseReturnsJoinedErrorsWithoutRelogging(t *testing.T) {
firstErr := errors.New("first close failed")
secondErr := errors.New("second close failed")
first := &stubLoggerWriter{closeErr: firstErr}
second := &stubLoggerWriter{closeErr: secondErr}
logger := CreateLogger().AddWriters(first, second)
err := logger.Close()
if !errors.Is(err, firstErr) {
t.Fatalf("Close() error should include first writer error, got %v", err)
}
if !errors.Is(err, secondErr) {
t.Fatalf("Close() error should include second writer error, got %v", err)
}
if first.printCalls != 0 || second.printCalls != 0 {
t.Fatalf("Close() should not log through writers again, got print calls first=%d second=%d", first.printCalls, second.printCalls)
}
if first.closeCalls != 1 || second.closeCalls != 1 {
t.Fatalf("Close() should close each writer once, got close calls first=%d second=%d", first.closeCalls, second.closeCalls)
}
if err := logger.Close(); err != nil {
t.Fatalf("second Close() should be a no-op, got %v", err)
}
}
func TestLoggerPrintDoesNotRecurseOnWriterError(t *testing.T) {
oldStderr := os.Stderr
stderrFile, err := os.CreateTemp(t.TempDir(), "stderr")
if err != nil {
t.Fatalf("CreateTemp() error = %v", err)
}
os.Stderr = stderrFile
t.Cleanup(func() {
os.Stderr = oldStderr
_ = stderrFile.Close()
})
bad := &stubLoggerWriter{printErr: errors.New("print failed")}
good := &stubLoggerWriter{}
logger := CreateLogger().AddWriters(bad, good)
logger.Error("boom")
if bad.printCalls != 1 {
t.Fatalf("bad writer should be called once, got %d", bad.printCalls)
}
if good.printCalls != 1 {
t.Fatalf("good writer should be called once, got %d", good.printCalls)
}
}
func TestCreateTextWriterCloseOnNonCloserIsNoOp(t *testing.T) {
writer := CreateTextWriter(&bytes.Buffer{}, false, false)
if err := writer.Close(); err != nil {
t.Fatalf("Close() error = %v", err)
}
}
func TestCreateTextWriterDoesNotCloseExternalCloser(t *testing.T) {
file, err := os.CreateTemp(t.TempDir(), "text-writer")
if err != nil {
t.Fatalf("CreateTemp() error = %v", err)
}
t.Cleanup(func() {
_ = file.Close()
})
writer := CreateTextWriter(file, false, false)
if err := writer.Close(); err != nil {
t.Fatalf("Close() error = %v", err)
}
if _, err := file.WriteString("still open"); err != nil {
t.Fatalf("CreateTextWriter() should not close external writers, got %v", err)
}
}
func TestCreateJsonWriterCloseOnNonCloserIsNoOp(t *testing.T) {
writer := CreateJsonWriter(&bytes.Buffer{}, false)
if err := writer.Close(); err != nil {
t.Fatalf("Close() error = %v", err)
}
}
func TestCreateJsonWriterDoesNotCloseExternalCloser(t *testing.T) {
file, err := os.CreateTemp(t.TempDir(), "json-writer")
if err != nil {
t.Fatalf("CreateTemp() error = %v", err)
}
t.Cleanup(func() {
_ = file.Close()
})
writer := CreateJsonWriter(file, false)
if err := writer.Close(); err != nil {
t.Fatalf("Close() error = %v", err)
}
if _, err := file.WriteString("still open"); err != nil {
t.Fatalf("CreateJsonWriter() should not close external writers, got %v", err)
}
}
func TestCreateTextStdoutWriterDoesNotCloseStdout(t *testing.T) {
stdoutFile := swapStdout(t)
writer := CreateTextStdoutWriter(false, false)
if err := writer.Close(); err != nil {
t.Fatalf("Close() error = %v", err)
}
if _, err := stdoutFile.WriteString("still open"); err != nil {
t.Fatalf("stdout writer Close() should not close stdout, got %v", err)
}
}
func TestCreateJsonStdoutWriterDoesNotCloseStdout(t *testing.T) {
stdoutFile := swapStdout(t)
writer := CreateJsonStdoutWriter(false)
if err := writer.Close(); err != nil {
t.Fatalf("Close() error = %v", err)
}
if _, err := stdoutFile.WriteString("still open"); err != nil {
t.Fatalf("stdout writer Close() should not close stdout, got %v", err)
}
}
func swapStdout(t *testing.T) *os.File {
t.Helper()
oldStdout := os.Stdout
stdoutFile, err := os.CreateTemp(t.TempDir(), "stdout")
if err != nil {
t.Fatalf("CreateTemp() error = %v", err)
}
os.Stdout = stdoutFile
t.Cleanup(func() {
os.Stdout = oldStdout
_ = stdoutFile.Close()
})
return stdoutFile
}

View File

@@ -1,7 +1,6 @@
package slog package slog
import ( import (
"bufio"
"encoding/json" "encoding/json"
"fmt" "fmt"
"io" "io"
@@ -20,17 +19,13 @@ type LoggerWriter interface {
type LoggerTextWriter struct { type LoggerTextWriter struct {
LoggerWriter LoggerWriter
writer io.Writer writer io.Writer
closer io.Closer
printTraceback bool printTraceback bool
printTime bool printTime bool
} }
func (w *LoggerTextWriter) Write(p []byte) (n int, err error) { func (w *LoggerTextWriter) Write(p []byte) (n int, err error) {
n, err = w.writer.Write(p) return w.writer.Write(p)
if err != nil {
return n, err
}
err = bufio.NewWriter(w.writer).Flush()
return n, err
} }
func (w *LoggerTextWriter) Print(level LogLevel, prefix string, _ []*MethodTraceback, messages ...any) error { func (w *LoggerTextWriter) Print(level LogLevel, prefix string, _ []*MethodTraceback, messages ...any) error {
s := BuildString(level, prefix, w.printTime, w.printTraceback, messages...) s := BuildString(level, prefix, w.printTime, w.printTraceback, messages...)
@@ -38,13 +33,17 @@ func (w *LoggerTextWriter) Print(level LogLevel, prefix string, _ []*MethodTrace
return err return err
} }
func (w *LoggerTextWriter) Close() error { func (w *LoggerTextWriter) Close() error {
return w.writer.(io.Closer).Close() if w.closer == nil {
return nil
}
return w.closer.Close()
} }
// LoggerJsonWriter write into writer JSON // LoggerJsonWriter write into writer JSON
type LoggerJsonWriter struct { type LoggerJsonWriter struct {
LoggerWriter LoggerWriter
writer io.Writer writer io.Writer
closer io.Closer
pretty bool pretty bool
} }
type LoggerJsonMessage struct { type LoggerJsonMessage struct {
@@ -56,12 +55,7 @@ type LoggerJsonMessage struct {
} }
func (w *LoggerJsonWriter) Write(data []byte) (int, error) { func (w *LoggerJsonWriter) Write(data []byte) (int, error) {
n, err := w.writer.Write(data) return w.writer.Write(data)
if err != nil {
return n, err
}
err = bufio.NewWriter(w.writer).Flush()
return n, err
} }
func (w *LoggerJsonWriter) Print(level LogLevel, prefix string, traceback []*MethodTraceback, messages ...any) error { func (w *LoggerJsonWriter) Print(level LogLevel, prefix string, traceback []*MethodTraceback, messages ...any) error {
msg := Map(messages, func(el any) string { msg := Map(messages, func(el any) string {
@@ -98,7 +92,10 @@ func (w *LoggerJsonWriter) Print(level LogLevel, prefix string, traceback []*Met
return err return err
} }
func (w *LoggerJsonWriter) Close() error { func (w *LoggerJsonWriter) Close() error {
return w.writer.(io.Closer).Close() if w.closer == nil {
return nil
}
return w.closer.Close()
} }
func CreateTextWriter(w io.Writer, printTraceback, printTime bool) *LoggerTextWriter { func CreateTextWriter(w io.Writer, printTraceback, printTime bool) *LoggerTextWriter {
@@ -116,10 +113,14 @@ func CreateTextFileWriter(path string, printTraceback, printTime bool) (*LoggerT
if err != nil { if err != nil {
return nil, err return nil, err
} }
return CreateTextWriter(file, printTraceback, printTime), nil writer := CreateTextWriter(file, printTraceback, printTime)
writer.closer = file
return writer, nil
} }
func CreateTextStdoutWriter(printTraceback, printTime bool) *LoggerTextWriter { func CreateTextStdoutWriter(printTraceback, printTime bool) *LoggerTextWriter {
return CreateTextWriter(os.Stdout, printTraceback, printTime) writer := CreateTextWriter(os.Stdout, printTraceback, printTime)
writer.closer = nil
return writer
} }
func CreateJsonWriter(w io.Writer, pretty bool) *LoggerJsonWriter { func CreateJsonWriter(w io.Writer, pretty bool) *LoggerJsonWriter {
@@ -129,7 +130,9 @@ func CreateJsonWriter(w io.Writer, pretty bool) *LoggerJsonWriter {
return writer return writer
} }
func CreateJsonStdoutWriter(pretty bool) *LoggerJsonWriter { func CreateJsonStdoutWriter(pretty bool) *LoggerJsonWriter {
return CreateJsonWriter(os.Stdout, pretty) writer := CreateJsonWriter(os.Stdout, pretty)
writer.closer = nil
return writer
} }
func CreateJsonFileWriter(path string, pretty bool) (*LoggerJsonWriter, error) { func CreateJsonFileWriter(path string, pretty bool) (*LoggerJsonWriter, error) {
err := os.MkdirAll(filepath.Dir(path), os.ModePerm) err := os.MkdirAll(filepath.Dir(path), os.ModePerm)
@@ -140,5 +143,7 @@ func CreateJsonFileWriter(path string, pretty bool) (*LoggerJsonWriter, error) {
if err != nil { if err != nil {
return nil, err return nil, err
} }
return CreateJsonWriter(file, pretty), nil writer := CreateJsonWriter(file, pretty)
writer.closer = file
return writer, nil
} }