dd-trace-go icon indicating copy to clipboard operation
dd-trace-go copied to clipboard

[BUG] contrib/labstack/echo middlewares both call and return error

Open nakkamarra opened this issue 3 months ago • 8 comments

Version of dd-trace-go 1.56.0

Describe what happened: As we can see from this comment documenting the Error() func:

// 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)

I don't think it makes sense for this middleware to both call the c.Error() (which essentially just calls the registered error handler with the given error), and then both return the error (which will propagate it inevitably up the middleware chain to the registered error handler when called from the serving function here).

In my opinion the most flexible thing to do is to just return the error up the chain and not call c.Error(), as that will inevitably happen anyway and allows for both DefaultHTTPErrorHandler behavior and any custom HTTPErrorHandler to both work with this package.

Describe what you expected: Errors are only handled once

Steps to reproduce the issue: Import and initialize the dd-trace-go echo package in an echo app:

package main

import (
	"context"
	"fmt"
	"os"
	"os/signal"

	"github.com/labstack/echo/v4"
	"github.com/labstack/echo/v4/middleware"
	echotrace "gopkg.in/DataDog/dd-trace-go.v1/contrib/labstack/echo.v4"
)

func main() {
	// Echo instance
	e := echo.New()

	// Middleware
	e.Use(middleware.Logger())
	e.Use(middleware.Recover())
	e.Use(
		echotrace.Middleware(
			// whatever options here
			echotrace.WithServiceName("service-name"),
			echotrace.WithAnalytics(true),
		),
	)
	e.HTTPErrorHandler = func(err error, c echo.Context) {
		fmt.Println("called error handler")
		c.String(500, "error encountered")
	}

	// Routes
	e.GET("/", hello)

	// Start server
	e.Logger.Fatal(e.Start(":1234"))
	c := make(chan os.Signal, 1)
	signal.Notify(c, os.Interrupt)
	<-c

	err := e.Shutdown(context.Background())
	if err != nil {
		panic(err)
	}
}

// Handler
func hello(c echo.Context) error {
	return fmt.Errorf("couldn't do it...")
}

Notice that calling this / route will result in the error handler being called more than once (noticeable in both logs and on response). Removing the datadog middleware will resolve the duplicate call to the error handler.

nakkamarra avatar Mar 11 '24 20:03 nakkamarra

@nakkamarra Thanks for getting in touch. We just reviewed it and we understood the issue at hand.

Our proposed solution is to return nil but keep the call to c.Error, as stated in Echo's official documentation.

If you find it acceptable, we'll close #2609 and create a new PR following our solution.

darccio avatar Mar 19 '24 15:03 darccio

Hey @darccio my only issue with that is that it assumes that the dd-trace middleware is the first in the chain / last to receive the error, since it will then consume that error. I don't know if I agree it is the place of a tracing framework to make that decision about the rest of the application.

There, in theory, could be another middleware preceding the datadog middleware in the chain that might want to do something with that error, and so in my mind that is a bit less flexible. IMO, I don't think the explicit invocation of the Error() function should be used anywhere except in places where the intended goal is to not pass the error to above middlewares.

Let me know what you think / if that makes sense. Thanks

nakkamarra avatar Mar 19 '24 15:03 nakkamarra

Sorry for double ping @darccio, also just wanted to highlight that the other middleware that is listed in that documentation page that you linked has a different behavior:

// ServerHeader middleware adds a `Server` header to the response.
func ServerHeader(next echo.HandlerFunc) echo.HandlerFunc {
	return func(c echo.Context) error {
		c.Response().Header().Set(echo.HeaderServer, "Echo/3.0")
		return next(c)
	}
}

wherein the error from the rest of the middleware chain is called and returned immediately via return next(c) and this is the pattern which almost every echo middleware I have seen uses. It's hard to say to for certain that the call to c.Error() in echo's docs is being stated as the de facto way to achieve this; you could just as easily make the case that they are using that method there as a means of demonstration, not to say that it is how it should be done.

In either case we know that the error resulting from executing the entirety of the chain will end up at the registered error handler, so I don't see the need to explicitly invoke the handler when the error can be returned and leave things more extensible. Consider the case in which someone might want the server to panic / shutdown if a specific error is encountered and not call the error handler, and that such logic exists in a middleware preceding the dd-trace middleware; this behavior or similar behavior would be unachieveable because of the invocation / consumption of the error.

nakkamarra avatar Mar 19 '24 15:03 nakkamarra

@nakkamarra Thanks for the detailed answer. @rarguelloF I think it's reasonable to go the way that @nakkamarra is proposing. WDYT?

darccio avatar Mar 20 '24 15:03 darccio

Hey @darccio @rarguelloF wanted to bump, my PR has been tagged stale

nakkamarra avatar Apr 01 '24 01:04 nakkamarra

@nakkamarra Thanks for your detailed explanation! makes sense to me, so we can consider this proposal as accepted and move on with your PR.

rarguelloF avatar Apr 01 '24 12:04 rarguelloF

Hey @rarguelloF and @darccio thanks for helping get this one merged in. Is there a release schedule I can follow? Seems like 1.63.0 did not include this change, and I don't want to point directly github instead of gopkg

nakkamarra avatar Apr 25 '24 16:04 nakkamarra

@nakkamarra You should be able to pull your specific commit like this:

replace gopkg.in/DataDog/dd-trace-go.v1 => github.com/DataDog/dd-trace-go f44904a412ebbfa274747b5f1189c252f452b249

go mod tidy will take of the rest. You can ignore that it'll show like it downloaded an older version, but if you check the signature it'll have the commit's prefix and merge time: v1.39.0-alpha.1.0.20240410080038-f44904a412eb. I know, it's confusing, but I double checked and your go.mod will be pointing to the right code.

Anyway, v1.64.0 release train will start next week.

darccio avatar Apr 26 '24 08:04 darccio