From f32eed1912c3a7a2f60dd5d489123ae3491586b3 Mon Sep 17 00:00:00 2001 From: Mateusz Gajewski Date: Wed, 8 Feb 2017 16:02:09 +0100 Subject: [PATCH] Feature #1246 - Remote syslog (#1301) * Remote syslog * golint * Initialize mutex --- caddyhttp/errors/errors.go | 18 +-- caddyhttp/errors/errors_test.go | 9 +- caddyhttp/errors/setup.go | 69 ++------ caddyhttp/errors/setup_test.go | 86 +++++----- caddyhttp/httpserver/logger.go | 148 +++++++++++++++++ caddyhttp/httpserver/logger_test.go | 212 +++++++++++++++++++++++++ caddyhttp/internalsrv/internal_test.go | 3 +- caddyhttp/log/log.go | 13 +- caddyhttp/log/log_test.go | 14 +- caddyhttp/log/setup.go | 92 +++-------- caddyhttp/log/setup_test.go | 117 ++++++-------- caddyhttp/markdown/process_test.go | 3 +- 12 files changed, 496 insertions(+), 288 deletions(-) create mode 100644 caddyhttp/httpserver/logger.go create mode 100644 caddyhttp/httpserver/logger_test.go diff --git a/caddyhttp/errors/errors.go b/caddyhttp/errors/errors.go index e60602952..a3412ce50 100644 --- a/caddyhttp/errors/errors.go +++ b/caddyhttp/errors/errors.go @@ -4,12 +4,10 @@ package errors import ( "fmt" "io" - "log" "net/http" "os" "runtime" "strings" - "sync" "time" "github.com/mholt/caddy" @@ -28,12 +26,8 @@ type ErrorHandler struct { Next httpserver.Handler GenericErrorPage string // default error page filename ErrorPages map[int]string // map of status code to filename - LogFile string - Log *log.Logger - 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 + Log *httpserver.Logger + Debug bool // if true, errors are written out to client rather than to a log } 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 fmt.Fprintln(w, errMsg) return 0, err // returning 0 signals that a response has been written } - h.fileMu.RLock() h.Log.Println(errMsg) - h.fileMu.RUnlock() } if status >= 400 { @@ -73,10 +65,8 @@ func (h ErrorHandler) errorPage(w http.ResponseWriter, r *http.Request, code int errorPage, err := os.Open(pagePath) if err != nil { // An additional error handling an error... - h.fileMu.RLock() h.Log.Printf("%s [NOTICE %d %s] could not load error page: %v", time.Now().Format(timeFormat), code, r.URL.String(), err) - h.fileMu.RUnlock() httpserver.DefaultErrorFunc(w, r, code) return } @@ -89,10 +79,8 @@ func (h ErrorHandler) errorPage(w http.ResponseWriter, r *http.Request, code int if err != nil { // Epic fail... sigh. - h.fileMu.RLock() h.Log.Printf("%s [NOTICE %d %s] could not respond with %s: %v", time.Now().Format(timeFormat), code, r.URL.String(), pagePath, err) - h.fileMu.RUnlock() httpserver.DefaultErrorFunc(w, r, code) } @@ -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)) } else { // Currently we don't use the function name, since file:line is more conventional - h.fileMu.RLock() h.Log.Printf(panicMsg) - h.fileMu.RUnlock() h.errorPage(w, r, http.StatusInternalServerError) } } diff --git a/caddyhttp/errors/errors_test.go b/caddyhttp/errors/errors_test.go index 2b1603926..4833ecb9a 100644 --- a/caddyhttp/errors/errors_test.go +++ b/caddyhttp/errors/errors_test.go @@ -4,14 +4,12 @@ import ( "bytes" "errors" "fmt" - "log" "net/http" "net/http/httptest" "os" "path/filepath" "strconv" "strings" - "sync" "testing" "github.com/mholt/caddy/caddyhttp/httpserver" @@ -33,8 +31,7 @@ func TestErrors(t *testing.T) { http.StatusNotFound: path, http.StatusForbidden: "not_exist_file", }, - Log: log.New(&buf, "", 0), - fileMu: new(sync.RWMutex), + Log: httpserver.NewTestLogger(&buf), } _, notExistErr := os.Open("not_exist_file") @@ -123,7 +120,6 @@ func TestVisibleErrorWithPanic(t *testing.T) { Next: httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) { panic(panicMsg) }), - fileMu: new(sync.RWMutex), } req, err := http.NewRequest("GET", "/", nil) @@ -179,8 +175,7 @@ func TestGenericErrorPage(t *testing.T) { ErrorPages: map[int]string{ http.StatusNotFound: notFoundErrorPagePath, }, - Log: log.New(&buf, "", 0), - fileMu: new(sync.RWMutex), + Log: httpserver.NewTestLogger(&buf), } tests := []struct { diff --git a/caddyhttp/errors/setup.go b/caddyhttp/errors/setup.go index db4177c22..113a7e02c 100644 --- a/caddyhttp/errors/setup.go +++ b/caddyhttp/errors/setup.go @@ -1,14 +1,11 @@ package errors import ( - "io" "log" "os" "path/filepath" "strconv" - "sync" - "github.com/hashicorp/go-syslog" "github.com/mholt/caddy" "github.com/mholt/caddy/caddyhttp/httpserver" ) @@ -16,61 +13,12 @@ import ( // setup configures a new errors middleware instance. func setup(c *caddy.Controller) error { handler, err := errorsParse(c) + if err != nil { return err } - // Open the log file for writing when the server starts - 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 - }) + handler.Log.Attach(c) httpserver.GetConfig(c).AddMiddleware(func(next httpserver.Handler) httpserver.Handler { handler.Next = next @@ -81,10 +29,14 @@ func setup(c *caddy.Controller) error { } func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { + // Very important that we make a pointer because the startup // function that opens the log file must have access to the // 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) @@ -104,7 +56,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { if where == "visible" { handler.Debug = true } else { - handler.LogFile = where + handler.Log.Output = where if c.NextArg() { if c.Val() == "{" { c.IncrNest() @@ -112,7 +64,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { if err != nil { return hadBlock, err } - handler.LogRoller = logRoller + handler.Log.Roller = logRoller } } } @@ -121,6 +73,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { if !filepath.IsAbs(where) { where = filepath.Join(cfg.Root, where) } + f, err := os.Open(where) if err != nil { log.Printf("[WARNING] Unable to open error page '%s': %v", where, err) @@ -166,7 +119,7 @@ func errorsParse(c *caddy.Controller) (*ErrorHandler, error) { if c.Val() == "visible" { handler.Debug = true } else { - handler.LogFile = c.Val() + handler.Log.Output = c.Val() } } } diff --git a/caddyhttp/errors/setup_test.go b/caddyhttp/errors/setup_test.go index f9e539c22..dd0896b8f 100644 --- a/caddyhttp/errors/setup_test.go +++ b/caddyhttp/errors/setup_test.go @@ -3,7 +3,6 @@ package errors import ( "path/filepath" "reflect" - "sync" "testing" "github.com/mholt/caddy" @@ -27,12 +26,12 @@ func TestSetup(t *testing.T) { t.Fatalf("Expected handler to be type ErrorHandler, got: %#v", handler) } - if myHandler.LogFile != "" { - t.Errorf("Expected '%s' as the default LogFile", "") - } - if myHandler.LogRoller != nil { - t.Errorf("Expected LogRoller to be nil, got: %v", *myHandler.LogRoller) + expectedLogger := &httpserver.Logger{} + + if !reflect.DeepEqual(expectedLogger, myHandler.Log) { + t.Errorf("Expected '%v' as the default Log, got: '%v'", expectedLogger, myHandler.Log) } + if !httpserver.SameNext(myHandler.Next, httpserver.EmptyNext) { t.Error("'Next' field of handler was not set properly") } @@ -59,78 +58,71 @@ func TestErrorsParse(t *testing.T) { }{ {`errors`, false, ErrorHandler{ ErrorPages: map[int]string{}, - fileMu: new(sync.RWMutex), + Log: &httpserver.Logger{}, }}, {`errors errors.txt`, false, ErrorHandler{ ErrorPages: map[int]string{}, - LogFile: "errors.txt", - fileMu: new(sync.RWMutex), + Log: &httpserver.Logger{Output: "errors.txt"}, }}, {`errors visible`, false, ErrorHandler{ ErrorPages: map[int]string{}, Debug: true, - fileMu: new(sync.RWMutex), + Log: &httpserver.Logger{}, }}, {`errors { log visible }`, false, ErrorHandler{ ErrorPages: map[int]string{}, Debug: true, - fileMu: new(sync.RWMutex), + Log: &httpserver.Logger{}, }}, {`errors { log errors.txt - 404 404.html - 500 500.html -}`, false, ErrorHandler{ - LogFile: "errors.txt", + 404 404.html + 500 500.html + }`, false, ErrorHandler{ ErrorPages: map[int]string{ 404: "404.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{ - LogFile: "errors.txt", - LogRoller: &httpserver.LogRoller{ + ErrorPages: map[int]string{}, + Log: &httpserver.Logger{Output: "errors.txt", Roller: &httpserver.LogRoller{ MaxSize: 2, MaxAge: 10, MaxBackups: 3, LocalTime: true, - }, - ErrorPages: map[int]string{}, - fileMu: new(sync.RWMutex), - }}, + }}}, + }, {`errors { log errors.txt { - size 3 - age 11 - keep 5 - } - 404 404.html - 503 503.html -}`, false, ErrorHandler{ - LogFile: "errors.txt", + size 3 + age 11 + keep 5 + } + 404 404.html + 503 503.html + }`, false, ErrorHandler{ ErrorPages: map[int]string{ 404: "404.html", 503: "503.html", }, - LogRoller: &httpserver.LogRoller{ + Log: &httpserver.Logger{Output: "errors.txt", Roller: &httpserver.LogRoller{ MaxSize: 3, MaxAge: 11, MaxBackups: 5, LocalTime: true, }, - fileMu: new(sync.RWMutex), - }}, + }}}, {`errors { log errors.txt - * generic_error.html - 404 404.html - 503 503.html -}`, false, ErrorHandler{ - LogFile: "errors.txt", + * generic_error.html + 404 404.html + 503 503.html + }`, false, ErrorHandler{ + Log: &httpserver.Logger{Output: "errors.txt"}, GenericErrorPage: "generic_error.html", ErrorPages: map[int]string{ 404: "404.html", 503: "503.html", }, - fileMu: new(sync.RWMutex), }}, // test absolute file path {`errors { @@ -140,18 +132,20 @@ func TestErrorsParse(t *testing.T) { ErrorPages: map[int]string{ 404: testAbs, }, - fileMu: new(sync.RWMutex), + Log: &httpserver.Logger{}, }}, // Next two test cases is the detection of duplicate status codes {`errors { - 503 503.html - 503 503.html -}`, true, ErrorHandler{ErrorPages: map[int]string{}, fileMu: new(sync.RWMutex)}}, + 503 503.html + 503 503.html + }`, true, ErrorHandler{ErrorPages: map[int]string{}, Log: &httpserver.Logger{}}}, + {`errors { - * generic_error.html - * generic_error.html -}`, true, ErrorHandler{ErrorPages: map[int]string{}, fileMu: new(sync.RWMutex)}}, + * generic_error.html + * generic_error.html + }`, true, ErrorHandler{ErrorPages: map[int]string{}, Log: &httpserver.Logger{}}}, } + for i, test := range tests { actualErrorsRule, err := errorsParse(caddy.NewTestController("http", test.inputErrorsRules)) diff --git a/caddyhttp/httpserver/logger.go b/caddyhttp/httpserver/logger.go new file mode 100644 index 000000000..f16042c03 --- /dev/null +++ b/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 +} diff --git a/caddyhttp/httpserver/logger_test.go b/caddyhttp/httpserver/logger_test.go new file mode 100644 index 000000000..b444c3a7c --- /dev/null +++ b/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) +} diff --git a/caddyhttp/internalsrv/internal_test.go b/caddyhttp/internalsrv/internal_test.go index b519460aa..ea0710448 100644 --- a/caddyhttp/internalsrv/internal_test.go +++ b/caddyhttp/internalsrv/internal_test.go @@ -6,8 +6,9 @@ import ( "net/http/httptest" "testing" - "github.com/mholt/caddy/caddyhttp/httpserver" "strconv" + + "github.com/mholt/caddy/caddyhttp/httpserver" ) const ( diff --git a/caddyhttp/log/log.go b/caddyhttp/log/log.go index 4470bccfe..d0a0fd695 100644 --- a/caddyhttp/log/log.go +++ b/caddyhttp/log/log.go @@ -3,10 +3,7 @@ package log import ( "fmt" - "log" "net/http" - "os" - "sync" "github.com/mholt/caddy" "github.com/mholt/caddy/caddyhttp/httpserver" @@ -55,9 +52,7 @@ 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 @@ -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 type Entry struct { - OutputFile string - Format string - 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) + Format string + Log *httpserver.Logger } // Rule configures the logging middleware. diff --git a/caddyhttp/log/log_test.go b/caddyhttp/log/log_test.go index 8dcf928b3..2cf46afd9 100644 --- a/caddyhttp/log/log_test.go +++ b/caddyhttp/log/log_test.go @@ -3,11 +3,9 @@ package log import ( "bytes" "io/ioutil" - "log" "net/http" "net/http/httptest" "strings" - "sync" "testing" "github.com/mholt/caddy/caddyhttp/httpserver" @@ -29,8 +27,7 @@ func TestLoggedStatus(t *testing.T) { PathScope: "/", Entries: []*Entry{{ Format: DefaultLogFormat + " {testval}", - Log: log.New(&f, "", 0), - fileMu: new(sync.RWMutex), + Log: httpserver.NewTestLogger(&f), }}, } @@ -73,8 +70,7 @@ func TestLogRequestBody(t *testing.T) { PathScope: "/", Entries: []*Entry{{ Format: "{request_body}", - Log: log.New(&got, "", 0), - fileMu: new(sync.RWMutex), + Log: httpserver.NewTestLogger(&got), }}, }}, Next: httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) { @@ -133,13 +129,11 @@ func TestMultiEntries(t *testing.T) { Entries: []*Entry{ { Format: "foo {request_body}", - Log: log.New(&got1, "", 0), - fileMu: new(sync.RWMutex), + Log: httpserver.NewTestLogger(&got1), }, { Format: "{method} {request_body}", - Log: log.New(&got2, "", 0), - fileMu: new(sync.RWMutex), + Log: httpserver.NewTestLogger(&got2), }, }, }}, diff --git a/caddyhttp/log/setup.go b/caddyhttp/log/setup.go index 8dd586b69..3b909d1a2 100644 --- a/caddyhttp/log/setup.go +++ b/caddyhttp/log/setup.go @@ -1,13 +1,6 @@ package log import ( - "io" - "log" - "os" - "path/filepath" - "sync" - - "github.com/hashicorp/go-syslog" "github.com/mholt/caddy" "github.com/mholt/caddy/caddyhttp/httpserver" ) @@ -19,61 +12,11 @@ func setup(c *caddy.Controller) error { return err } - // Open the log files for writing when the server starts - c.OnStartup(func() error { - for _, rule := range rules { - 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) - } + for _, rule := range rules { + for _, entry := range rule.Entries { + entry.Log.Attach(c) } - - 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 { return Logger{Next: next, Rules: rules, ErrorFunc: httpserver.DefaultErrorFunc} @@ -111,18 +54,20 @@ func logParse(c *caddy.Controller) ([]*Rule, error) { if len(args) == 0 { // Nothing specified; use defaults rules = appendEntry(rules, "/", &Entry{ - OutputFile: DefaultLogFilename, - Format: DefaultLogFormat, - Roller: logRoller, - fileMu: new(sync.RWMutex), + Log: &httpserver.Logger{ + Output: DefaultLogFilename, + Roller: logRoller, + }, + Format: DefaultLogFormat, }) } else if len(args) == 1 { // Only an output file specified rules = appendEntry(rules, "/", &Entry{ - OutputFile: args[0], - Format: DefaultLogFormat, - Roller: logRoller, - fileMu: new(sync.RWMutex), + Log: &httpserver.Logger{ + Output: args[0], + Roller: logRoller, + }, + Format: DefaultLogFormat, }) } else { // Path scope, output file, and maybe a format specified @@ -141,10 +86,11 @@ func logParse(c *caddy.Controller) ([]*Rule, error) { } rules = appendEntry(rules, args[0], &Entry{ - OutputFile: args[1], - Format: format, - Roller: logRoller, - fileMu: new(sync.RWMutex), + Log: &httpserver.Logger{ + Output: args[1], + Roller: logRoller, + }, + Format: format, }) } } diff --git a/caddyhttp/log/setup_test.go b/caddyhttp/log/setup_test.go index 8d6139070..fa82e69ce 100644 --- a/caddyhttp/log/setup_test.go +++ b/caddyhttp/log/setup_test.go @@ -3,6 +3,8 @@ package log import ( "testing" + "reflect" + "github.com/mholt/caddy" "github.com/mholt/caddy/caddyhttp/httpserver" ) @@ -29,20 +31,19 @@ func TestSetup(t *testing.T) { if myHandler.Rules[0].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 { 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) { t.Error("'Next' field of handler was not set properly") } - } func TestLogParse(t *testing.T) { @@ -54,95 +55,108 @@ func TestLogParse(t *testing.T) { {`log`, false, []Rule{{ PathScope: "/", Entries: []*Entry{{ - OutputFile: DefaultLogFilename, - Format: DefaultLogFormat, + Log: &httpserver.Logger{Output: DefaultLogFilename}, + Format: DefaultLogFormat, }}, }}}, {`log log.txt`, false, []Rule{{ PathScope: "/", Entries: []*Entry{{ - OutputFile: "log.txt", - Format: DefaultLogFormat, + Log: &httpserver.Logger{Output: "log.txt"}, + 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{{ PathScope: "/api", Entries: []*Entry{{ - OutputFile: "log.txt", - Format: DefaultLogFormat, + Log: &httpserver.Logger{Output: "log.txt"}, + Format: DefaultLogFormat, }}, }}}, {`log /serve stdout`, false, []Rule{{ PathScope: "/serve", Entries: []*Entry{{ - OutputFile: "stdout", - Format: DefaultLogFormat, + Log: &httpserver.Logger{Output: "stdout"}, + Format: DefaultLogFormat, }}, }}}, {`log /myapi log.txt {common}`, false, []Rule{{ PathScope: "/myapi", Entries: []*Entry{{ - OutputFile: "log.txt", - Format: CommonLogFormat, + Log: &httpserver.Logger{Output: "log.txt"}, + Format: CommonLogFormat, }}, }}}, {`log /test accesslog.txt {combined}`, false, []Rule{{ PathScope: "/test", Entries: []*Entry{{ - OutputFile: "accesslog.txt", - Format: CombinedLogFormat, + Log: &httpserver.Logger{Output: "accesslog.txt"}, + Format: CombinedLogFormat, }}, }}}, {`log /api1 log.txt log /api2 accesslog.txt {combined}`, false, []Rule{{ PathScope: "/api1", Entries: []*Entry{{ - OutputFile: "log.txt", - Format: DefaultLogFormat, + Log: &httpserver.Logger{Output: "log.txt"}, + Format: DefaultLogFormat, }}, }, { PathScope: "/api2", Entries: []*Entry{{ - OutputFile: "accesslog.txt", - Format: CombinedLogFormat, + Log: &httpserver.Logger{Output: "accesslog.txt"}, + Format: CombinedLogFormat, }}, }}}, {`log /api3 stdout {host} log /api4 log.txt {when}`, false, []Rule{{ PathScope: "/api3", Entries: []*Entry{{ - OutputFile: "stdout", - Format: "{host}", + Log: &httpserver.Logger{Output: "stdout"}, + Format: "{host}", }}, }, { PathScope: "/api4", Entries: []*Entry{{ - OutputFile: "log.txt", - Format: "{when}", + Log: &httpserver.Logger{Output: "log.txt"}, + Format: "{when}", }}, }}}, {`log access.log { rotate { size 2 age 10 keep 3 } }`, false, []Rule{{ PathScope: "/", Entries: []*Entry{{ - OutputFile: "access.log", - Format: DefaultLogFormat, - Roller: &httpserver.LogRoller{ + Log: &httpserver.Logger{Output: "access.log", Roller: &httpserver.LogRoller{ MaxSize: 2, MaxAge: 10, MaxBackups: 3, LocalTime: true, - }, + }}, + Format: DefaultLogFormat, }}, }}}, {`log / stdout {host} log / log.txt {when}`, false, []Rule{{ PathScope: "/", Entries: []*Entry{{ - OutputFile: "stdout", - Format: "{host}", + Log: &httpserver.Logger{Output: "stdout"}, + Format: "{host}", }, { - OutputFile: "log.txt", - Format: "{when}", + Log: &httpserver.Logger{Output: "log.txt"}, + Format: "{when}", }}, }}}, } @@ -172,43 +186,16 @@ func TestLogParse(t *testing.T) { } for k, actualEntry := range actualLogRule.Entries { - if actualEntry.OutputFile != test.expectedLogRules[j].Entries[k].OutputFile { - t.Errorf("Test %d expected %dth LogRule OutputFile to be %s , but got %s", - i, j, test.expectedLogRules[j].Entries[k].OutputFile, actualEntry.OutputFile) + if !reflect.DeepEqual(actualEntry.Log, test.expectedLogRules[j].Entries[k].Log) { + t.Errorf("Test %d expected %dth LogRule Log to be %v , but got %v", + i, j, test.expectedLogRules[j].Entries[k].Log, actualEntry.Log) } if actualEntry.Format != test.expectedLogRules[j].Entries[k].Format { t.Errorf("Test %d expected %dth LogRule Format to be %s , but got %s", 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) - } - } } } } - } diff --git a/caddyhttp/markdown/process_test.go b/caddyhttp/markdown/process_test.go index bce1613d6..fbafaf989 100644 --- a/caddyhttp/markdown/process_test.go +++ b/caddyhttp/markdown/process_test.go @@ -1,10 +1,11 @@ package markdown import ( - "github.com/mholt/caddy/caddyhttp/httpserver" "os" "strings" "testing" + + "github.com/mholt/caddy/caddyhttp/httpserver" ) func TestConfig_Markdown(t *testing.T) {