From 0be856e54c989b04f9f6af3c644b538ec206f7c4 Mon Sep 17 00:00:00 2001 From: "Gerasimos (Makis) Maropoulos" Date: Sun, 6 Sep 2020 10:38:48 +0300 Subject: [PATCH] add accesslog middleware (rel: #1601) --- HISTORY.md | 3 + NOTICE | 5 +- _examples/README.md | 3 +- .../access.log.sample | 0 .../logging/request-logger/accesslog/main.go | 47 ++++ .../public/index.html | 0 _examples/logging/request-logger/main.go | 1 - .../request-logger-access-log-file/main.go | 174 ------------ .../request-logger-file/main.go | 107 -------- configuration.go | 2 + context/context.go | 35 ++- core/router/fs.go | 12 +- go.mod | 1 - middleware/accesslog/accesslog.go | 251 ++++++++++++++++++ middleware/logger/config.go | 14 +- middleware/logger/logger.go | 31 --- 16 files changed, 339 insertions(+), 347 deletions(-) rename _examples/logging/request-logger/{request-logger-access-log-file => accesslog}/access.log.sample (100%) create mode 100644 _examples/logging/request-logger/accesslog/main.go rename _examples/logging/request-logger/{request-logger-access-log-file => accesslog}/public/index.html (100%) delete mode 100644 _examples/logging/request-logger/request-logger-access-log-file/main.go delete mode 100644 _examples/logging/request-logger/request-logger-file/main.go create mode 100644 middleware/accesslog/accesslog.go diff --git a/HISTORY.md b/HISTORY.md index 350bb5b5..50a6764e 100644 --- a/HISTORY.md +++ b/HISTORY.md @@ -602,6 +602,8 @@ New Package-level Variables: New Context Methods: +- `Context.RecordBody()` same as the Application's `DisableBodyConsumptionOnUnmarshal` configuration field but registers per chain of handlers. It makes the request body readable more than once. +- `Context.IsRecordingBody() bool` reports whether the request body can be readen multiple times. - `Context.ReadHeaders(ptr interface{}) error` binds request headers to "ptr". [Example](https://github.com/kataras/iris/blob/master/_examples/request-body/read-headers/main.go). - `Context.ReadParams(ptr interface{}) error` binds dynamic path parameters to "ptr". [Example](https://github.com/kataras/iris/blob/master/_examples/request-body/read-params/main.go). - `Context.SaveFormFile(fh *multipart.FileHeader, dest string) (int64, error)` previously unexported. Accepts a result file of `Context.FormFile` and saves it to the disk. @@ -643,6 +645,7 @@ New Context Methods: Breaking Changes: +- Request Logger's `Columns bool` field has been removed. Use the new [accesslog](https://github.com/kataras/iris/tree/master/_examples/logging/request-logger/accesslog/main.go) middleware instead. - The `.Binary` method of all view engines was removed: pass the go-bindata's latest version `AssetFile()` exported function as the first argument instead of string. All examples updated. - `ContextUploadFormFiles(destDirectory string, before ...func(*Context, *multipart.FileHeader) bool) (uploaded []*multipart.FileHeader, n int64, err error)` now returns the total files uploaded too (as its first parameter) and the "before" variadic option should return a boolean, if false then the specific file is skipped. - `Context.PostValues(name string) ([]string, error)` now returns a second output argument of `error` type too, which reports `ErrEmptyForm` or `ErrNotFound` or `ErrEmptyFormField`. The single post value getters now returns the **last value** if multiple was given instead of the first one (this allows clients to append values on flow updates). diff --git a/NOTICE b/NOTICE index 716ea617..776d72a3 100644 --- a/NOTICE +++ b/NOTICE @@ -34,10 +34,7 @@ Revision ID: ab226d925aa394ccecf01e515ea8479367e0961c d25082d2d2 closestmatch 1fbe626be92eb4c https://github.com/schollz/closestmatch 347d182cae9f8f0 - 0a046bf2f4 - columnize 9e6335e58db3b4c https://github.com/ryanuber/columnize - fe3c3c5c881f51f - fbc1091b34 + 0a046bf2f4 compress 4a2d40e4b07e5b3 https://github.com/klauspost/compress d333bc0569facd0 f2dbf4ef39 diff --git a/_examples/README.md b/_examples/README.md index bf12aebe..5ac8802a 100644 --- a/_examples/README.md +++ b/_examples/README.md @@ -72,8 +72,7 @@ * [Sitemap](routing/sitemap/main.go) * Logging * [Request Logger](logging/request-logger/main.go) - * [Log requests and responses to access.log](logging/request-logger/request-logger-access-log-file) - * [Log Requests to a File](logging/request-logger/request-logger-file/main.go) + * [Log requests and responses to access.log](logging/request-logger/accesslog) * [Log Requests to a JSON File](logging/request-logger/request-logger-file-json/main.go) * [Application File Logger](logging/file-logger/main.go) * [Application JSON Logger](logging/json-logger/main.go) diff --git a/_examples/logging/request-logger/request-logger-access-log-file/access.log.sample b/_examples/logging/request-logger/accesslog/access.log.sample similarity index 100% rename from _examples/logging/request-logger/request-logger-access-log-file/access.log.sample rename to _examples/logging/request-logger/accesslog/access.log.sample diff --git a/_examples/logging/request-logger/accesslog/main.go b/_examples/logging/request-logger/accesslog/main.go new file mode 100644 index 00000000..e2cfb16c --- /dev/null +++ b/_examples/logging/request-logger/accesslog/main.go @@ -0,0 +1,47 @@ +package main // See https://github.com/kataras/iris/issues/1601 + +import ( + "github.com/kataras/iris/v12" + "github.com/kataras/iris/v12/middleware/accesslog" +) + +func main() { + app := iris.New() + ac := accesslog.File("./access.log") + defer ac.Close() + iris.RegisterOnInterrupt(func() { + ac.Close() + }) + + // Register the middleware (UseRouter to catch http errors too). + app.UseRouter(ac.Handler) + // + + // Register some routes... + app.HandleDir("/", iris.Dir("./public")) + + app.Get("/user/{username}", userHandler) + app.Post("/read_body", readBodyHandler) + app.Get("/html_response", htmlResponse) + // + + app.Listen(":8080") +} + +func readBodyHandler(ctx iris.Context) { + var request interface{} + if err := ctx.ReadBody(&request); err != nil { + ctx.StopWithPlainError(iris.StatusBadRequest, err) + return + } + + ctx.JSON(iris.Map{"message": "OK", "data": request}) +} + +func userHandler(ctx iris.Context) { + ctx.Writef("Hello, %s!", ctx.Params().Get("username")) +} + +func htmlResponse(ctx iris.Context) { + ctx.HTML("

HTML Response

") +} diff --git a/_examples/logging/request-logger/request-logger-access-log-file/public/index.html b/_examples/logging/request-logger/accesslog/public/index.html similarity index 100% rename from _examples/logging/request-logger/request-logger-access-log-file/public/index.html rename to _examples/logging/request-logger/accesslog/public/index.html diff --git a/_examples/logging/request-logger/main.go b/_examples/logging/request-logger/main.go index 3b9ef1e2..bf66726c 100644 --- a/_examples/logging/request-logger/main.go +++ b/_examples/logging/request-logger/main.go @@ -21,7 +21,6 @@ func main() { Query: true, // Shows information about the executed route. TraceRoute: true, - // Columns: true, // if !empty then its contents derives from `ctx.Values().Get("logger_message") // will be added to the logs. diff --git a/_examples/logging/request-logger/request-logger-access-log-file/main.go b/_examples/logging/request-logger/request-logger-access-log-file/main.go deleted file mode 100644 index 892bd140..00000000 --- a/_examples/logging/request-logger/request-logger-access-log-file/main.go +++ /dev/null @@ -1,174 +0,0 @@ -package main // See https://github.com/kataras/iris/issues/1601 - -import ( - "bytes" - "encoding/json" - "fmt" - "io" - "os" - "strings" - "time" - - "github.com/kataras/iris/v12" - "github.com/kataras/iris/v12/middleware/logger" -) - -func main() { - // Create or use the ./access.log file. - f, err := os.OpenFile("access.log", os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666) - if err != nil { - panic(err) - } - defer f.Close() - iris.RegisterOnInterrupt(func() { f.Close() }) - // - - app := iris.New() - - // Init the request logger with - // the LogFuncCtx field alone. - reqLogger := logger.New(logger.Config{ - LogFuncCtx: requestLogFunc(f), - }) - // - - // Wrap the request logger middleware - // with a response recorder because - // we want to record the response body - // sent to the client. - reqLoggerWithRecord := func(ctx iris.Context) { - // Store the requested path just in case. - ctx.Values().Set("path", ctx.Path()) - ctx.Record() - reqLogger(ctx) - } - // - - // Register the middleware (UseRouter to catch http errors too). - app.UseRouter(reqLoggerWithRecord) - // - - // Register some routes... - app.HandleDir("/", iris.Dir("./public")) - - app.Get("/user/{username}", userHandler) - app.Post("/read_body", readBodyHandler) - // - - // Start the server with `WithoutBodyConsumptionOnUnmarshal` - // option so the request body can be readen twice: - // one for our handlers and one from inside our request logger middleware. - app.Listen(":8080", iris.WithoutBodyConsumptionOnUnmarshal) -} - -func readBodyHandler(ctx iris.Context) { - var request interface{} - if err := ctx.ReadBody(&request); err != nil { - ctx.StopWithPlainError(iris.StatusBadRequest, err) - return - } - - ctx.JSON(iris.Map{"message": "OK"}) -} - -func userHandler(ctx iris.Context) { - ctx.Writef("Hello, %s!", ctx.Params().Get("username")) -} - -func jsonToString(src []byte) string { - buf := new(bytes.Buffer) - if err := json.Compact(buf, src); err != nil { - return err.Error() - } - - return buf.String() -} - -func requestLogFunc(w io.Writer) func(ctx iris.Context, lat time.Duration) { - return func(ctx iris.Context, lat time.Duration) { - var ( - method = ctx.Method() // request method. - // Use a stored value instead of ctx.Path() - // because some handlers may change the relative path - // to perform some action. - path = ctx.Values().GetString("path") - code = ctx.GetStatusCode() // response status code - // request and response data or error reading them. - requestBody string - responseBody string - - // url parameters and path parameters separated by space, - // key=value key2=value2. - requestValues string - ) - - // any error handler stored ( ctx.SetErr or StopWith(Plain)Error ) - errHandler := ctx.GetErr() - // check if not error and client sent a response with a content-type set-ed. - if errHandler == nil { - if ctx.GetContentTypeRequested() == "application/json" { - // Read and log request body the client sent to the server: - // - // You can use ctx.ReadBody(&body) - // which will decode any body (json, xml, msgpack, protobuf...) - // and use %v inside the fmt.Fprintf to print something like: - // map[age:22 id:10 name:Tim] - // - // But if you want specific to json string, - // then do that: - var tmp json.RawMessage - if err := ctx.ReadJSON(&tmp); err != nil { - requestBody = err.Error() - } else { - requestBody = jsonToString(tmp) - } - // - } else { - // left for exercise. - } - } else { - requestBody = fmt.Sprintf("error(%s)", errHandler.Error()) - } - - responseData := ctx.Recorder().Body() - // check if the server sent any response with content type, - // note that this will return the ;charset too - // so we check for its prefix instead. - if strings.HasPrefix(ctx.GetContentType(), "application/json") { - responseBody = jsonToString(responseData) - } else { - responseBody = string(responseData) - } - - var buf strings.Builder - - ctx.Params().Visit(func(key, value string) { - buf.WriteString(key) - buf.WriteByte('=') - buf.WriteString(value) - buf.WriteByte(' ') - }) - - for _, entry := range ctx.URLParamsSorted() { - buf.WriteString(entry.Key) - buf.WriteByte('=') - buf.WriteString(entry.Value) - buf.WriteByte(' ') - } - - if n := buf.Len(); n > 1 { - requestValues = buf.String()[0 : n-1] // remove last space. - } - - fmt.Fprintf(w, "%s|%s|%s|%s|%s|%d|%s|%s|\n", - time.Now().Format("2006-01-02 15:04:05"), - lat, - method, - path, - requestValues, - code, - requestBody, - responseBody, - ) - } -} diff --git a/_examples/logging/request-logger/request-logger-file/main.go b/_examples/logging/request-logger/request-logger-file/main.go deleted file mode 100644 index ac387963..00000000 --- a/_examples/logging/request-logger/request-logger-file/main.go +++ /dev/null @@ -1,107 +0,0 @@ -package main - -import ( - "os" - "strings" - "time" - - "github.com/kataras/iris/v12" - "github.com/kataras/iris/v12/middleware/logger" -) - -const deleteFileOnExit = false - -func main() { - app := iris.New() - r, close := newRequestLogger() - defer close() - - app.Use(r) - app.OnAnyErrorCode(r, func(ctx iris.Context) { - ctx.HTML("

Error: Please try this instead.

") - }) - - h := func(ctx iris.Context) { - ctx.Writef("Hello from %s", ctx.Path()) - } - - app.Get("/", h) - - app.Get("/1", h) - - app.Get("/2", h) - - // http://localhost:8080 - // http://localhost:8080/1 - // http://localhost:8080/2 - // http://lcoalhost:8080/notfoundhere - app.Listen(":8080") -} - -// get a filename based on the date, file logs works that way the most times -// but these are just a sugar. -func todayFilename() string { - today := time.Now().Format("Jan 02 2006") - return today + ".txt" -} - -func newLogFile() *os.File { - filename := todayFilename() - // open an output file, this will append to the today's file if server restarted. - f, err := os.OpenFile(filename, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666) - if err != nil { - panic(err) - } - - return f -} - -var excludeExtensions = [...]string{ - ".js", - ".css", - ".jpg", - ".png", - ".ico", - ".svg", -} - -func newRequestLogger() (h iris.Handler, close func() error) { - close = func() error { return nil } - - c := logger.Config{ - Status: true, - IP: true, - Method: true, - Path: true, - Columns: true, - } - - logFile := newLogFile() - close = func() error { - err := logFile.Close() - if deleteFileOnExit { - err = os.Remove(logFile.Name()) - } - return err - } - - c.LogFunc = func(endTime time.Time, latency time.Duration, status, ip, method, path string, message interface{}, headerMessage interface{}) { - output := logger.Columnize(endTime.Format("2006/01/02 - 15:04:05"), latency, status, ip, method, path, message, headerMessage) - logFile.Write([]byte(output)) - } // or make use of the `LogFuncCtx`, see the '../request-logger-file-json' example for more. - - // when we don't want to use to log requests to assets and etc. - c.AddSkipper(func(ctx iris.Context) bool { - path := ctx.Path() - for _, ext := range excludeExtensions { - if strings.HasSuffix(path, ext) { - return true - } - } - return false - }) - - h = logger.New(c) - - return -} diff --git a/configuration.go b/configuration.go index 470fa825..8b3e93d9 100644 --- a/configuration.go +++ b/configuration.go @@ -715,6 +715,8 @@ type Configuration struct { // if this field set to true then a new buffer will be created to read from and the request body. // The body will not be changed and existing data before the // context.UnmarshalBody/ReadJSON/ReadXML will be not consumed. + // + // See `Context.RecordBody` method for the same feature, per-request. DisableBodyConsumptionOnUnmarshal bool `json:"disableBodyConsumptionOnUnmarshal,omitempty" yaml:"DisableBodyConsumptionOnUnmarshal" toml:"DisableBodyConsumptionOnUnmarshal"` // FireEmptyFormError returns if set to tue true then the `context.ReadBody/ReadForm` // will return an `iris.ErrEmptyForm` on empty request form data. diff --git a/context/context.go b/context/context.go index 3094b94e..a0311277 100644 --- a/context/context.go +++ b/context/context.go @@ -2095,15 +2095,6 @@ func (ctx *Context) SetMaxRequestBodySize(limitOverBytes int64) { ctx.request.Body = http.MaxBytesReader(ctx.writer, ctx.request.Body, limitOverBytes) } -// GetBody reads and returns the request body. -// The default behavior for the http request reader is to consume the data readen -// but you can change that behavior by passing the `WithoutBodyConsumptionOnUnmarshal` iris option. -// -// However, whenever you can use the `ctx.Request().Body` instead. -func (ctx *Context) GetBody() ([]byte, error) { - return GetBody(ctx.request, ctx.app.ConfigurationReadOnly().GetDisableBodyConsumptionOnUnmarshal()) -} - // GetBody reads and returns the request body. func GetBody(r *http.Request, resetBody bool) ([]byte, error) { data, err := ioutil.ReadAll(r.Body) @@ -2120,6 +2111,31 @@ func GetBody(r *http.Request, resetBody bool) ([]byte, error) { return data, nil } +const disableRequestBodyConsumptionContextKey = "iris.request.body.record" + +// RecordBody same as the Application's DisableBodyConsumptionOnUnmarshal configuration field +// but acts for the current request. +// It makes the request body readable more than once. +func (ctx *Context) RecordBody() { + ctx.Values().Set(disableRequestBodyConsumptionContextKey, true) +} + +// IsRecordingBody reports whether the request body can be readen multiple times. +func (ctx *Context) IsRecordingBody() bool { + return ctx.Values().GetBoolDefault(disableRequestBodyConsumptionContextKey, + ctx.app.ConfigurationReadOnly().GetDisableBodyConsumptionOnUnmarshal()) +} + +// GetBody reads and returns the request body. +// The default behavior for the http request reader is to consume the data readen +// but you can change that behavior by passing the `WithoutBodyConsumptionOnUnmarshal` Iris option +// or by calling the `RecordBody` method. +// +// However, whenever you can use the `ctx.Request().Body` instead. +func (ctx *Context) GetBody() ([]byte, error) { + return GetBody(ctx.request, ctx.IsRecordingBody()) +} + // Validator is the validator for request body on Context methods such as // ReadJSON, ReadMsgPack, ReadXML, ReadYAML, ReadForm, ReadQuery, ReadBody and e.t.c. type Validator interface { @@ -2395,6 +2411,7 @@ func (ctx *Context) ReadBody(ptr interface{}) error { switch ctx.GetContentTypeRequested() { case ContentXMLHeaderValue, ContentXMLUnreadableHeaderValue: return ctx.ReadXML(ptr) + // "%v reflect.Indirect(reflect.ValueOf(ptr)).Interface()) case ContentYAMLHeaderValue: return ctx.ReadYAML(ptr) case ContentFormHeaderValue, ContentFormMultipartHeaderValue: diff --git a/core/router/fs.go b/core/router/fs.go index 0cc7f89b..f336eb87 100644 --- a/core/router/fs.go +++ b/core/router/fs.go @@ -64,9 +64,9 @@ type DirCacheOptions struct { // See `DefaultDirOptions`. type DirOptions struct { // Defaults to "/index.html", if request path is ending with **/*/$IndexName - // then it redirects to **/*(/) which another handler is handling it, - // that another handler, called index handler, is auto-registered by the framework - // if end developer does not managed to handle it by hand. + // then it redirects to **/*(/). + // That index handler is registered automatically + // by the framework unless but it can be overridden. IndexName string // PushTargets filenames (map's value) to // be served without additional client's requests (HTTP/2 Push) @@ -94,10 +94,12 @@ type DirOptions struct { // When files should served under compression. Compress bool - // List the files inside the current requested directory if `IndexName` not found. + // List the files inside the current requested + // directory if `IndexName` not found. ShowList bool // If `ShowList` is true then this function will be used instead - // of the default one to show the list of files of a current requested directory(dir). + // of the default one to show the list of files + // of a current requested directory(dir). // See `DirListRich` package-level function too. DirList DirListFunc diff --git a/go.mod b/go.mod index a5e164a9..eae68450 100644 --- a/go.mod +++ b/go.mod @@ -29,7 +29,6 @@ require ( github.com/mediocregopher/radix/v3 v3.5.2 github.com/microcosm-cc/bluemonday v1.0.4 github.com/russross/blackfriday/v2 v2.0.1 - github.com/ryanuber/columnize v2.1.2+incompatible github.com/schollz/closestmatch v2.1.0+incompatible github.com/square/go-jose/v3 v3.0.0-20200630053402-0a67ce9b0693 github.com/tdewolff/minify/v2 v2.9.2 diff --git a/middleware/accesslog/accesslog.go b/middleware/accesslog/accesslog.go new file mode 100644 index 00000000..75068e67 --- /dev/null +++ b/middleware/accesslog/accesslog.go @@ -0,0 +1,251 @@ +package accesslog + +import ( + "fmt" + "io" + "os" + "strings" + "sync" + "time" + + "github.com/kataras/iris/v12/context" +) + +// AccessLog is a middleware which prints information +// incoming HTTP requests. +// +// Sample access log line: +// 2020-08-22 00:44:20|1ms|POST|/read_body||200|{"id":10,"name":"Tim","age":22}|{"message":"OK"}| +// +// Look `New`, `File` package-level functions +// and its `Handler` method to learn more. +type AccessLog struct { + mu sync.Mutex // ensures atomic writes. + // If not nil then it overrides the Application's Logger. + // Useful to write to a file. + // If multiple output required, then define an `io.MultiWriter`. + // See `SetOutput` and `AddOutput` methods too. + Writer io.Writer + // If not empty then each one of them is called on `Close` method. + Closers []io.Closer + + // If not empty then it overrides the Application's configuration's TimeFormat field. + TimeFormat string + // Force minify request and response contents. + BodyMinify bool + // Enable request body logging. + // Note that, if this is true then it modifies the underline request's body type. + RequestBody bool + // Enable response body logging. + // Note that, if this is true then it uses a response recorder. + ResponseBody bool +} + +// New returns a new AccessLog value with the default values. +// Writes to the Application's logger. +// Register by its `Handler` method. +// See `File` package-level function too. +func New() *AccessLog { + return &AccessLog{ + BodyMinify: true, + RequestBody: true, + ResponseBody: true, + TimeFormat: "2006-01-02 15:04:05", + } +} + +// File returns a new AccessLog value with the given "path" +// as the log's output file destination. +// Register by its `Handler` method. +// +// A call of its `Close` method to unlock the underline +// file is required on program termination. +// +// It panics on error. +func File(path string) *AccessLog { + f, err := os.OpenFile(path, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0666) + if err != nil { + panic(err) + } + + ac := New() + ac.SetOutput(f) + return ac +} + +// Write writes to the log destination. +// It completes the io.Writer interface. +// Safe for concurrent use. +func (ac *AccessLog) Write(p []byte) (int, error) { + ac.mu.Lock() + n, err := ac.Writer.Write(p) + ac.mu.Unlock() + return n, err +} + +// SetOutput sets the log's output destination. Accepts one or more io.Writer values. +// Also, if a writer is a Closer, then it is automatically appended to the Closers. +func (ac *AccessLog) SetOutput(writers ...io.Writer) *AccessLog { + for _, w := range writers { + if closer, ok := w.(io.Closer); ok { + ac.Closers = append(ac.Closers, closer) + } + } + + ac.Writer = io.MultiWriter(writers...) + return ac +} + +// AddOutput appends an io.Writer value to the existing writer. +func (ac *AccessLog) AddOutput(writers ...io.Writer) *AccessLog { + if ac.Writer != nil { // prepend if one exists. + writers = append([]io.Writer{ac.Writer}, writers...) + } + + return ac.SetOutput(writers...) +} + +// Close calls each registered Closer's Close method. +// Exits when all close methods have been executed. +func (ac *AccessLog) Close() (err error) { + for _, closer := range ac.Closers { + cErr := closer.Close() + if cErr != nil { + if err == nil { + err = cErr + } else { + err = fmt.Errorf("%v, %v", err, cErr) + } + } + } + + return +} + +// Handler prints request information to the output destination. +// It is the main method of the AccessLog middleware. +// +// Usage: +// ac := New() or File("access.log") +// defer ac.Close() +// app.UseRouter(ac.Handler) +func (ac *AccessLog) Handler(ctx *context.Context) { + var ( + startTime = time.Now() + // Store some values, as future handler chain + // can modify those (note: we could clone the request or context object too). + method = ctx.Method() + path = ctx.Path() + ) + + // Enable response recording. + if ac.ResponseBody { + ctx.Record() + } + // Enable reading the request body + // multiple times (route handler and this middleware). + if ac.RequestBody { + ctx.RecordBody() + } + + // Proceed to the handlers chain. + ctx.Next() + + latency := time.Since(startTime) + ac.after(ctx, latency, method, path) +} + +func (ac *AccessLog) after(ctx *context.Context, lat time.Duration, method, path string) { + var ( + code = ctx.GetStatusCode() // response status code + // request and response data or error reading them. + requestBody string + responseBody string + + // url parameters and path parameters separated by space, + // key=value key2=value2. + requestValues string + ) + + // any error handler stored ( ctx.SetErr or StopWith(Plain)Error ) + if ctxErr := ctx.GetErr(); ctxErr != nil { + requestBody = fmt.Sprintf("error(%s)", ctxErr.Error()) + } else if ac.RequestBody { + requestData, err := ctx.GetBody() + if err != nil { + requestBody = fmt.Sprintf("error(%s)", ctxErr.Error()) + } else { + if ac.BodyMinify { + if minified, err := ctx.Application().Minifier().Bytes(ctx.GetContentTypeRequested(), requestData); err == nil { + requestBody = string(minified) + } + } + /* Some content types, like the text/plain, + no need minifier. Should be printed with spaces and \n. */ + if requestBody == "" { + requestBody = string(requestData) + } + } + } + + if ac.RequestBody { + if responseData := ctx.Recorder().Body(); len(responseData) > 0 { + if ac.BodyMinify { + if minified, err := ctx.Application().Minifier().Bytes(ctx.GetContentType(), ctx.Recorder().Body()); err == nil { + responseBody = string(minified) + } + + } + + if responseBody == "" { + responseBody = string(responseData) + } + } + } + + var buf strings.Builder + + if !context.StatusCodeNotSuccessful(code) { + // collect path parameters on a successful request-response only. + ctx.Params().Visit(func(key, value string) { + buf.WriteString(key) + buf.WriteByte('=') + buf.WriteString(value) + buf.WriteByte(' ') + }) + } + + for _, entry := range ctx.URLParamsSorted() { + buf.WriteString(entry.Key) + buf.WriteByte('=') + buf.WriteString(entry.Value) + buf.WriteByte(' ') + } + + if n := buf.Len(); n > 1 { + requestValues = buf.String()[0 : n-1] // remove last space. + } + + timeFormat := ac.TimeFormat + if timeFormat == "" { + timeFormat = ctx.Application().ConfigurationReadOnly().GetTimeFormat() + } + + w := ac.Writer + if w == nil { + w = ctx.Application().Logger().Printer + } + + // the number of separators are the same, in order to be easier + // for 3rd-party programs to read the result log file. + fmt.Fprintf(w, "%s|%s|%s|%s|%s|%d|%s|%s|\n", + time.Now().Format(timeFormat), + lat, + method, + path, + requestValues, + code, + requestBody, + responseBody, + ) +} diff --git a/middleware/logger/config.go b/middleware/logger/config.go index 54d277ce..3ab87d8b 100644 --- a/middleware/logger/config.go +++ b/middleware/logger/config.go @@ -48,20 +48,11 @@ type Config struct { // Defaults to false. TraceRoute bool - // Columns will display the logs as a formatted columns-rows text (bool). - // If custom `LogFunc` has been provided then this field is useless and users should - // use the `Columinize` function of the logger to get the output result as columns. - // - // Defaults to false. - Columns bool - // MessageContextKeys if not empty, // the middleware will try to fetch // the contents with `ctx.Values().Get(MessageContextKey)` // and if available then these contents will be // appended as part of the logs (with `%v`, in order to be able to set a struct too), - // if Columns field was set to true then - // a new column will be added named 'Message'. // // Defaults to empty. MessageContextKeys []string @@ -71,8 +62,6 @@ type Config struct { // the contents with `ctx.Values().Get(MessageHeaderKey)` // and if available then these contents will be // appended as part of the logs (with `%v`, in order to be able to set a struct too), - // if Columns field was set to true then - // a new column will be added named 'HeaderMessage'. // // Defaults to empty. MessageHeaderKeys []string @@ -93,7 +82,7 @@ type Config struct { } // DefaultConfig returns a default config -// that have all boolean fields to true except `Columns`, +// that have all boolean fields to true, // all strings are empty, // LogFunc and Skippers to nil as well. func DefaultConfig() Config { @@ -105,7 +94,6 @@ func DefaultConfig() Config { PathAfterHandler: false, Query: false, TraceRoute: false, - Columns: false, LogFunc: nil, LogFuncCtx: nil, Skippers: nil, diff --git a/middleware/logger/logger.go b/middleware/logger/logger.go index 1b3aa963..da4f1f01 100644 --- a/middleware/logger/logger.go +++ b/middleware/logger/logger.go @@ -7,8 +7,6 @@ import ( "time" "github.com/kataras/iris/v12/context" - - "github.com/ryanuber/columnize" ) func init() { @@ -120,12 +118,6 @@ func (l *requestLoggerMiddleware) ServeHTTP(ctx *context.Context) { return } - if l.config.Columns { - endTimeFormatted := endTime.Format("2006/01/02 - 15:04:05") - output := Columnize(endTimeFormatted, latency, status, ip, method, path, message, headerMessage) - _, _ = ctx.Application().Logger().Printer.Write([]byte(output)) - return - } // no new line, the framework's logger is responsible how to render each log. line := fmt.Sprintf("%v %4v %s %s %s", status, latency, ip, method, path) if message != nil { @@ -158,26 +150,3 @@ func (l *requestLoggerMiddleware) ServeHTTP(ctx *context.Context) { ctx.GetCurrentRoute().Trace(ctx.Application().Logger().Printer, ctx.HandlerIndex(-1)) } } - -// Columnize formats the given arguments as columns and returns the formatted output, -// note that it appends a new line to the end. -func Columnize(nowFormatted string, latency time.Duration, status, ip, method, path string, message interface{}, headerMessage interface{}) string { - titles := "Time | Status | Latency | IP | Method | Path" - line := fmt.Sprintf("%s | %v | %4v | %s | %s | %s", nowFormatted, status, latency, ip, method, path) - if message != nil { - titles += " | Message" - line += fmt.Sprintf(" | %v", message) - } - - if headerMessage != nil { - titles += " | HeaderMessage" - line += fmt.Sprintf(" | %v", headerMessage) - } - - outputC := []string{ - titles, - line, - } - output := columnize.SimpleFormat(outputC) + "\n" - return output -}