diff --git a/lumberjack.go b/lumberjack.go new file mode 100644 index 0000000..c3bf1cf --- /dev/null +++ b/lumberjack.go @@ -0,0 +1,378 @@ +// Package lumberjack provides a rolling logger. +// +// Lumberjack is intended to be one part of a logging infrastructure. +// It is not an all-in-one solution, but instead is a pluggable +// 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. +// +// For example, to use lumberjack with the std lib's log package, just pass it +// into the SetOutput function when your application starts: +// +// log.SetOutput(&lumberjack.Logger{ +// Dir: "/var/log/myapp/" +// NameFormat: time.RFC822+".log", +// MaxSize: lumberjack.Gigabyte, +// Backups: 3, +// MaxAge: lumberjack.Week * 4, +// )) +// +// Note that lumberjack assumes whatever is writing to it will use locks to +// prevent concurrent writes. Lumberjack does not implement its own lock. +package lumberjack + +import ( + "fmt" + "io" + "io/ioutil" + "os" + "path/filepath" + "sort" + "time" +) + +const ( + // Some helper constants to make your declarations easier to read. + Megabyte = 1024 * 1024 + Gigabyte = 1024 * Megabyte + + // note that lumberjack days and weeks may not exactly conform to calendar + // days and weeks due to daylight savings, leap seconds, etc. + Day = 24 * time.Hour + Week = 7 * Day + + defaultNameFormat = "2006-01-02T15-04-05.000.log" + defaultMaxSize = 100 * Megabyte +) + +// ensure we always implement io.WriteCloser +var _ io.WriteCloser = &Logger{} + +// 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 filename for the OS. For more about time +// formatting layouts, read http://golang.org/pkg/time/#pkg-constants. +// +// Logger opens or creates the logfile on first Write. If the most recently +// modified file in the log file directory that matches the NameFormat is less +// than MaxSize, that file will be appended to. If no file such exists, a new +// file is created using the current time to generate the filename. +// +// Whenever a write would cause the current log file exceed MaxSize, a new file +// is created using the current time. +// +// 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 recently +// modified files which are newer than MaxAge (up to a number of files equal to +// Backups) are retained, all other log files are deleted. +// +// Defaults +// +// If Dir is empty, the files will be created in os.TempDir(). +// +// If NameFormat is empty, will be used as the +// name format. +// +// If MaxSize is 0, 100 megabytes will be used as the max size. +// +// if MaxAge is 0, last modification time will not be used to delete old log +// files. +// +// If Backups is 0, there's no limit to the number of old log files that will be +// retained, as long as they're newer than MaxAge. +// +// If MaxAge and Backups are both 0, no old log files will be deteled. +// +// Thus, an default lumberjack.Logger struct will log to os.TempDir() with a 100 +// megabyte max size and never delete old log files. +type Logger struct { + // Dir determines the directory in which to store log files. + // It defaults to os.TempDir() if empty. + Dir string + + // NameFormat is the time formatting layout used to generate filenames. + // It defaults to "2006-01-02T15-04-05.000.log". + NameFormat string + + // MaxSize is the maximum size in bytes of the log file before it gets + // rolled. It defaults to 100 megabytes. + MaxSize int64 + + // MaxAge is the maximum time to retain old log files. The default is not + // to remove old log files based on age. + MaxAge time.Duration + + // Backups is the maximum number of old log files to retain. The default is + // to retain all old log files (though MaxAge may still cause them to get + // deleted.) + Backups int + + // LocalTime determines if the time used for formatting the filename is the + // computer's local time. The default is to use UTC time. + LocalTime bool + + size int64 + file *os.File +} + +// currentTime is only used for testing. Normally it's the time.Now() function. +var currentTime = time.Now + +// 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 that satisfies IsWriteTooLong. +func (l *Logger) Write(p []byte) (n int, err error) { + writeLen := int64(len(p)) + if writeLen > l.max() { + return 0, writeTooLongError{fmt.Errorf( + "write length %d exceeds maximum file size %d", writeLen, l.max(), + )} + } + f := l.file + rotate := l.size+writeLen > l.max() + if f == nil { + if f, err = l.openExistingOrNew(len(p)); err != nil { + return 0, err + } + } else if rotate { + if f, err = l.openNew(); err != nil { + return 0, err + } + } + + n, err = f.Write(p) + l.size += int64(n) + + if rotate { + if err := l.cleanup(); err != nil { + return 0, err + } + } + + if l.file != nil && rotate { + l.file.Close() + } + l.file = f + return n, err +} + +// openNew opens a new log file for writing. +func (l *Logger) openNew() (*os.File, error) { + err := os.MkdirAll(l.dir(), 0744) + if err != nil { + return nil, fmt.Errorf("can't make directories for new logfile: %s", err) + } + filename := l.genFilename() + f, err := os.OpenFile(filename, os.O_CREATE|os.O_WRONLY, 0644) + if err != nil { + return nil, 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 nil, fmt.Errorf("can't get size of new logfile: %s", err) + } + l.size = info.Size() + return f, 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) (*os.File, error) { + files, err := ioutil.ReadDir(l.dir()) + if os.IsNotExist(err) { + return l.openNew() + } + if err != nil { + return nil, fmt.Errorf("can't read files in log file directory: %s", err) + } + sort.Sort(byFormatTime{files, l.format()}) + for _, f := range files { + if f.IsDir() { + continue + } + + if !l.isLogFile(f) { + continue + } + + // the first file we find that matches our pattern will be the most + // recently modified log file. + if f.Size()+int64(writeLen) < l.max() { + filename := filepath.Join(l.dir(), f.Name()) + file, err := os.OpenFile(filename, os.O_APPEND|os.O_WRONLY, 0644) + if err == nil { + return file, nil + } + // if we fail to open the old log file for some reason, just ignore + // it and open a new log file. + } + break + } + 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() + } + return filepath.Join(l.dir(), t.Format(l.format())) +} + +// cleanup deletes old log files, keeping at most l.Backups files, as long as +// none of them are older than MaxAge. +func (l *Logger) cleanup() error { + if l.Backups == 0 && l.MaxAge == 0 { + return nil + } + + files, err := l.oldLogFiles() + if err != nil { + return err + } + + var deletes []os.FileInfo + + if l.Backups > 0 { + deletes = files[l.Backups:] + files = files[:l.Backups] + } + + if l.MaxAge > 0 { + cutoff := currentTime().Add(-1 * l.MaxAge) + for _, f := range files { + if f.ModTime().Before(cutoff) { + deletes = append(deletes, f) + } + } + } + + if len(deletes) == 0 { + return nil + } + + go deleteAll(l.dir(), deletes) + + return nil +} + +func deleteAll(dir string, files []os.FileInfo) { + // remove files on a separate goroutine + for _, f := range files { + // what am I going to do, log this? + _ = os.Remove(filepath.Join(dir, f.Name())) + } +} + +// 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) { + files, err := ioutil.ReadDir(l.dir()) + if err != nil { + return nil, fmt.Errorf("can't read log file directory: %s", err) + } + logFiles := []os.FileInfo{} + + for _, f := range files { + if f.IsDir() { + continue + } + if filepath.Base(f.Name()) == filepath.Base(l.file.Name()) { + continue + } + + if l.isLogFile(f) { + logFiles = append(logFiles, f) + } + } + + sort.Sort(byFormatTime{logFiles, l.format()}) + + return logFiles, nil +} + +func (l *Logger) isLogFile(f os.FileInfo) bool { + _, err := time.Parse(l.format(), filepath.Base(f.Name())) + return err == nil +} + +// Close implements io.Closer, and closes the current logfile. +func (l *Logger) Close() error { + if l.file != nil { + err := l.file.Close() + l.file = nil + return err + } + return nil +} + +func (l *Logger) max() int64 { + if l.MaxSize == 0 { + return defaultMaxSize + } + return l.MaxSize +} + +func (l *Logger) dir() string { + if l.Dir != "" { + return l.Dir + } + return os.TempDir() +} + +func (l *Logger) format() string { + if l.NameFormat != "" { + return l.NameFormat + } + return defaultNameFormat +} + +// byFormatTime sorts by newest time formatted in the name. +type byFormatTime struct { + files []os.FileInfo + format string +} + +func (b byFormatTime) Less(i, j int) bool { + return b.time(i).After(b.time(j)) +} + +func (b byFormatTime) Swap(i, j int) { + b.files[i], b.files[j] = b.files[j], b.files[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 +} + +// IsWriteTooLong returns whether the given error reports a write to Logger that +// exceeds the Logger's MaxSize. +func IsWriteTooLong(err error) bool { + if err == nil { + return false + } + _, ok := err.(writeTooLongError) + return ok +} + +type writeTooLongError struct { + error +} diff --git a/lumberjack_test.go b/lumberjack_test.go new file mode 100644 index 0000000..7645507 --- /dev/null +++ b/lumberjack_test.go @@ -0,0 +1,241 @@ +package lumberjack + +import ( + "io/ioutil" + "os" + "path/filepath" + "testing" + "time" +) + +// make sure we set the format to something safe for windows, too. +const format = "2006-01-02T15-04-05.000" + +// this is the expected format for faketime goven the +const timeString = "2009-11-10T13-22-33.444" + +var fakeCurrentTime = time.Date(2009, time.November, 10, 13, 22, 33, 444000000, time.UTC) + +func fakeTime() time.Time { + return fakeCurrentTime +} + +func TestFakeTime(t *testing.T) { + // test the tests + s := fakeTime().Format(format) + equals(timeString, s, t) +} + +func TestNewFile(t *testing.T) { + currentTime = fakeTime + dir := makeTempDir("TestNewFile", t) + defer os.RemoveAll(dir) + l := &Logger{ + Dir: dir, + NameFormat: format, + MaxSize: Megabyte, + } + defer l.Close() + b := []byte("boo!") + n, err := l.Write(b) + isNil(err, t) + equals(len(b), n, t) + existsWithLen(logFile(dir), n, t) + fileCount(dir, 1, t) +} + +func TestOpenExisting(t *testing.T) { + currentTime = fakeTime + dir := makeTempDir("TestOpenExisting", t) + defer os.RemoveAll(dir) + + filename := logFile(dir) + data := []byte("foo!") + err := ioutil.WriteFile(filename, data, 0644) + isNil(err, t) + existsWithLen(filename, len(data), t) + + l := &Logger{ + Dir: dir, + NameFormat: format, + MaxSize: Megabyte, + } + defer l.Close() + b := []byte("boo!") + n, err := l.Write(b) + isNil(err, t) + equals(len(b), n, t) + + // make sure the file got appended + existsWithLen(filename, len(data)+n, t) + + // make sure no other files were created + fileCount(dir, 1, t) +} + +func TestWriteTooLong(t *testing.T) { + currentTime = fakeTime + dir := makeTempDir("TestWriteTooLong", t) + defer os.RemoveAll(dir) + l := &Logger{ + Dir: dir, + NameFormat: format, + MaxSize: 5, + } + defer l.Close() + b := []byte("booooooooooooooo!") + n, err := l.Write(b) + assert(IsWriteTooLong(err), t, + "Should have gotten write too long error, instead got %s (%T)", err, err) + equals(0, n, t) + _, err = os.Stat(logFile(dir)) + assert(os.IsNotExist(err), t, "File exists, but should not have been created") +} + +func TestRotate(t *testing.T) { + currentTime = fakeTime + dir := makeTempDir("TestRotate", t) + defer os.RemoveAll(dir) + + l := &Logger{ + Dir: dir, + NameFormat: format, + MaxSize: 10, + } + defer l.Close() + b := []byte("boo!") + n, err := l.Write(b) + 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 + defer newFakeTime()() + + b2 := []byte("foooooo!") + n, err = l.Write(b2) + isNil(err, t) + equals(len(b2), n, t) + + // this will use the new fake time + newFilename := logFile(dir) + existsWithLen(newFilename, n, t) + + // make sure the old file still exists with the same size. + existsWithLen(filename, len(b), t) + + fileCount(dir, 2, t) +} + +func TestBackups(t *testing.T) { + currentTime = fakeTime + dir := makeTempDir("TestBackups", t) + defer os.RemoveAll(dir) + + l := &Logger{ + Dir: dir, + NameFormat: format, + MaxSize: 10, + Backups: 1, + } + defer l.Close() + b := []byte("boo!") + n, err := l.Write(b) + isNil(err, t) + equals(len(b), n, t) + + firstFilename := logFile(dir) + existsWithLen(firstFilename, n, t) + fileCount(dir, 1, t) + + // set the current time one day later + defer 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 := logFile(dir) + existsWithLen(secondFilename, n, t) + + // make sure the old file still exists with the same size. + existsWithLen(firstFilename, len(b), t) + + fileCount(dir, 2, t) + + // set the current time one day later + defer newFakeTime()() + + // this will make us rotate again + n, err = l.Write(b2) + isNil(err, t) + equals(len(b2), n, t) + + // this will use the new fake time + thirdFilename := logFile(dir) + existsWithLen(thirdFilename, n, 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 + existsWithLen(secondFilename, n, t) + + // should have deleted the first filename + notExist(firstFilename, t) +} + +// makeTempDir creates a file with a semi-unique name in the OS temp directory. +// 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 = filepath.Join(os.TempDir(), dir) + isNilUp(os.Mkdir(dir, 0777), t, 1) + return dir +} + +// existsWithLen checks that the given file exists and has the correct length. +func existsWithLen(path string, length int, t testing.TB) { + info, err := os.Stat(path) + isNilUp(err, t, 1) + equalsUp(int64(length), info.Size(), t, 1) +} + +// 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().Format(format)) +} + +// fileCount checks that the number of files in the directory is exp. +func fileCount(dir string, exp int, t testing.TB) { + files, err := ioutil.ReadDir(dir) + isNilUp(err, t, 1) + // Make sure no other files were created. + equalsUp(exp, len(files), t, 1) +} + +// newFakeTime sets the fake "current time" to one day later. +func newFakeTime() func() { + old := fakeCurrentTime + fakeCurrentTime = fakeCurrentTime.Add(Day) + return func() { + fakeCurrentTime = old + } +} + +func notExist(path string, t testing.TB) { + _, err := os.Stat(path) + assertUp(os.IsNotExist(err), t, 1, "expected to get os.IsNotExist, but instead got %s", err) +} diff --git a/testing_test.go b/testing_test.go new file mode 100644 index 0000000..2b1b944 --- /dev/null +++ b/testing_test.go @@ -0,0 +1,72 @@ +package lumberjack + +import ( + "fmt" + "path/filepath" + "reflect" + "runtime" + "testing" +) + +func assert(condition bool, t testing.TB, msg string, v ...interface{}) { + assertUp(condition, t, 1, msg, v...) +} + +func assertUp(condition bool, t testing.TB, caller int, msg string, v ...interface{}) { + if !condition { + _, file, line, _ := runtime.Caller(caller + 1) + v = append([]interface{}{filepath.Base(file), line}, v...) + fmt.Printf("%s:%d: "+msg+"\n", v...) + t.FailNow() + } +} + +func equals(exp, act interface{}, t testing.TB) { + equalsUp(exp, act, t, 1) +} + +func equalsUp(exp, act interface{}, t testing.TB, caller int) { + if !reflect.DeepEqual(exp, act) { + _, file, line, _ := runtime.Caller(caller + 1) + fmt.Printf("%s:%d: exp: %v (%T), got: %v (%T)\n", + filepath.Base(file), line, exp, exp, act, act) + t.FailNow() + } +} + +func isNil(obtained interface{}, t testing.TB) { + isNilUp(obtained, t, 1) +} + +func isNilUp(obtained interface{}, t testing.TB, caller int) { + if !_isNil(obtained) { + _, file, line, _ := runtime.Caller(caller + 1) + fmt.Printf("%s:%d: expected nil, got: %v\n", filepath.Base(file), line, obtained) + t.FailNow() + } +} + +func notNil(obtained interface{}, t testing.TB) { + notNilUp(obtained, t, 1) +} + +func notNilUp(obtained interface{}, t testing.TB, caller int) { + if _isNil(obtained) { + _, file, line, _ := runtime.Caller(caller + 1) + fmt.Printf("%s:%d: expected non-nil, got: %v\n", filepath.Base(file), line, obtained) + t.FailNow() + } +} + +func _isNil(obtained interface{}) bool { + if obtained == nil { + return true + } + + switch v := reflect.ValueOf(obtained); v.Kind() { + case reflect.Chan, reflect.Func, reflect.Interface, reflect.Map, reflect.Ptr, reflect.Slice: + return v.IsNil() + } + + return false +}