From 77a79cae587d77dbd5f30416760a9e1da5118afe Mon Sep 17 00:00:00 2001 From: "Gerasimos (Makis) Maropoulos" Date: Sun, 26 Apr 2020 06:21:20 +0300 Subject: [PATCH] improve route debug info, see HISTORY.md Former-commit-id: ae245bae5fefa57c5f7663f7d1d661ec68ad366a --- HISTORY.md | 4 +- _examples/mvc/grpc-compatible/main.go | 7 +- context/handler.go | 17 +++-- core/router/api_builder.go | 15 +++-- core/router/route.go | 94 +++++++++++++++++++++------ go.mod | 3 +- iris.go | 12 ++-- mvc/grpc.go | 2 +- 8 files changed, 115 insertions(+), 39 deletions(-) diff --git a/HISTORY.md b/HISTORY.md index 9ebbacce..053e0a9c 100644 --- a/HISTORY.md +++ b/HISTORY.md @@ -180,7 +180,9 @@ Other Improvements: - New Router [Wrapper](middleware/grpc). - New MVC `.Handle(ctrl, mvc.GRPC{...})` option which allows to register gRPC services per-party (without the requirement of a full wrapper) and optionally strict access to gRPC clients only, see the [example here](_examples/mvc/grpc-compatible). -- Improved logging (with `app.Logger().SetLevel("debug")`) for MVC-registered routes. +- Improved tracing (with `app.Logger().SetLevel("debug")`) for routes. Example: + +![DBUG routes](https://iris-go.com/images/v12.2.0-dbug.png) - New `iris.WithLowercaseRouting` option which forces all routes' paths to be lowercase and converts request paths to their lowercase for matching. diff --git a/_examples/mvc/grpc-compatible/main.go b/_examples/mvc/grpc-compatible/main.go index 576d92e4..667b78c9 100644 --- a/_examples/mvc/grpc-compatible/main.go +++ b/_examples/mvc/grpc-compatible/main.go @@ -31,7 +31,12 @@ func main() { func newApp() *iris.Application { app := iris.New() - app.Logger().SetLevel("debug") + // app.Configure(iris.WithLowercaseRouting) // OPTIONAL. + app.Logger().SetLevel("debug").SetTimeFormat("") + + app.Get("/", func(ctx iris.Context) { + ctx.HTML("

Index Page

") + }) ctrl := &myController{} // Register gRPC server. diff --git a/context/handler.go b/context/handler.go index 4c117c12..63c3b35c 100644 --- a/context/handler.go +++ b/context/handler.go @@ -51,25 +51,30 @@ func HandlerFileLine(h interface{}) (file string, line int) { } // HandlerFileLineRel same as `HandlerFileLine` but it returns the path as relative to the "workingDir". -func HandlerFileLineRel(h interface{}, workingDir string) (string, int) { - file, line := HandlerFileLine(h) +func HandlerFileLineRel(h interface{}, workingDir string) (file string, line int) { + file, line = HandlerFileLine(h) if relFile, err := filepath.Rel(workingDir, file); err == nil { - file = "./" + relFile + if !strings.HasPrefix(relFile, "..") { + // Only if it's relative to this path, not parent. + file = "./" + relFile + } } - return file, line + return } -// MainHandlerName tries to find the main handler than end-developer +// MainHandlerName tries to find the main handler that end-developer // registered on the provided chain of handlers and returns its function name. -func MainHandlerName(handlers Handlers) (name string) { +func MainHandlerName(handlers Handlers) (name string, index int) { for i := 0; i < len(handlers); i++ { name = HandlerName(handlers[i]) + index = i if !strings.HasPrefix(name, "github.com/kataras/iris/v12") || strings.HasPrefix(name, "github.com/kataras/iris/v12/core/router.StripPrefix") || strings.HasPrefix(name, "github.com/kataras/iris/v12/core/router.FileServer") { break } + } return diff --git a/core/router/api_builder.go b/core/router/api_builder.go index 48ee33ce..397a181b 100644 --- a/core/router/api_builder.go +++ b/core/router/api_builder.go @@ -444,7 +444,9 @@ func (api *APIBuilder) CreateRoutes(methods []string, relativePath string, handl mainHandlers := context.Handlers(handlers) // before join the middleware + handlers + done handlers and apply the execution rules. - possibleMainHandlerName := context.MainHandlerName(mainHandlers) + possibleMainHandlerName, mainHandlerIndex := context.MainHandlerName(mainHandlers) + wd, _ := os.Getwd() + mainHandlerFileName, mainHandlerFileNumber := context.HandlerFileLineRel(handlers[mainHandlerIndex], wd) // TODO: for UseGlobal/DoneGlobal that doesn't work. applyExecutionRules(api.handlerExecutionRules, &beginHandlers, &doneHandlers, &mainHandlers) @@ -470,8 +472,11 @@ func (api *APIBuilder) CreateRoutes(methods []string, relativePath string, handl continue } - route.SourceFileName = filename - route.SourceLineNumber = line + route.SourceFileName = mainHandlerFileName + route.SourceLineNumber = mainHandlerFileNumber + + route.RegisterFileName = filename + route.RegisterLineNumber = line // Add UseGlobal & DoneGlobal Handlers route.Use(api.beginGlobalHandlers...) @@ -1011,8 +1016,8 @@ func getCaller() (string, int) { } if !strings.Contains(file, "/kataras/iris") || - strings.Contains(file, "/kataras/iris/_examples") || - strings.Contains(file, "iris-contrib/examples") { + strings.Contains(file, "_examples") || + strings.Contains(file, "examples") { if relFile, err := filepath.Rel(wd, file); err == nil { file = "./" + relFile } diff --git a/core/router/route.go b/core/router/route.go index c0c583c2..df95b341 100644 --- a/core/router/route.go +++ b/core/router/route.go @@ -2,12 +2,16 @@ package router import ( "fmt" + "net/http" + "os" "strings" "time" "github.com/kataras/iris/v12/context" "github.com/kataras/iris/v12/macro" "github.com/kataras/iris/v12/macro/handler" + + "github.com/kataras/pio" ) // Route contains the information about a registered Route. @@ -37,8 +41,12 @@ type Route struct { FormattedPath string `json:"formattedPath"` // the source code's filename:filenumber that this route was created from. - SourceFileName string - SourceLineNumber int + SourceFileName string `json:"sourceFileName"` + SourceLineNumber int `json:"sourceLineNumber"` + + // where the route registered. + RegisterFileName string `json:"registerFileName"` + RegisterLineNumber int `json:"registerLineNumber"` // StaticSites if not empty, refers to the system (or virtual if embedded) directory // and sub directories that this "GET" route was registered to serve files and folders @@ -317,34 +325,82 @@ func (r *Route) ResolvePath(args ...string) string { } // Trace returns some debug infos as a string sentence. -// Should be called after Build. +// Should be called after `Build` state. +// +// It prints the @method: @path (@description) (@route_rel_location) +// * @handler_name (@handler_rel_location) +// * @second_handler ... +// If route and handler line:number locations are equal then the second is ignored. func (r *Route) Trace() string { - printfmt := fmt.Sprintf("[%s:%d] %s:", r.SourceFileName, r.SourceLineNumber, r.Method) + // Color the method. + color := pio.Black + switch r.Method { + case http.MethodGet: + color = pio.Green + case http.MethodPost: + color = pio.Magenta + case http.MethodPut: + color = pio.Blue + case http.MethodDelete: + color = pio.Red + case http.MethodConnect: + color = pio.Green + case http.MethodHead: + color = pio.Green + case http.MethodPatch: + color = pio.Blue + case http.MethodOptions: + color = pio.Gray + case http.MethodTrace: + color = pio.Yellow + } + + path := r.Tmpl().Src if r.Subdomain != "" { - printfmt += fmt.Sprintf(" %s", r.Subdomain) + path = fmt.Sprintf("%s %s", r.Subdomain, path) } - printfmt += fmt.Sprintf(" %s", r.Tmpl().Src) + // @method: @path + s := fmt.Sprintf("%s: %s", pio.Rich(r.Method, color), path) + + // (@description) if r.Description != "" { - printfmt += fmt.Sprintf(" (%s)", r.Description) + s += fmt.Sprintf(" %s", pio.Rich(r.Description, pio.Cyan, pio.Underline)) } - mainHandlerName := r.MainHandlerName - if !strings.HasSuffix(mainHandlerName, ")") { - mainHandlerName += "()" + // (@route_rel_location) + s += fmt.Sprintf(" (%s:%d)", r.RegisterFileName, r.RegisterLineNumber) + + // if the main handler is not an anonymous function (so, differs from @route_rel_location) + // then * @handler_name (@handler_rel_location) + if r.SourceFileName != r.RegisterFileName || r.SourceLineNumber != r.RegisterLineNumber { + s += fmt.Sprintf("\n ⬝ %s (%s:%d)", r.MainHandlerName, r.SourceFileName, r.SourceLineNumber) } - if l := r.RegisteredHandlersLen(); l > 1 { - printfmt += fmt.Sprintf(" -> %s and %d more", mainHandlerName, l-1) - } else { - printfmt += fmt.Sprintf(" -> %s", mainHandlerName) + wd, _ := os.Getwd() + + for _, h := range r.Handlers { + name := context.HandlerName(h) + if name == r.MainHandlerName { + continue + } + + // trim the path for Iris' internal middlewares, e.g. + // irs/mvc.GRPC.Apply.func1 + if internalName := "github.com/kataras/iris/v12"; strings.HasPrefix(name, internalName) { + name = strings.Replace(name, internalName, "iris", 1) + } + + file, line := context.HandlerFileLineRel(h, wd) + if file == r.RegisterFileName && line == r.RegisterLineNumber { + continue + } + + // * @handler_name (@handler_rel_location) + s += fmt.Sprintf("\n ⬝ %s (%s:%d)", name, file, line) } - // printfmt := fmt.Sprintf("%s: %s >> %s", r.Method, r.Subdomain+r.Tmpl().Src, r.MainHandlerName) - // if l := len(r.Handlers); l > 0 { - // printfmt += fmt.Sprintf(" and %d more", l) - // } - return printfmt // without new line. + return s } type routeReadOnlyWrapper struct { diff --git a/go.mod b/go.mod index 426e7556..dffa861c 100644 --- a/go.mod +++ b/go.mod @@ -21,7 +21,8 @@ require ( github.com/iris-contrib/pongo2 v0.0.1 github.com/iris-contrib/schema v0.0.1 github.com/json-iterator/go v1.1.9 - github.com/kataras/golog v0.0.10 + github.com/kataras/golog v0.0.11 + github.com/kataras/pio v0.0.3 github.com/kataras/neffos v0.0.14 github.com/kataras/sitemap v0.0.5 github.com/klauspost/compress v1.9.7 diff --git a/iris.go b/iris.go index 624864d7..0a6cc223 100644 --- a/iris.go +++ b/iris.go @@ -641,7 +641,7 @@ func (app *Application) NewHost(srv *http.Server) *host.Supervisor { srv.Addr = addr } - app.logger.Debugf("Host: addr is %s", srv.Addr) + // app.logger.Debugf("Host: addr is %s", srv.Addr) // create the new host supervisor // bind the constructed server and return it @@ -657,21 +657,21 @@ func (app *Application) NewHost(srv *http.Server) *host.Supervisor { app.config.vhost = netutil.ResolveVHost(srv.Addr) } - app.logger.Debugf("Host: virtual host is %s", app.config.vhost) + // app.logger.Debugf("Host: virtual host is %s", app.config.vhost) // the below schedules some tasks that will run among the server if !app.config.DisableStartupLog { // show the available info to exit from app. su.RegisterOnServe(host.WriteStartupLogOnServe(app.logger.Printer.Output)) // app.logger.Writer -> Info - app.logger.Debugf("Host: register startup notifier") + // app.logger.Debugf("Host: register startup notifier") } if !app.config.DisableInterruptHandler { // when CTRL+C/CMD+C pressed. shutdownTimeout := 5 * time.Second host.RegisterOnInterrupt(host.ShutdownOnInterrupt(su, shutdownTimeout)) - app.logger.Debugf("Host: register server shutdown on interrupt(CTRL+C/CMD+C)") + // app.logger.Debugf("Host: register server shutdown on interrupt(CTRL+C/CMD+C)") } su.IgnoredErrors = append(su.IgnoredErrors, app.config.IgnoreServerErrors...) @@ -1017,7 +1017,9 @@ func (app *Application) Run(serve Runner, withOrWithout ...Configurator) error { app.Configure(withOrWithout...) app.tryStartTunneling() - app.logger.Debugf("Application: running using %d host(s)", len(app.Hosts)+1) + if len(app.Hosts) > 0 { + app.logger.Debugf("Application: running using %d host(s)", len(app.Hosts)+1 /* +1 the current */) + } // this will block until an error(unless supervisor's DeferFlow called from a Task). err := serve(app) diff --git a/mvc/grpc.go b/mvc/grpc.go index f0ee8855..6d8bce65 100644 --- a/mvc/grpc.go +++ b/mvc/grpc.go @@ -59,7 +59,7 @@ func (g GRPC) Apply(c *ControllerActivator) { if route := c.Handle(http.MethodPost, path, m.Name, pre); route != nil { route.Description = "gRPC" if g.Strict { - route.Description = "-only" + route.Description += "-only" } } }