Skip to content

Commit

Permalink
log rotation: addressing PR feedback
Browse files Browse the repository at this point in the history
  • Loading branch information
javicrespo committed May 1, 2019
1 parent cd92162 commit c9a8261
Show file tree
Hide file tree
Showing 7 changed files with 103 additions and 68 deletions.
19 changes: 11 additions & 8 deletions cmd/telegraf/telegraf.go
Original file line number Diff line number Diff line change
Expand Up @@ -114,7 +114,7 @@ func runAgent(ctx context.Context,
) error {
// Setup default logging. This may need to change after reading the config
// file, but we can configure it to use our logger implementation now.
logger.SetupLogging(false, false, "", internal.Duration{Duration: 0}, internal.Size{Size: int64(0)}, 0)
logger.SetupLogging(logger.LogConfig{})
log.Printf("I! Starting Telegraf %s", version)

// If no other options are specified, load the config file and run.
Expand Down Expand Up @@ -155,13 +155,16 @@ func runAgent(ctx context.Context,
}

// Setup logging as configured.
logger.SetupLogging(
ag.Config.Agent.Debug || *fDebug,
ag.Config.Agent.Quiet || *fQuiet,
ag.Config.Agent.Logfile,
ag.Config.Agent.LogfileRotationInterval,
ag.Config.Agent.LogfileRotationMaxSize,
ag.Config.Agent.LogfileRotationMaxArchives)
logConfig := logger.LogConfig{
Debug: ag.Config.Agent.Debug || *fDebug,
Quiet: ag.Config.Agent.Quiet || *fQuiet,
Logfile: ag.Config.Agent.Logfile,
RotationInterval: ag.Config.Agent.LogfileRotationInterval,
RotationMaxSize: ag.Config.Agent.LogfileRotationMaxSize,
RotationMaxArchives: ag.Config.Agent.LogfileRotationMaxArchives,
}

logger.SetupLogging(logConfig)

if *fTest {
return ag.Test(ctx)
Expand Down
2 changes: 1 addition & 1 deletion docs/CONFIGURATION.md
Original file line number Diff line number Diff line change
Expand Up @@ -147,7 +147,7 @@ The agent table configures Telegraf and the defaults used across all plugins.
The log file max [size][]. Log files will be rotated when they exceed this size. Default is 0 => no rotation based on file size.
- **logfile_rotation_max_archives**:
Maximum number of archives (rotated) files to keep. Older log files are deleted first.
This setting is only applicable if MaxAge and/or MaxSize settings have been specified (otherwise there is no rotation)
This setting is only applicable if `logfile_rotation_interval` and/or `logfile_rotation_max_size` settings have been specified (otherwise there is no rotation)
Default is 0 => all rotated files are deleted. Use -1 to keep all archives.

- **hostname**:
Expand Down
2 changes: 1 addition & 1 deletion internal/config/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -288,7 +288,7 @@ var agentConfig = `
## The log file max size. Log files will be rotated when they exceed this size. Default is 0 => no rotation based on file size.
# logfile_rotation_max_size = "10 MB"
## Maximum number of archives (rotated) files to keep. Older log files are deleted first.
## This setting is only applicable if MaxAge and/or MaxSize settings have been specified (otherwise there is no rotation)
## This setting is only applicable if logfile_rotation_interval and/or logfile_rotation_max_size settings have been specified (otherwise there is no rotation)
## Default is 0 => all rotated files are deleted.
## Use -1 to keep all archives.
## Analogous to logrotate "rotate" setting http://man7.org/linux/man-pages/man8/logrotate.8.html
Expand Down
53 changes: 28 additions & 25 deletions internal/rotate/file_writer.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,7 +7,6 @@ import (
"os"
"path/filepath"
"sort"
"strconv"
"strings"
"sync"
"time"
Expand All @@ -17,7 +16,7 @@ import (
// the files it creates.
const (
FilePerm = os.FileMode(0644)
DateFormat = "2006-01-02"
DateFormat = "2006-01-02T150405"
)

// FileWriter implements the io.Writer interface and writes to the
Expand All @@ -44,10 +43,15 @@ func NewFileWriter(filename string, interval time.Duration, maxSizeInBytes int64
return openFile(filename)
}

w := &FileWriter{filename: filename, interval: interval, maxSizeInBytes: maxSizeInBytes,
maxArchives: maxArchives, filenameRotationTemplate: getFilenameRotationTemplate(filename)}
w := &FileWriter{
filename: filename,
interval: interval,
maxSizeInBytes: maxSizeInBytes,
maxArchives: maxArchives,
filenameRotationTemplate: getFilenameRotationTemplate(filename),
}

if err := w.openCurrent(true); err != nil {
if err := w.openCurrent(); err != nil {
return nil, err
}

Expand All @@ -62,8 +66,8 @@ func getFilenameRotationTemplate(filename string) string {
// Extract the file extension
fileExt := filepath.Ext(filename)
// Remove the file extension from the filename (if any)
filenameWithoutExtension := strings.TrimSuffix(filename, fileExt)
return filenameWithoutExtension + "-%s-%s" + fileExt
stem := strings.TrimSuffix(filename, fileExt)
return stem + ".%s" + fileExt
}

// Write writes p to the current file, then checks to see if
Expand All @@ -90,7 +94,7 @@ func (w *FileWriter) Close() (err error) {
defer w.Unlock()

// Rotate before closing
if err = w.rotate(false); err != nil {
if err = w.rotate(); err != nil {
return err
}

Expand All @@ -101,21 +105,21 @@ func (w *FileWriter) Close() (err error) {
return nil
}

func (w *FileWriter) openCurrent(firstRun bool) (err error) {
w.current, err = openFile(w.filename)
func (w *FileWriter) openCurrent() (err error) {
// In case ModTime() fails, we use time.Now()
w.expireTime = time.Now().Add(w.interval)
w.bytesWritten = 0
w.current, err = openFile(w.filename)

if err != nil {
return err
}
if !firstRun {
return nil
}

// Goal here is to rotate old pre-existing files. For that we use fileInfo.ModTime, instead of time.Now(), only when the FileWriter is created (firstRun)
// Example: telegraf is restarted every 23 hours and the rotation interval is set to 24 hours. With time.now() as a reference we'd never rotate the file.
// It's only necessary to use modtime when the filewriter is created, otherwise we assume that we've been continuously running, so time.now is fine.
// Goal here is to rotate old pre-existing files.
// For that we use fileInfo.ModTime, instead of time.Now().
// Example: telegraf is restarted every 23 hours and
// the rotation interval is set to 24 hours.
// With time.now() as a reference we'd never rotate the file.
if fileInfo, err := w.current.Stat(); err == nil {
w.expireTime = fileInfo.ModTime().Add(w.interval)
}
Expand All @@ -125,18 +129,20 @@ func (w *FileWriter) openCurrent(firstRun bool) (err error) {
func (w *FileWriter) rotateIfNeeded() error {
if (w.interval > 0 && time.Now().After(w.expireTime)) ||
(w.maxSizeInBytes > 0 && w.bytesWritten >= w.maxSizeInBytes) {
return w.rotate(true)
if err := w.rotate(); err != nil {
//Ignore rotation errors and keep the log open
fmt.Printf("unable to rotate the file '%s', %s", w.filename, err.Error())
}
return w.openCurrent()
}
return nil
}

func (w *FileWriter) rotate(createNewFile bool) (err error) {
func (w *FileWriter) rotate() (err error) {
if err = w.current.Close(); err != nil {
return err
}
now := time.Now()
// Use year-month-date for readability, unix time to make archive names unique
rotatedFilename := fmt.Sprintf(w.filenameRotationTemplate, now.Format(DateFormat), strconv.FormatInt(now.UnixNano(), 10))
rotatedFilename := fmt.Sprintf(w.filenameRotationTemplate, time.Now().Format(DateFormat))
if err = os.Rename(w.filename, rotatedFilename); err != nil {
return err
}
Expand All @@ -145,9 +151,6 @@ func (w *FileWriter) rotate(createNewFile bool) (err error) {
return err
}

if createNewFile {
return w.openCurrent(false)
}
return nil
}

Expand All @@ -158,7 +161,7 @@ func (w *FileWriter) purgeArchivesIfNeeded() (err error) {
}

var matches []string
if matches, err = filepath.Glob(fmt.Sprintf(w.filenameRotationTemplate, "*", "*")); err != nil {
if matches, err = filepath.Glob(fmt.Sprintf(w.filenameRotationTemplate, "*")); err != nil {
return err
}

Expand Down
9 changes: 7 additions & 2 deletions internal/rotate/file_writer_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -59,7 +59,7 @@ func TestFileWriter_SizeRotation(t *testing.T) {
assert.Equal(t, 2, len(files))
}

func TestFileWriter_deleteArchives(t *testing.T) {
func TestFileWriter_DeleteArchives(t *testing.T) {
tempDir, err := ioutil.TempDir("", "RotationDeleteArchives")
require.NoError(t, err)
maxSize := int64(5)
Expand All @@ -69,8 +69,13 @@ func TestFileWriter_deleteArchives(t *testing.T) {

_, err = writer.Write([]byte("First file"))
require.NoError(t, err)
// File names include the date with second precision
// So, to force rotation with different file names
// we need to wait
time.Sleep(1 * time.Second)
_, err = writer.Write([]byte("Second file"))
require.NoError(t, err)
time.Sleep(1 * time.Second)
_, err = writer.Write([]byte("Third file"))
require.NoError(t, err)

Expand Down Expand Up @@ -106,5 +111,5 @@ func TestFileWriter_CloseRotates(t *testing.T) {

files, _ := ioutil.ReadDir(tempDir)
assert.Equal(t, 1, len(files))
assert.Regexp(t, "^test-[^\\.]+\\.log$", files[0].Name())
assert.Regexp(t, "^test\\.[^\\.]+\\.log$", files[0].Name())
}
51 changes: 31 additions & 20 deletions logger/logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,12 +18,32 @@ var prefixRegex = regexp.MustCompile("^[DIWE]!")
// newTelegrafWriter returns a logging-wrapped writer.
func newTelegrafWriter(w io.Writer) io.Writer {
return &telegrafLog{
writer: wlog.NewWriter(w),
writer: wlog.NewWriter(w),
internalWriter: w,
}
}

// LogConfig contains the log configuration settings
type LogConfig struct {
// will set the log level to DEBUG
Debug bool
//will set the log level to ERROR
Quiet bool
// will direct the logging output to a file. Empty string is
// interpreted as stderr. If there is an error opening the file the
// logger will fallback to stderr
Logfile string
// will rotate when current file at the specified time interval
RotationInterval internal.Duration
// will rotate when current file size exceeds this parameter.
RotationMaxSize internal.Size
// maximum rotated files to keep (older ones will be deleted)
RotationMaxArchives int
}

type telegrafLog struct {
writer io.Writer
writer io.Writer
internalWriter io.Writer
}

func (t *telegrafLog) Write(b []byte) (n int, err error) {
Expand All @@ -37,41 +57,32 @@ func (t *telegrafLog) Write(b []byte) (n int, err error) {
}

func (t *telegrafLog) Close() error {
closer, isCloser := t.writer.(io.Closer)
closer, isCloser := t.internalWriter.(io.Closer)
if !isCloser {
return errors.New("the underlying writer cannot be closed")
}
return closer.Close()
}

// SetupLogging configures the logging output.
// debug will set the log level to DEBUG
// quiet will set the log level to ERROR
// logfile will direct the logging output to a file. Empty string is
// interpreted as stderr. If there is an error opening the file the
// logger will fallback to stderr.
// logRotationInterval will rotate when current file at the specified time interval.
// logRotationMaxSize will rotate when current file size exceeds this parameter.
// logRotationMaxArchives maximum rotated files to keep (older ones will be deleted)
func SetupLogging(debug, quiet bool, logfile string, logRotationInterval internal.Duration, logRotationMaxSize internal.Size, logRotationMaxArchives int) {
setupLoggingAndReturnWriter(debug, quiet, logfile, logRotationInterval, logRotationMaxSize, logRotationMaxArchives)
func SetupLogging(config LogConfig) {
setupLoggingAndReturnWriter(config)
}

func setupLoggingAndReturnWriter(debug, quiet bool, logfile string, logRotationInterval internal.Duration, logRotationMaxSize internal.Size,
logRotationMaxArchives int) io.Writer {
func setupLoggingAndReturnWriter(config LogConfig) io.Writer {
log.SetFlags(0)
if debug {
if config.Debug {
wlog.SetLevel(wlog.DEBUG)
}
if quiet {
if config.Quiet {
wlog.SetLevel(wlog.ERROR)
}

var writer io.Writer
if logfile != "" {
if config.Logfile != "" {
var err error
if writer, err = rotate.NewFileWriter(logfile, logRotationInterval.Duration, logRotationMaxSize.Size, logRotationMaxArchives); err != nil {
log.Printf("E! Unable to open %s (%s), using stderr", logfile, err)
if writer, err = rotate.NewFileWriter(config.Logfile, config.RotationInterval.Duration, config.RotationMaxSize.Size, config.RotationMaxArchives); err != nil {
log.Printf("E! Unable to open %s (%s), using stderr", config.Logfile, err)
writer = os.Stderr
}
} else {
Expand Down
35 changes: 24 additions & 11 deletions logger/logger_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,7 +19,8 @@ func TestWriteLogToFile(t *testing.T) {
assert.NoError(t, err)
defer func() { os.Remove(tmpfile.Name()) }()

SetupLogging(false, false, tmpfile.Name(), internal.Duration{Duration: 0}, internal.Size{Size: int64(0)}, 0)
config := createBasicLogConfig(tmpfile.Name())
SetupLogging(config)
log.Printf("I! TEST")
log.Printf("D! TEST") // <- should be ignored

Expand All @@ -32,8 +33,9 @@ func TestDebugWriteLogToFile(t *testing.T) {
tmpfile, err := ioutil.TempFile("", "")
assert.NoError(t, err)
defer func() { os.Remove(tmpfile.Name()) }()

SetupLogging(true, false, tmpfile.Name(), internal.Duration{Duration: 0}, internal.Size{Size: int64(0)}, 0)
config := createBasicLogConfig(tmpfile.Name())
config.Debug = true
SetupLogging(config)
log.Printf("D! TEST")

f, err := ioutil.ReadFile(tmpfile.Name())
Expand All @@ -45,8 +47,9 @@ func TestErrorWriteLogToFile(t *testing.T) {
tmpfile, err := ioutil.TempFile("", "")
assert.NoError(t, err)
defer func() { os.Remove(tmpfile.Name()) }()

SetupLogging(false, true, tmpfile.Name(), internal.Duration{Duration: 0}, internal.Size{Size: int64(0)}, 0)
config := createBasicLogConfig(tmpfile.Name())
config.Quiet = true
SetupLogging(config)
log.Printf("E! TEST")
log.Printf("I! TEST") // <- should be ignored

Expand All @@ -59,8 +62,9 @@ func TestAddDefaultLogLevel(t *testing.T) {
tmpfile, err := ioutil.TempFile("", "")
assert.NoError(t, err)
defer func() { os.Remove(tmpfile.Name()) }()

SetupLogging(true, false, tmpfile.Name(), internal.Duration{Duration: 0}, internal.Size{Size: int64(0)}, 0)
config := createBasicLogConfig(tmpfile.Name())
config.Debug = true
SetupLogging(config)
log.Printf("TEST")

f, err := ioutil.ReadFile(tmpfile.Name())
Expand All @@ -72,8 +76,9 @@ func TestWriteToTruncatedFile(t *testing.T) {
tmpfile, err := ioutil.TempFile("", "")
assert.NoError(t, err)
defer func() { os.Remove(tmpfile.Name()) }()

SetupLogging(true, false, tmpfile.Name(), internal.Duration{Duration: 0}, internal.Size{Size: int64(0)}, 0)
config := createBasicLogConfig(tmpfile.Name())
config.Debug = true
SetupLogging(config)
log.Printf("TEST")

f, err := ioutil.ReadFile(tmpfile.Name())
Expand All @@ -94,8 +99,9 @@ func TestWriteToTruncatedFile(t *testing.T) {
func TestWriteToFileInRotation(t *testing.T) {
tempDir, err := ioutil.TempDir("", "LogRotation")
require.NoError(t, err)
writer := setupLoggingAndReturnWriter(false, false, filepath.Join(tempDir, "test.log"),
internal.Duration{Duration: 0}, internal.Size{Size: int64(30)}, -1)
config := createBasicLogConfig(filepath.Join(tempDir, "test.log"))
config.RotationMaxSize = internal.Size{Size: int64(30)}
writer := setupLoggingAndReturnWriter(config)
// Close the writer here, otherwise the temp folder cannot be deleted because the current log file is in use.
closer, isCloser := writer.(io.Closer)
assert.True(t, isCloser)
Expand All @@ -116,3 +122,10 @@ func BenchmarkTelegrafLogWrite(b *testing.B) {
w.Write(msg)
}
}

func createBasicLogConfig(filename string) LogConfig {
return LogConfig{
Logfile: filename,
RotationMaxArchives: -1,
}
}

0 comments on commit c9a8261

Please sign in to comment.