request logger middleware: add graphical information about executed route's handlers

HISTORY.md

@@ -362,7 +362,7 @@ Response:
 
 Other Improvements:
 
-- New `TraceRoute bool` on [request logger](https://github.com/kataras/iris/tree/master/middleware/logger) middleware. Displays information about the executed route, screenshot:
+- New `TraceRoute bool` on [request logger](https://github.com/kataras/iris/tree/master/middleware/logger) middleware. Displays information about the executed route. Also marks the handlers executed. Screenshot:
 
 ![logger middleware: TraceRoute screenshot](https://iris-go.com/images/github/logger-trace-route.png)
 

_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")
@@ -32,25 +31,18 @@ func main() {
 		MessageHeaderKeys: []string{"User-Agent"},
 	})
 
-	app.Use(customLogger)
+	// Runs first on every request: parties & subdomains, route match or not and all http errors.
+	app.UseRouter(customLogger)
 
-	h := func(ctx iris.Context) {
+	// Runs first on each matched route of this Party and its children on every request.
-		ctx.Writef("Hello from %s", ctx.Path())
+	app.Use(routesMiddleware)
-	}
-	app.Get("/", h)
 
-	app.Get("/1", h)
+	app.Get("/", indexMiddleware, index)
+	app.Get("/list", listMiddleware, list)
 
-	app.Get("/2", h)
+	app.Get("/1", hello)
+	app.Get("/2", hello)
 
-	// http errors have their own handlers, therefore
-	// registering a middleare should be done manually.
-	/*
-	 app.OnErrorCode(404 ,customLogger, func(ctx iris.Context) {
-	 	ctx.Writef("My Custom 404 error page ")
-	 })
-	*/
-	// or catch all http errors:
 	app.OnAnyErrorCode(customLogger, func(ctx iris.Context) {
 		// this should be added to the logs, at the end because of the `logger.Config#MessageContextKey`
 		ctx.Values().Set("logger_message",
@@ -59,9 +51,41 @@ func main() {
 	})
 
 	// http://localhost:8080
+	// http://localhost:8080/list
+	// http://localhost:8080/list?stop=true
 	// http://localhost:8080/1
 	// http://localhost:8080/2
 	// http://lcoalhost:8080/notfoundhere
 	// see the output on the console.
 	app.Listen(":8080")
 }
+
+func routesMiddleware(ctx iris.Context) {
+	ctx.Writef("Executing Route: %s\n", ctx.GetCurrentRoute().MainHandlerName())
+	ctx.Next()
+}
+
+func indexMiddleware(ctx iris.Context) {
+	ctx.WriteString("Index Middleware\n")
+	ctx.Next()
+}
+
+func index(ctx iris.Context) {
+	ctx.WriteString("Index Handler")
+}
+
+func listMiddleware(ctx iris.Context) {
+	ctx.WriteString("List Middleware\n")
+
+	if simulateStop, _ := ctx.URLParamBool("stop"); !simulateStop {
+		ctx.Next()
+	}
+}
+
+func list(ctx iris.Context) {
+	ctx.WriteString("List Handler")
+}
+
+func hello(ctx iris.Context) {
+	ctx.Writef("Hello from %s", ctx.Path())
+}

context/route.go

@@ -46,7 +46,7 @@ type RouteReadOnly interface {
 	ResolvePath(args ...string) string
 	// Trace should writes debug route info to the "w".
 	// Should be called after Build.
-	Trace(w io.Writer)
+	Trace(w io.Writer, stoppedIndex int)
 
 	// Tmpl returns the path template,
 	// it contains the parsed template

core/router/handler.go

@@ -288,7 +288,7 @@ func (h *routerHandler) Build(provider RoutesProvider) error {
 
 		for i, m := range methodRoutes {
 			for _, r := range m.routes {
-				r.Trace(logger.Printer)
+				r.Trace(logger.Printer, -1)
 			}
 
 			if i != len(allMethods)-1 {

core/router/route.go

@@ -388,7 +388,7 @@ func traceMethodColor(method string) int {
 //               * @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(w io.Writer) {
+func (r *Route) Trace(w io.Writer, stoppedIndex int) {
 	method := r.Method
 	if method == "" {
 		method = fmt.Sprintf("%d", r.StatusCode)
@@ -470,6 +470,13 @@ func (r *Route) Trace(w io.Writer) {
 
 		// * @handler_name (@handler_rel_location)
 		fmt.Fprint(w, traceHandlerFile(r.Method, name, file, line))
+		if stoppedIndex != -1 && stoppedIndex <= len(r.Handlers) {
+			if i <= stoppedIndex {
+				pio.WriteRich(w, " ✓", pio.Green)
+			} else {
+				// pio.WriteRich(w, " ✕", pio.Red, pio.Underline)
+			}
+		}
 	}
 
 	fmt.Fprintln(w)
@@ -499,8 +506,8 @@ func (rd routeReadOnlyWrapper) Path() string {
 	return rd.Route.tmpl.Src
 }
 
-func (rd routeReadOnlyWrapper) Trace(w io.Writer) {
+func (rd routeReadOnlyWrapper) Trace(w io.Writer, stoppedIndex int) {
-	rd.Route.Trace(w)
+	rd.Route.Trace(w, stoppedIndex)
 }
 
 func (rd routeReadOnlyWrapper) Tmpl() macro.Template {

middleware/logger/logger.go

@@ -141,7 +141,19 @@ func (l *requestLoggerMiddleware) ServeHTTP(ctx *context.Context) {
 	}
 
 	if l.config.TraceRoute && ctx.GetCurrentRoute() != nil /* it is nil on unhandled error codes */ {
-		ctx.GetCurrentRoute().Trace(ctx.Application().Logger().Printer)
+		// Get the total length of handlers and see if all are executed.
+		// Note(@kataras): we get those after handler executed, because
+		// filters (and overlap) feature will set the handlers on router build
+		// state to fullfil their needs. And we need to respect
+		// any dev's custom SetHandlers&Do actions too so we don't give false info.
+		// if n, idx := len(ctx.Handlers()), ctx.HandlerIndex(-1); idx < n-1 {
+		//
+		// }
+		// Let's pass it into the Trace function itself which will "mark"
+		// every handler that is eventually executed.
+		// Note that if StopExecution is called, the index is always -1,
+		// so no "mark" signs will be printed at all <- this can be fixed by introducing a new ctx field.
+		ctx.GetCurrentRoute().Trace(ctx.Application().Logger().Printer, ctx.HandlerIndex(-1))
 	}
 }