Commit f32eed19 authored by Mateusz Gajewski's avatar Mateusz Gajewski Committed by Matt Holt

Feature #1246 - Remote syslog (#1301)

* Remote syslog

* golint

* Initialize mutex
parent cdb79a60
...@@ -4,12 +4,10 @@ package errors ...@@ -4,12 +4,10 @@ package errors
import ( import (
"fmt" "fmt"
"io" "io"
"log"
"net/http" "net/http"
"os" "os"
"runtime" "runtime"
"strings" "strings"
"sync"
"time" "time"
"github.com/mholt/caddy" "github.com/mholt/caddy"
...@@ -28,12 +26,8 @@ type ErrorHandler struct { ...@@ -28,12 +26,8 @@ type ErrorHandler struct {
Next httpserver.Handler Next httpserver.Handler
GenericErrorPage string // default error page filename GenericErrorPage string // default error page filename
ErrorPages map[int]string // map of status code to filename ErrorPages map[int]string // map of status code to filename
LogFile string Log *httpserver.Logger
Log *log.Logger Debug bool // if true, errors are written out to client rather than to a log
LogRoller *httpserver.LogRoller
Debug bool // if true, errors are written out to client rather than to a log
file *os.File // a log file to close when done
fileMu *sync.RWMutex // like with log middleware, os.File can't "safely" be closed in a different goroutine
} }
func (h ErrorHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, error) { func (h ErrorHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, error) {
...@@ -50,9 +44,7 @@ func (h ErrorHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, er ...@@ -50,9 +44,7 @@ func (h ErrorHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, er
fmt.Fprintln(w, errMsg) fmt.Fprintln(w, errMsg)
return 0, err // returning 0 signals that a response has been written return 0, err // returning 0 signals that a response has been written
} }
h.fileMu.RLock()
h.Log.Println(errMsg) h.Log.Println(errMsg)
h.fileMu.RUnlock()
} }
if status >= 400 { if status >= 400 {
...@@ -73,10 +65,8 @@ func (h ErrorHandler) errorPage(w http.ResponseWriter, r *http.Request, code int ...@@ -73,10 +65,8 @@ func (h ErrorHandler) errorPage(w http.ResponseWriter, r *http.Request, code int
errorPage, err := os.Open(pagePath) errorPage, err := os.Open(pagePath)
if err != nil { if err != nil {
// An additional error handling an error... <insert grumpy cat here> // An additional error handling an error... <insert grumpy cat here>
h.fileMu.RLock()
h.Log.Printf("%s [NOTICE %d %s] could not load error page: %v", h.Log.Printf("%s [NOTICE %d %s] could not load error page: %v",
time.Now().Format(timeFormat), code, r.URL.String(), err) time.Now().Format(timeFormat), code, r.URL.String(), err)
h.fileMu.RUnlock()
httpserver.DefaultErrorFunc(w, r, code) httpserver.DefaultErrorFunc(w, r, code)
return return
} }
...@@ -89,10 +79,8 @@ func (h ErrorHandler) errorPage(w http.ResponseWriter, r *http.Request, code int ...@@ -89,10 +79,8 @@ func (h ErrorHandler) errorPage(w http.ResponseWriter, r *http.Request, code int
if err != nil { if err != nil {
// Epic fail... sigh. // Epic fail... sigh.
h.fileMu.RLock()
h.Log.Printf("%s [NOTICE %d %s] could not respond with %s: %v", h.Log.Printf("%s [NOTICE %d %s] could not respond with %s: %v",
time.Now().Format(timeFormat), code, r.URL.String(), pagePath, err) time.Now().Format(timeFormat), code, r.URL.String(), pagePath, err)
h.fileMu.RUnlock()
httpserver.DefaultErrorFunc(w, r, code) httpserver.DefaultErrorFunc(w, r, code)
} }
...@@ -154,9 +142,7 @@ func (h ErrorHandler) recovery(w http.ResponseWriter, r *http.Request) { ...@@ -154,9 +142,7 @@ func (h ErrorHandler) recovery(w http.ResponseWriter, r *http.Request) {
httpserver.WriteTextResponse(w, http.StatusInternalServerError, fmt.Sprintf("%s\n\n%s", panicMsg, stack)) httpserver.WriteTextResponse(w, http.StatusInternalServerError, fmt.Sprintf("%s\n\n%s", panicMsg, stack))
} else { } else {
// Currently we don't use the function name, since file:line is more conventional // Currently we don't use the function name, since file:line is more conventional
h.fileMu.RLock()
h.Log.Printf(panicMsg) h.Log.Printf(panicMsg)
h.fileMu.RUnlock()
h.errorPage(w, r, http.StatusInternalServerError) h.errorPage(w, r, http.StatusInternalServerError)
} }
} }
......
...@@ -4,14 +4,12 @@ import ( ...@@ -4,14 +4,12 @@ import (
"bytes" "bytes"
"errors" "errors"
"fmt" "fmt"
"log"
"net/http" "net/http"
"net/http/httptest" "net/http/httptest"
"os" "os"
"path/filepath" "path/filepath"
"strconv" "strconv"
"strings" "strings"
"sync"
"testing" "testing"
"github.com/mholt/caddy/caddyhttp/httpserver" "github.com/mholt/caddy/caddyhttp/httpserver"
...@@ -33,8 +31,7 @@ func TestErrors(t *testing.T) { ...@@ -33,8 +31,7 @@ func TestErrors(t *testing.T) {
http.StatusNotFound: path, http.StatusNotFound: path,
http.StatusForbidden: "not_exist_file", http.StatusForbidden: "not_exist_file",
}, },
Log: log.New(&buf, "", 0), Log: httpserver.NewTestLogger(&buf),
fileMu: new(sync.RWMutex),
} }
_, notExistErr := os.Open("not_exist_file") _, notExistErr := os.Open("not_exist_file")
...@@ -123,7 +120,6 @@ func TestVisibleErrorWithPanic(t *testing.T) { ...@@ -123,7 +120,6 @@ func TestVisibleErrorWithPanic(t *testing.T) {
Next: httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) { Next: httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) {
panic(panicMsg) panic(panicMsg)
}), }),
fileMu: new(sync.RWMutex),
} }
req, err := http.NewRequest("GET", "/", nil) req, err := http.NewRequest("GET", "/", nil)
...@@ -179,8 +175,7 @@ func TestGenericErrorPage(t *testing.T) { ...@@ -179,8 +175,7 @@ func TestGenericErrorPage(t *testing.T) {
ErrorPages: map[int]string{ ErrorPages: map[int]string{
http.StatusNotFound: notFoundErrorPagePath, http.StatusNotFound: notFoundErrorPagePath,
}, },
Log: log.New(&buf, "", 0), Log: httpserver.NewTestLogger(&buf),
fileMu: new(sync.RWMutex),
} }
tests := []struct { tests := []struct {
......
package errors package errors
import ( import (
"io"
"log" "log"
"os" "os"
"path/filepath" "path/filepath"
"strconv" "strconv"
"sync"
"github.com/hashicorp/go-syslog"
"github.com/mholt/caddy" "github.com/mholt/caddy"
"github.com/mholt/caddy/caddyhttp/httpserver" "github.com/mholt/caddy/caddyhttp/httpserver"
) )
...@@ -16,61 +13,12 @@ import ( ...@@ -16,61 +13,12 @@ import (
// setup configures a new errors middleware instance. // setup configures a new errors middleware instance.
func setup(c *caddy.Controller) error { func setup(c *caddy.Controller) error {
handler, err := errorsParse(c) handler, err := errorsParse(c)
if err != nil { if err != nil {
return err return err
} }
// Open the log file for writing when the server starts handler.Log.Attach(c)
c.OnStartup(func() error {
var err error
var writer io.Writer
switch handler.LogFile {
case "visible":
handler.Debug = true
case "stdout":
writer = os.Stdout
case "stderr":
writer = os.Stderr
case "syslog":
writer, err = gsyslog.NewLogger(gsyslog.LOG_ERR, "LOCAL0", "caddy")
if err != nil {
return err
}
default:
if handler.LogFile == "" {
writer = os.Stderr // default
break
}
var file *os.File
file, err = os.OpenFile(handler.LogFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0644)
if err != nil {
return err
}
if handler.LogRoller != nil {
file.Close()
handler.LogRoller.Filename = handler.LogFile
writer = handler.LogRoller.GetLogWriter()
} else {
handler.file = file
writer = file
}
}
handler.Log = log.New(writer, "", 0)
return nil
})
// When server stops, close any open log file
c.OnShutdown(func() error {
if handler.file != nil {
handler.fileMu.Lock()
handler.file.Close()
handler.fileMu.Unlock()
}
return nil
})
httpserver.GetConfig(c).AddMiddleware(func(next httpserver.Handler) httpserver.Handler { httpserver.GetConfig(c).AddMiddleware(func(next httpserver.Handler) httpserver.Handler {
handler.Next = next handler.Next = next
...@@ -81,10 +29,14 @@ func setup(c *caddy.Controller) error { ...@@ -81,10 +29,14 @@ func setup(c *caddy.Controller) error {
} }
func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { func errorsParse(c *caddy.Controller) (*ErrorHandler, error) {
// Very important that we make a pointer because the startup // Very important that we make a pointer because the startup
// function that opens the log file must have access to the // function that opens the log file must have access to the
// same instance of the handler, not a copy. // same instance of the handler, not a copy.
handler := &ErrorHandler{ErrorPages: make(map[int]string), fileMu: new(sync.RWMutex)} handler := &ErrorHandler{
ErrorPages: make(map[int]string),
Log: &httpserver.Logger{},
}
cfg := httpserver.GetConfig(c) cfg := httpserver.GetConfig(c)
...@@ -104,7 +56,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { ...@@ -104,7 +56,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) {
if where == "visible" { if where == "visible" {
handler.Debug = true handler.Debug = true
} else { } else {
handler.LogFile = where handler.Log.Output = where
if c.NextArg() { if c.NextArg() {
if c.Val() == "{" { if c.Val() == "{" {
c.IncrNest() c.IncrNest()
...@@ -112,7 +64,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { ...@@ -112,7 +64,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) {
if err != nil { if err != nil {
return hadBlock, err return hadBlock, err
} }
handler.LogRoller = logRoller handler.Log.Roller = logRoller
} }
} }
} }
...@@ -121,6 +73,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { ...@@ -121,6 +73,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) {
if !filepath.IsAbs(where) { if !filepath.IsAbs(where) {
where = filepath.Join(cfg.Root, where) where = filepath.Join(cfg.Root, where)
} }
f, err := os.Open(where) f, err := os.Open(where)
if err != nil { if err != nil {
log.Printf("[WARNING] Unable to open error page '%s': %v", where, err) log.Printf("[WARNING] Unable to open error page '%s': %v", where, err)
...@@ -166,7 +119,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { ...@@ -166,7 +119,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) {
if c.Val() == "visible" { if c.Val() == "visible" {
handler.Debug = true handler.Debug = true
} else { } else {
handler.LogFile = c.Val() handler.Log.Output = c.Val()
} }
} }
} }
......
...@@ -3,7 +3,6 @@ package errors ...@@ -3,7 +3,6 @@ package errors
import ( import (
"path/filepath" "path/filepath"
"reflect" "reflect"
"sync"
"testing" "testing"
"github.com/mholt/caddy" "github.com/mholt/caddy"
...@@ -27,12 +26,12 @@ func TestSetup(t *testing.T) { ...@@ -27,12 +26,12 @@ func TestSetup(t *testing.T) {
t.Fatalf("Expected handler to be type ErrorHandler, got: %#v", handler) t.Fatalf("Expected handler to be type ErrorHandler, got: %#v", handler)
} }
if myHandler.LogFile != "" { expectedLogger := &httpserver.Logger{}
t.Errorf("Expected '%s' as the default LogFile", "")
} if !reflect.DeepEqual(expectedLogger, myHandler.Log) {
if myHandler.LogRoller != nil { t.Errorf("Expected '%v' as the default Log, got: '%v'", expectedLogger, myHandler.Log)
t.Errorf("Expected LogRoller to be nil, got: %v", *myHandler.LogRoller)
} }
if !httpserver.SameNext(myHandler.Next, httpserver.EmptyNext) { if !httpserver.SameNext(myHandler.Next, httpserver.EmptyNext) {
t.Error("'Next' field of handler was not set properly") t.Error("'Next' field of handler was not set properly")
} }
...@@ -59,78 +58,71 @@ func TestErrorsParse(t *testing.T) { ...@@ -59,78 +58,71 @@ func TestErrorsParse(t *testing.T) {
}{ }{
{`errors`, false, ErrorHandler{ {`errors`, false, ErrorHandler{
ErrorPages: map[int]string{}, ErrorPages: map[int]string{},
fileMu: new(sync.RWMutex), Log: &httpserver.Logger{},
}}, }},
{`errors errors.txt`, false, ErrorHandler{ {`errors errors.txt`, false, ErrorHandler{
ErrorPages: map[int]string{}, ErrorPages: map[int]string{},
LogFile: "errors.txt", Log: &httpserver.Logger{Output: "errors.txt"},
fileMu: new(sync.RWMutex),
}}, }},
{`errors visible`, false, ErrorHandler{ {`errors visible`, false, ErrorHandler{
ErrorPages: map[int]string{}, ErrorPages: map[int]string{},
Debug: true, Debug: true,
fileMu: new(sync.RWMutex), Log: &httpserver.Logger{},
}}, }},
{`errors { log visible }`, false, ErrorHandler{ {`errors { log visible }`, false, ErrorHandler{
ErrorPages: map[int]string{}, ErrorPages: map[int]string{},
Debug: true, Debug: true,
fileMu: new(sync.RWMutex), Log: &httpserver.Logger{},
}}, }},
{`errors { log errors.txt {`errors { log errors.txt
404 404.html 404 404.html
500 500.html 500 500.html
}`, false, ErrorHandler{ }`, false, ErrorHandler{
LogFile: "errors.txt",
ErrorPages: map[int]string{ ErrorPages: map[int]string{
404: "404.html", 404: "404.html",
500: "500.html", 500: "500.html",
}, },
fileMu: new(sync.RWMutex), Log: &httpserver.Logger{Output: "errors.txt"},
}}, }},
{`errors { log errors.txt { size 2 age 10 keep 3 } }`, false, ErrorHandler{ {`errors { log errors.txt { size 2 age 10 keep 3 } }`, false, ErrorHandler{
LogFile: "errors.txt", ErrorPages: map[int]string{},
LogRoller: &httpserver.LogRoller{ Log: &httpserver.Logger{Output: "errors.txt", Roller: &httpserver.LogRoller{
MaxSize: 2, MaxSize: 2,
MaxAge: 10, MaxAge: 10,
MaxBackups: 3, MaxBackups: 3,
LocalTime: true, LocalTime: true,
}, }}},
ErrorPages: map[int]string{}, },
fileMu: new(sync.RWMutex),
}},
{`errors { log errors.txt { {`errors { log errors.txt {
size 3 size 3
age 11 age 11
keep 5 keep 5
} }
404 404.html 404 404.html
503 503.html 503 503.html
}`, false, ErrorHandler{ }`, false, ErrorHandler{
LogFile: "errors.txt",
ErrorPages: map[int]string{ ErrorPages: map[int]string{
404: "404.html", 404: "404.html",
503: "503.html", 503: "503.html",
}, },
LogRoller: &httpserver.LogRoller{ Log: &httpserver.Logger{Output: "errors.txt", Roller: &httpserver.LogRoller{
MaxSize: 3, MaxSize: 3,
MaxAge: 11, MaxAge: 11,
MaxBackups: 5, MaxBackups: 5,
LocalTime: true, LocalTime: true,
}, },
fileMu: new(sync.RWMutex), }}},
}},
{`errors { log errors.txt {`errors { log errors.txt
* generic_error.html * generic_error.html
404 404.html 404 404.html
503 503.html 503 503.html
}`, false, ErrorHandler{ }`, false, ErrorHandler{
LogFile: "errors.txt", Log: &httpserver.Logger{Output: "errors.txt"},
GenericErrorPage: "generic_error.html", GenericErrorPage: "generic_error.html",
ErrorPages: map[int]string{ ErrorPages: map[int]string{
404: "404.html", 404: "404.html",
503: "503.html", 503: "503.html",
}, },
fileMu: new(sync.RWMutex),
}}, }},
// test absolute file path // test absolute file path
{`errors { {`errors {
...@@ -140,18 +132,20 @@ func TestErrorsParse(t *testing.T) { ...@@ -140,18 +132,20 @@ func TestErrorsParse(t *testing.T) {
ErrorPages: map[int]string{ ErrorPages: map[int]string{
404: testAbs, 404: testAbs,
}, },
fileMu: new(sync.RWMutex), Log: &httpserver.Logger{},
}}, }},
// Next two test cases is the detection of duplicate status codes // Next two test cases is the detection of duplicate status codes
{`errors { {`errors {
503 503.html 503 503.html
503 503.html 503 503.html
}`, true, ErrorHandler{ErrorPages: map[int]string{}, fileMu: new(sync.RWMutex)}}, }`, true, ErrorHandler{ErrorPages: map[int]string{}, Log: &httpserver.Logger{}}},
{`errors { {`errors {
* generic_error.html * generic_error.html
* generic_error.html * generic_error.html
}`, true, ErrorHandler{ErrorPages: map[int]string{}, fileMu: new(sync.RWMutex)}}, }`, true, ErrorHandler{ErrorPages: map[int]string{}, Log: &httpserver.Logger{}}},
} }
for i, test := range tests { for i, test := range tests {
actualErrorsRule, err := errorsParse(caddy.NewTestController("http", test.inputErrorsRules)) actualErrorsRule, err := errorsParse(caddy.NewTestController("http", test.inputErrorsRules))
......
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
}
//+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)
}
...@@ -6,8 +6,9 @@ import ( ...@@ -6,8 +6,9 @@ import (
"net/http/httptest" "net/http/httptest"
"testing" "testing"
"github.com/mholt/caddy/caddyhttp/httpserver"
"strconv" "strconv"
"github.com/mholt/caddy/caddyhttp/httpserver"
) )
const ( const (
......
...@@ -3,10 +3,7 @@ package log ...@@ -3,10 +3,7 @@ package log
import ( import (
"fmt" "fmt"
"log"
"net/http" "net/http"
"os"
"sync"
"github.com/mholt/caddy" "github.com/mholt/caddy"
"github.com/mholt/caddy/caddyhttp/httpserver" "github.com/mholt/caddy/caddyhttp/httpserver"
...@@ -55,9 +52,7 @@ func (l Logger) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, error) { ...@@ -55,9 +52,7 @@ func (l Logger) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, error) {
// Write log entries // Write log entries
for _, e := range rule.Entries { for _, e := range rule.Entries {
e.fileMu.RLock()
e.Log.Println(rep.Replace(e.Format)) e.Log.Println(rep.Replace(e.Format))
e.fileMu.RUnlock()
} }
return status, err return status, err
...@@ -68,12 +63,8 @@ func (l Logger) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, error) { ...@@ -68,12 +63,8 @@ func (l Logger) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, error) {
// Entry represents a log entry under a path scope // Entry represents a log entry under a path scope
type Entry struct { type Entry struct {
OutputFile string Format string
Format string Log *httpserver.Logger
Log *log.Logger
Roller *httpserver.LogRoller
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. // Rule configures the logging middleware.
......
...@@ -3,11 +3,9 @@ package log ...@@ -3,11 +3,9 @@ package log
import ( import (
"bytes" "bytes"
"io/ioutil" "io/ioutil"
"log"
"net/http" "net/http"
"net/http/httptest" "net/http/httptest"
"strings" "strings"
"sync"
"testing" "testing"
"github.com/mholt/caddy/caddyhttp/httpserver" "github.com/mholt/caddy/caddyhttp/httpserver"
...@@ -29,8 +27,7 @@ func TestLoggedStatus(t *testing.T) { ...@@ -29,8 +27,7 @@ func TestLoggedStatus(t *testing.T) {
PathScope: "/", PathScope: "/",
Entries: []*Entry{{ Entries: []*Entry{{
Format: DefaultLogFormat + " {testval}", Format: DefaultLogFormat + " {testval}",
Log: log.New(&f, "", 0), Log: httpserver.NewTestLogger(&f),
fileMu: new(sync.RWMutex),
}}, }},
} }
...@@ -73,8 +70,7 @@ func TestLogRequestBody(t *testing.T) { ...@@ -73,8 +70,7 @@ func TestLogRequestBody(t *testing.T) {
PathScope: "/", PathScope: "/",
Entries: []*Entry{{ Entries: []*Entry{{
Format: "{request_body}", Format: "{request_body}",
Log: log.New(&got, "", 0), Log: httpserver.NewTestLogger(&got),
fileMu: new(sync.RWMutex),
}}, }},
}}, }},
Next: httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) { Next: httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) {
...@@ -133,13 +129,11 @@ func TestMultiEntries(t *testing.T) { ...@@ -133,13 +129,11 @@ func TestMultiEntries(t *testing.T) {
Entries: []*Entry{ Entries: []*Entry{
{ {
Format: "foo {request_body}", Format: "foo {request_body}",
Log: log.New(&got1, "", 0), Log: httpserver.NewTestLogger(&got1),
fileMu: new(sync.RWMutex),
}, },
{ {
Format: "{method} {request_body}", Format: "{method} {request_body}",
Log: log.New(&got2, "", 0), Log: httpserver.NewTestLogger(&got2),
fileMu: new(sync.RWMutex),
}, },
}, },
}}, }},
......
package log package log
import ( import (
"io"
"log"
"os"
"path/filepath"
"sync"
"github.com/hashicorp/go-syslog"
"github.com/mholt/caddy" "github.com/mholt/caddy"
"github.com/mholt/caddy/caddyhttp/httpserver" "github.com/mholt/caddy/caddyhttp/httpserver"
) )
...@@ -19,61 +12,11 @@ func setup(c *caddy.Controller) error { ...@@ -19,61 +12,11 @@ func setup(c *caddy.Controller) error {
return err return err
} }
// Open the log files for writing when the server starts for _, rule := range rules {
c.OnStartup(func() error { for _, entry := range rule.Entries {
for _, rule := range rules { entry.Log.Attach(c)
for _, entry := range rule.Entries {
var err error
var writer io.Writer
if entry.OutputFile == "stdout" {
writer = os.Stdout
} else if entry.OutputFile == "stderr" {
writer = os.Stderr
} else if entry.OutputFile == "syslog" {
writer, err = gsyslog.NewLogger(gsyslog.LOG_INFO, "LOCAL0", "caddy")
if err != nil {
return err
}
} else {
err := os.MkdirAll(filepath.Dir(entry.OutputFile), 0744)
if err != nil {
return err
}
file, err := os.OpenFile(entry.OutputFile, os.O_RDWR|os.O_CREATE|os.O_APPEND, 0644)
if err != nil {
return err
}
if entry.Roller != nil {
file.Close()
entry.Roller.Filename = entry.OutputFile
writer = entry.Roller.GetLogWriter()
} else {
entry.file = file
writer = file
}
}
entry.Log = log.New(writer, "", 0)
}
}
return nil
})
// When server stops, close any open log files
c.OnShutdown(func() error {
for _, rule := range rules {
for _, entry := range rule.Entries {
if entry.file != nil {
entry.fileMu.Lock()
entry.file.Close()
entry.fileMu.Unlock()
}
}
} }
return nil }
})
httpserver.GetConfig(c).AddMiddleware(func(next httpserver.Handler) httpserver.Handler { httpserver.GetConfig(c).AddMiddleware(func(next httpserver.Handler) httpserver.Handler {
return Logger{Next: next, Rules: rules, ErrorFunc: httpserver.DefaultErrorFunc} return Logger{Next: next, Rules: rules, ErrorFunc: httpserver.DefaultErrorFunc}
...@@ -111,18 +54,20 @@ func logParse(c *caddy.Controller) ([]*Rule, error) { ...@@ -111,18 +54,20 @@ func logParse(c *caddy.Controller) ([]*Rule, error) {
if len(args) == 0 { if len(args) == 0 {
// Nothing specified; use defaults // Nothing specified; use defaults
rules = appendEntry(rules, "/", &Entry{ rules = appendEntry(rules, "/", &Entry{
OutputFile: DefaultLogFilename, Log: &httpserver.Logger{
Format: DefaultLogFormat, Output: DefaultLogFilename,
Roller: logRoller, Roller: logRoller,
fileMu: new(sync.RWMutex), },
Format: DefaultLogFormat,
}) })
} else if len(args) == 1 { } else if len(args) == 1 {
// Only an output file specified // Only an output file specified
rules = appendEntry(rules, "/", &Entry{ rules = appendEntry(rules, "/", &Entry{
OutputFile: args[0], Log: &httpserver.Logger{
Format: DefaultLogFormat, Output: args[0],
Roller: logRoller, Roller: logRoller,
fileMu: new(sync.RWMutex), },
Format: DefaultLogFormat,
}) })
} else { } else {
// Path scope, output file, and maybe a format specified // Path scope, output file, and maybe a format specified
...@@ -141,10 +86,11 @@ func logParse(c *caddy.Controller) ([]*Rule, error) { ...@@ -141,10 +86,11 @@ func logParse(c *caddy.Controller) ([]*Rule, error) {
} }
rules = appendEntry(rules, args[0], &Entry{ rules = appendEntry(rules, args[0], &Entry{
OutputFile: args[1], Log: &httpserver.Logger{
Format: format, Output: args[1],
Roller: logRoller, Roller: logRoller,
fileMu: new(sync.RWMutex), },
Format: format,
}) })
} }
} }
......
...@@ -3,6 +3,8 @@ package log ...@@ -3,6 +3,8 @@ package log
import ( import (
"testing" "testing"
"reflect"
"github.com/mholt/caddy" "github.com/mholt/caddy"
"github.com/mholt/caddy/caddyhttp/httpserver" "github.com/mholt/caddy/caddyhttp/httpserver"
) )
...@@ -29,20 +31,19 @@ func TestSetup(t *testing.T) { ...@@ -29,20 +31,19 @@ func TestSetup(t *testing.T) {
if myHandler.Rules[0].PathScope != "/" { if myHandler.Rules[0].PathScope != "/" {
t.Errorf("Expected / as the default PathScope") t.Errorf("Expected / as the default PathScope")
} }
if myHandler.Rules[0].Entries[0].OutputFile != DefaultLogFilename {
t.Errorf("Expected %s as the default OutputFile", DefaultLogFilename) expectedLogger := &httpserver.Logger{Output: DefaultLogFilename}
if !reflect.DeepEqual(myHandler.Rules[0].Entries[0].Log, expectedLogger) {
t.Errorf("Expected %v as the default Log, got: %v", expectedLogger, myHandler.Rules[0].Entries[0].Log)
} }
if myHandler.Rules[0].Entries[0].Format != DefaultLogFormat { if myHandler.Rules[0].Entries[0].Format != DefaultLogFormat {
t.Errorf("Expected %s as the default Log Format", DefaultLogFormat) t.Errorf("Expected %s as the default Log Format", DefaultLogFormat)
} }
if myHandler.Rules[0].Entries[0].Roller != nil {
t.Errorf("Expected Roller to be nil, got: %v",
*myHandler.Rules[0].Entries[0].Roller)
}
if !httpserver.SameNext(myHandler.Next, httpserver.EmptyNext) { if !httpserver.SameNext(myHandler.Next, httpserver.EmptyNext) {
t.Error("'Next' field of handler was not set properly") t.Error("'Next' field of handler was not set properly")
} }
} }
func TestLogParse(t *testing.T) { func TestLogParse(t *testing.T) {
...@@ -54,95 +55,108 @@ func TestLogParse(t *testing.T) { ...@@ -54,95 +55,108 @@ func TestLogParse(t *testing.T) {
{`log`, false, []Rule{{ {`log`, false, []Rule{{
PathScope: "/", PathScope: "/",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: DefaultLogFilename, Log: &httpserver.Logger{Output: DefaultLogFilename},
Format: DefaultLogFormat, Format: DefaultLogFormat,
}}, }},
}}}, }}},
{`log log.txt`, false, []Rule{{ {`log log.txt`, false, []Rule{{
PathScope: "/", PathScope: "/",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "log.txt", Log: &httpserver.Logger{Output: "log.txt"},
Format: DefaultLogFormat, Format: DefaultLogFormat,
}},
}}},
{`log syslog://127.0.0.1:5000`, false, []Rule{{
PathScope: "/",
Entries: []*Entry{{
Log: &httpserver.Logger{Output: "syslog://127.0.0.1:5000"},
Format: DefaultLogFormat,
}},
}}},
{`log syslog+tcp://127.0.0.1:5000`, false, []Rule{{
PathScope: "/",
Entries: []*Entry{{
Log: &httpserver.Logger{Output: "syslog+tcp://127.0.0.1:5000"},
Format: DefaultLogFormat,
}}, }},
}}}, }}},
{`log /api log.txt`, false, []Rule{{ {`log /api log.txt`, false, []Rule{{
PathScope: "/api", PathScope: "/api",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "log.txt", Log: &httpserver.Logger{Output: "log.txt"},
Format: DefaultLogFormat, Format: DefaultLogFormat,
}}, }},
}}}, }}},
{`log /serve stdout`, false, []Rule{{ {`log /serve stdout`, false, []Rule{{
PathScope: "/serve", PathScope: "/serve",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "stdout", Log: &httpserver.Logger{Output: "stdout"},
Format: DefaultLogFormat, Format: DefaultLogFormat,
}}, }},
}}}, }}},
{`log /myapi log.txt {common}`, false, []Rule{{ {`log /myapi log.txt {common}`, false, []Rule{{
PathScope: "/myapi", PathScope: "/myapi",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "log.txt", Log: &httpserver.Logger{Output: "log.txt"},
Format: CommonLogFormat, Format: CommonLogFormat,
}}, }},
}}}, }}},
{`log /test accesslog.txt {combined}`, false, []Rule{{ {`log /test accesslog.txt {combined}`, false, []Rule{{
PathScope: "/test", PathScope: "/test",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "accesslog.txt", Log: &httpserver.Logger{Output: "accesslog.txt"},
Format: CombinedLogFormat, Format: CombinedLogFormat,
}}, }},
}}}, }}},
{`log /api1 log.txt {`log /api1 log.txt
log /api2 accesslog.txt {combined}`, false, []Rule{{ log /api2 accesslog.txt {combined}`, false, []Rule{{
PathScope: "/api1", PathScope: "/api1",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "log.txt", Log: &httpserver.Logger{Output: "log.txt"},
Format: DefaultLogFormat, Format: DefaultLogFormat,
}}, }},
}, { }, {
PathScope: "/api2", PathScope: "/api2",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "accesslog.txt", Log: &httpserver.Logger{Output: "accesslog.txt"},
Format: CombinedLogFormat, Format: CombinedLogFormat,
}}, }},
}}}, }}},
{`log /api3 stdout {host} {`log /api3 stdout {host}
log /api4 log.txt {when}`, false, []Rule{{ log /api4 log.txt {when}`, false, []Rule{{
PathScope: "/api3", PathScope: "/api3",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "stdout", Log: &httpserver.Logger{Output: "stdout"},
Format: "{host}", Format: "{host}",
}}, }},
}, { }, {
PathScope: "/api4", PathScope: "/api4",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "log.txt", Log: &httpserver.Logger{Output: "log.txt"},
Format: "{when}", Format: "{when}",
}}, }},
}}}, }}},
{`log access.log { rotate { size 2 age 10 keep 3 } }`, false, []Rule{{ {`log access.log { rotate { size 2 age 10 keep 3 } }`, false, []Rule{{
PathScope: "/", PathScope: "/",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "access.log", Log: &httpserver.Logger{Output: "access.log", Roller: &httpserver.LogRoller{
Format: DefaultLogFormat,
Roller: &httpserver.LogRoller{
MaxSize: 2, MaxSize: 2,
MaxAge: 10, MaxAge: 10,
MaxBackups: 3, MaxBackups: 3,
LocalTime: true, LocalTime: true,
}, }},
Format: DefaultLogFormat,
}}, }},
}}}, }}},
{`log / stdout {host} {`log / stdout {host}
log / log.txt {when}`, false, []Rule{{ log / log.txt {when}`, false, []Rule{{
PathScope: "/", PathScope: "/",
Entries: []*Entry{{ Entries: []*Entry{{
OutputFile: "stdout", Log: &httpserver.Logger{Output: "stdout"},
Format: "{host}", Format: "{host}",
}, { }, {
OutputFile: "log.txt", Log: &httpserver.Logger{Output: "log.txt"},
Format: "{when}", Format: "{when}",
}}, }},
}}}, }}},
} }
...@@ -172,43 +186,16 @@ func TestLogParse(t *testing.T) { ...@@ -172,43 +186,16 @@ func TestLogParse(t *testing.T) {
} }
for k, actualEntry := range actualLogRule.Entries { for k, actualEntry := range actualLogRule.Entries {
if actualEntry.OutputFile != test.expectedLogRules[j].Entries[k].OutputFile { if !reflect.DeepEqual(actualEntry.Log, test.expectedLogRules[j].Entries[k].Log) {
t.Errorf("Test %d expected %dth LogRule OutputFile to be %s , but got %s", t.Errorf("Test %d expected %dth LogRule Log to be %v , but got %v",
i, j, test.expectedLogRules[j].Entries[k].OutputFile, actualEntry.OutputFile) i, j, test.expectedLogRules[j].Entries[k].Log, actualEntry.Log)
} }
if actualEntry.Format != test.expectedLogRules[j].Entries[k].Format { if actualEntry.Format != test.expectedLogRules[j].Entries[k].Format {
t.Errorf("Test %d expected %dth LogRule Format to be %s , but got %s", t.Errorf("Test %d expected %dth LogRule Format to be %s , but got %s",
i, j, test.expectedLogRules[j].Entries[k].Format, actualEntry.Format) i, j, test.expectedLogRules[j].Entries[k].Format, actualEntry.Format)
} }
if actualEntry.Roller != nil && test.expectedLogRules[j].Entries[k].Roller == nil || actualEntry.Roller == nil && test.expectedLogRules[j].Entries[k].Roller != nil {
t.Fatalf("Test %d expected %dth LogRule Roller to be %v, but got %v",
i, j, test.expectedLogRules[j].Entries[k].Roller, actualEntry.Roller)
}
if actualEntry.Roller != nil && test.expectedLogRules[j].Entries[k].Roller != nil {
if actualEntry.Roller.Filename != test.expectedLogRules[j].Entries[k].Roller.Filename {
t.Fatalf("Test %d expected %dth LogRule Roller Filename to be %s, but got %s",
i, j, test.expectedLogRules[j].Entries[k].Roller.Filename, actualEntry.Roller.Filename)
}
if actualEntry.Roller.MaxAge != test.expectedLogRules[j].Entries[k].Roller.MaxAge {
t.Fatalf("Test %d expected %dth LogRule Roller MaxAge to be %d, but got %d",
i, j, test.expectedLogRules[j].Entries[k].Roller.MaxAge, actualEntry.Roller.MaxAge)
}
if actualEntry.Roller.MaxBackups != test.expectedLogRules[j].Entries[k].Roller.MaxBackups {
t.Fatalf("Test %d expected %dth LogRule Roller MaxBackups to be %d, but got %d",
i, j, test.expectedLogRules[j].Entries[k].Roller.MaxBackups, actualEntry.Roller.MaxBackups)
}
if actualEntry.Roller.MaxSize != test.expectedLogRules[j].Entries[k].Roller.MaxSize {
t.Fatalf("Test %d expected %dth LogRule Roller MaxSize to be %d, but got %d",
i, j, test.expectedLogRules[j].Entries[k].Roller.MaxSize, actualEntry.Roller.MaxSize)
}
if actualEntry.Roller.LocalTime != test.expectedLogRules[j].Entries[k].Roller.LocalTime {
t.Fatalf("Test %d expected %dth LogRule Roller LocalTime to be %t, but got %t",
i, j, test.expectedLogRules[j].Entries[k].Roller.LocalTime, actualEntry.Roller.LocalTime)
}
}
} }
} }
} }
} }
package markdown package markdown
import ( import (
"github.com/mholt/caddy/caddyhttp/httpserver"
"os" "os"
"strings" "strings"
"testing" "testing"
"github.com/mholt/caddy/caddyhttp/httpserver"
) )
func TestConfig_Markdown(t *testing.T) { func TestConfig_Markdown(t *testing.T) {
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment