Enable loss less rotation of log files

log/logger.go

@@ -227,8 +227,10 @@ func RotateFile() error {
 		return nil
 	}
 
-	if err := CloseFile(); err != nil {
-		return fmt.Errorf("error closing log file: %s", err)
+	if logFile != nil {
+		defer func(f *os.File) {
+			f.Close()
+		}(logFile)
 	}
 
 	if err := OpenFile(logFilePath); err != nil {

log/logger_test.go

@@ -0,0 +1,79 @@
+package log
+
+import (
+	"io/ioutil"
+	"os"
+	"strings"
+	"testing"
+	"time"
+)
+
+func TestLogRotation(t *testing.T) {
+	tempDir, err := ioutil.TempDir("", "traefik_")
+	if err != nil {
+		t.Fatalf("Error setting up temporary directory: %s", err)
+	}
+
+	fileName := tempDir + "traefik.log"
+	if err := OpenFile(fileName); err != nil {
+		t.Fatalf("Error opening temporary file %s: %s", fileName, err)
+	}
+	defer CloseFile()
+
+	rotatedFileName := fileName + ".rotated"
+
+	iterations := 20
+	halfDone := make(chan bool)
+	writeDone := make(chan bool)
+	go func() {
+		for i := 0; i < iterations; i++ {
+			Println("Test log line")
+			if i == iterations/2 {
+				halfDone <- true
+			}
+		}
+		writeDone <- true
+	}()
+
+	<-halfDone
+	err = os.Rename(fileName, rotatedFileName)
+	if err != nil {
+		t.Fatalf("Error renaming file: %s", err)
+	}
+
+	err = RotateFile()
+	if err != nil {
+		t.Fatalf("Error rotating file: %s", err)
+	}
+
+	select {
+	case <-writeDone:
+		gotLineCount := lineCount(t, fileName) + lineCount(t, rotatedFileName)
+		if iterations != gotLineCount {
+			t.Errorf("Wanted %d written log lines, got %d", iterations, gotLineCount)
+		}
+	case <-time.After(500 * time.Millisecond):
+		t.Fatalf("test timed out")
+	}
+
+	close(halfDone)
+	close(writeDone)
+}
+
+func lineCount(t *testing.T, fileName string) int {
+	t.Helper()
+	fileContents, err := ioutil.ReadFile(fileName)
+	if err != nil {
+		t.Fatalf("Error reading from file %s: %s", fileName, err)
+	}
+
+	count := 0
+	for _, line := range strings.Split(string(fileContents), "\n") {
+		if strings.TrimSpace(line) == "" {
+			continue
+		}
+		count++
+	}
+
+	return count
+}

middlewares/accesslog/logger.go

@@ -8,6 +8,7 @@ import (
 	"net/url"
 	"os"
 	"path/filepath"
+	"sync"
 	"sync/atomic"
 	"time"
 
@@ -34,6 +35,7 @@ type LogHandler struct {
 	logger   *logrus.Logger
 	file     *os.File
 	filePath string
+	mu       sync.Mutex
 }
 
 // NewLogHandler creates a new LogHandler
@@ -148,14 +150,19 @@ func (l *LogHandler) Close() error {
 // by an external source.
 func (l *LogHandler) Rotate() error {
 	var err error
-	if err = l.Close(); err != nil {
-		return err
+
+	if l.file != nil {
+		defer func(f *os.File) {
+			f.Close()
+		}(l.file)
 	}
 
 	l.file, err = os.OpenFile(l.filePath, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0664)
 	if err != nil {
 		return err
 	}
+	l.mu.Lock()
+	defer l.mu.Unlock()
 	l.logger.Out = l.file
 	return nil
 }
@@ -226,6 +233,8 @@ func (l *LogHandler) logTheRoundTrip(logDataTable *LogData, crr *captureRequestR
 		fields["downstream_"+k] = logDataTable.DownstreamResponse.Get(k)
 	}
 
+	l.mu.Lock()
+	defer l.mu.Unlock()
 	l.logger.WithFields(fields).Println()
 }
 

middlewares/accesslog/logger_test.go

@@ -10,7 +10,9 @@ import (
 	"os"
 	"path/filepath"
 	"regexp"
+	"strings"
 	"testing"
+	"time"
 
 	"github.com/containous/traefik/types"
 	shellwords "github.com/mattn/go-shellwords"
@@ -36,6 +38,84 @@ var (
 	testRetryAttempts       = 2
 )
 
+func TestLogRotation(t *testing.T) {
+	tempDir, err := ioutil.TempDir("", "traefik_")
+	if err != nil {
+		t.Fatalf("Error setting up temporary directory: %s", err)
+	}
+
+	fileName := tempDir + "traefik.log"
+	rotatedFileName := fileName + ".rotated"
+
+	config := &types.AccessLog{FilePath: fileName, Format: CommonFormat}
+	logHandler, err := NewLogHandler(config)
+	if err != nil {
+		t.Fatalf("Error creating new log handler: %s", err)
+	}
+	defer logHandler.Close()
+
+	recorder := httptest.NewRecorder()
+	req := httptest.NewRequest(http.MethodGet, "http://localhost", nil)
+	next := func(rw http.ResponseWriter, req *http.Request) {
+		rw.WriteHeader(http.StatusOK)
+	}
+
+	iterations := 20
+	halfDone := make(chan bool)
+	writeDone := make(chan bool)
+	go func() {
+		for i := 0; i < iterations; i++ {
+			logHandler.ServeHTTP(recorder, req, next)
+			if i == iterations/2 {
+				halfDone <- true
+			}
+		}
+		writeDone <- true
+	}()
+
+	<-halfDone
+	err = os.Rename(fileName, rotatedFileName)
+	if err != nil {
+		t.Fatalf("Error renaming file: %s", err)
+	}
+
+	err = logHandler.Rotate()
+	if err != nil {
+		t.Fatalf("Error rotating file: %s", err)
+	}
+
+	select {
+	case <-writeDone:
+		gotLineCount := lineCount(t, fileName) + lineCount(t, rotatedFileName)
+		if iterations != gotLineCount {
+			t.Errorf("Wanted %d written log lines, got %d", iterations, gotLineCount)
+		}
+	case <-time.After(500 * time.Millisecond):
+		t.Fatalf("test timed out")
+	}
+
+	close(halfDone)
+	close(writeDone)
+}
+
+func lineCount(t *testing.T, fileName string) int {
+	t.Helper()
+	fileContents, err := ioutil.ReadFile(fileName)
+	if err != nil {
+		t.Fatalf("Error reading from file %s: %s", fileName, err)
+	}
+
+	count := 0
+	for _, line := range strings.Split(string(fileContents), "\n") {
+		if strings.TrimSpace(line) == "" {
+			continue
+		}
+		count++
+	}
+
+	return count
+}
+
 func TestLoggerCLF(t *testing.T) {
 	tmpDir := createTempDir(t, CommonFormat)
 	defer os.RemoveAll(tmpDir)

server/server_signals.go

@@ -27,7 +27,7 @@ func (server *Server) listenSignals() {
 			}
 
 			if err := log.RotateFile(); err != nil {
-				log.Errorf("Error rotating error log: %s", err)
+				log.Errorf("Error rotating traefik log: %s", err)
 			}
 		default:
 			log.Infof("I have to go... %+v", sig)