mirror of
https://github.com/containers/podman.git
synced 2025-05-17 23:26:08 +08:00
Add log rotation based on log size
Add new functions to logfile.go for rotating and truncating the events log file once the log file and its contents exceed the maximum size limit while keeping 50% of the log file's content Also add tests to verify log rotation and truncation Signed-off-by: Niall Crowe <nicrowe@redhat.com> Signed-off-by: Valentin Rothberg <vrothberg@redhat.com>
This commit is contained in:
Niall Crowe
@ -13,8 +13,9 @@ import (
|
||||
// newEventer returns an eventer that can be used to read/write events
|
||||
func (r *Runtime) newEventer() (events.Eventer, error) {
|
||||
options := events.EventerOptions{
|
||||
EventerType: r.config.Engine.EventsLogger,
|
||||
LogFilePath: r.config.Engine.EventsLogFilePath,
|
||||
EventerType: r.config.Engine.EventsLogger,
|
||||
LogFilePath: r.config.Engine.EventsLogFilePath,
|
||||
LogFileMaxSize: r.config.Engine.EventsLogFileMaxSize,
|
||||
}
|
||||
return events.NewEventer(options)
|
||||
}
|
||||
|
||||
@ -60,6 +60,8 @@ type EventerOptions struct {
|
||||
// LogFilePath is the path to where the log file should reside if using
|
||||
// the file logger
|
||||
LogFilePath string
|
||||
// LogFileMaxSize is the default limit used for rotating the log file
|
||||
LogFileMaxSize uint64
|
||||
}
|
||||
|
||||
// Eventer is the interface for journald or file event logging
|
||||
@ -171,6 +173,8 @@ const (
|
||||
Restart Status = "restart"
|
||||
// Restore ...
|
||||
Restore Status = "restore"
|
||||
// Rotate indicates that the log file was rotated
|
||||
Rotate Status = "log-rotation"
|
||||
// Save ...
|
||||
Save Status = "save"
|
||||
// Start ...
|
||||
|
||||
@ -3,11 +3,9 @@ package events
|
||||
import (
|
||||
"encoding/json"
|
||||
"fmt"
|
||||
"os"
|
||||
"time"
|
||||
|
||||
"github.com/containers/storage/pkg/stringid"
|
||||
"github.com/nxadm/tail"
|
||||
"github.com/pkg/errors"
|
||||
)
|
||||
|
||||
@ -87,7 +85,11 @@ func (e *Event) ToHumanReadable(truncate bool) string {
|
||||
case Image:
|
||||
humanFormat = fmt.Sprintf("%s %s %s %s %s", e.Time, e.Type, e.Status, id, e.Name)
|
||||
case System:
|
||||
humanFormat = fmt.Sprintf("%s %s %s", e.Time, e.Type, e.Status)
|
||||
if e.Name != "" {
|
||||
humanFormat = fmt.Sprintf("%s %s %s %s", e.Time, e.Type, e.Status, e.Name)
|
||||
} else {
|
||||
humanFormat = fmt.Sprintf("%s %s %s", e.Time, e.Type, e.Status)
|
||||
}
|
||||
case Volume:
|
||||
humanFormat = fmt.Sprintf("%s %s %s %s", e.Time, e.Type, e.Status, e.Name)
|
||||
}
|
||||
@ -196,6 +198,8 @@ func StringToStatus(name string) (Status, error) {
|
||||
return Restart, nil
|
||||
case Restore.String():
|
||||
return Restore, nil
|
||||
case Rotate.String():
|
||||
return Rotate, nil
|
||||
case Save.String():
|
||||
return Save, nil
|
||||
case Start.String():
|
||||
@ -215,14 +219,3 @@ func StringToStatus(name string) (Status, error) {
|
||||
}
|
||||
return "", errors.Errorf("unknown event status %q", name)
|
||||
}
|
||||
|
||||
func (e EventLogFile) getTail(options ReadOptions) (*tail.Tail, error) {
|
||||
reopen := true
|
||||
seek := tail.SeekInfo{Offset: 0, Whence: os.SEEK_END}
|
||||
if options.FromStart || !options.Stream {
|
||||
seek.Whence = 0
|
||||
reopen = false
|
||||
}
|
||||
stream := options.Stream
|
||||
return tail.TailFile(e.options.LogFilePath, tail.Config{ReOpen: reopen, Follow: stream, Location: &seek, Logger: tail.DiscardingLogger, Poll: true})
|
||||
}
|
||||
|
||||
@ -1,15 +1,24 @@
|
||||
//go:build linux
|
||||
// +build linux
|
||||
|
||||
package events
|
||||
|
||||
import (
|
||||
"bufio"
|
||||
"context"
|
||||
"fmt"
|
||||
"io"
|
||||
"io/ioutil"
|
||||
"os"
|
||||
"path"
|
||||
"time"
|
||||
|
||||
"github.com/containers/podman/v4/pkg/util"
|
||||
"github.com/containers/storage/pkg/lockfile"
|
||||
"github.com/nxadm/tail"
|
||||
"github.com/pkg/errors"
|
||||
"github.com/sirupsen/logrus"
|
||||
"golang.org/x/sys/unix"
|
||||
)
|
||||
|
||||
// EventLogFile is the structure for event writing to a logfile. It contains the eventer
|
||||
@ -27,21 +36,55 @@ func (e EventLogFile) Write(ee Event) error {
|
||||
}
|
||||
lock.Lock()
|
||||
defer lock.Unlock()
|
||||
f, err := os.OpenFile(e.options.LogFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0700)
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
defer f.Close()
|
||||
|
||||
eventJSONString, err := ee.ToJSONString()
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
if _, err := f.WriteString(fmt.Sprintf("%s\n", eventJSONString)); err != nil {
|
||||
|
||||
rotated, err := rotateLog(e.options.LogFilePath, eventJSONString, e.options.LogFileMaxSize)
|
||||
if err != nil {
|
||||
return fmt.Errorf("rotating log file: %w", err)
|
||||
}
|
||||
|
||||
if rotated {
|
||||
rEvent := NewEvent(Rotate)
|
||||
rEvent.Type = System
|
||||
rEvent.Name = e.options.LogFilePath
|
||||
rotateJSONString, err := rEvent.ToJSONString()
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
if err := e.writeString(rotateJSONString); err != nil {
|
||||
return err
|
||||
}
|
||||
}
|
||||
|
||||
return e.writeString(eventJSONString)
|
||||
}
|
||||
|
||||
func (e EventLogFile) writeString(s string) error {
|
||||
f, err := os.OpenFile(e.options.LogFilePath, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0700)
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
if _, err := f.WriteString(s + "\n"); err != nil {
|
||||
return err
|
||||
}
|
||||
return nil
|
||||
}
|
||||
|
||||
func (e EventLogFile) getTail(options ReadOptions) (*tail.Tail, error) {
|
||||
reopen := true
|
||||
seek := tail.SeekInfo{Offset: 0, Whence: os.SEEK_END}
|
||||
if options.FromStart || !options.Stream {
|
||||
seek.Whence = 0
|
||||
reopen = false
|
||||
}
|
||||
stream := options.Stream
|
||||
return tail.TailFile(e.options.LogFilePath, tail.Config{ReOpen: reopen, Follow: stream, Location: &seek, Logger: tail.DiscardingLogger, Poll: true})
|
||||
}
|
||||
|
||||
// Reads from the log file
|
||||
func (e EventLogFile) Read(ctx context.Context, options ReadOptions) error {
|
||||
defer close(options.EventChannel)
|
||||
@ -107,3 +150,108 @@ func (e EventLogFile) Read(ctx context.Context, options ReadOptions) error {
|
||||
func (e EventLogFile) String() string {
|
||||
return LogFile.String()
|
||||
}
|
||||
|
||||
// Rotates the log file if the log file size and content exceeds limit
|
||||
func rotateLog(logfile string, content string, limit uint64) (bool, error) {
|
||||
if limit == 0 {
|
||||
return false, nil
|
||||
}
|
||||
file, err := os.Stat(logfile)
|
||||
if err != nil {
|
||||
return false, err
|
||||
}
|
||||
var filesize = uint64(file.Size())
|
||||
var contentsize = uint64(len([]rune(content)))
|
||||
if filesize+contentsize < limit {
|
||||
return false, nil
|
||||
}
|
||||
|
||||
if err := truncate(logfile); err != nil {
|
||||
return false, err
|
||||
}
|
||||
return true, nil
|
||||
}
|
||||
|
||||
// Truncates the log file and saves 50% of content to new log file
|
||||
func truncate(filePath string) error {
|
||||
orig, err := os.Open(filePath)
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
defer orig.Close()
|
||||
|
||||
origFinfo, err := orig.Stat()
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
|
||||
size := origFinfo.Size()
|
||||
threshold := size / 2
|
||||
|
||||
tmp, err := ioutil.TempFile(path.Dir(filePath), "")
|
||||
if err != nil {
|
||||
// Retry in /tmp in case creating a tmp file in the same
|
||||
// directory has failed.
|
||||
tmp, err = ioutil.TempFile("", "")
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
}
|
||||
defer tmp.Close()
|
||||
|
||||
// Jump directly to the threshold, drop the first line and copy the remainder
|
||||
if _, err := orig.Seek(threshold, 0); err != nil {
|
||||
return err
|
||||
}
|
||||
reader := bufio.NewReader(orig)
|
||||
if _, err := reader.ReadString('\n'); err != nil {
|
||||
if !errors.Is(err, io.EOF) {
|
||||
return err
|
||||
}
|
||||
}
|
||||
if _, err := reader.WriteTo(tmp); err != nil {
|
||||
return fmt.Errorf("writing truncated contents: %w", err)
|
||||
}
|
||||
|
||||
if err := renameLog(tmp.Name(), filePath); err != nil {
|
||||
return fmt.Errorf("writing back %s to %s: %w", tmp.Name(), filePath, err)
|
||||
}
|
||||
|
||||
return nil
|
||||
}
|
||||
|
||||
// Renames from, to
|
||||
func renameLog(from, to string) error {
|
||||
err := os.Rename(from, to)
|
||||
if err == nil {
|
||||
return nil
|
||||
}
|
||||
|
||||
if !errors.Is(err, unix.EXDEV) {
|
||||
return err
|
||||
}
|
||||
|
||||
// Files are not on the same partition, so we need to copy them the
|
||||
// hard way.
|
||||
fFrom, err := os.Open(from)
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
defer fFrom.Close()
|
||||
|
||||
fTo, err := os.Create(to)
|
||||
if err != nil {
|
||||
return err
|
||||
}
|
||||
defer fTo.Close()
|
||||
|
||||
if _, err := io.Copy(fTo, fFrom); err != nil {
|
||||
return fmt.Errorf("writing back from temporary file: %w", err)
|
||||
}
|
||||
|
||||
if err := os.Remove(from); err != nil {
|
||||
return fmt.Errorf("removing temporary file: %w", err)
|
||||
}
|
||||
|
||||
return nil
|
||||
}
|
||||
|
||||
140
libpod/events/logfile_test.go
Normal file
140
libpod/events/logfile_test.go
Normal file
@ -0,0 +1,140 @@
|
||||
package events
|
||||
|
||||
import (
|
||||
"io/ioutil"
|
||||
"os"
|
||||
"testing"
|
||||
|
||||
"github.com/stretchr/testify/require"
|
||||
)
|
||||
|
||||
func TestRotateLog(t *testing.T) {
|
||||
tests := []struct {
|
||||
// If sizeInitial + sizeContent >= sizeLimit, then rotate
|
||||
sizeInitial uint64
|
||||
sizeContent uint64
|
||||
sizeLimit uint64
|
||||
mustRotate bool
|
||||
}{
|
||||
// No rotation
|
||||
{0, 0, 1, false},
|
||||
{1, 1, 0, false},
|
||||
{10, 10, 30, false},
|
||||
{1000, 500, 1600, false},
|
||||
// Rotation
|
||||
{10, 10, 20, true},
|
||||
{30, 0, 29, true},
|
||||
{200, 50, 150, true},
|
||||
{1000, 600, 1500, true},
|
||||
}
|
||||
|
||||
for _, test := range tests {
|
||||
tmp, err := ioutil.TempFile("", "log-rotation-")
|
||||
require.NoError(t, err)
|
||||
defer os.Remove(tmp.Name())
|
||||
defer tmp.Close()
|
||||
|
||||
// Create dummy file and content.
|
||||
initialContent := make([]byte, test.sizeInitial)
|
||||
logContent := make([]byte, test.sizeContent)
|
||||
|
||||
// Write content to the file.
|
||||
_, err = tmp.Write(initialContent)
|
||||
require.NoError(t, err)
|
||||
|
||||
// Now rotate
|
||||
fInfoBeforeRotate, err := tmp.Stat()
|
||||
require.NoError(t, err)
|
||||
isRotated, err := rotateLog(tmp.Name(), string(logContent), test.sizeLimit)
|
||||
require.NoError(t, err)
|
||||
|
||||
fInfoAfterRotate, err := os.Stat(tmp.Name())
|
||||
// Test if rotation was successful
|
||||
if test.mustRotate {
|
||||
// File has been renamed
|
||||
require.True(t, isRotated)
|
||||
require.NoError(t, err, "log file has been renamed")
|
||||
require.NotEqual(t, fInfoBeforeRotate.Size(), fInfoAfterRotate.Size())
|
||||
} else {
|
||||
// File has not been renamed
|
||||
require.False(t, isRotated)
|
||||
require.NoError(t, err, "log file has not been renamed")
|
||||
require.Equal(t, fInfoBeforeRotate.Size(), fInfoAfterRotate.Size())
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
func TestTruncationOutput(t *testing.T) {
|
||||
contentBefore := `0
|
||||
1
|
||||
2
|
||||
3
|
||||
4
|
||||
5
|
||||
6
|
||||
7
|
||||
8
|
||||
9
|
||||
10
|
||||
`
|
||||
contentAfter := `6
|
||||
7
|
||||
8
|
||||
9
|
||||
10
|
||||
`
|
||||
// Create dummy file
|
||||
tmp, err := ioutil.TempFile("", "log-rotation")
|
||||
require.NoError(t, err)
|
||||
defer os.Remove(tmp.Name())
|
||||
defer tmp.Close()
|
||||
|
||||
// Write content before truncation to dummy file
|
||||
_, err = tmp.WriteString(contentBefore)
|
||||
require.NoError(t, err)
|
||||
|
||||
// Truncate the file
|
||||
beforeTruncation, err := ioutil.ReadFile(tmp.Name())
|
||||
require.NoError(t, err)
|
||||
err = truncate(tmp.Name())
|
||||
require.NoError(t, err)
|
||||
afterTruncation, err := ioutil.ReadFile(tmp.Name())
|
||||
require.NoError(t, err)
|
||||
|
||||
// Test if rotation was successful
|
||||
require.NoError(t, err, "Log content has changed")
|
||||
require.NotEqual(t, beforeTruncation, afterTruncation)
|
||||
require.Equal(t, string(afterTruncation), contentAfter)
|
||||
}
|
||||
|
||||
func TestRenameLog(t *testing.T) {
|
||||
fileContent := `0
|
||||
1
|
||||
2
|
||||
3
|
||||
4
|
||||
5
|
||||
`
|
||||
// Create two dummy files
|
||||
source, err := ioutil.TempFile("", "removing")
|
||||
require.NoError(t, err)
|
||||
target, err := ioutil.TempFile("", "renaming")
|
||||
require.NoError(t, err)
|
||||
|
||||
// Write to source dummy file
|
||||
_, err = source.WriteString(fileContent)
|
||||
require.NoError(t, err)
|
||||
|
||||
// Rename the files
|
||||
beforeRename, err := ioutil.ReadFile(source.Name())
|
||||
require.NoError(t, err)
|
||||
err = renameLog(source.Name(), target.Name())
|
||||
require.NoError(t, err)
|
||||
afterRename, err := ioutil.ReadFile(target.Name())
|
||||
require.NoError(t, err)
|
||||
|
||||
// Test if renaming was successful
|
||||
require.Error(t, os.Remove(source.Name()))
|
||||
require.NoError(t, os.Remove(target.Name()))
|
||||
require.Equal(t, beforeRename, afterRename)
|
||||
}
|
||||
@ -129,3 +129,68 @@ EOF
|
||||
run cat $events_file
|
||||
is "$output" ".*\"Name\":\"$IMAGE" "test"
|
||||
}
|
||||
|
||||
function _populate_events_file() {
|
||||
# Create 100 duplicate entries to populate the events log file.
|
||||
local events_file=$1
|
||||
truncate --size=0 $events_file
|
||||
for i in {0..99}; do
|
||||
printf '{"Name":"busybox","Status":"pull","Time":"2022-04-06T11:26:42.7236679%02d+02:00","Type":"image","Attributes":null}\n' $i >> $events_file
|
||||
done
|
||||
}
|
||||
|
||||
@test "events log-file rotation" {
|
||||
skip_if_remote "setting CONTAINERS_CONF logger options does not affect remote client"
|
||||
|
||||
# Make sure that the events log file is (not) rotated depending on the
|
||||
# settings in containers.conf.
|
||||
|
||||
# Config without a limit
|
||||
eventsFile=$PODMAN_TMPDIR/events.txt
|
||||
_populate_events_file $eventsFile
|
||||
containersConf=$PODMAN_TMPDIR/containers.conf
|
||||
cat >$containersConf <<EOF
|
||||
[engine]
|
||||
events_logger="file"
|
||||
events_logfile_path="$eventsFile"
|
||||
EOF
|
||||
|
||||
# Create events *without* a limit and make sure that it has not been
|
||||
# rotated/truncated.
|
||||
contentBefore=$(head -n100 $eventsFile)
|
||||
CONTAINERS_CONF=$containersConf run_podman run --rm $IMAGE true
|
||||
contentAfter=$(head -n100 $eventsFile)
|
||||
is "$contentBefore" "$contentAfter" "events file has not been rotated"
|
||||
|
||||
# Repopulate events file
|
||||
rm $eventsFile
|
||||
_populate_events_file $eventsFile
|
||||
|
||||
# Config with a limit
|
||||
rm $containersConf
|
||||
cat >$containersConf <<EOF
|
||||
[engine]
|
||||
events_logger="file"
|
||||
events_logfile_path="$eventsFile"
|
||||
# The limit of 4750 is the *exact* half of the inital events file.
|
||||
events_logfile_max_size=4750
|
||||
EOF
|
||||
|
||||
# Create events *with* a limit and make sure that it has been
|
||||
# rotated/truncated. Once rotated, the events file should only contain the
|
||||
# second half of its previous events plus the new ones.
|
||||
expectedContentAfterTruncation=$PODMAN_TMPDIR/truncated.txt
|
||||
|
||||
run_podman create $IMAGE
|
||||
CONTAINERS_CONF=$containersConf run_podman rm $output
|
||||
tail -n52 $eventsFile >> $expectedContentAfterTruncation
|
||||
|
||||
# Make sure the events file looks as expected.
|
||||
is "$(cat $eventsFile)" "$(cat $expectedContentAfterTruncation)" "events file has been rotated"
|
||||
|
||||
# Make sure that `podman events` can read the file, and that it returns the
|
||||
# same amount of events. We checked the contents before.
|
||||
CONTAINERS_CONF=$containersConf run_podman events --stream=false --since="2022-03-06T11:26:42.723667984+02:00"
|
||||
is "$(wc -l <$eventsFile)" "$(wc -l <<<$output)" "all events are returned"
|
||||
is "${lines[-2]}" ".* log-rotation $eventsFile"
|
||||
}
|
||||
|
||||
Reference in New Issue
Block a user