diff --git a/caddyhttp/caddyhttp.go b/caddyhttp/caddyhttp.go index 5c804b648..9b9514d58 100644 --- a/caddyhttp/caddyhttp.go +++ b/caddyhttp/caddyhttp.go @@ -6,6 +6,7 @@ import ( // plug in the standard directives _ "github.com/mholt/caddy/caddyhttp/bind" + _ "github.com/mholt/caddy/caddyhttp/errors" _ "github.com/mholt/caddy/caddyhttp/gzip" _ "github.com/mholt/caddy/caddyhttp/log" _ "github.com/mholt/caddy/caddyhttp/root" diff --git a/caddyhttp/errors/errors.go b/caddyhttp/errors/errors.go new file mode 100644 index 000000000..2527b0069 --- /dev/null +++ b/caddyhttp/errors/errors.go @@ -0,0 +1,141 @@ +// Package errors implements an HTTP error handling middleware. +package errors + +import ( + "fmt" + "io" + "log" + "net/http" + "os" + "runtime" + "strings" + "time" + + "github.com/mholt/caddy" + "github.com/mholt/caddy/caddyhttp/httpserver" +) + +func init() { + caddy.RegisterPlugin(caddy.Plugin{ + Name: "errors", + ServerType: "http", + Action: setup, + }) +} + +// ErrorHandler handles HTTP errors (and errors from other middleware). +type ErrorHandler struct { + Next httpserver.Handler + 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 +} + +func (h ErrorHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) (int, error) { + defer h.recovery(w, r) + + status, err := h.Next.ServeHTTP(w, r) + + if err != nil { + errMsg := fmt.Sprintf("%s [ERROR %d %s] %v", time.Now().Format(timeFormat), status, r.URL.Path, err) + if h.Debug { + // Write error to response instead of to log + w.Header().Set("Content-Type", "text/plain; charset=utf-8") + w.WriteHeader(status) + fmt.Fprintln(w, errMsg) + return 0, err // returning 0 signals that a response has been written + } + h.Log.Println(errMsg) + } + + if status >= 400 { + h.errorPage(w, r, status) + return 0, err + } + + return status, err +} + +// errorPage serves a static error page to w according to the status +// code. If there is an error serving the error page, a plaintext error +// message is written instead, and the extra error is logged. +func (h ErrorHandler) errorPage(w http.ResponseWriter, r *http.Request, code int) { + // See if an error page for this status code was specified + if pagePath, ok := h.ErrorPages[code]; ok { + // Try to open it + errorPage, err := os.Open(pagePath) + if err != nil { + // An additional error handling an error... + h.Log.Printf("%s [NOTICE %d %s] could not load error page: %v", + time.Now().Format(timeFormat), code, r.URL.String(), err) + httpserver.DefaultErrorFunc(w, r, code) + return + } + defer errorPage.Close() + + // Copy the page body into the response + w.Header().Set("Content-Type", "text/html; charset=utf-8") + w.WriteHeader(code) + _, err = io.Copy(w, errorPage) + + if err != nil { + // Epic fail... sigh. + h.Log.Printf("%s [NOTICE %d %s] could not respond with %s: %v", + time.Now().Format(timeFormat), code, r.URL.String(), pagePath, err) + httpserver.DefaultErrorFunc(w, r, code) + } + + return + } + + // Default error response + httpserver.DefaultErrorFunc(w, r, code) +} + +func (h ErrorHandler) recovery(w http.ResponseWriter, r *http.Request) { + rec := recover() + if rec == nil { + return + } + + // Obtain source of panic + // From: https://gist.github.com/swdunlop/9629168 + var name, file string // function name, file name + var line int + var pc [16]uintptr + n := runtime.Callers(3, pc[:]) + for _, pc := range pc[:n] { + fn := runtime.FuncForPC(pc) + if fn == nil { + continue + } + file, line = fn.FileLine(pc) + name = fn.Name() + if !strings.HasPrefix(name, "runtime.") { + break + } + } + + // Trim file path + delim := "/caddy/" + pkgPathPos := strings.Index(file, delim) + if pkgPathPos > -1 && len(file) > pkgPathPos+len(delim) { + file = file[pkgPathPos+len(delim):] + } + + panicMsg := fmt.Sprintf("%s [PANIC %s] %s:%d - %v", time.Now().Format(timeFormat), r.URL.String(), file, line, rec) + if h.Debug { + // Write error and stack trace to the response rather than to a log + var stackBuf [4096]byte + stack := stackBuf[:runtime.Stack(stackBuf[:], false)] + 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.Log.Printf(panicMsg) + h.errorPage(w, r, http.StatusInternalServerError) + } +} + +const timeFormat = "02/Jan/2006:15:04:05 -0700" diff --git a/caddyhttp/errors/errors_test.go b/caddyhttp/errors/errors_test.go new file mode 100644 index 000000000..26456c7a9 --- /dev/null +++ b/caddyhttp/errors/errors_test.go @@ -0,0 +1,168 @@ +package errors + +import ( + "bytes" + "errors" + "fmt" + "log" + "net/http" + "net/http/httptest" + "os" + "path/filepath" + "strconv" + "strings" + "testing" + + "github.com/mholt/caddy/caddyhttp/httpserver" +) + +func TestErrors(t *testing.T) { + // create a temporary page + path := filepath.Join(os.TempDir(), "errors_test.html") + f, err := os.Create(path) + if err != nil { + t.Fatal(err) + } + defer os.Remove(path) + + const content = "This is a error page" + _, err = f.WriteString(content) + if err != nil { + t.Fatal(err) + } + f.Close() + + buf := bytes.Buffer{} + em := ErrorHandler{ + ErrorPages: map[int]string{ + http.StatusNotFound: path, + http.StatusForbidden: "not_exist_file", + }, + Log: log.New(&buf, "", 0), + } + _, notExistErr := os.Open("not_exist_file") + + testErr := errors.New("test error") + tests := []struct { + next httpserver.Handler + expectedCode int + expectedBody string + expectedLog string + expectedErr error + }{ + { + next: genErrorHandler(http.StatusOK, nil, "normal"), + expectedCode: http.StatusOK, + expectedBody: "normal", + expectedLog: "", + expectedErr: nil, + }, + { + next: genErrorHandler(http.StatusMovedPermanently, testErr, ""), + expectedCode: http.StatusMovedPermanently, + expectedBody: "", + expectedLog: fmt.Sprintf("[ERROR %d %s] %v\n", http.StatusMovedPermanently, "/", testErr), + expectedErr: testErr, + }, + { + next: genErrorHandler(http.StatusBadRequest, nil, ""), + expectedCode: 0, + expectedBody: fmt.Sprintf("%d %s\n", http.StatusBadRequest, + http.StatusText(http.StatusBadRequest)), + expectedLog: "", + expectedErr: nil, + }, + { + next: genErrorHandler(http.StatusNotFound, nil, ""), + expectedCode: 0, + expectedBody: content, + expectedLog: "", + expectedErr: nil, + }, + { + next: genErrorHandler(http.StatusForbidden, nil, ""), + expectedCode: 0, + expectedBody: fmt.Sprintf("%d %s\n", http.StatusForbidden, + http.StatusText(http.StatusForbidden)), + expectedLog: fmt.Sprintf("[NOTICE %d /] could not load error page: %v\n", + http.StatusForbidden, notExistErr), + expectedErr: nil, + }, + } + + req, err := http.NewRequest("GET", "/", nil) + if err != nil { + t.Fatal(err) + } + for i, test := range tests { + em.Next = test.next + buf.Reset() + rec := httptest.NewRecorder() + code, err := em.ServeHTTP(rec, req) + + if err != test.expectedErr { + t.Errorf("Test %d: Expected error %v, but got %v", + i, test.expectedErr, err) + } + if code != test.expectedCode { + t.Errorf("Test %d: Expected status code %d, but got %d", + i, test.expectedCode, code) + } + if body := rec.Body.String(); body != test.expectedBody { + t.Errorf("Test %d: Expected body %q, but got %q", + i, test.expectedBody, body) + } + if log := buf.String(); !strings.Contains(log, test.expectedLog) { + t.Errorf("Test %d: Expected log %q, but got %q", + i, test.expectedLog, log) + } + } +} + +func TestVisibleErrorWithPanic(t *testing.T) { + const panicMsg = "I'm a panic" + eh := ErrorHandler{ + ErrorPages: make(map[int]string), + Debug: true, + Next: httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) { + panic(panicMsg) + }), + } + + req, err := http.NewRequest("GET", "/", nil) + if err != nil { + t.Fatal(err) + } + rec := httptest.NewRecorder() + + code, err := eh.ServeHTTP(rec, req) + + if code != 0 { + t.Errorf("Expected error handler to return 0 (it should write to response), got status %d", code) + } + if err != nil { + t.Errorf("Expected error handler to return nil error (it should panic!), but got '%v'", err) + } + + body := rec.Body.String() + + if !strings.Contains(body, "[PANIC /] caddyhttp/errors/errors_test.go") { + t.Errorf("Expected response body to contain error log line, but it didn't:\n%s", body) + } + if !strings.Contains(body, panicMsg) { + t.Errorf("Expected response body to contain panic message, but it didn't:\n%s", body) + } + if len(body) < 500 { + t.Errorf("Expected response body to contain stack trace, but it was too short: len=%d", len(body)) + } +} + +func genErrorHandler(status int, err error, body string) httpserver.Handler { + return httpserver.HandlerFunc(func(w http.ResponseWriter, r *http.Request) (int, error) { + if len(body) > 0 { + w.Header().Set("Content-Length", strconv.Itoa(len(body))) + fmt.Fprint(w, body) + } + return status, err + }) +} diff --git a/caddyhttp/errors/setup.go b/caddyhttp/errors/setup.go new file mode 100644 index 000000000..f43c95e97 --- /dev/null +++ b/caddyhttp/errors/setup.go @@ -0,0 +1,152 @@ +package errors + +import ( + "io" + "log" + "os" + "path/filepath" + "strconv" + + "github.com/hashicorp/go-syslog" + "github.com/mholt/caddy" + "github.com/mholt/caddy/caddyhttp/httpserver" +) + +// 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 { + writer = file + } + } + + handler.Log = log.New(writer, "", 0) + return nil + }) + + httpserver.GetConfig(c.Key).AddMiddleware(func(next httpserver.Handler) httpserver.Handler { + handler.Next = next + return handler + }) + + return nil +} + +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)} + + cfg := httpserver.GetConfig(c.Key) + + optionalBlock := func() (bool, error) { + var hadBlock bool + + for c.NextBlock() { + hadBlock = true + + what := c.Val() + if !c.NextArg() { + return hadBlock, c.ArgErr() + } + where := c.Val() + + if what == "log" { + if where == "visible" { + handler.Debug = true + } else { + handler.LogFile = where + if c.NextArg() { + if c.Val() == "{" { + c.IncrNest() + logRoller, err := httpserver.ParseRoller(c) + if err != nil { + return hadBlock, err + } + handler.LogRoller = logRoller + } + } + } + } else { + // Error page; ensure it exists + 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) + } + f.Close() + + whatInt, err := strconv.Atoi(what) + if err != nil { + return hadBlock, c.Err("Expecting a numeric status code, got '" + what + "'") + } + handler.ErrorPages[whatInt] = where + } + } + return hadBlock, nil + } + + for c.Next() { + // weird hack to avoid having the handler values overwritten. + if c.Val() == "}" { + continue + } + // Configuration may be in a block + hadBlock, err := optionalBlock() + if err != nil { + return handler, err + } + + // Otherwise, the only argument would be an error log file name or 'visible' + if !hadBlock { + if c.NextArg() { + if c.Val() == "visible" { + handler.Debug = true + } else { + handler.LogFile = c.Val() + } + } + } + } + + return handler, nil +} diff --git a/caddyhttp/errors/setup_test.go b/caddyhttp/errors/setup_test.go new file mode 100644 index 000000000..aed907ee8 --- /dev/null +++ b/caddyhttp/errors/setup_test.go @@ -0,0 +1,154 @@ +package errors + +import ( + "testing" + + "github.com/mholt/caddy" + "github.com/mholt/caddy/caddyhttp/httpserver" +) + +func TestSetup(t *testing.T) { + err := setup(caddy.NewTestController(`errors`)) + if err != nil { + t.Errorf("Expected no errors, got: %v", err) + } + mids := httpserver.GetConfig("").Middleware() + if len(mids) == 0 { + t.Fatal("Expected middlewares, was nil instead") + } + + handler := mids[0](httpserver.EmptyNext) + myHandler, ok := handler.(*ErrorHandler) + if !ok { + 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) + } + if !httpserver.SameNext(myHandler.Next, httpserver.EmptyNext) { + t.Error("'Next' field of handler was not set properly") + } + + // Test Startup function -- TODO + // if len(c.Startup) == 0 { + // t.Fatal("Expected 1 startup function, had 0") + // } + // c.Startup[0]() + // if myHandler.Log == nil { + // t.Error("Expected Log to be non-nil after startup because Debug is not enabled") + // } +} + +func TestErrorsParse(t *testing.T) { + tests := []struct { + inputErrorsRules string + shouldErr bool + expectedErrorHandler ErrorHandler + }{ + {`errors`, false, ErrorHandler{ + LogFile: "", + }}, + {`errors errors.txt`, false, ErrorHandler{ + LogFile: "errors.txt", + }}, + {`errors visible`, false, ErrorHandler{ + LogFile: "", + Debug: true, + }}, + {`errors { log visible }`, false, ErrorHandler{ + LogFile: "", + Debug: true, + }}, + {`errors { log errors.txt + 404 404.html + 500 500.html +}`, false, ErrorHandler{ + LogFile: "errors.txt", + ErrorPages: map[int]string{ + 404: "404.html", + 500: "500.html", + }, + }}, + {`errors { log errors.txt { size 2 age 10 keep 3 } }`, false, ErrorHandler{ + LogFile: "errors.txt", + LogRoller: &httpserver.LogRoller{ + MaxSize: 2, + MaxAge: 10, + MaxBackups: 3, + LocalTime: true, + }, + }}, + {`errors { log errors.txt { + size 3 + age 11 + keep 5 + } + 404 404.html + 503 503.html +}`, false, ErrorHandler{ + LogFile: "errors.txt", + ErrorPages: map[int]string{ + 404: "404.html", + 503: "503.html", + }, + LogRoller: &httpserver.LogRoller{ + MaxSize: 3, + MaxAge: 11, + MaxBackups: 5, + LocalTime: true, + }, + }}, + } + for i, test := range tests { + actualErrorsRule, err := errorsParse(caddy.NewTestController(test.inputErrorsRules)) + + if err == nil && test.shouldErr { + t.Errorf("Test %d didn't error, but it should have", i) + } else if err != nil && !test.shouldErr { + t.Errorf("Test %d errored, but it shouldn't have; got '%v'", i, err) + } + if actualErrorsRule.LogFile != test.expectedErrorHandler.LogFile { + t.Errorf("Test %d expected LogFile to be %s, but got %s", + i, test.expectedErrorHandler.LogFile, actualErrorsRule.LogFile) + } + if actualErrorsRule.Debug != test.expectedErrorHandler.Debug { + t.Errorf("Test %d expected Debug to be %v, but got %v", + i, test.expectedErrorHandler.Debug, actualErrorsRule.Debug) + } + if actualErrorsRule.LogRoller != nil && test.expectedErrorHandler.LogRoller == nil || actualErrorsRule.LogRoller == nil && test.expectedErrorHandler.LogRoller != nil { + t.Fatalf("Test %d expected LogRoller to be %v, but got %v", + i, test.expectedErrorHandler.LogRoller, actualErrorsRule.LogRoller) + } + if len(actualErrorsRule.ErrorPages) != len(test.expectedErrorHandler.ErrorPages) { + t.Fatalf("Test %d expected %d no of Error pages, but got %d ", + i, len(test.expectedErrorHandler.ErrorPages), len(actualErrorsRule.ErrorPages)) + } + if actualErrorsRule.LogRoller != nil && test.expectedErrorHandler.LogRoller != nil { + if actualErrorsRule.LogRoller.Filename != test.expectedErrorHandler.LogRoller.Filename { + t.Fatalf("Test %d expected LogRoller Filename to be %s, but got %s", + i, test.expectedErrorHandler.LogRoller.Filename, actualErrorsRule.LogRoller.Filename) + } + if actualErrorsRule.LogRoller.MaxAge != test.expectedErrorHandler.LogRoller.MaxAge { + t.Fatalf("Test %d expected LogRoller MaxAge to be %d, but got %d", + i, test.expectedErrorHandler.LogRoller.MaxAge, actualErrorsRule.LogRoller.MaxAge) + } + if actualErrorsRule.LogRoller.MaxBackups != test.expectedErrorHandler.LogRoller.MaxBackups { + t.Fatalf("Test %d expected LogRoller MaxBackups to be %d, but got %d", + i, test.expectedErrorHandler.LogRoller.MaxBackups, actualErrorsRule.LogRoller.MaxBackups) + } + if actualErrorsRule.LogRoller.MaxSize != test.expectedErrorHandler.LogRoller.MaxSize { + t.Fatalf("Test %d expected LogRoller MaxSize to be %d, but got %d", + i, test.expectedErrorHandler.LogRoller.MaxSize, actualErrorsRule.LogRoller.MaxSize) + } + if actualErrorsRule.LogRoller.LocalTime != test.expectedErrorHandler.LogRoller.LocalTime { + t.Fatalf("Test %d expected LogRoller LocalTime to be %t, but got %t", + i, test.expectedErrorHandler.LogRoller.LocalTime, actualErrorsRule.LogRoller.LocalTime) + } + } + } + +} diff --git a/caddyhttp/httpserver/server.go b/caddyhttp/httpserver/server.go index e1270ec64..2156bcf42 100644 --- a/caddyhttp/httpserver/server.go +++ b/caddyhttp/httpserver/server.go @@ -214,7 +214,7 @@ func (s *Server) serveHTTP(w http.ResponseWriter, r *http.Request) (int, error) if err != nil { remoteHost = r.RemoteAddr } - writeTextResponse(w, http.StatusNotFound, "No such site at "+s.Server.Addr) + WriteTextResponse(w, http.StatusNotFound, "No such site at "+s.Server.Addr) log.Printf("[INFO] %s - No such site at %s (Remote: %s, Referer: %s)", hostname, s.Server.Addr, remoteHost, r.Header.Get("Referer")) return 0, nil @@ -329,7 +329,7 @@ func (s *Server) OnStartupComplete() { } for _, site := range s.sites { output := site.Addr.String() - if caddy.IsLocalhost(s.Address()) && !caddy.IsLocalhost(site.Addr.Host) { + if caddy.IsLoopback(s.Address()) && !caddy.IsLoopback(site.Addr.Host) { output += " (only accessible on this machine)" } fmt.Println(output) @@ -365,12 +365,12 @@ func (ln tcpKeepAliveListener) File() (*os.File, error) { // DefaultErrorFunc responds to an HTTP request with a simple description // of the specified HTTP status code. func DefaultErrorFunc(w http.ResponseWriter, r *http.Request, status int) { - writeTextResponse(w, status, fmt.Sprintf("%d %s", status, http.StatusText(status))) + WriteTextResponse(w, status, fmt.Sprintf("%d %s\n", status, http.StatusText(status))) } -// writeTextResponse writes body with code status to w. The body will +// WriteTextResponse writes body with code status to w. The body will // be interpreted as plain text. -func writeTextResponse(w http.ResponseWriter, status int, body string) { +func WriteTextResponse(w http.ResponseWriter, status int, body string) { w.Header().Set("Content-Type", "text/plain; charset=utf-8") w.Header().Set("X-Content-Type-Options", "nosniff") w.WriteHeader(status)