diff --git a/example_test.go b/example_test.go index d085ac4..09332b5 100644 --- a/example_test.go +++ b/example_test.go @@ -10,9 +10,8 @@ import ( // the SetOutput function when your application starts. func Example() { log.SetOutput(&lumberjack.Logger{ - Dir: "/var/log/myapp/", - NameFormat: "2006-01-02T15-04-05.000.log", - MaxSize: lumberjack.Gigabyte, + Filename: "/var/log/myapp/foo.log", + MaxSize: 500, // megabytes MaxBackups: 3, MaxAge: 28, }) diff --git a/lumberjack.go b/lumberjack.go index b64f505..dcc2289 100644 --- a/lumberjack.go +++ b/lumberjack.go @@ -5,8 +5,8 @@ // component at the bottom of the logging stack that simply controls the files // to which logs are written. // -// Lumberjack plays well with any logger that can write to an io.Writer, -// including the standard library's log package. +// Lumberjack plays well with any logging package that can write to an +// io.Writer, including the standard library's log package. // // Lumberjack assumes that only one process is writing to the output files. // Using the same lumberjack configuration from multiple processes on the same @@ -20,67 +20,58 @@ import ( "os" "path/filepath" "sort" + "strings" "sync" "time" ) const ( - // Some helper constants to make your declarations easier to read. - - Megabyte = 1024 * 1024 - Gigabyte = 1024 * Megabyte - - defaultNameFormat = "2006-01-02T15-04-05.000.log" - defaultMaxSize = 100 * Megabyte + backupTimeFormat = "2006-01-02T15-04-05.000" + defaultMaxSize = 100 ) // ensure we always implement io.WriteCloser var _ io.WriteCloser = (*Logger)(nil) -// Logger is an io.WriteCloser that writes to a log file in the given directory -// with the given NameFormat. NameFormat should include a time formatting -// layout in it that produces a valid unique filename for the OS. For more -// about time formatting layouts, read http://golang.org/pkg/time/#pkg-constants. +// Logger is an io.WriteCloser that writes to the specified filename. // -// The date encoded in the filename by NameFormat is used to determine which log -// files are most recent in several situations. +// Logger opens or creates the logfile on first Write. If the file exists and +// is less than MaxSize megabytes, lumberjack will open and append to that file. +// If the file exists and its size is >= MaxSize megabytes, the file is renamed +// by putting the current time in a timestamp in the name immediately before the +// file's extension (or the end of the filename if there's no extension). A new +// log file is then created using original filename. // -// Logger opens or creates a logfile on first Write. It looks for files in the -// directory that match its name format, and if the one with the most recent -// NameFormat date is less than MaxSize, it will open and append to that file. -// If no such file exists, or the file is >= MaxSize, a new file is created -// using the current time with NameFormat to generate the filename. -// -// Whenever a write would cause the current log file exceed MaxSize, a new file -// is created using the current time. +// Whenever a write would cause the current log file exceed MaxSize megabytes, +// the current file is closed, renamed, and a new log file created with the +// original name. Thus, the filename you give Logger is always the "current" log +// file. // // Cleaning Up Old Log Files // -// Whenever a new file gets created, old log files may be deleted. The log file -// directory is scanned for files that match NameFormat. The most recent files -// according to their NameFormat date will be retained, up to a number equal to -// MaxBackups (or all of them if MaxBackups is 0). Any files with a last -// modified time (based on FileInfo.ModTime) older than MaxAge days are deleted, -// regardless of MaxBackups. +// Whenever a new logfile gets created, old log files may be deleted. The most +// recent files according to the encoded timestamp will be retained, up to a +// number equal to MaxBackups (or all of them if MaxBackups is 0). Any files +// with an encoded timestamp older than MaxAge days are deleted, regardless of +// MaxBackups. Note that the time encoded in the timestamp is the rotation +// time, which may differ from the last time that file was written to. // // If MaxBackups and MaxAge are both 0, no old log files will be deleted. type Logger struct { - // Dir determines the directory in which to store log files. - // It defaults to os.TempDir() if empty. - Dir string `json:"dir" yaml:"dir"` + // Filename is the file to write logs to. Backup log files will be retained + // in the same directory. It uses -lumberjack.log in + // os.TempDir() if empty. + Filename string `json:"filename" yaml:"filename"` - // NameFormat is the time formatting layout used to generate filenames. - // It defaults to "2006-01-02T15-04-05.000.log". - NameFormat string `json:"nameformat" yaml:"nameformat"` + // 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"` - // MaxSize is the maximum size in bytes of the log file before it gets - // rolled. It defaults to 100 megabytes. - MaxSize int64 `json:"maxsize" yaml:"maxsize"` - - // MaxAge is the maximum number of days to retain old log files based on - // FileInfo.ModTime. Note that a day is defined as 24 hours and may not - // exactly correspond to calendar days due to daylight savings, leap - // seconds, etc. The default is not to remove old log files based on age. + // MaxAge is the maximum number of days to retain old log files based on the + // timestamp encoded in their filename. Note that a day is defined as 24 + // hours and may not exactly correspond to calendar days due to daylight + // savings, leap seconds, etc. The default is not to remove old log files + // based on age. MaxAge int `json:"maxage" yaml:"maxage"` // MaxBackups is the maximum number of old log files to retain. The default @@ -88,8 +79,9 @@ type Logger struct { // deleted.) MaxBackups int `json:"maxbackups" yaml:"maxbackups"` - // LocalTime determines if the time used for formatting the filename is the - // computer's local time. The default is to use UTC time. + // LocalTime determines if the time used for formatting the timestamps in + // backup files is the computer's local time. The default is to use UTC + // time. LocalTime bool `json:"localtime" yaml:"localtime"` size int64 @@ -101,15 +93,16 @@ var ( // currentTime exists so it can be mocked out by tests. currentTime = time.Now - // day is the units that MaxAge converts into. It is a variable so we can - // change it during tests. - day = 24 * time.Hour + // megabyte is the conversion factor between MaxSize and bytes. It is a + // variable so tests can mock it out and not need to write megabytes of data + // to disk. + megabyte = 1024 * 1024 ) // Write implements io.Writer. If a write would cause the log file to be larger -// than MaxSize, a new log file is created using the current time formatted with -// PathFormat. If the length of the write is greater than MaxSize, an error is -// returned. +// than MaxSize, the file is closed, renamed to include a timestamp of the +// current time, and a new log file is created using the original log file name. +// If the length of the write is greater than MaxSize, an error is returned. func (l *Logger) Write(p []byte) (n int, err error) { l.mu.Lock() defer l.mu.Unlock() @@ -167,88 +160,101 @@ func (l *Logger) Rotate() error { return l.rotate() } -// rotate closes the current file, if any, opens a new file, and then calls +// rotate closes the current file, moves it aside with a timestamp in the name, +// (if it exists), opens a new file with the original filename, and then runs // cleanup. func (l *Logger) rotate() error { if err := l.close(); err != nil { return nil } + if err := l.openNew(); err != nil { return err } return l.cleanup() } -// openNew opens a new log file for writing. +// openNew opens a new log file for writing, moving any old log file out of the +// way. This methods assumes the file has already been closed. func (l *Logger) openNew() error { err := os.MkdirAll(l.dir(), 0744) if err != nil { return fmt.Errorf("can't make directories for new logfile: %s", err) } - f, err := os.OpenFile(l.genFilename(), os.O_CREATE|os.O_WRONLY, 0644) + + name := l.filename() + _, err = os.Stat(name) + if err == nil { + // move the existing file + newname := backupName(name, l.LocalTime) + if err := os.Rename(name, newname); err != nil { + return fmt.Errorf("can't rename log file: %s", err) + } + } + + // we use truncate here because this should only get called when we've moved + // the file ourselves. if someone else creates the file in the meantime, + // just wipe out the contents. + f, err := os.OpenFile(l.filename(), os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0644) if err != nil { return fmt.Errorf("can't open new logfile: %s", err) } - info, err := f.Stat() - if err != nil { - // can't really do anything if close fails here - _ = f.Close() - return fmt.Errorf("can't get size of new logfile: %s", err) - } - l.size = info.Size() l.file = f + l.size = 0 return nil } -// openExistingOrNew opens the most recently modified logfile in the log -// directory, if the current write would not put it over MaxSize. If there is -// no such file or the write would put it over the MaxSize, a new file is -// created. -func (l *Logger) openExistingOrNew(writeLen int) error { - if l.Dir == "" && l.NameFormat == "" { - return l.openNew() +// 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) + filename := filepath.Base(name) + ext := filepath.Ext(filename) + prefix := filename[:len(filename)-len(ext)] + t := currentTime() + if !local { + t = t.UTC() } - files, err := ioutil.ReadDir(l.dir()) + + timestamp := t.Format(backupTimeFormat) + return filepath.Join(dir, fmt.Sprintf("%s-%s%s", prefix, timestamp, ext)) +} + +// openExistingOrNew opens the logfile if it exists and if the current write +// would not put it over MaxSize. If there is no such file or the write would +// put it over the MaxSize, a new file is created. +func (l *Logger) openExistingOrNew(writeLen int) error { + filename := l.filename() + info, err := os.Stat(filename) if os.IsNotExist(err) { return l.openNew() } if err != nil { - return fmt.Errorf("can't read files in log file directory: %s", err) + return fmt.Errorf("error getting log file info: %s", err) } - sort.Sort(byFormatTime{files, l.format()}) - for _, info := range files { - if info.IsDir() { - continue + // the first file we find that matches our pattern will be the most + // recently modified log file. + if info.Size()+int64(writeLen) < l.max() { + file, err := os.OpenFile(filename, os.O_APPEND|os.O_WRONLY, 0644) + if err == nil { + l.file = file + l.size = info.Size() + return nil } - - if !l.isLogFile(info) { - continue - } - - // the first file we find that matches our pattern will be the most - // recently modified log file. - if info.Size()+int64(writeLen) < l.max() { - filename := filepath.Join(l.dir(), info.Name()) - file, err := os.OpenFile(filename, os.O_APPEND|os.O_WRONLY, 0644) - if err == nil { - l.file = file - return nil - } - // if we fail to open the old log file for some reason, just ignore - // it and open a new log file. - } - break + // if we fail to open the old log file for some reason, just ignore + // it and open a new log file. } return l.openNew() } // genFilename generates the name of the logfile from the current time. -func (l *Logger) genFilename() string { - t := currentTime() - if !l.LocalTime { - t = t.UTC() +func (l *Logger) filename() string { + if l.Filename != "" { + return l.Filename } - return filepath.Join(l.dir(), t.Format(l.format())) + name := filepath.Base(os.Args[0]) + "-lumberjack.log" + return filepath.Join(os.TempDir(), name) } // cleanup deletes old log files, keeping at most l.MaxBackups files, as long as @@ -263,19 +269,19 @@ func (l *Logger) cleanup() error { return err } - var deletes []os.FileInfo + var deletes []logInfo - if l.MaxBackups > 0 { + if l.MaxBackups > 0 && l.MaxBackups < len(files) { deletes = files[l.MaxBackups:] files = files[:l.MaxBackups] } if l.MaxAge > 0 { - diff := time.Duration(-1 * int64(day) * int64(l.MaxAge)) + diff := time.Duration(int64(24*time.Hour) * int64(l.MaxAge)) - cutoff := currentTime().Add(diff) + cutoff := currentTime().Add(-1 * diff) for _, f := range files { - if f.ModTime().Before(cutoff) { + if f.timestamp.Before(cutoff) { deletes = append(deletes, f) } } @@ -290,7 +296,7 @@ func (l *Logger) cleanup() error { return nil } -func deleteAll(dir string, files []os.FileInfo) { +func deleteAll(dir string, files []logInfo) { // remove files on a separate goroutine for _, f := range files { // what am I going to do, log this? @@ -300,84 +306,91 @@ func deleteAll(dir string, files []os.FileInfo) { // 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() ([]os.FileInfo, error) { +func (l *Logger) oldLogFiles() ([]logInfo, error) { files, err := ioutil.ReadDir(l.dir()) if err != nil { return nil, fmt.Errorf("can't read log file directory: %s", err) } - logFiles := []os.FileInfo{} + logFiles := []logInfo{} + + prefix, ext := l.prefixAndExt() for _, f := range files { if f.IsDir() { continue } - if filepath.Base(f.Name()) == filepath.Base(l.file.Name()) { + + name := l.timeFromName(f.Name(), prefix, ext) + if name == "" { continue } - - if l.isLogFile(f) { - logFiles = append(logFiles, f) + t, err := time.Parse(backupTimeFormat, name) + if err == nil { + logFiles = append(logFiles, logInfo{t, f}) } } - sort.Sort(byFormatTime{logFiles, l.format()}) + sort.Sort(byFormatTime(logFiles)) return logFiles, nil } -// isLogFile reports where the name of f fits the format of a logfile created by -// this Logger. -func (l *Logger) isLogFile(f os.FileInfo) bool { - _, err := time.Parse(l.format(), filepath.Base(f.Name())) - return err == nil +// timeFromName extracts the formatted time from the filename by stripping off +// the filename's prefix and extension. This prevents someone's filename from +// confusing time.parse. +func (l *Logger) timeFromName(filename, prefix, ext string) string { + if !strings.HasPrefix(filename, prefix) { + return "" + } + filename = filename[len(prefix):] + + if !strings.HasSuffix(filename, ext) { + return "" + } + filename = filename[:len(filename)-len(ext)] + return filename } -// max returns the maximum size of log files before rolling.. +// max returns the maximum size in bytes of log files before rolling. func (l *Logger) max() int64 { if l.MaxSize == 0 { - return defaultMaxSize + return int64(defaultMaxSize * megabyte) } - return l.MaxSize + return int64(l.MaxSize) * int64(megabyte) } -// dir returns the directory in which log files should be stored. +// dir returns the directory for the current filename. func (l *Logger) dir() string { - if l.Dir != "" { - return l.Dir - } - return os.TempDir() + return filepath.Dir(l.filename()) } -// format returns the name format for log files. -func (l *Logger) format() string { - if l.NameFormat != "" { - return l.NameFormat - } - return defaultNameFormat +// prefixAndExt returns the filename part and extension part from the Logger's +// filename. +func (l *Logger) prefixAndExt() (prefix, ext string) { + filename := filepath.Base(l.filename()) + ext = filepath.Ext(filename) + prefix = filename[:len(filename)-len(ext)] + "-" + return prefix, ext +} + +// logInfo is a convenience struct to return the filename and its embedded +// timestamp. +type logInfo struct { + timestamp time.Time + os.FileInfo } // byFormatTime sorts by newest time formatted in the name. -type byFormatTime struct { - files []os.FileInfo - format string -} +type byFormatTime []logInfo func (b byFormatTime) Less(i, j int) bool { - return b.time(i).After(b.time(j)) + return b[i].timestamp.After(b[j].timestamp) } func (b byFormatTime) Swap(i, j int) { - b.files[i], b.files[j] = b.files[j], b.files[i] + b[i], b[j] = b[j], b[i] } func (b byFormatTime) Len() int { - return len(b.files) -} - -func (b byFormatTime) time(i int) time.Time { - t, err := time.Parse(b.format, filepath.Base(b.files[i].Name())) - if err != nil { - return time.Time{} - } - return t + return len(b) } diff --git a/lumberjack_test.go b/lumberjack_test.go index 7ba1e44..d31889b 100644 --- a/lumberjack_test.go +++ b/lumberjack_test.go @@ -19,9 +19,6 @@ import ( // regular) failures, because they're all messing with the same global variable // that controls the logic's mocked time.Now. So... don't do that. -// make sure we set the format to something safe for windows, too. -const format = "2006-01-02T15-04-05.000" - // Since all the tests uses the time to determine filenames etc, we need to // control the wall clock as much as possible, which means having a wall clock // that doesn't change unless we want it to. @@ -37,8 +34,7 @@ func TestNewFile(t *testing.T) { dir := makeTempDir("TestNewFile", t) defer os.RemoveAll(dir) l := &Logger{ - Dir: dir, - NameFormat: format, + Filename: logFile(dir), } defer l.Close() b := []byte("boo!") @@ -61,8 +57,7 @@ func TestOpenExisting(t *testing.T) { existsWithLen(filename, len(data), t) l := &Logger{ - Dir: dir, - NameFormat: format, + Filename: filename, } defer l.Close() b := []byte("boo!") @@ -79,12 +74,12 @@ func TestOpenExisting(t *testing.T) { func TestWriteTooLong(t *testing.T) { currentTime = fakeTime + megabyte = 1 dir := makeTempDir("TestWriteTooLong", t) defer os.RemoveAll(dir) l := &Logger{ - Dir: dir, - NameFormat: format, - MaxSize: 5, + Filename: logFile(dir), + MaxSize: 5, } defer l.Close() b := []byte("booooooooooooooo!") @@ -99,12 +94,12 @@ func TestWriteTooLong(t *testing.T) { func TestMakeLogDir(t *testing.T) { currentTime = fakeTime - dir := time.Now().Format("TestMakeLogDir" + format) + dir := time.Now().Format("TestMakeLogDir" + backupTimeFormat) dir = filepath.Join(os.TempDir(), dir) defer os.RemoveAll(dir) + filename := logFile(dir) l := &Logger{ - Dir: dir, - NameFormat: format, + Filename: filename, } defer l.Close() b := []byte("boo!") @@ -115,49 +110,32 @@ func TestMakeLogDir(t *testing.T) { fileCount(dir, 1, t) } -func TestDefaultLogDir(t *testing.T) { - currentTime = fakeTime - dir := os.TempDir() - l := &Logger{ - NameFormat: format, - } - defer l.Close() - b := []byte("boo!") - n, err := l.Write(b) - defer os.Remove(logFile(dir)) - - isNil(err, t) - equals(len(b), n, t) - existsWithLen(logFile(dir), n, t) -} - func TestDefaultFilename(t *testing.T) { currentTime = fakeTime - dir := makeTempDir("TestDefaultFilename", t) - defer os.RemoveAll(dir) - l := &Logger{ - Dir: dir, - } + dir := os.TempDir() + filename := filepath.Join(dir, filepath.Base(os.Args[0])+"-lumberjack.log") + l := &Logger{} defer l.Close() b := []byte("boo!") n, err := l.Write(b) + defer os.Remove(filename) + isNil(err, t) equals(len(b), n, t) - - name := filepath.Join(dir, fakeTime().UTC().Format(defaultNameFormat)) - existsWithLen(name, n, t) - fileCount(dir, 1, t) + existsWithLen(filename, n, t) } func TestAutoRotate(t *testing.T) { currentTime = fakeTime + megabyte = 1 + dir := makeTempDir("TestAutoRotate", t) defer os.RemoveAll(dir) + filename := logFile(dir) l := &Logger{ - Dir: dir, - NameFormat: format, - MaxSize: 10, + Filename: filename, + MaxSize: 10, } defer l.Close() b := []byte("boo!") @@ -165,11 +143,9 @@ func TestAutoRotate(t *testing.T) { isNil(err, t) equals(len(b), n, t) - filename := logFile(dir) existsWithLen(filename, n, t) fileCount(dir, 1, t) - // set the current time one day later newFakeTime() b2 := []byte("foooooo!") @@ -177,33 +153,33 @@ func TestAutoRotate(t *testing.T) { isNil(err, t) equals(len(b2), n, t) - // this will use the new fake time - newFilename := logFile(dir) - existsWithLen(newFilename, n, t) + // the old logfile should be moved aside and the main logfile should have + // only the last write in it. + existsWithLen(filename, n, t) - // make sure the old file still exists with the same size. - existsWithLen(filename, len(b), t) + // the backup file will use the current fake time and have the old contents. + existsWithLen(backupFile(dir), len(b), t) fileCount(dir, 2, t) } func TestFirstWriteRotate(t *testing.T) { currentTime = fakeTime + megabyte = 1 dir := makeTempDir("TestFirstWriteRotate", t) defer os.RemoveAll(dir) + filename := logFile(dir) l := &Logger{ - Dir: dir, - NameFormat: format, - MaxSize: 10, + Filename: filename, + MaxSize: 10, } defer l.Close() - filename := logFile(dir) - err := ioutil.WriteFile(filename, []byte("boooooo!"), 0600) + start := []byte("boooooo!") + err := ioutil.WriteFile(filename, start, 0600) isNil(err, t) - // set the current time one day later newFakeTime() // this would make us rotate @@ -212,20 +188,21 @@ func TestFirstWriteRotate(t *testing.T) { isNil(err, t) equals(len(b), n, t) - filename2 := logFile(dir) - existsWithLen(filename2, n, t) + existsWithLen(filename, n, t) + existsWithLen(backupFile(dir), len(start), t) fileCount(dir, 2, t) } func TestMaxBackups(t *testing.T) { currentTime = fakeTime + megabyte = 1 dir := makeTempDir("TestMaxBackups", t) defer os.RemoveAll(dir) + filename := logFile(dir) l := &Logger{ - Dir: dir, - NameFormat: format, + Filename: filename, MaxSize: 10, MaxBackups: 1, } @@ -235,11 +212,9 @@ func TestMaxBackups(t *testing.T) { isNil(err, t) equals(len(b), n, t) - firstFilename := logFile(dir) - existsWithLen(firstFilename, n, t) + existsWithLen(filename, n, t) fileCount(dir, 1, t) - // set the current time one day later newFakeTime() // this will put us over the max @@ -249,15 +224,14 @@ func TestMaxBackups(t *testing.T) { equals(len(b2), n, t) // this will use the new fake time - secondFilename := logFile(dir) - existsWithLen(secondFilename, n, t) + secondFilename := backupFile(dir) + existsWithLen(secondFilename, len(b), t) // make sure the old file still exists with the same size. - existsWithLen(firstFilename, len(b), t) + existsWithLen(filename, n, t) fileCount(dir, 2, t) - // set the current time one day later newFakeTime() // this will make us rotate again @@ -266,8 +240,10 @@ func TestMaxBackups(t *testing.T) { equals(len(b2), n, t) // this will use the new fake time - thirdFilename := logFile(dir) - existsWithLen(thirdFilename, n, t) + thirdFilename := backupFile(dir) + existsWithLen(thirdFilename, len(b2), t) + + existsWithLen(filename, n, t) // we need to wait a little bit since the files get deleted on a different // goroutine. @@ -277,25 +253,24 @@ func TestMaxBackups(t *testing.T) { fileCount(dir, 2, t) // second file name should still exist - existsWithLen(secondFilename, n, t) + existsWithLen(thirdFilename, len(b2), t) - // should have deleted the first filename - notExist(firstFilename, t) + // should have deleted the first backup + notExist(secondFilename, t) // now test that we don't delete directories or non-logfile files - // set the current time one day later newFakeTime() // create a file that is close to but different from the logfile name. - /// It shouldn't get caught by our deletion filters. + // 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 := logFile(dir) + notlogfiledir := backupFile(dir) err = os.Mkdir(notlogfiledir, 0700) isNil(err, t) @@ -307,8 +282,8 @@ func TestMaxBackups(t *testing.T) { equals(len(b2), n, t) // this will use the new fake time - fourthFilename := logFile(dir) - existsWithLen(fourthFilename, n, t) + fourthFilename := backupFile(dir) + existsWithLen(fourthFilename, len(b2), t) // we need to wait a little bit since the files get deleted on a different // goroutine. @@ -318,11 +293,13 @@ func TestMaxBackups(t *testing.T) { // not log file, and the directory fileCount(dir, 4, t) - // second file name should still exist - existsWithLen(thirdFilename, n, t) + // third file name should still exist + existsWithLen(filename, n, t) + + existsWithLen(fourthFilename, len(b2), t) // should have deleted the first filename - notExist(firstFilename, t) + notExist(thirdFilename, t) // the not-a-logfile should still exist exists(notlogfile, t) @@ -333,21 +310,16 @@ func TestMaxBackups(t *testing.T) { func TestMaxAge(t *testing.T) { currentTime = fakeTime + megabyte = 1 - // change how maxage is interpreted from days to milliseconds - day = time.Millisecond - - // This test uses ModTime on files, and so we need to make sure we're using - // the most current time possible. - fakeCurrentTime = time.Now() dir := makeTempDir("TestMaxAge", t) defer os.RemoveAll(dir) + filename := logFile(dir) l := &Logger{ - Dir: dir, - NameFormat: format, - MaxSize: 10, - MaxAge: 10, + Filename: filename, + MaxSize: 10, + MaxAge: 1, } defer l.Close() b := []byte("boo!") @@ -355,45 +327,122 @@ func TestMaxAge(t *testing.T) { isNil(err, t) equals(len(b), n, t) - filename := logFile(dir) existsWithLen(filename, n, t) fileCount(dir, 1, t) - // We need to wait for wall clock time since MaxAge uses file ModTime, which - // can't be mocked. - <-time.After(50 * time.Millisecond) - fakeCurrentTime = time.Now() + // two days later + newFakeTime() b2 := []byte("foooooo!") n, err = l.Write(b2) isNil(err, t) equals(len(b2), n, t) + existsWithLen(backupFile(dir), len(b), t) // we need to wait a little bit since the files get deleted on a different // goroutine. <-time.After(10 * time.Millisecond) - // We should have just one log file - fileCount(dir, 1, t) + // We should still have 2 log files, since the most recent backup was just + // created. + fileCount(dir, 2, t) - // this will use the new fake time - newFilename := logFile(dir) - existsWithLen(newFilename, n, t) + existsWithLen(filename, len(b2), t) // we should have deleted the old file due to being too old - notExist(filename, t) + existsWithLen(backupFile(dir), len(b), t) + + // two days later + newFakeTime() + + b3 := []byte("foooooo!") + n, err = l.Write(b2) + isNil(err, t) + equals(len(b3), n, t) + existsWithLen(backupFile(dir), len(b2), t) + + // we need to wait a little bit since the files get deleted on a different + // goroutine. + <-time.After(10 * time.Millisecond) + + // We should have 2 log files - the main log file, and the most recent + // backup. The earlier backup is past the cutoff and should be gone. + fileCount(dir, 2, t) + + existsWithLen(filename, len(b3), t) + + // we should have deleted the old file due to being too old + existsWithLen(backupFile(dir), len(b2), t) + +} + +func TestOldLogFiles(t *testing.T) { + currentTime = fakeTime + megabyte = 1 + + dir := makeTempDir("TestOldLogFiles", t) + defer os.RemoveAll(dir) + + filename := logFile(dir) + data := []byte("data") + err := ioutil.WriteFile(filename, data, 07) + isNil(err, t) + + // This gives us a time with the same precision as the time we get from the + // timestamp in the name. + t1, err := time.Parse(backupTimeFormat, fakeTime().UTC().Format(backupTimeFormat)) + isNil(err, t) + + backup := backupFile(dir) + err = ioutil.WriteFile(backup, data, 07) + isNil(err, t) + + newFakeTime() + + t2, err := time.Parse(backupTimeFormat, fakeTime().UTC().Format(backupTimeFormat)) + isNil(err, t) + + backup2 := backupFile(dir) + err = ioutil.WriteFile(backup2, data, 07) + isNil(err, t) + + l := &Logger{Filename: filename} + files, err := l.oldLogFiles() + isNil(err, t) + equals(2, len(files), t) + + // should be sorted by newest file first, which would be t2 + equals(t2, files[0].timestamp, t) + equals(t1, files[1].timestamp, t) +} + +func TestTimeFromName(t *testing.T) { + l := &Logger{Filename: "/var/log/myfoo/foo.log"} + prefix, ext := l.prefixAndExt() + val := l.timeFromName("foo-2014-05-04T14-44-33.555.log", prefix, ext) + equals("2014-05-04T14-44-33.555", val, t) + + val = l.timeFromName("foo-2014-05-04T14-44-33.555", prefix, ext) + equals("", val, t) + + val = l.timeFromName("2014-05-04T14-44-33.555.log", prefix, ext) + equals("", val, t) + + val = l.timeFromName("foo.log", prefix, ext) + equals("", val, t) } func TestLocalTime(t *testing.T) { currentTime = fakeTime + megabyte = 1 dir := makeTempDir("TestLocalTime", t) defer os.RemoveAll(dir) l := &Logger{ - Dir: dir, - NameFormat: format, - LocalTime: true, + Filename: logFile(dir), + MaxSize: 10, + LocalTime: true, } defer l.Close() b := []byte("boo!") @@ -401,41 +450,13 @@ func TestLocalTime(t *testing.T) { isNil(err, t) equals(len(b), n, t) - filename := logFileLocal(dir) - existsWithLen(filename, n, t) -} - -func TestDefaultDirAndName(t *testing.T) { - currentTime = fakeTime - - l := &Logger{MaxSize: Megabyte} - defer l.Close() - b := []byte("boo!") - n, err := l.Write(b) - filename := filepath.Join(os.TempDir(), fakeTime().UTC().Format(defaultNameFormat)) - defer os.Remove(filename) - + b2 := []byte("fooooooo!") + n2, err := l.Write(b2) isNil(err, t) - equals(len(b), n, t) + equals(len(b2), n2, t) - existsWithLen(filename, n, t) - - err = l.Close() - isNil(err, t) - - newFakeTime() - - // even though the old file is under MaxSize, we should write a new file - // to prevent two processes using lumberjack from writing to the same file. - n, err = l.Write(b) - - f2 := filepath.Join(os.TempDir(), fakeTime().UTC().Format(defaultNameFormat)) - defer os.Remove(f2) - - isNil(err, t) - equals(len(b), n, t) - - existsWithLen(f2, n, t) + existsWithLen(logFile(dir), n2, t) + existsWithLen(backupFileLocal(dir), n, t) } func TestRotate(t *testing.T) { @@ -443,11 +464,12 @@ func TestRotate(t *testing.T) { dir := makeTempDir("TestRotate", t) defer os.RemoveAll(dir) + filename := logFile(dir) + l := &Logger{ - Dir: dir, - NameFormat: format, + Filename: filename, MaxBackups: 1, - MaxSize: Megabyte, + MaxSize: 100, // megabytes } defer l.Close() b := []byte("boo!") @@ -455,11 +477,9 @@ func TestRotate(t *testing.T) { isNil(err, t) equals(len(b), n, t) - filename := logFile(dir) existsWithLen(filename, n, t) fileCount(dir, 1, t) - // set the current time one day later newFakeTime() err = l.Rotate() @@ -469,12 +489,11 @@ func TestRotate(t *testing.T) { // goroutine. <-time.After(10 * time.Millisecond) - filename2 := logFile(dir) - existsWithLen(filename2, 0, t) - existsWithLen(filename, n, t) + filename2 := backupFile(dir) + existsWithLen(filename2, n, t) + existsWithLen(filename, 0, t) fileCount(dir, 2, t) - // set the current time one day later newFakeTime() err = l.Rotate() @@ -484,9 +503,9 @@ func TestRotate(t *testing.T) { // goroutine. <-time.After(10 * time.Millisecond) - filename3 := logFile(dir) + filename3 := backupFile(dir) existsWithLen(filename3, 0, t) - existsWithLen(filename2, 0, t) + existsWithLen(filename, 0, t) fileCount(dir, 2, t) b2 := []byte("foooooo!") @@ -495,14 +514,13 @@ func TestRotate(t *testing.T) { equals(len(b2), n, t) // this will use the new fake time - existsWithLen(filename3, n, t) + existsWithLen(filename, n, t) } func TestJson(t *testing.T) { data := []byte(` { - "dir": "foo", - "nameformat": "bar", + "filename": "foo", "maxsize": 5, "maxage": 10, "maxbackups": 3, @@ -512,9 +530,8 @@ func TestJson(t *testing.T) { l := Logger{} err := json.Unmarshal(data, &l) isNil(err, t) - equals("foo", l.Dir, t) - equals("bar", l.NameFormat, t) - equals(int64(5), l.MaxSize, t) + equals("foo", l.Filename, t) + equals(5, l.MaxSize, t) equals(10, l.MaxAge, t) equals(3, l.MaxBackups, t) equals(true, l.LocalTime, t) @@ -522,8 +539,7 @@ func TestJson(t *testing.T) { func TestYaml(t *testing.T) { data := []byte(` -dir: foo -nameformat: bar +filename: foo maxsize: 5 maxage: 10 maxbackups: 3 @@ -532,9 +548,8 @@ localtime: true`[1:]) l := Logger{} err := yaml.Unmarshal(data, &l) isNil(err, t) - equals("foo", l.Dir, t) - equals("bar", l.NameFormat, t) - equals(int64(5), l.MaxSize, t) + equals("foo", l.Filename, t) + equals(5, l.MaxSize, t) equals(10, l.MaxAge, t) equals(3, l.MaxBackups, t) equals(true, l.LocalTime, t) @@ -542,8 +557,7 @@ localtime: true`[1:]) func TestToml(t *testing.T) { data := ` -dir = "foo" -nameformat = "bar" +filename = "foo" maxsize = 5 maxage = 10 maxbackups = 3 @@ -552,9 +566,8 @@ localtime = true`[1:] l := Logger{} md, err := toml.Decode(data, &l) isNil(err, t) - equals("foo", l.Dir, t) - equals("bar", l.NameFormat, t) - equals(int64(5), l.MaxSize, t) + equals("foo", l.Filename, t) + equals(5, l.MaxSize, t) equals(10, l.MaxAge, t) equals(3, l.MaxBackups, t) equals(true, l.LocalTime, t) @@ -565,7 +578,7 @@ localtime = true`[1:] // It should be based on the name of the test, to keep parallel tests from // colliding, and must be cleaned up after the test is finished. func makeTempDir(name string, t testing.TB) string { - dir := time.Now().Format(name + format) + dir := time.Now().Format(name + backupTimeFormat) dir = filepath.Join(os.TempDir(), dir) isNilUp(os.Mkdir(dir, 0777), t, 1) return dir @@ -581,13 +594,21 @@ func existsWithLen(path string, length int, t testing.TB) { // logFile returns the log file name in the given directory for the current fake // time. func logFile(dir string) string { - return filepath.Join(dir, fakeTime().UTC().Format(format)) + return filepath.Join(dir, "foobar.log") +} + +func backupFile(dir string) string { + return filepath.Join(dir, "foobar-"+fakeTime().UTC().Format(backupTimeFormat)+".log") +} + +func backupFileLocal(dir string) string { + return filepath.Join(dir, "foobar-"+fakeTime().Format(backupTimeFormat)+".log") } // logFileLocal returns the log file name in the given directory for the current // fake time using the local timezone. func logFileLocal(dir string) string { - return filepath.Join(dir, fakeTime().Format(format)) + return filepath.Join(dir, fakeTime().Format(backupTimeFormat)) } // fileCount checks that the number of files in the directory is exp. @@ -598,9 +619,9 @@ func fileCount(dir string, exp int, t testing.TB) { equalsUp(exp, len(files), t, 1) } -// newFakeTime sets the fake "current time" to one day later. +// newFakeTime sets the fake "current time" to two days later. func newFakeTime() { - fakeCurrentTime = fakeCurrentTime.Add(time.Hour * 24) + fakeCurrentTime = fakeCurrentTime.Add(time.Hour * 24 * 2) } func notExist(path string, t testing.TB) {