middleware + group => 404 is returned when 405 should be returned

[croissanne]

Issue Description

When using a middleware in combination with a group, 404 is returned when 405 should be returned.

Checklist

• [x] Dependencies installed
• [x] No typos
• [x] Searched existing issues and docs

Expected behaviour

Return 405 when calling the endpoint behind the group with a wrong method.

Actual behaviour

Received 404.

Steps to reproduce

minimal reproducer:

package main

import (
	"github.com/labstack/echo/v4"
	"github.com/labstack/echo/v4/middleware"
)

func main() {
	e := echo.New()
	g := e.Group("/api")
	g.Use(middleware.Logger())
	g.GET("/endpoint", func(c echo.Context) error {
		return c.String(200, "OK\n")
	})
	e.Start(":8080")
}

in a shell:

curl -X POST localhost:8080/api/endpoint

->{"message":"Not Found"}

Version/commit

This was broken in 643066594d00891e3151c7ed87244bfeddcd57b9, released in 4.3.0 and onward

[croissanne]

I took a stab at it but without a lot of knowledge of all the edge cases of the rather complex router code I have no idea if it's a good one.

tree: https://github.com/Gundersanne/echo/tree/1981 commit: 584291d81be55157100dc04754ef938c45565ec3 diff: git apply ...

diff --git a/router.go b/router.go
index 5b2474b..8fc19b1 100644
--- a/router.go
+++ b/router.go
@@ -526,10 +526,10 @@ func (r *Router) Find(method, path string, c Context) {
 			// best matching in case we do no find no more routes matching this path+method
 			if previousBestMatchNode == nil {
 				previousBestMatchNode = currentNode
-			}
-			if h := currentNode.findHandler(method); h != nil {
-				matchedHandler = h
-				break
+				if h := currentNode.findHandler(method); h != nil {
+					matchedHandler = h
+					break
+				}
 			}
 		}

diff --git a/router_test.go b/router_test.go
index 71cedf8..3d1109f 100644
--- a/router_test.go
+++ b/router_test.go
@@ -747,11 +747,12 @@ func TestMethodNotAllowedAndNotFound(t *testing.T) {
 			expectError: ErrMethodNotAllowed,
 		},
 		{
+			// isn't best match here a route which matches the path but not the method?
 			name:        "best match is any route up in tree",
 			whenMethod:  http.MethodGet,
 			whenURL:     "/users/1",
-			expectRoute: "/*",
-			expectParam: map[string]string{"*": "users/1"},
+			expectRoute: nil,
+			expectError: ErrMethodNotAllowed,
 		},
 	}
 	for _, tc := range testCases {

[aldas]

Probably is related to https://github.com/labstack/echo/blob/7f502b1ff10913aeab28abab64f2bf45952c768d/group.go#L28-L29

when group is created it adds 2 routes so middlewares will be executed for that group in case of 404

[croissanne]

Ah, that seems weird to me, returning the NotFoundHandler when there's a better candidate (path match but not method).

[aldas]

well it depends. for router match created by .Any is a valid route. Any adds a route for POST that results 404. Router does not know that result would be 404 and therefore does not look for 405.

I'll have to investigate this situation.

[croissanne]

Ah I get that, but I'm not sure if it should take priority over the exact path match as in the reproducer.

Note that with this patch calling the group point (localhost:8080/api) directly will still result in a 404. And in that case it's totally valid to return a 404 I agree, since there's no path which matches exactly. With an exact path match however (and in that case I think previousBestMatchNode will already be set in router.go:527, chances are a user is using the wrong method to call the endpoint they want.

[aldas]

If you comment out

	//g.Any("", NotFoundHandler)
	//g.Any("/*", NotFoundHandler)

you would get 405 but this means that your Logger middleware will not be fired for that request. When logger is added with e.Pre() it would be fired as pre mws are executed before routing is done.

just a note - group is pretty much helper for adding routes with same prefix and middlewares. it does not exist as a separate entity.

[croissanne]

Right, but with Use the Router definitely has to be involved no? Like the middleware should only apply with a request to a valid endpoint? So we can't just comment those lines out?

With Pre none of this applies of course.

---

edit: Not entirely sure I follow, but I think I see your point. But in the case of calling the group endpoint directly, previousBestMatchNode (on router.go:527) will be nil afaik, at which point it'll mark it as the best match and return 404?

[aldas]

well, removing those 2 lines would probably be surprise after update for some (probably rare cases?). We are planning to remove those lines in v5 but it is far in future and v5 has other "potentially breaking changes" also. Anyway this does not help us currently. If think those lines were added because of static middleware or something similar. I have investigated these lines git history before. As usual these things need a little bit thinking/investigation not to break too much.

Pre middlewares are executed even if there are no route match Group Use middlewares are executed only when there is a match. When you use Use with group this does not mean that these middlewares are immediately "registered" in Echo. Group Use middlewares exist/have meaning only when they are added to route handler chain - which Any in that case does.

For example:

	e := echo.New()
	g := e.Group("/api")
	g.Use(middleware.Logger())
	e.Start(":8080")

has 2 routes in runtime

• /api with handler that returns always 404 (for predefined 11 methods because of Any inside g.Use())
• /api/* with handler that returns always 404 (for predefined 11 methods because of Any)

[croissanne]

Yea and I think that behaviour remains intact for https://github.com/labstack/echo/commit/584291d81be55157100dc04754ef938c45565ec3. The commit message isn't entirely correct however, really it should be something like:

only return the notfoundhandler for anykind if no previous (exact) match/best candidate was found

Removing the two Any calls would be the better solution perhaps if the middlewares didn't have to be executed.

For instance:

	e := echo.New()
	g := e.Group("/api")
	g.Use(middleware.Logger())
	g2 := g.Group("/api2")
	g2.Use(middleware.Logger())
	g2.GET("/endpoint", func(c echo.Context) error {
		return c.String(200, "OK\n")
	})
	e.Start(":8080")

With a nested group you'd expect a call to /api return 404 and get logged once, and indeed:

{"time":"2021-09-08T23:33:04.652820416+02:00","id":"","remote_ip":"::1","host":"localhost:8080","method":"POST","uri":"/api/","user_agent":"curl/7.74.0","status":404,"error":"code=404, message=Not Found","latency":32823,"latency_human":"32.823µs","bytes_in":0,"bytes_out":24}

In this case /api gets matched, but does return 404 of course, as defined by those Any calls in Group.Use. Remove those 2 Any calls and you get 0 logging output because the router can't find any matches.

a call to /api/api2 has 2 logging calls and returns 404:

{"time":"2021-09-08T23:34:57.145792259+02:00","id":"","remote_ip":"::1","host":"localhost:8080","method":"POST","uri":"/api/api2","user_agent":"curl/7.74.0","status":404,"error":"code=404, message=Not Found","latency":111619,"latency_human":"111.619µs","bytes_in":0,"bytes_out":24}
{"time":"2021-09-08T23:34:57.146048684+02:00","id":"","remote_ip":"::1","host":"localhost:8080","method":"POST","uri":"/api/api2","user_agent":"curl/7.74.0","status":404,"error":"","latency":368607,"latency_human":"368.607µs","bytes_in":0,"bytes_out":24}

Which is what you'd expect right, it matches g, executes the logging middleware; it matches g2, executes the logging middleware again, and then returns 404. Again removing the two Any calls in results in no logging output, the router can't find any matches.

[DylanDD13]

Was a workaround ever found for this issue ?

[aldas]

It is not but I think we can fix this by replacing

https://github.com/labstack/echo/blob/40eb889d14001640d8e9c48f22db8388dcf0feb5/group.go#L28-L30

with (probably the most correct in this situation as RouteNotFound is treated a little bit differently in routing)

	g.RouteNotFound("", NotFoundHandler)
	g.RouteNotFound("/*", NotFoundHandler)

and maybe add new method g.MethodNotAllowed(

I'll create PR for this

[eroncastro]

@aldas I think this issue can be closed, since #2411 was merged.