initial code

2014-06-14 07:57:17 -04:00
parent 79e51fbec1
commit 1c3db7d9ea
3 changed files with 691 additions and 0 deletions
@@ -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
+}
@@ -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)
+}
@@ -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
+}