-
Notifications
You must be signed in to change notification settings - Fork 40.7k
Add log file rotation #127667
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Add log file rotation #127667
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
Original file line number | Diff line number | Diff line change |
---|---|---|
@@ -0,0 +1,205 @@ | ||
/* | ||
Copyright 2025 The Kubernetes Authors. | ||
|
||
Licensed under the Apache License, Version 2.0 (the "License"); | ||
you may not use this file except in compliance with the License. | ||
You may obtain a copy of the License at | ||
|
||
http://www.apache.org/licenses/LICENSE-2.0 | ||
|
||
Unless required by applicable law or agreed to in writing, software | ||
distributed under the License is distributed on an "AS IS" BASIS, | ||
WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. | ||
See the License for the specific language governing permissions and | ||
limitations under the License. | ||
*/ | ||
|
||
package logrotation | ||
|
||
import ( | ||
"io" | ||
"os" | ||
"path/filepath" | ||
"strings" | ||
"sync" | ||
"time" | ||
) | ||
|
||
const timeLayout string = "20060102-150405" | ||
|
||
type rotationFile struct { | ||
// required, the max size of the log file in bytes, 0 means no rotation | ||
maxSize int64 | ||
// required, the max age of the log file, 0 means no cleanup | ||
maxAge time.Duration | ||
filePath string | ||
mut sync.Mutex | ||
file *os.File | ||
currentSize int64 | ||
lasSyncTime time.Time | ||
flushInterval time.Duration | ||
} | ||
|
||
func Open(filePath string, flushInterval time.Duration, maxSize int64, maxAge time.Duration) (io.WriteCloser, error) { | ||
w := &rotationFile{ | ||
filePath: filePath, | ||
maxSize: maxSize, | ||
maxAge: maxAge, | ||
flushInterval: flushInterval, | ||
} | ||
|
||
logFile, err := os.OpenFile(w.filePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) | ||
if err != nil { | ||
return nil, err | ||
} | ||
|
||
w.file = logFile | ||
|
||
w.lasSyncTime = time.Now() | ||
|
||
if w.maxSize > 0 { | ||
info, err := os.Stat(w.filePath) | ||
if err != nil { | ||
return nil, err | ||
} | ||
w.currentSize = info.Size() | ||
} | ||
|
||
return w, nil | ||
} | ||
|
||
// Write implements the io.Writer interface. | ||
func (w *rotationFile) Write(p []byte) (n int, err error) { | ||
w.mut.Lock() | ||
defer w.mut.Unlock() | ||
|
||
n, err = w.file.Write(p) | ||
if err != nil { | ||
return 0, err | ||
} | ||
|
||
if w.flushInterval > 0 && time.Since(w.lasSyncTime) >= w.flushInterval { | ||
err = w.file.Sync() | ||
if err != nil { | ||
return 0, err | ||
} | ||
w.lasSyncTime = time.Now() | ||
} | ||
|
||
if w.maxSize > 0 { | ||
w.currentSize += int64(len(p)) | ||
|
||
// if file size over maxsize rotate the log file | ||
if w.currentSize >= w.maxSize { | ||
err = w.rotate() | ||
if err != nil { | ||
return 0, err | ||
} | ||
} | ||
} | ||
|
||
return n, nil | ||
} | ||
|
||
func (w *rotationFile) rotate() error { | ||
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Not sure whether I asked about it here already: can we somehow ensure that rotation doesn't cut a log message into two halves? If that happens, the end of one file and start of the next cannot be parsed. One possible solution would be for logrunner to set up a Unix domain datagram socket, then read entire messages from it. This wasn't necessary before because it was just a bit pipe, but with log rotation it becomes a router for log messages. Relevant in the context of kubernetes/enhancements#5022. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Thanks for the context! There will be performance tax by adding a datagram layer? If we want to add that, I think we should make it to be optional so that people who do not care much about the splitting can avoid some performance loss? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Also, any high-level idea on how to test this? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Actually, I feel a little confused here. Can you please help to explain how a writing to stderr/stdout can result into halves messages with the rotation? if the write() interface being called holds the "original" message boundary? if not, this message boundary can't be guaranteed by unix datagram neither as the message in write() call is the visible message boundary for datagram? Unless we have some info on application level message boundary, this does not seem possible? Please let me know if I missed anything @pohly @harshanarayana? An example will be much helpful, thanks! There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. With normal pipes, the writer might do a single write with 1024 bytes containing one log entry. The kernels is free to split those bytes up however it likes, so logrunner reading into a 1024 byte buffer might only get 512 bytes, write those to one file, rotate, and then write the next 512 of that log entry in the next file. I would need to read up on Unix Datagram, but I'm pretty sure it avoids that. If I remember correctly, the reader can determine what the size of the next datagram is. How well this is supported by Go is yet another open question.
I don't think so (it's still all in kernel memory), but it would be worthwhile to benchmark it.
A stress might be able to show this happening. There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Couldn't we just coordinate on newlines? There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Let's continue in the issue: #131788 (comment) |
||
// Get the file extension | ||
ext := filepath.Ext(w.filePath) | ||
|
||
// Remove the extension from the filename | ||
pathWithoutExt := strings.TrimSuffix(w.filePath, ext) | ||
|
||
rotateFilePath := pathWithoutExt + "-" + time.Now().Format(timeLayout) + ext | ||
|
||
if w.filePath == rotateFilePath { | ||
return nil | ||
} | ||
|
||
err := w.file.Close() | ||
if err != nil { | ||
return err | ||
} | ||
|
||
err = os.Rename(w.filePath, rotateFilePath) | ||
if err != nil { | ||
return err | ||
} | ||
|
||
w.file, err = os.OpenFile(w.filePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644) | ||
if err != nil { | ||
return err | ||
} | ||
|
||
w.currentSize = 0 | ||
|
||
if w.maxAge > 0 { | ||
go func() { | ||
err = w.clean(pathWithoutExt, ext) | ||
}() | ||
} | ||
|
||
return nil | ||
} | ||
|
||
// Clean up the old log files in the format of | ||
// <basename>-<timestamp><ext>. | ||
// This should be safe enough to avoid false deletion. | ||
// This will work for multiple restarts of the same program. | ||
func (w *rotationFile) clean(pathWithoutExt string, ext string) error { | ||
ageTime := time.Now().Add(-w.maxAge) | ||
|
||
directory := filepath.Dir(pathWithoutExt) | ||
basename := filepath.Base(pathWithoutExt) + "-" | ||
|
||
dir, err := os.ReadDir(directory) | ||
if err != nil { | ||
return err | ||
} | ||
|
||
err = nil | ||
for _, v := range dir { | ||
if strings.HasPrefix(v.Name(), basename) && strings.HasSuffix(v.Name(), ext) { | ||
// Remove the prefix and suffix | ||
trimmed := strings.TrimPrefix(v.Name(), basename) | ||
trimmed = strings.TrimSuffix(trimmed, ext) | ||
|
||
_, err = time.Parse(timeLayout, trimmed) | ||
if err == nil { | ||
info, errInfo := v.Info() | ||
if errInfo != nil { | ||
err = errInfo | ||
// Ignore the error while continue with the next clenup | ||
continue | ||
} | ||
|
||
if ageTime.After(info.ModTime()) { | ||
err = os.Remove(filepath.Join(directory, v.Name())) | ||
if err != nil { | ||
// Ignore the error while continue with the next clenup | ||
continue | ||
} | ||
} | ||
} | ||
|
||
} | ||
} | ||
|
||
return err | ||
} | ||
|
||
func (w *rotationFile) Close() error { | ||
w.mut.Lock() | ||
defer w.mut.Unlock() | ||
|
||
// Explicitly call file.Sync() to ensure data is written to disk | ||
err := w.file.Sync() | ||
if err != nil { | ||
return err | ||
} | ||
|
||
err = w.file.Close() | ||
if err != nil { | ||
return err | ||
} | ||
|
||
return nil | ||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
updated
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Let's not forget about the problem.
I created https://github.com/kubernetes/kubernetes/compare/master...pohly:kubernetes:log-runner-torn-writes?expand=1 to demonstrate it and #131788 for tracking.