log: Fix race when stopping server

High improbability of being an actual problem. Logs are safe for
concurrent use, but os.Files are apparently not... Fixes #1371.

caddyhttp/log/log.go

@@ -6,6 +6,7 @@ import (
 	"log"
 	"net/http"
 	"os"
+	"sync"
 
 	"github.com/mholt/caddy"
 	"github.com/mholt/caddy/caddyhttp/httpserver"
@@ -54,7 +55,9 @@ func (l Logger) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, error) {
 
 			// Write log entries
 			for _, e := range rule.Entries {
+				e.fileMu.RLock()
 				e.Log.Println(rep.Replace(e.Format))
+				e.fileMu.RUnlock()
 			}
 
 			return status, err
@@ -69,7 +72,8 @@ type Entry struct {
 	Format     string
 	Log        *log.Logger
 	Roller     *httpserver.LogRoller
-	file       *os.File // if logging to a file that needs to be closed
+	file       *os.File      // if logging to a file that needs to be closed
+	fileMu     *sync.RWMutex // files can't be safely read/written in one goroutine and closed in another (issue #1371)
 }
 
 // Rule configures the logging middleware.

caddyhttp/log/log_test.go

@@ -7,6 +7,7 @@ import (
 	"net/http"
 	"net/http/httptest"
 	"strings"
+	"sync"
 	"testing"
 
 	"github.com/mholt/caddy/caddyhttp/httpserver"
@@ -29,6 +30,7 @@ func TestLoggedStatus(t *testing.T) {
 		Entries: []*Entry{{
 			Format: DefaultLogFormat + " {testval}",
 			Log:    log.New(&f, "", 0),
+			fileMu: new(sync.RWMutex),
 		}},
 	}
 
@@ -72,6 +74,7 @@ func TestLogRequestBody(t *testing.T) {
 			Entries: []*Entry{{
 				Format: "{request_body}",
 				Log:    log.New(&got, "", 0),
+				fileMu: new(sync.RWMutex),
 			}},
 		}},
 		Next: httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) {
@@ -131,10 +134,12 @@ func TestMultiEntries(t *testing.T) {
 				{
 					Format: "foo {request_body}",
 					Log:    log.New(&got1, "", 0),
+					fileMu: new(sync.RWMutex),
 				},
 				{
 					Format: "{method} {request_body}",
 					Log:    log.New(&got2, "", 0),
+					fileMu: new(sync.RWMutex),
 				},
 			},
 		}},

caddyhttp/log/setup.go

@@ -5,6 +5,7 @@ import (
 	"log"
 	"os"
 	"path/filepath"
+	"sync"
 
 	"github.com/hashicorp/go-syslog"
 	"github.com/mholt/caddy"
@@ -65,7 +66,9 @@ func setup(c *caddy.Controller) error {
 		for _, rule := range rules {
 			for _, entry := range rule.Entries {
 				if entry.file != nil {
+					entry.fileMu.Lock()
 					entry.file.Close()
+					entry.fileMu.Unlock()
 				}
 			}
 		}
@@ -111,6 +114,7 @@ func logParse(c *caddy.Controller) ([]*Rule, error) {
 				OutputFile: DefaultLogFilename,
 				Format:     DefaultLogFormat,
 				Roller:     logRoller,
+				fileMu:     new(sync.RWMutex),
 			})
 		} else if len(args) == 1 {
 			// Only an output file specified
@@ -118,6 +122,7 @@ func logParse(c *caddy.Controller) ([]*Rule, error) {
 				OutputFile: args[0],
 				Format:     DefaultLogFormat,
 				Roller:     logRoller,
+				fileMu:     new(sync.RWMutex),
 			})
 		} else {
 			// Path scope, output file, and maybe a format specified
@@ -139,6 +144,7 @@ func logParse(c *caddy.Controller) ([]*Rule, error) {
 				OutputFile: args[1],
 				Format:     format,
 				Roller:     logRoller,
+				fileMu:     new(sync.RWMutex),
 			})
 		}
 	}