Fix bug natefinch#12

Fixes bug natefinch#12. If the first write to a file would cause it to rotate, instead
of rotating, we'd just move it aside.  This change fixes that problem
by ensuring that we just run rotate in this situation, which does the
right thing (open new and then cleanup.)  Also added test to verify
the fix.

lumberjack.go

@@ -252,19 +252,20 @@ func (l *Logger) openExistingOrNew(writeLen int) error {
 	if err != nil {
 		return fmt.Errorf("error getting log file info: %s", err)
 	}
-	// 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 info.Size()+int64(writeLen) >= l.max() {
+		return l.rotate()
+	}
+
+	file, err := os.OpenFile(filename, os.O_APPEND|os.O_WRONLY, 0644)
+	if err != nil {
 		// if we fail to open the old log file for some reason, just ignore
 		// it and open a new log file.
+		return l.openNew()
 	}
-	return l.openNew()
+	l.file = file
+	l.size = info.Size()
+	return nil
 }
 
 // genFilename generates the name of the logfile from the current time.
@@ -338,7 +339,6 @@ func (l *Logger) oldLogFiles() ([]logInfo, error) {
 		if f.IsDir() {
 			continue
 		}
-
 		name := l.timeFromName(f.Name(), prefix, ext)
 		if name == "" {
 			continue
@@ -347,6 +347,8 @@ func (l *Logger) oldLogFiles() ([]logInfo, error) {
 		if err == nil {
 			logFiles = append(logFiles, logInfo{t, f})
 		}
+		// error parsing means that the suffix at the end was not generated
+		// by lumberjack, and therefore it's not a backup file.
 	}
 
 	sort.Sort(byFormatTime(logFiles))

lumberjack_test.go

@@ -308,6 +308,62 @@ func TestMaxBackups(t *testing.T) {
 	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.
+
+	currentTime = fakeTime
+	megabyte = 1
+
+	dir := makeTempDir("TestCleanupExistingBackups", t)
+	defer os.RemoveAll(dir)
+
+	// make 3 backup files
+
+	data := []byte("data")
+	backup := backupFile(dir)
+	err := ioutil.WriteFile(backup, data, 0644)
+	isNil(err, t)
+
+	newFakeTime()
+
+	backup = backupFile(dir)
+	err = ioutil.WriteFile(backup, data, 0644)
+	isNil(err, t)
+
+	newFakeTime()
+
+	backup = backupFile(dir)
+	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,
+		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 2 files left - the primary and one backup
+	fileCount(dir, 2, t)
+}
+
 func TestMaxAge(t *testing.T) {
 	currentTime = fakeTime
 	megabyte = 1