Merge branch 'master' into go18shutdown

caddyhttp/httpserver/logger.go

@@ -0,0 +1,148 @@
+package httpserver
+
+import (
+	"bytes"
+	"io"
+	"log"
+	"os"
+	"strings"
+	"sync"
+
+	"github.com/hashicorp/go-syslog"
+	"github.com/mholt/caddy"
+)
+
+var remoteSyslogPrefixes = map[string]string{
+	"syslog+tcp://": "tcp",
+	"syslog+udp://": "udp",
+	"syslog://":     "udp",
+}
+
+// Logger is shared between errors and log plugins and supports both logging to
+// a file (with an optional file roller), local and remote syslog servers.
+type Logger struct {
+	Output string
+	*log.Logger
+	Roller *LogRoller
+	writer io.Writer
+	fileMu *sync.RWMutex
+}
+
+// NewTestLogger creates logger suitable for testing purposes
+func NewTestLogger(buffer *bytes.Buffer) *Logger {
+	return &Logger{
+		Logger: log.New(buffer, "", 0),
+		fileMu: new(sync.RWMutex),
+	}
+}
+
+// Println wraps underlying logger with mutex
+func (l Logger) Println(args ...interface{}) {
+	l.fileMu.RLock()
+	l.Logger.Println(args...)
+	l.fileMu.RUnlock()
+}
+
+// Printf wraps underlying logger with mutex
+func (l Logger) Printf(format string, args ...interface{}) {
+	l.fileMu.RLock()
+	l.Logger.Printf(format, args...)
+	l.fileMu.RUnlock()
+}
+
+// Attach binds logger Start and Close functions to
+// controller's OnStartup and OnShutdown hooks.
+func (l *Logger) Attach(controller *caddy.Controller) {
+	if controller != nil {
+		// Opens file or connect to local/remote syslog
+		controller.OnStartup(l.Start)
+
+		// Closes file or disconnects from local/remote syslog
+		controller.OnShutdown(l.Close)
+	}
+}
+
+type syslogAddress struct {
+	network string
+	address string
+}
+
+func parseSyslogAddress(location string) *syslogAddress {
+	for prefix, network := range remoteSyslogPrefixes {
+		if strings.HasPrefix(location, prefix) {
+			return &syslogAddress{
+				network: network,
+				address: strings.TrimPrefix(location, prefix),
+			}
+		}
+	}
+
+	return nil
+}
+
+// Start initializes logger opening files or local/remote syslog connections
+func (l *Logger) Start() error {
+	// initialize mutex on start
+	l.fileMu = new(sync.RWMutex)
+
+	var err error
+
+selectwriter:
+	switch l.Output {
+	case "", "stderr":
+		l.writer = os.Stderr
+
+	case "stdout":
+		l.writer = os.Stdout
+
+	case "syslog":
+		l.writer, err = gsyslog.NewLogger(gsyslog.LOG_ERR, "LOCAL0", "caddy")
+		if err != nil {
+			return err
+		}
+	default:
+
+		if address := parseSyslogAddress(l.Output); address != nil {
+			l.writer, err = gsyslog.DialLogger(address.network, address.address, gsyslog.LOG_ERR, "LOCAL0", "caddy")
+
+			if err != nil {
+				return err
+			}
+
+			break selectwriter
+		}
+
+		var file *os.File
+
+		file, err = os.OpenFile(l.Output, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0644)
+		if err != nil {
+			return err
+		}
+
+		if l.Roller != nil {
+			file.Close()
+			l.Roller.Filename = l.Output
+			l.writer = l.Roller.GetLogWriter()
+		} else {
+			l.writer = file
+		}
+	}
+
+	l.Logger = log.New(l.writer, "", 0)
+
+	return nil
+
+}
+
+// Close closes open log files or connections to syslog.
+func (l *Logger) Close() error {
+	// Will close local/remote syslog connections too :)
+	if closer, ok := l.writer.(io.WriteCloser); ok {
+		l.fileMu.Lock()
+		err := closer.Close()
+		l.fileMu.Unlock()
+		return err
+	}
+
+	return nil
+}

caddyhttp/httpserver/logger_test.go

@@ -0,0 +1,212 @@
+//+build linux darwin
+
+package httpserver
+
+import (
+	"bytes"
+	"fmt"
+	"io/ioutil"
+	"os"
+	"path/filepath"
+	"strings"
+	"sync"
+	"testing"
+
+	"gopkg.in/mcuadros/go-syslog.v2"
+	"gopkg.in/mcuadros/go-syslog.v2/format"
+)
+
+func TestLoggingToStdout(t *testing.T) {
+	testCases := []struct {
+		Output         string
+		ExpectedOutput string
+	}{
+		{
+			Output:         "stdout",
+			ExpectedOutput: "Hello world logged to stdout",
+		},
+	}
+
+	for i, testCase := range testCases {
+		output := captureStdout(func() {
+			logger := Logger{Output: testCase.Output, fileMu: new(sync.RWMutex)}
+
+			if err := logger.Start(); err != nil {
+				t.Fatalf("Got unexpected error: %v", err)
+			}
+
+			logger.Println(testCase.ExpectedOutput)
+		})
+
+		if !strings.Contains(output, testCase.ExpectedOutput) {
+			t.Fatalf("Test #%d: Expected output to contain: %s, got: %s", i, testCase.ExpectedOutput, output)
+		}
+	}
+}
+
+func TestLoggingToStderr(t *testing.T) {
+
+	testCases := []struct {
+		Output         string
+		ExpectedOutput string
+	}{
+		{
+			Output:         "stderr",
+			ExpectedOutput: "Hello world logged to stderr",
+		},
+		{
+			Output:         "",
+			ExpectedOutput: "Hello world logged to stderr #2",
+		},
+	}
+
+	for i, testCase := range testCases {
+		output := captureStderr(func() {
+			logger := Logger{Output: testCase.Output, fileMu: new(sync.RWMutex)}
+
+			if err := logger.Start(); err != nil {
+				t.Fatalf("Got unexpected error: %v", err)
+			}
+
+			logger.Println(testCase.ExpectedOutput)
+		})
+
+		if !strings.Contains(output, testCase.ExpectedOutput) {
+			t.Fatalf("Test #%d: Expected output to contain: %s, got: %s", i, testCase.ExpectedOutput, output)
+		}
+	}
+}
+
+func TestLoggingToFile(t *testing.T) {
+	file := filepath.Join(os.TempDir(), "access.log")
+	expectedOutput := "Hello world written to file"
+
+	logger := Logger{Output: file}
+
+	if err := logger.Start(); err != nil {
+		t.Fatalf("Got unexpected error during logger start: %v", err)
+	}
+
+	logger.Print(expectedOutput)
+
+	content, err := ioutil.ReadFile(file)
+	if err != nil {
+		t.Fatalf("Could not read log file content: %v", err)
+	}
+
+	if !bytes.Contains(content, []byte(expectedOutput)) {
+		t.Fatalf("Expected log file to contain: %s, got: %s", expectedOutput, string(content))
+	}
+
+	os.Remove(file)
+}
+
+func TestLoggingToSyslog(t *testing.T) {
+
+	testCases := []struct {
+		Output         string
+		ExpectedOutput string
+	}{
+		{
+			Output:         "syslog://127.0.0.1:5660",
+			ExpectedOutput: "Hello world! Test #1 over tcp",
+		},
+		{
+			Output:         "syslog+tcp://127.0.0.1:5661",
+			ExpectedOutput: "Hello world! Test #2 over tcp",
+		},
+		{
+			Output:         "syslog+udp://127.0.0.1:5662",
+			ExpectedOutput: "Hello world! Test #3 over udp",
+		},
+	}
+
+	for i, testCase := range testCases {
+
+		ch := make(chan format.LogParts, 256)
+		server, err := bootServer(testCase.Output, ch)
+		defer server.Kill()
+
+		if err != nil {
+			t.Errorf("Test #%d: expected no error during syslog server boot, got: %v", i, err)
+		}
+
+		logger := Logger{Output: testCase.Output, fileMu: new(sync.RWMutex)}
+
+		if err := logger.Start(); err != nil {
+			t.Errorf("Test #%d: expected no error during logger start, got: %v", i, err)
+		}
+
+		defer logger.Close()
+
+		logger.Print(testCase.ExpectedOutput)
+
+		actual := <-ch
+
+		if content, ok := actual["content"].(string); ok {
+			if !strings.Contains(content, testCase.ExpectedOutput) {
+				t.Errorf("Test #%d: expected server to capture content: %s, but got: %s", i, testCase.ExpectedOutput, content)
+			}
+		} else {
+			t.Errorf("Test #%d: expected server to capture content but got: %v", i, actual)
+		}
+	}
+}
+
+func bootServer(location string, ch chan format.LogParts) (*syslog.Server, error) {
+	address := parseSyslogAddress(location)
+
+	if address == nil {
+		return nil, fmt.Errorf("Could not parse syslog address: %s", location)
+	}
+
+	server := syslog.NewServer()
+	server.SetFormat(syslog.Automatic)
+
+	switch address.network {
+	case "tcp":
+		server.ListenTCP(address.address)
+	case "udp":
+		server.ListenUDP(address.address)
+	}
+
+	server.SetHandler(syslog.NewChannelHandler(ch))
+
+	if err := server.Boot(); err != nil {
+		return nil, err
+	}
+
+	return server, nil
+}
+
+func captureStdout(f func()) string {
+	original := os.Stdout
+	r, w, _ := os.Pipe()
+
+	os.Stdout = w
+
+	f()
+
+	w.Close()
+
+	written, _ := ioutil.ReadAll(r)
+	os.Stdout = original
+
+	return string(written)
+}
+
+func captureStderr(f func()) string {
+	original := os.Stderr
+	r, w, _ := os.Pipe()
+
+	os.Stderr = w
+
+	f()
+
+	w.Close()
+
+	written, _ := ioutil.ReadAll(r)
+	os.Stderr = original
+
+	return string(written)
+}

caddyhttp/httpserver/plugin.go

@@ -55,6 +55,10 @@ func init() {
 func hideCaddyfile(cctx caddy.Context) error {
 	ctx := cctx.(*httpContext)
 	for _, cfg := range ctx.siteConfigs {
+		// if no Caddyfile exists exit.
+		if cfg.originCaddyfile == "" {
+			return nil
+		}
 		absRoot, err := filepath.Abs(cfg.Root)
 		if err != nil {
 			return err
@@ -454,6 +458,7 @@ var directives = []string{
 	"prometheus", // github.com/miekg/caddy-prometheus
 	"proxy",
 	"fastcgi",
+	"cgi", // github.com/jung-kurt/caddy-cgi
 	"websocket",
 	"filemanager", // github.com/hacdias/caddy-filemanager
 	"markdown",

caddyhttp/httpserver/replacer.go

@@ -198,6 +198,13 @@ func (r *replacer) getSubstitution(key string) string {
 			}
 		}
 	}
+	// next check for cookies
+	if key[1] == '~' {
+		name := key[2 : len(key)-1]
+		if cookie, err := r.request.Cookie(name); err == nil {
+			return cookie.Value
+		}
+	}
 
 	// search default replacements in the end
 	switch key {

caddyhttp/httpserver/replacer_test.go

@@ -47,6 +47,7 @@ func TestReplace(t *testing.T) {
 	repl := NewReplacer(request, recordRequest, "-")
 	// add some headers after creating replacer
 	request.Header.Set("CustomAdd", "caddy")
+	request.Header.Set("Cookie", "foo=bar; taste=delicious")
 
 	hostname, err := os.Hostname()
 	if err != nil {
@@ -72,12 +73,17 @@ func TestReplace(t *testing.T) {
 		{"{when_iso}", "2006-01-02T15:04:12Z"},
 		{"The Custom header is {>Custom}.", "The Custom header is foobarbaz."},
 		{"The CustomAdd header is {>CustomAdd}.", "The CustomAdd header is caddy."},
-		{"The request is {request}.", "The request is POST / HTTP/1.1\\r\\nHost: localhost\\r\\nCustom: foobarbaz\\r\\nCustomadd: caddy\\r\\nShorterval: 1\\r\\n\\r\\n."},
+		{"The request is {request}.", "The request is POST / HTTP/1.1\\r\\nHost: localhost\\r\\n" +
+			"Cookie: foo=bar; taste=delicious\\r\\nCustom: foobarbaz\\r\\nCustomadd: caddy\\r\\n" +
+			"Shorterval: 1\\r\\n\\r\\n."},
 		{"The cUsToM header is {>cUsToM}...", "The cUsToM header is foobarbaz..."},
 		{"The Non-Existent header is {>Non-Existent}.", "The Non-Existent header is -."},
 		{"Bad {host placeholder...", "Bad {host placeholder..."},
 		{"Bad {>Custom placeholder", "Bad {>Custom placeholder"},
 		{"Bad {>Custom placeholder {>ShorterVal}", "Bad -"},
+		{"Bad {}", "Bad -"},
+		{"Cookies are {~taste}", "Cookies are delicious"},
+		{"Missing cookie is {~missing}", "Missing cookie is -"},
 	}
 
 	for _, c := range testCases {

caddyhttp/httpserver/roller.go

@@ -2,10 +2,9 @@ package httpserver
 
 import (
 	"io"
+	"path/filepath"
 	"strconv"
 
-	"github.com/mholt/caddy"
-
 	"gopkg.in/natefinch/lumberjack.v2"
 )
 
@@ -19,46 +18,83 @@ type LogRoller struct {
 }
 
 // GetLogWriter returns an io.Writer that writes to a rolling logger.
+// This should be called only from the main goroutine (like during
+// server setup) because this method is not thread-safe; it is careful
+// to create only one log writer per log file, even if the log file
+// is shared by different sites or middlewares. This ensures that
+// rolling is synchronized, since a process (or multiple processes)
+// should not create more than one roller on the same file at the
+// same time. See issue #1363.
 func (l LogRoller) GetLogWriter() io.Writer {
-	return &lumberjack.Logger{
-		Filename:   l.Filename,
-		MaxSize:    l.MaxSize,
-		MaxAge:     l.MaxAge,
-		MaxBackups: l.MaxBackups,
-		LocalTime:  l.LocalTime,
+	absPath, err := filepath.Abs(l.Filename)
+	if err != nil {
+		absPath = l.Filename // oh well, hopefully they're consistent in how they specify the filename
 	}
+	lj, has := lumberjacks[absPath]
+	if !has {
+		lj = &lumberjack.Logger{
+			Filename:   l.Filename,
+			MaxSize:    l.MaxSize,
+			MaxAge:     l.MaxAge,
+			MaxBackups: l.MaxBackups,
+			LocalTime:  l.LocalTime,
+		}
+		lumberjacks[absPath] = lj
+	}
+	return lj
+}
+
+// IsLogRollerSubdirective is true if the subdirective is for the log roller.
+func IsLogRollerSubdirective(subdir string) bool {
+	return subdir == directiveRotateSize ||
+		subdir == directiveRotateAge ||
+		subdir == directiveRotateKeep
 }
 
 // ParseRoller parses roller contents out of c.
-func ParseRoller(c *caddy.Controller) (*LogRoller, error) {
-	var size, age, keep int
-	// This is kind of a hack to support nested blocks:
-	// As we are already in a block: either log or errors,
-	// c.nesting > 0 but, as soon as c meets a }, it thinks
-	// the block is over and return false for c.NextBlock.
-	for c.NextBlock() {
-		what := c.Val()
-		if !c.NextArg() {
-			return nil, c.ArgErr()
-		}
-		value := c.Val()
-		var err error
-		switch what {
-		case "size":
-			size, err = strconv.Atoi(value)
-		case "age":
-			age, err = strconv.Atoi(value)
-		case "keep":
-			keep, err = strconv.Atoi(value)
-		}
-		if err != nil {
-			return nil, err
-		}
+func ParseRoller(l *LogRoller, what string, where string) error {
+	if l == nil {
+		l = DefaultLogRoller()
 	}
-	return &LogRoller{
-		MaxSize:    size,
-		MaxAge:     age,
-		MaxBackups: keep,
-		LocalTime:  true,
-	}, nil
+	var value int
+	var err error
+	value, err = strconv.Atoi(where)
+	if err != nil {
+		return err
+	}
+	switch what {
+	case directiveRotateSize:
+		l.MaxSize = value
+	case directiveRotateAge:
+		l.MaxAge = value
+	case directiveRotateKeep:
+		l.MaxBackups = value
+	}
+	return nil
 }
+
+// DefaultLogRoller will roll logs by default.
+func DefaultLogRoller() *LogRoller {
+	return &LogRoller{
+		MaxSize:    defaultRotateSize,
+		MaxAge:     defaultRotateAge,
+		MaxBackups: defaultRotateKeep,
+		LocalTime:  true,
+	}
+}
+
+const (
+	// defaultRotateSize is 100 MB.
+	defaultRotateSize = 100
+	// defaultRotateAge is 14 days.
+	defaultRotateAge = 14
+	// defaultRotateKeep is 10 files.
+	defaultRotateKeep   = 10
+	directiveRotateSize = "rotate_size"
+	directiveRotateAge  = "rotate_age"
+	directiveRotateKeep = "rotate_keep"
+)
+
+// lumberjacks maps log filenames to the logger
+// that is being used to keep them rolled/maintained.
+var lumberjacks = make(map[string]*lumberjack.Logger)

caddyhttp/httpserver/server.go

@@ -127,8 +127,17 @@ func (s *Server) Listen() (net.Listener, error) {
 	return ln.(*net.TCPListener), nil
 }
 
-// ListenPacket is a noop to implement the Server interface.
-func (s *Server) ListenPacket() (net.PacketConn, error) { return nil, nil }
+// ListenPacket creates udp connection for QUIC if it is enabled,
+func (s *Server) ListenPacket() (net.PacketConn, error) {
+	if QUIC {
+		udpAddr, err := net.ResolveUDPAddr("udp", s.Server.Addr)
+		if err != nil {
+			return nil, err
+		}
+		return net.ListenUDP("udp", udpAddr)
+	}
+	return nil, nil
+}
 
 // Serve serves requests on ln. It blocks until ln is closed.
 func (s *Server) Serve(ln net.Listener) error {
@@ -152,15 +161,6 @@ func (s *Server) Serve(ln net.Listener) error {
 		s.tlsGovChan = caddytls.RotateSessionTicketKeys(s.Server.TLSConfig)
 	}
 
-	if QUIC {
-		go func() {
-			err := s.quicServer.ListenAndServe()
-			if err != nil {
-				log.Printf("[ERROR] listening for QUIC connections: %v", err)
-			}
-		}()
-	}
-
 	err := s.Server.Serve(ln)
 	if QUIC {
 		s.quicServer.Close()
@@ -168,8 +168,14 @@ func (s *Server) Serve(ln net.Listener) error {
 	return err
 }
 
-// ServePacket is a noop to implement the Server interface.
-func (s *Server) ServePacket(pc net.PacketConn) error { return nil }
+// ServePacket serves QUIC requests on pc until it is closed.
+func (s *Server) ServePacket(pc net.PacketConn) error {
+	if QUIC {
+		err := s.quicServer.Serve(pc.(*net.UDPConn))
+		return fmt.Errorf("serving QUIC connections: %v", err)
+	}
+	return nil
+}
 
 // ServeHTTP is the entry point of all HTTP requests.
 func (s *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) {