Fixed goroutine leak, made tests deterministic

example_test.go

@@ -3,7 +3,7 @@ package lumberjack_test
 import (
 	"log"
 
-	"gopkg.in/natefinch/lumberjack.v2"
+	"github.com/tanium/lumberjack"
 )
 
 // To use lumberjack with the standard library's log package, just pass it into
@@ -13,7 +13,7 @@ func Example() {
 		Filename:   "/var/log/myapp/foo.log",
 		MaxSize:    500, // megabytes
 		MaxBackups: 3,
-		MaxAge:     28, // days
+		MaxAge:     28,   // days
 		Compress:   true, // disabled by default
 	})
 }

linux_test.go

@@ -4,9 +4,9 @@ package lumberjack
 
 import (
 	"os"
+	"sync"
 	"syscall"
 	"testing"
-	"time"
 )
 
 func TestMaintainMode(t *testing.T) {
@@ -98,10 +98,11 @@ func TestCompressMaintainMode(t *testing.T) {
 	f.Close()
 
 	l := &Logger{
-		Compress: true,
-		Filename:   filename,
-		MaxBackups: 1,
-		MaxSize:    100, // megabytes
+		Compress:         true,
+		Filename:         filename,
+		MaxBackups:       1,
+		MaxSize:          100, // megabytes
+		notifyCompressed: make(chan struct{}),
 	}
 	defer l.Close()
 	b := []byte("boo!")
@@ -114,16 +115,14 @@ func TestCompressMaintainMode(t *testing.T) {
 	err = l.Rotate()
 	isNil(err, t)
 
-	// we need to wait a little bit since the files get compressed on a different
-	// goroutine.
-	<-time.After(10 * time.Millisecond)
+	waitForNotify(l.notifyCompressed, t)
 
 	// a compressed version of the log file should now exist with the correct
 	// mode.
 	filename2 := backupFile(dir)
 	info, err := os.Stat(filename)
 	isNil(err, t)
-	info2, err := os.Stat(filename2+compressSuffix)
+	info2, err := os.Stat(filename2 + compressSuffix)
 	isNil(err, t)
 	equals(mode, info.Mode(), t)
 	equals(mode, info2.Mode(), t)
@@ -148,10 +147,11 @@ func TestCompressMaintainOwner(t *testing.T) {
 	f.Close()
 
 	l := &Logger{
-		Compress:   true,
-		Filename:   filename,
-		MaxBackups: 1,
-		MaxSize:    100, // megabytes
+		Compress:         true,
+		Filename:         filename,
+		MaxBackups:       1,
+		MaxSize:          100, // megabytes
+		notifyCompressed: make(chan struct{}),
 	}
 	defer l.Close()
 	b := []byte("boo!")
@@ -164,15 +164,14 @@ func TestCompressMaintainOwner(t *testing.T) {
 	err = l.Rotate()
 	isNil(err, t)
 
-	// we need to wait a little bit since the files get compressed on a different
-	// goroutine.
-	<-time.After(10 * time.Millisecond)
+	waitForNotify(l.notifyCompressed, t)
 
 	// a compressed version of the log file should now exist with the correct
 	// owner.
 	filename2 := backupFile(dir)
-	equals(555, fakeFS.files[filename2+compressSuffix].uid, t)
-	equals(666, fakeFS.files[filename2+compressSuffix].gid, t)
+	uid, gid := fakeFS.fileOwners(filename2 + compressSuffix)
+	equals(555, uid, t)
+	equals(666, gid, t)
 }
 
 type fakeFile struct {
@@ -182,18 +181,30 @@ type fakeFile struct {
 
 type fakeFS struct {
 	files map[string]fakeFile
+	mu sync.Mutex
 }
 
 func newFakeFS() *fakeFS {
 	return &fakeFS{files: make(map[string]fakeFile)}
 }
 
+func (fs *fakeFS) fileOwners(name string) int, int {
+	fs.mu.Lock()
+	defer fs.mu.Unlock()
+	result := fs.files[name]
+	return result.uid, result.gid
+}
+
 func (fs *fakeFS) Chown(name string, uid, gid int) error {
+	fs.mu.Lock()
+	defer fs.mu.Unlock()
 	fs.files[name] = fakeFile{uid: uid, gid: gid}
 	return nil
 }
 
 func (fs *fakeFS) Stat(name string) (os.FileInfo, error) {
+	fs.mu.Lock()
+	defer fs.mu.Unlock()
 	info, err := os.Stat(name)
 	if err != nil {
 		return nil, err

lumberjack.go

@@ -111,8 +111,15 @@ type Logger struct {
 	file *os.File
 	mu   sync.Mutex
 
-	millCh    chan bool
-	startMill sync.Once
+	// millCh is signalled to tell mill to compress/remove old log files.
+	millCh chan struct{}
+	// millShutdownCh is signalled when mill has shutdown completely.
+	millShutdownCh chan struct{}
+
+	// notifyRemoved is signalled when one or more files are removed. Used only for testing.
+	notifyRemoved chan struct{}
+	// notifyCompressed is signalled when a file is compressed. Used only for testing.
+	notifyCompressed chan struct{}
 }
 
 var (
@@ -165,6 +172,14 @@ func (l *Logger) Write(p []byte) (n int, err error) {
 func (l *Logger) Close() error {
 	l.mu.Lock()
 	defer l.mu.Unlock()
+
+	if l.millCh != nil {
+		close(l.millCh)
+		<-l.millShutdownCh
+		l.millCh = nil
+		l.millShutdownCh = nil
+	}
+
 	return l.close()
 }
 
@@ -356,18 +371,29 @@ func (l *Logger) millRunOnce() error {
 		}
 	}
 
+	filesRemoved := false
 	for _, f := range remove {
 		errRemove := os.Remove(filepath.Join(l.dir(), f.Name()))
 		if err == nil && errRemove != nil {
 			err = errRemove
 		}
+		filesRemoved = true
+	}
+	if filesRemoved && l.notifyRemoved != nil {
+		l.notifyRemoved <- struct{}{}
 	}
+
+	filesCompressed := false
 	for _, f := range compress {
 		fn := filepath.Join(l.dir(), f.Name())
 		errCompress := compressLogFile(fn, fn+compressSuffix)
 		if err == nil && errCompress != nil {
 			err = errCompress
 		}
+		filesCompressed = true
+	}
+	if filesCompressed && l.notifyCompressed != nil {
+		l.notifyCompressed <- struct{}{}
 	}
 
 	return err
@@ -376,21 +402,24 @@ func (l *Logger) millRunOnce() error {
 // millRun runs in a goroutine to manage post-rotation compression and removal
 // of old log files.
 func (l *Logger) millRun() {
-	for _ = range l.millCh {
+	for range l.millCh {
 		// what am I going to do, log this?
 		_ = l.millRunOnce()
 	}
+	l.millShutdownCh <- struct{}{}
 }
 
 // mill performs post-rotation compression and removal of stale log files,
 // starting the mill goroutine if necessary.
 func (l *Logger) mill() {
-	l.startMill.Do(func() {
-		l.millCh = make(chan bool, 1)
+	// We're inside the mutex, so it's okay to access millCh.
+	if l.millCh == nil {
+		l.millCh = make(chan struct{}, 1)
+		l.millShutdownCh = make(chan struct{}, 1)
 		go l.millRun()
-	})
+	}
 	select {
-	case l.millCh <- true:
+	case l.millCh <- struct{}{}:
 	default:
 	}
 }