From dd7693231ff41b05f33460d13eeb8addde5ff9b9 Mon Sep 17 00:00:00 2001 From: Lars Pehrsson Date: Thu, 26 Mar 2026 10:57:26 +1100 Subject: [PATCH 1/5] prevent panic and resource leak in file rotation The log rotation logic could cause a panic by attempting to access a closed file handle when renaming log files. This is resolved by: - Caching the filename in the roll() function before the file is closed. - Setting the file handle to nil after closing it. - Adding a nil check in CloseAllOpenFileLoggers() to handle already-rolled files. Additionally, a resource leak is fixed where rolling files were repeatedly added to the global open files slice. A new 'registered' flag ensures each file is added only once. As a minor improvement, the log writer now combines the timestamp and message into a single buffer to perform one atomic write preventing splitting up timestamp and message into different logs --- lib/logging/logging.go | 34 +++++++++++++++++++--------------- 1 file changed, 19 insertions(+), 15 deletions(-) diff --git a/lib/logging/logging.go b/lib/logging/logging.go index d06f92b..a2b0c72 100644 --- a/lib/logging/logging.go +++ b/lib/logging/logging.go @@ -1,6 +1,6 @@ // SILVER - Service Wrapper // -// Copyright (c) 2014 PaperCut Software http://www.papercut.com/ +// Copyright (c) 2014-2026 PaperCut Software http://www.papercut.com/ // Use of this source code is governed by an MIT or GPL Version 2 license. // See the project's LICENSE file for more information. // @@ -53,6 +53,7 @@ type rollingFile struct { bytesSinceLastFlush int64 currentSize int64 flusher *flusher + registered bool } type flusher struct { @@ -71,13 +72,10 @@ type logWriter struct { // custom Write to add timestamps with custom format func (w logWriter) Write(bytes []byte) (int, error) { - timestamp := time.Now().Format(w.timeformat) + " " - n1, err := io.WriteString(w.Writer, timestamp) - if err != nil { - return n1, err - } - n2, err := w.Writer.Write(bytes) - return n1 + n2, err + timestamp := []byte(time.Now().Format(w.timeformat) + " ") + combined := append(timestamp, bytes...) + n, err := w.Writer.Write(combined) + return n, err } func (f *flusher) run(rf *rollingFile) { @@ -149,24 +147,29 @@ func (rf *rollingFile) open() error { return err } rf.currentSize = finfo.Size() - openRollingFiles = append(openRollingFiles, rf) + if !rf.registered { + openRollingFiles = append(openRollingFiles, rf) + rf.registered = true + } return nil } func (rf *rollingFile) roll() error { rf.bufWriter.Flush() + name := rf.file.Name() rf.file.Close() + rf.file = nil // Start from the last backup file and move everything back by 1 step for i := rf.maxBackupFiles; i > 0; i-- { var renameFrom, renameTo string if i == 1 { - renameFrom = rf.file.Name() // Original file + renameFrom = name // Original file } else { - renameFrom = fmt.Sprintf("%s.%d", rf.file.Name(), i-1) + renameFrom = fmt.Sprintf("%s.%d", name, i-1) } - renameTo = fmt.Sprintf("%s.%d", rf.file.Name(), i) + renameTo = fmt.Sprintf("%s.%d", name, i) if err := os.Rename(renameFrom, renameTo); err == nil || errors.Is(err, os.ErrNotExist) { // Continue if no error or if the error is 'file not found' @@ -175,7 +178,6 @@ func (rf *rollingFile) roll() error { // For any other error. fmt.Fprintf(os.Stderr, "ERROR: Error renaming %s to %s. %v\n", renameFrom, renameTo, err) } - } // Reopen a new log file for writing @@ -183,7 +185,7 @@ func (rf *rollingFile) roll() error { } func openLogFile(name string, owner string) (f *os.File, err error) { - f, err = os.OpenFile(name, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0644) + f, err = os.OpenFile(name, os.O_WRONLY|os.O_CREATE|os.O_APPEND, 0o644) if err != nil { return } @@ -224,7 +226,9 @@ func NewFileLoggerWithMaxSize(file string, owner string, maxSize int64, maxBacku func CloseAllOpenFileLoggers() { for _, rf := range openRollingFiles { rf.bufWriter.Flush() - rf.file.Close() + if rf.file != nil { + rf.file.Close() + } } openRollingFiles = []*rollingFile{} } From 82df8c3afac615ff5a829fefa8b8d532b616b88f Mon Sep 17 00:00:00 2001 From: Lars Pehrsson Date: Thu, 26 Mar 2026 11:29:07 +1100 Subject: [PATCH 2/5] abort write if roll() fails during rotation Capture and return roll() error in rollingFile.Write to avoid proceeding with a write when log rotation fails --- lib/logging/logging.go | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/lib/logging/logging.go b/lib/logging/logging.go index a2b0c72..8e80cd3 100644 --- a/lib/logging/logging.go +++ b/lib/logging/logging.go @@ -118,7 +118,10 @@ func (rf *rollingFile) Write(p []byte) (n int, err error) { defer rf.Unlock() if rf.currentSize+int64(len(p)) >= rf.maxSize { - rf.roll() + err = rf.roll() + if err != nil { + return + } } n, err = rf.bufWriter.Write(p) rf.currentSize += int64(n) From 39fda036210c349bc26f40d75c60ef108026e3cb Mon Sep 17 00:00:00 2001 From: Lars Pehrsson Date: Thu, 26 Mar 2026 11:51:36 +1100 Subject: [PATCH 3/5] lazily open log file in Write when handle is nil Ensures writes can resume after rotation or startup by calling open() if rf.file is nil. If open fails, return the error instead of attempting to write. --- lib/logging/logging.go | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/lib/logging/logging.go b/lib/logging/logging.go index 8e80cd3..728d567 100644 --- a/lib/logging/logging.go +++ b/lib/logging/logging.go @@ -117,6 +117,13 @@ func (rf *rollingFile) Write(p []byte) (n int, err error) { rf.Lock() defer rf.Unlock() + if rf.file == nil { + err = rf.open() + if err != nil { + return + } + } + if rf.currentSize+int64(len(p)) >= rf.maxSize { err = rf.roll() if err != nil { From e53cc5be24006603b5e8a95e4ea1471258f67c74 Mon Sep 17 00:00:00 2001 From: Lars Pehrsson Date: Thu, 26 Mar 2026 12:32:15 +1100 Subject: [PATCH 4/5] avoid attempting rotation when file handle is nil If a file rotation (`roll`) fails after closing the file but before reopening a new one, the file handle would be left as `nil`. Subsequent calls to `Write` would trigger another roll, leading to a panic when `roll` tried to access the `nil` file handle. This change moves the `nil` file check from `Write` into `roll` to ensure the file is open before proceeding with rotation logic, thus preventing the panic. --- lib/logging/logging.go | 10 +++------- 1 file changed, 3 insertions(+), 7 deletions(-) diff --git a/lib/logging/logging.go b/lib/logging/logging.go index 728d567..a2d058f 100644 --- a/lib/logging/logging.go +++ b/lib/logging/logging.go @@ -117,13 +117,6 @@ func (rf *rollingFile) Write(p []byte) (n int, err error) { rf.Lock() defer rf.Unlock() - if rf.file == nil { - err = rf.open() - if err != nil { - return - } - } - if rf.currentSize+int64(len(p)) >= rf.maxSize { err = rf.roll() if err != nil { @@ -165,6 +158,9 @@ func (rf *rollingFile) open() error { } func (rf *rollingFile) roll() error { + if rf.file == nil { + return rf.open() + } rf.bufWriter.Flush() name := rf.file.Name() rf.file.Close() From ebcb7c0244c13f70c86f5ace0dd104e502a9ada3 Mon Sep 17 00:00:00 2001 From: Lars Pehrsson Date: Thu, 26 Mar 2026 16:28:06 +1100 Subject: [PATCH 5/5] reduce allocations in logWriter The logWriter.Write method previously performed several string and byte slice allocations to prepend a timestamp to log messages. This change refactors the implementation to use time.AppendFormat with a pre-allocated buffer, which significantly reduces memory allocations in a hot path. --- lib/logging/logging.go | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/lib/logging/logging.go b/lib/logging/logging.go index a2d058f..cbf1fc0 100644 --- a/lib/logging/logging.go +++ b/lib/logging/logging.go @@ -72,10 +72,11 @@ type logWriter struct { // custom Write to add timestamps with custom format func (w logWriter) Write(bytes []byte) (int, error) { - timestamp := []byte(time.Now().Format(w.timeformat) + " ") - combined := append(timestamp, bytes...) - n, err := w.Writer.Write(combined) - return n, err + // This buffer will be escaped to the heap since it is used for an argument of io.Writer. + // However, no additional allocation will occur unless the message length exceeds 4096 bytes. + var buffer [4096]byte + b := append(time.Now().AppendFormat(buffer[:0], w.timeformat), ' ') + return w.Writer.Write(append(b, bytes...)) } func (f *flusher) run(rf *rollingFile) {