From 0bd137e73a72d92c39768f26f019a5865cc75e6a Mon Sep 17 00:00:00 2001 From: lmbsog0 Date: Mon, 14 Mar 2022 13:51:36 +0100 Subject: [PATCH 1/2] fix #152 --- lumberjack.go | 26 ++- lumberjack_test.go | 442 +++++++++++++++++++++++++++++++++++++++++++++ 2 files changed, 462 insertions(+), 6 deletions(-) diff --git a/lumberjack.go b/lumberjack.go index 3447cdc..126c9b0 100644 --- a/lumberjack.go +++ b/lumberjack.go @@ -82,6 +82,10 @@ type Logger struct { // os.TempDir() if empty. Filename string `json:"filename" yaml:"filename"` + // BackupDirectory is the directory to store logs to. It will store the + // backups in the same folder specified by Filename if empty. + BackupDirectory string `json:backupdirectory yaml:"backupdirectory"` + // MaxSize is the maximum size in megabytes of the log file before it gets // rotated. It defaults to 100 megabytes. MaxSize int `json:"maxsize" yaml:"maxsize"` @@ -218,7 +222,7 @@ func (l *Logger) openNew() error { // Copy the mode off the old logfile. mode = info.Mode() // move the existing file - newname := backupName(name, l.LocalTime) + newname := l.backupName(name, l.LocalTime) if err := os.Rename(name, newname); err != nil { return fmt.Errorf("can't rename log file: %s", err) } @@ -244,8 +248,8 @@ func (l *Logger) openNew() error { // backupName creates a new filename from the given name, inserting a timestamp // between the filename and the extension, using the local time if requested // (otherwise UTC). -func backupName(name string, local bool) string { - dir := filepath.Dir(name) +func (l *Logger) backupName(name string, local bool) string { + dir := l.backupDirectory() filename := filepath.Base(name) ext := filepath.Ext(filename) prefix := filename[:len(filename)-len(ext)] @@ -297,6 +301,16 @@ func (l *Logger) filename() string { return filepath.Join(os.TempDir(), name) } +func (l *Logger) backupDirectory() (result string) { + if l.BackupDirectory != "" { + result = l.BackupDirectory + } else { + result = filepath.Dir(l.filename()) + } + + return result +} + // millRunOnce performs compression and removal of stale log files. // Log files are compressed if enabled via configuration and old log // files are removed, keeping at most l.MaxBackups files, as long as @@ -357,13 +371,13 @@ func (l *Logger) millRunOnce() error { } for _, f := range remove { - errRemove := os.Remove(filepath.Join(l.dir(), f.Name())) + errRemove := os.Remove(filepath.Join(l.backupDirectory(), f.Name())) if err == nil && errRemove != nil { err = errRemove } } for _, f := range compress { - fn := filepath.Join(l.dir(), f.Name()) + fn := filepath.Join(l.backupDirectory(), f.Name()) errCompress := compressLogFile(fn, fn+compressSuffix) if err == nil && errCompress != nil { err = errCompress @@ -398,7 +412,7 @@ func (l *Logger) mill() { // oldLogFiles returns the list of backup log files stored in the same // directory as the current log file, sorted by ModTime func (l *Logger) oldLogFiles() ([]logInfo, error) { - files, err := ioutil.ReadDir(l.dir()) + files, err := ioutil.ReadDir(l.backupDirectory()) if err != nil { return nil, fmt.Errorf("can't read log file directory: %s", err) } diff --git a/lumberjack_test.go b/lumberjack_test.go index 484ee9d..d5f8cda 100644 --- a/lumberjack_test.go +++ b/lumberjack_test.go @@ -165,6 +165,51 @@ func TestAutoRotate(t *testing.T) { fileCount(dir, 2, t) } +func TestAutoRotateInBackupDirectory(t *testing.T) { + currentTime = fakeTime + megabyte = 1 + + dir := makeTempDir("TestAutoRotate", t) + backupDir := filepath.Join(dir, "backup") + isNilUp(os.Mkdir(backupDir, 0700), t, 1) + defer os.RemoveAll(dir) + + filename := logFile(dir) + l := &Logger{ + Filename: filename, + BackupDirectory: backupDir, + MaxSize: 10, + } + defer l.Close() + b := []byte("boo!") + n, err := l.Write(b) + isNil(err, t) + equals(len(b), n, t) + + existsWithContent(filename, b, t) + + // we expect to have the backup directory as well as the active log file + // here. + fileCount(dir, 2, t) + + newFakeTime() + + b2 := []byte("foooooo!") + n, err = l.Write(b2) + isNil(err, t) + equals(len(b2), n, t) + + // the old logfile should be moved in the backup directory and the main + // logfile should have only the last write in it. + existsWithContent(filename, b2, t) + + // the backup file will use the current fake time and have the old contents. + existsWithContent(backupFile(backupDir), b, t) + + fileCount(dir, 2, t) + fileCount(backupDir, 1, t) +} + func TestFirstWriteRotate(t *testing.T) { currentTime = fakeTime megabyte = 1 @@ -196,6 +241,41 @@ func TestFirstWriteRotate(t *testing.T) { fileCount(dir, 2, t) } +func TestFirstWriteRotateInBackupDirectory(t *testing.T) { + currentTime = fakeTime + megabyte = 1 + dir := makeTempDir("TestFirstWriteRotate", t) + backupDir := filepath.Join(dir, "backup") + isNilUp(os.Mkdir(backupDir, 0700), t, 1) + defer os.RemoveAll(dir) + + filename := logFile(dir) + l := &Logger{ + Filename: filename, + BackupDirectory: backupDir, + MaxSize: 10, + } + defer l.Close() + + start := []byte("boooooo!") + err := ioutil.WriteFile(filename, start, 0600) + isNil(err, t) + + newFakeTime() + + // this would make us rotate + b := []byte("fooo!") + n, err := l.Write(b) + isNil(err, t) + equals(len(b), n, t) + + existsWithContent(filename, b, t) + existsWithContent(backupFile(backupDir), start, t) + + fileCount(dir, 2, t) + fileCount(backupDir, 1, t) +} + func TestMaxBackups(t *testing.T) { currentTime = fakeTime megabyte = 1 @@ -321,6 +401,142 @@ func TestMaxBackups(t *testing.T) { exists(notlogfiledir, t) } +func TestMaxBackupsInBackupDir(t *testing.T) { + currentTime = fakeTime + megabyte = 1 + dir := makeTempDir("TestMaxBackups", t) + backupDir := filepath.Join(dir, "backup") + isNilUp(os.Mkdir(backupDir, 0700), t, 1) + defer os.RemoveAll(dir) + + filename := logFile(dir) + l := &Logger{ + Filename: filename, + BackupDirectory: backupDir, + MaxSize: 10, + MaxBackups: 1, + } + defer l.Close() + b := []byte("boo!") + n, err := l.Write(b) + isNil(err, t) + equals(len(b), n, t) + + existsWithContent(filename, b, t) + + // we expect to have the backup directory as well as the active log file + // here. + fileCount(dir, 2, t) + + newFakeTime() + + // this will put us over the max + b2 := []byte("foooooo!") + n, err = l.Write(b2) + isNil(err, t) + equals(len(b2), n, t) + + // this will use the new fake time + secondFilename := backupFile(backupDir) + existsWithContent(secondFilename, b, t) + + // make sure the old file still exists with the same content. + existsWithContent(filename, b2, t) + + fileCount(dir, 2, t) + + newFakeTime() + + // this will make us rotate again + b3 := []byte("baaaaaar!") + n, err = l.Write(b3) + isNil(err, t) + equals(len(b3), n, t) + + // this will use the new fake time + thirdFilename := backupFile(backupDir) + existsWithContent(thirdFilename, b2, t) + + existsWithContent(filename, b3, t) + + // we need to wait a little bit since the files get deleted on a different + // goroutine. + <-time.After(time.Millisecond * 10) + + // should only have two files in the dir still + fileCount(dir, 2, t) + + // second file name should still exist + existsWithContent(thirdFilename, b2, t) + + // should have deleted the first backup + notExist(secondFilename, t) + + // now test that we don't delete directories or non-logfile files + + newFakeTime() + + // create a file that is close to but different from the logfile name. + // It shouldn't get caught by our deletion filters. + notlogfile := logFile(dir) + ".foo" + err = ioutil.WriteFile(notlogfile, []byte("data"), 0644) + isNil(err, t) + + // Make a directory that exactly matches our log file filters... it still + // shouldn't get caught by the deletion filter since it's a directory. + notlogfiledir := backupFile(backupDir) + err = os.Mkdir(notlogfiledir, 0700) + isNil(err, t) + + newFakeTime() + + // this will use the new fake time + fourthFilename := backupFile(backupDir) + + // Create a log file that is/was being compressed - this should + // not be counted since both the compressed and the uncompressed + // log files still exist. + compLogFile := fourthFilename + compressSuffix + err = ioutil.WriteFile(compLogFile, []byte("compress"), 0644) + isNil(err, t) + + // this will make us rotate again + b4 := []byte("baaaaaaz!") + n, err = l.Write(b4) + isNil(err, t) + equals(len(b4), n, t) + + existsWithContent(fourthFilename, b3, t) + existsWithContent(fourthFilename+compressSuffix, []byte("compress"), t) + + // we need to wait a little bit since the files get deleted on a different + // goroutine. + <-time.After(time.Millisecond * 10) + + // We should have tree things in the directory now - the log file, the not + // log file, and the directory + fileCount(dir, 3, t) + + // We should have tree things in the directory now - the log file as + // directory, the compressed log file and the not log file and the log + // file. + fileCount(backupDir, 3, t) + + // third file name should still exist + existsWithContent(filename, b4, t) + + existsWithContent(fourthFilename, b3, t) + + // should have deleted the first filename + notExist(thirdFilename, t) + + // the not-a-logfile should still exist + exists(notlogfile, t) + + // the directory + exists(notlogfiledir, t) +} + func TestCleanupExistingBackups(t *testing.T) { // test that if we start with more backup files than we're supposed to have // in total, that extra ones get cleaned up when we rotate. @@ -377,6 +593,67 @@ func TestCleanupExistingBackups(t *testing.T) { fileCount(dir, 2, t) } +func TestCleanupExistingBackupsInBackupDir(t *testing.T) { + // test that if we start with more backup files than we're supposed to have + // in total, that extra ones get cleaned up when we rotate. + + currentTime = fakeTime + megabyte = 1 + + dir := makeTempDir("TestCleanupExistingBackups", t) + backupDir := filepath.Join(dir, "backup") + isNilUp(os.Mkdir(backupDir, 0700), t, 1) + defer os.RemoveAll(dir) + + // make 3 backup files + + data := []byte("data") + backup := backupFile(backupDir) + err := ioutil.WriteFile(backup, data, 0644) + isNil(err, t) + + newFakeTime() + + backup = backupFile(backupDir) + err = ioutil.WriteFile(backup+compressSuffix, data, 0644) + isNil(err, t) + + newFakeTime() + + backup = backupFile(backupDir) + err = ioutil.WriteFile(backup, data, 0644) + isNil(err, t) + + // now create a primary log file with some data + filename := logFile(dir) + err = ioutil.WriteFile(filename, data, 0644) + isNil(err, t) + + l := &Logger{ + Filename: filename, + BackupDirectory: backupDir, + MaxSize: 10, + MaxBackups: 1, + } + defer l.Close() + + newFakeTime() + + b2 := []byte("foooooo!") + n, err := l.Write(b2) + isNil(err, t) + equals(len(b2), n, t) + + // we need to wait a little bit since the files get deleted on a different + // goroutine. + <-time.After(time.Millisecond * 10) + + // now we should only have 1 file left - one backup + fileCount(backupDir, 1, t) + // and the primary log file (plus the backup folder) + fileCount(dir, 2, t) +} + func TestMaxAge(t *testing.T) { currentTime = fakeTime megabyte = 1 @@ -590,6 +867,67 @@ func TestRotate(t *testing.T) { existsWithContent(filename, b2, t) } +func TestRotateInBackupDir(t *testing.T) { + currentTime = fakeTime + dir := makeTempDir("TestRotate", t) + backupDir := filepath.Join(dir, "backup") + isNilUp(os.Mkdir(backupDir, 0700), t, 1) + defer os.RemoveAll(dir) + + filename := logFile(dir) + + l := &Logger{ + Filename: filename, + BackupDirectory: backupDir, + MaxBackups: 1, + MaxSize: 100, // megabytes + } + defer l.Close() + b := []byte("boo!") + n, err := l.Write(b) + isNil(err, t) + equals(len(b), n, t) + + existsWithContent(filename, b, t) + fileCount(dir, 2, t) + + newFakeTime() + + err = l.Rotate() + isNil(err, t) + + // we need to wait a little bit since the files get deleted on a different + // goroutine. + <-time.After(10 * time.Millisecond) + + filename2 := backupFile(backupDir) + existsWithContent(filename2, b, t) + existsWithContent(filename, []byte{}, t) + fileCount(dir, 2, t) + fileCount(backupDir, 1, t) + newFakeTime() + + err = l.Rotate() + isNil(err, t) + + // we need to wait a little bit since the files get deleted on a different + // goroutine. + <-time.After(10 * time.Millisecond) + + filename3 := backupFile(backupDir) + existsWithContent(filename3, []byte{}, t) + existsWithContent(filename, []byte{}, t) + fileCount(backupDir, 1, t) + + b2 := []byte("foooooo!") + n, err = l.Write(b2) + isNil(err, t) + equals(len(b2), n, t) + + // this will use the new fake time + existsWithContent(filename, b2, t) +} + func TestCompressOnRotate(t *testing.T) { currentTime = fakeTime megabyte = 1 @@ -639,6 +977,58 @@ func TestCompressOnRotate(t *testing.T) { fileCount(dir, 2, t) } +func TestCompressOnRotateInBackupDir(t *testing.T) { + currentTime = fakeTime + megabyte = 1 + + dir := makeTempDir("TestCompressOnRotate", t) + backupDir := filepath.Join(dir, "backup") + isNilUp(os.Mkdir(backupDir, 0700), t, 1) + defer os.RemoveAll(dir) + + filename := logFile(dir) + l := &Logger{ + Compress: true, + Filename: filename, + BackupDirectory: backupDir, + MaxSize: 10, + } + defer l.Close() + b := []byte("boo!") + n, err := l.Write(b) + isNil(err, t) + equals(len(b), n, t) + + existsWithContent(filename, b, t) + fileCount(dir, 2, t) + + newFakeTime() + + err = l.Rotate() + isNil(err, t) + + // the old logfile should be moved aside and the main logfile should have + // nothing in it. + existsWithContent(filename, []byte{}, t) + + // we need to wait a little bit since the files get compressed on a different + // goroutine. + <-time.After(300 * time.Millisecond) + + // a compressed version of the log file should now exist and the original + // should have been removed. + bc := new(bytes.Buffer) + gz := gzip.NewWriter(bc) + _, err = gz.Write(b) + isNil(err, t) + err = gz.Close() + isNil(err, t) + existsWithContent(backupFile(backupDir)+compressSuffix, bc.Bytes(), t) + notExist(backupFile(backupDir), t) + + fileCount(dir, 2, t) +} + func TestCompressOnResume(t *testing.T) { currentTime = fakeTime megabyte = 1 @@ -688,6 +1078,58 @@ func TestCompressOnResume(t *testing.T) { fileCount(dir, 2, t) } +func TestCompressOnResumeInBackupDir(t *testing.T) { + currentTime = fakeTime + megabyte = 1 + + dir := makeTempDir("TestCompressOnResume", t) + backupDir := filepath.Join(dir, "backup") + isNilUp(os.Mkdir(backupDir, 0700), t, 1) + defer os.RemoveAll(dir) + + filename := logFile(dir) + l := &Logger{ + Compress: true, + Filename: filename, + BackupDirectory: backupDir, + MaxSize: 10, + } + defer l.Close() + + // Create a backup file and empty "compressed" file. + filename2 := backupFile(backupDir) + b := []byte("foo!") + err := ioutil.WriteFile(filename2, b, 0644) + isNil(err, t) + err = ioutil.WriteFile(filename2+compressSuffix, []byte{}, 0644) + isNil(err, t) + + newFakeTime() + + b2 := []byte("boo!") + n, err := l.Write(b2) + isNil(err, t) + equals(len(b2), n, t) + existsWithContent(filename, b2, t) + + // we need to wait a little bit since the files get compressed on a different + // goroutine. + <-time.After(300 * time.Millisecond) + + // The write should have started the compression - a compressed version of + // the log file should now exist and the original should have been removed. + bc := new(bytes.Buffer) + gz := gzip.NewWriter(bc) + _, err = gz.Write(b) + isNil(err, t) + err = gz.Close() + isNil(err, t) + existsWithContent(filename2+compressSuffix, bc.Bytes(), t) + notExist(filename2, t) + + fileCount(dir, 2, t) +} + func TestJson(t *testing.T) { data := []byte(` { From 97179efb168d147990aa5901464d12484364de14 Mon Sep 17 00:00:00 2001 From: lmbsog0 Date: Thu, 17 Mar 2022 14:44:07 +0100 Subject: [PATCH 2/2] fix rename issue when backup directory is not on the same partition --- lumberjack.go | 42 ++++++++++++++++++++++++++++++++++++++++-- 1 file changed, 40 insertions(+), 2 deletions(-) diff --git a/lumberjack.go b/lumberjack.go index 126c9b0..a303c6c 100644 --- a/lumberjack.go +++ b/lumberjack.go @@ -223,8 +223,19 @@ func (l *Logger) openNew() error { mode = info.Mode() // move the existing file newname := l.backupName(name, l.LocalTime) - if err := os.Rename(name, newname); err != nil { - return fmt.Errorf("can't rename log file: %s", err) + + // If the backup directory is not located on the same partition as the + // active log directory, the os.Rename call might fail. Thus, we check if + // the active and the backup directories are the same first, and copy the + // content of the active log into the backup log if it is not the case. + if l.backupDirectory() == l.dir() { + if err := os.Rename(name, newname); err != nil { + return fmt.Errorf("can't rename log file: %s", err) + } + } else { + if err := moveFile(name, newname); err != nil { + return fmt.Errorf("can't move log file: %s", err) + } } // this is a no-op anywhere but linux @@ -532,6 +543,33 @@ func compressLogFile(src, dst string) (err error) { return nil } +// moveFile moves a file from a source to a destination. This function is used when +// the file is moved from locations in different partitions of the file system. +func moveFile(sourcePath, destPath string) error { + inputFile, err := os.Open(sourcePath) + if err != nil { + return err + } + outputFile, err := os.Create(destPath) + if err != nil { + _ = inputFile.Close() + return err + } + defer func() { _ = outputFile.Close() }() + if _, err = io.Copy(outputFile, inputFile); err != nil { + return err + } + if err = inputFile.Close(); err != nil { + return err + } + // The copy was successful, so now delete the original file + err = os.Remove(sourcePath) + if err != nil { + return err + } + return nil +} + // logInfo is a convenience struct to return the filename and its embedded // timestamp. type logInfo struct {