go/echo
go/echo
1
0
Fork 0
mirror of https://github.com/labstack/echo.git synced 2024-11-24 08:22:21 +02:00
Code Issues Releases Activity

Additional configuration options for RequestLogger and Logger middleware (#2341)

Browse Source 
* Add `middleware.RequestLoggerConfig.HandleError` configuration option to handle error within middleware with global error handler thus setting response status code decided by error handler and not derived from error itself.
* Add `middleware.LoggerConfig.CustomTagFunc` so Logger middleware can add custom text to logged row.
This commit is contained in:
Martti T 2022-11-30 15:47:23 +02:00 committed by GitHub
parent 466bf80e41
commit 8d4ac4c907
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 162 additions and 33 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

6
context.go
View File

@ -169,7 +169,11 @@ type (
// Redirect redirects the request to a provided URL with status code.
Redirect(code int, url string) error
// Error invokes the registered HTTP error handler. Generally used by middleware.
// Error invokes the registered global HTTP error handler. Generally used by middleware.
// A side-effect of calling global error handler is that now Response has been committed (sent to the client) and
// middlewares up in chain can not change Response status code or Response body anymore.
//
// Avoid using this method in handlers as no middleware will be able to effectively handle errors after that.
Error(err error)
// Handler returns the matched handler by router.

2
echo.go
View File

@ -116,7 +116,7 @@ type (
HandlerFunc func(c Context) error
// HTTPErrorHandler is a centralized HTTP error handler.
HTTPErrorHandler func(error, Context)
HTTPErrorHandler func(err error, c Context)
// Validator is the interface that wraps the Validate function.
Validator interface {

11
middleware/logger.go
View File

@ -47,6 +47,7 @@ type (
// - header:<NAME>
// - query:<NAME>
// - form:<NAME>
// - custom (see CustomTagFunc field)
//
// Example "${remote_ip} ${status}"
//
@ -56,6 +57,11 @@ type (
// Optional. Default value DefaultLoggerConfig.CustomTimeFormat.
CustomTimeFormat string `yaml:"custom_time_format"`
// CustomTagFunc is function called for `${custom}` tag to output user implemented text by writing it to buf.
// Make sure that outputted text creates valid JSON string with other logged tags.
// Optional.
CustomTagFunc func(c echo.Context, buf *bytes.Buffer) (int, error)
// Output is a writer where logs in JSON format are written.
// Optional. Default value os.Stdout.
Output io.Writer
@ -126,6 +132,11 @@ func LoggerWithConfig(config LoggerConfig) echo.MiddlewareFunc {
if _, err = config.template.ExecuteFunc(buf, func(w io.Writer, tag string) (int, error) {
switch tag {
case "custom":
if config.CustomTagFunc == nil {
return 0, nil
}
return config.CustomTagFunc(c, buf)
case "time_unix":
return buf.WriteString(strconv.FormatInt(time.Now().Unix(), 10))
case "time_unix_milli":

22
middleware/logger_test.go
View File

@ -173,6 +173,28 @@ func TestLoggerCustomTimestamp(t *testing.T) {
assert.Error(t, err)
}
func TestLoggerCustomTagFunc(t *testing.T) {
e := echo.New()
buf := new(bytes.Buffer)
e.Use(LoggerWithConfig(LoggerConfig{
Format: `{"method":"${method}",${custom}}` + "\n",
CustomTagFunc: func(c echo.Context, buf *bytes.Buffer) (int, error) {
return buf.WriteString(`"tag":"my-value"`)
},
Output: buf,
}))
e.GET("/", func(c echo.Context) error {
return c.String(http.StatusOK, "custom time stamp test")
})
req := httptest.NewRequest(http.MethodGet, "/", nil)
rec := httptest.NewRecorder()
e.ServeHTTP(rec, req)
assert.Equal(t, `{"method":"GET","tag":"my-value"}`+"\n", buf.String())
}
func BenchmarkLoggerWithConfig_withoutMapFields(b *testing.B) {
e := echo.New()

102
middleware/request_logger.go
View File

@ -10,10 +10,16 @@ import (
// Example for `fmt.Printf`
// e.Use(middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
// LogStatus: true,
// LogURI: true,
// LogStatus: true,
// LogURI: true,
// LogError: true,
// HandleError: true, // forwards error to the global error handler, so it can decide appropriate status code
// LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error {
// fmt.Printf("REQUEST: uri: %v, status: %v\n", v.URI, v.Status)
// if v.Error == nil {
// fmt.Printf("REQUEST: uri: %v, status: %v\n", v.URI, v.Status)
// } else {
// fmt.Printf("REQUEST_ERROR: uri: %v, status: %v, err: %v\n", v.URI, v.Status, v.Error)
// }
// return nil
// },
// }))
@ -21,14 +27,23 @@ import (
// Example for Zerolog (https://github.com/rs/zerolog)
// logger := zerolog.New(os.Stdout)
// e.Use(middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
// LogURI: true,
// LogStatus: true,
// LogURI: true,
// LogStatus: true,
// LogError: true,
// HandleError: true, // forwards error to the global error handler, so it can decide appropriate status code
// LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error {
// logger.Info().
// Str("URI", v.URI).
// Int("status", v.Status).
// Msg("request")
//
// if v.Error == nil {
// logger.Info().
// Str("URI", v.URI).
// Int("status", v.Status).
// Msg("request")
// } else {
// logger.Error().
// Err(v.Error).
// Str("URI", v.URI).
// Int("status", v.Status).
// Msg("request error")
// }
// return nil
// },
// }))
@ -36,29 +51,47 @@ import (
// Example for Zap (https://github.com/uber-go/zap)
// logger, _ := zap.NewProduction()
// e.Use(middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
// LogURI: true,
// LogStatus: true,
// LogURI: true,
// LogStatus: true,
// LogError: true,
// HandleError: true, // forwards error to the global error handler, so it can decide appropriate status code
// LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error {
// logger.Info("request",
// zap.String("URI", v.URI),
// zap.Int("status", v.Status),
// )
//
// if v.Error == nil {
// logger.Info("request",
// zap.String("URI", v.URI),
// zap.Int("status", v.Status),
// )
// } else {
// logger.Error("request error",
// zap.String("URI", v.URI),
// zap.Int("status", v.Status),
// zap.Error(v.Error),
// )
// }
// return nil
// },
// }))
//
// Example for Logrus (https://github.com/sirupsen/logrus)
// log := logrus.New()
// log := logrus.New()
// e.Use(middleware.RequestLoggerWithConfig(middleware.RequestLoggerConfig{
// LogURI: true,
// LogStatus: true,
// LogValuesFunc: func(c echo.Context, values middleware.RequestLoggerValues) error {
// log.WithFields(logrus.Fields{
// "URI": values.URI,
// "status": values.Status,
// }).Info("request")
//
// LogURI: true,
// LogStatus: true,
// LogError: true,
// HandleError: true, // forwards error to the global error handler, so it can decide appropriate status code
// LogValuesFunc: func(c echo.Context, v middleware.RequestLoggerValues) error {
// if v.Error == nil {
// log.WithFields(logrus.Fields{
// "URI": v.URI,
// "status": v.Status,
// }).Info("request")
// } else {
// log.WithFields(logrus.Fields{
// "URI": v.URI,
// "status": v.Status,
// "error": v.Error,
// }).Error("request error")
// }
// return nil
// },
// }))
@ -74,6 +107,13 @@ type RequestLoggerConfig struct {
// Mandatory.
LogValuesFunc func(c echo.Context, v RequestLoggerValues) error
// HandleError instructs logger to call global error handler when next middleware/handler returns an error.
// This is useful when you have custom error handler that can decide to use different status codes.
//
// A side-effect of calling global error handler is that now Response has been committed and sent to the client
// and middlewares up in chain can not change Response status code or response body.
HandleError bool
// LogLatency instructs logger to record duration it took to execute rest of the handler chain (next(c) call).
LogLatency bool
// LogProtocol instructs logger to extract request protocol (i.e. `HTTP/1.1` or `HTTP/2`)
@ -217,6 +257,9 @@ func (config RequestLoggerConfig) ToMiddleware() (echo.MiddlewareFunc, error) {
config.BeforeNextFunc(c)
}
err := next(c)
if config.HandleError {
c.Error(err)
}
v := RequestLoggerValues{
StartTime: start,
@ -264,7 +307,9 @@ func (config RequestLoggerConfig) ToMiddleware() (echo.MiddlewareFunc, error) {
}
if config.LogStatus {
v.Status = res.Status
if err != nil {
if err != nil && !config.HandleError {
// this block should not be executed in case of HandleError=true as the global error handler will decide
// the status code. In that case status code could be different from what err contains.
var httpErr *echo.HTTPError
if errors.As(err, &httpErr) {
v.Status = httpErr.Code
@ -310,6 +355,9 @@ func (config RequestLoggerConfig) ToMiddleware() (echo.MiddlewareFunc, error) {
return errOnLog
}
// in case of HandleError=true we are returning the error that we already have handled with global error handler
// this is deliberate as this error could be useful for upstream middlewares and default global error handler
// will ignore that error when it bubbles up in middleware chain.
return err
}
}, nil

52
middleware/request_logger_test.go
View File

@ -103,12 +103,12 @@ func TestRequestLogger_beforeNextFunc(t *testing.T) {
func TestRequestLogger_logError(t *testing.T) {
e := echo.New()
var expect RequestLoggerValues
var actual RequestLoggerValues
e.Use(RequestLoggerWithConfig(RequestLoggerConfig{
LogError: true,
LogStatus: true,
LogValuesFunc: func(c echo.Context, values RequestLoggerValues) error {
expect = values
actual = values
return nil
},
}))
@ -123,8 +123,52 @@ func TestRequestLogger_logError(t *testing.T) {
e.ServeHTTP(rec, req)
assert.Equal(t, http.StatusNotAcceptable, rec.Code)
assert.Equal(t, http.StatusNotAcceptable, expect.Status)
assert.EqualError(t, expect.Error, "code=406, message=nope")
assert.Equal(t, http.StatusNotAcceptable, actual.Status)
assert.EqualError(t, actual.Error, "code=406, message=nope")
}
func TestRequestLogger_HandleError(t *testing.T) {
e := echo.New()
var actual RequestLoggerValues
e.Use(RequestLoggerWithConfig(RequestLoggerConfig{
timeNow: func() time.Time {
return time.Unix(1631045377, 0).UTC()
},
HandleError: true,
LogError: true,
LogStatus: true,
LogValuesFunc: func(c echo.Context, values RequestLoggerValues) error {
actual = values
return nil
},
}))
// to see if "HandleError" works we create custom error handler that uses its own status codes
e.HTTPErrorHandler = func(err error, c echo.Context) {
if c.Response().Committed {
return
}
c.JSON(http.StatusTeapot, "custom error handler")
}
e.GET("/test", func(c echo.Context) error {
return echo.NewHTTPError(http.StatusForbidden, "nope")
})
req := httptest.NewRequest(http.MethodGet, "/test", nil)
rec := httptest.NewRecorder()
e.ServeHTTP(rec, req)
assert.Equal(t, http.StatusTeapot, rec.Code)
expect := RequestLoggerValues{
StartTime: time.Unix(1631045377, 0).UTC(),
Status: http.StatusTeapot,
Error: echo.NewHTTPError(http.StatusForbidden, "nope"),
}
assert.Equal(t, expect, actual)
}
func TestRequestLogger_LogValuesFuncError(t *testing.T) {