Question: Datadog trace for echo is giving useless trace stack for 4xx and 5xx status code.

[ckyko]

Hi, I am using Datadog trace for my go echo server. And, I saw there is a trace stack for 4xx and 5xx status codes on the Datadog APM traces tag tab. But, looks like it is showing the same error stack. And, it is not my error stack. Looks like it is the trace stack where we set the error-tag.

Should we show it if it is not the real error trace stack? Is there any way to disable it for the wrong error trace stack?
Also, I saw the error trace stack on both 'error' tab and 'tag' tab, is it duplicate information?

The trace stack on the Datadog APM traces:

gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer.(*span).setTagError
/Users/kachen/go/pkg/mod/gopkg.in/!data!dog/dd-trace-go.v1@v1.31.1/ddtrace/tracer/span.go:164
gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer.(*span).SetTag
/Users/kachen/go/pkg/mod/gopkg.in/!data!dog/dd-trace-go.v1@v1.31.1/ddtrace/tracer/span.go:107
gopkg.in/DataDog/dd-trace-go.v1/contrib/labstack/echo%2ev4.Middleware.func1.1
/Users/kachen/go/pkg/mod/gopkg.in/!data!dog/dd-trace-go.v1@v1.31.1/contrib/labstack/echo.v4/echotrace.go:55
github.com/labstack/echo/v4.(*Echo).add.func1
/Users/kachen/go/pkg/mod/github.com/labstack/echo/v4@v4.5.0/echo.go:544
github.com/labstack/echo/v4.(*Echo).ServeHTTP
/Users/kachen/go/pkg/mod/github.com/labstack/echo/v4@v4.5.0/echo.go:654
net/http.serverHandler.ServeHTTP
/usr/local/Cellar/go/1.15.8/libexec/src/net/http/server.go:2843
net/http.(*conn).serve
/usr/local/Cellar/go/1.15.8/libexec/src/net/http/server.go:1925
runtime.goexit
/usr/local/Cellar/go/1.15.8/libexec/src/runtime/asm_amd64.s:1374

Here is the code to generate the trace stack:

package main

import (
	"github.com/labstack/echo/v4"
	echotrace "gopkg.in/DataDog/dd-trace-go.v1/contrib/labstack/echo.v4"
	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer"
	"net/http"
)

func main() {
	tracer.Start(
		tracer.WithEnv("test"),
		tracer.WithService("test-go"),
		tracer.WithServiceVersion("abc123"),
	)

	defer tracer.Stop()

	e := echo.New()
	topGroup := e.Group("/top", echotrace.Middleware())
	subGroup := topGroup.Group("/sub")
	subGroup.Add("GET", "/foo/:bar", func(c echo.Context) error {
		return echo.NewHTTPError(http.StatusBadRequest, "my error message")
	})

	e.Logger.Fatal(e.Start(":1325"))

}

dd-trace-go/contrib/labstack/echo.v4/echotrace.go

Line 55 in d326bfb

span.SetTag(ext.Error, err)

dd-trace-go/ddtrace/tracer/span.go

Line 107 in d326bfb

s.setTagError(value, errorConfig{

[dubonzi]

I might be wrong, but I believe this line of the stack

github.com/labstack/echo/v4.(*Echo).add.func1
/Users/kachen/go/pkg/mod/github.com/labstack/echo/v4@v4.5.0/echo.go:544

refers to your handler defined in

subGroup.Add("GET", "/foo/:bar", func(c echo.Context) error {
	return echo.NewHTTPError(http.StatusBadRequest, "my error message")
})

Its not clear because its an anonymous function. Try defining a actual function and check the stack again. Something like

subGroup.Add("GET", "/foo/:bar", fooHandler)

func fooHandler(c echo.Context) error {
	return echo.NewHTTPError(http.StatusBadRequest, "my error message")
}

[ckyko]

I try the actual function and the stack looks the same.

gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer.(*span).setTagError
/Users/kachen/go/pkg/mod/gopkg.in/!data!dog/dd-trace-go.v1@v1.31.1/ddtrace/tracer/span.go:164
gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer.(*span).SetTag
/Users/kachen/go/pkg/mod/gopkg.in/!data!dog/dd-trace-go.v1@v1.31.1/ddtrace/tracer/span.go:107
gopkg.in/DataDog/dd-trace-go.v1/contrib/labstack/echo%2ev4.Middleware.func1.1
/Users/kachen/go/pkg/mod/gopkg.in/!data!dog/dd-trace-go.v1@v1.31.1/contrib/labstack/echo.v4/echotrace.go:55
github.com/labstack/echo/v4.(*Echo).add.func1
/Users/kachen/go/pkg/mod/github.com/labstack/echo/v4@v4.5.0/echo.go:544
github.com/labstack/echo/v4.(*Echo).ServeHTTP
/Users/kachen/go/pkg/mod/github.com/labstack/echo/v4@v4.5.0/echo.go:654
net/http.serverHandler.ServeHTTP
/usr/local/Cellar/go/1.15.8/libexec/src/net/http/server.go:2843
net/http.(*conn).serve
/usr/local/Cellar/go/1.15.8/libexec/src/net/http/server.go:1925
runtime.goexit
/usr/local/Cellar/go/1.15.8/libexec/src/runtime/asm_amd64.s:1374

package main

import (
	"github.com/labstack/echo/v4"
	echotrace "gopkg.in/DataDog/dd-trace-go.v1/contrib/labstack/echo.v4"
	"gopkg.in/DataDog/dd-trace-go.v1/ddtrace/tracer"
	"net/http"
)

func main() {
	tracer.Start(
		tracer.WithEnv("test"),
		tracer.WithService("test-go"),
		tracer.WithServiceVersion("abc123"),
	)

	defer tracer.Stop()

	e := echo.New()
	topGroup := e.Group("/top", echotrace.Middleware())
	subGroup := topGroup.Group("/sub")
	subGroup.Add("GET", "/foo/:bar", fooHandler)

	e.Logger.Fatal(e.Start(":1325"))

}

func fooHandler(c echo.Context) error {
	return echo.NewHTTPError(http.StatusBadRequest, "my error message")
}

The stack doesn't show my handler.

[knusbaum]

Hi, @ckyko.
Stack trace collecting is done on a best-effort basis. We can't know the full stack of an error since that information doesn't get propagated with the errors. Instead, we collect stack traces as close to the error as we can get (span.Finish). Sometimes these are useful, but other times they are completely unhelpful.

Also, I saw the error trace stack on both 'error' tab and 'tag' tab, is it duplicate information?

The information is presented in two places in the UI, but the information is not duplicated in the span (there is only one copy of the data being sent from the application). The UI just chooses to display the error tag specially.

You can consider using the WithDebugStack option, which will disable collection of stack traces for the entire program.

If that's not an acceptable solution, we can add an Option to the echo integration similar to NoDebugStack from goji or grpc and several others.

[ckyko]

Thanks, I don't think disabling stack traces for the entire program is a good solution. I would expect there is an option to disable the stack traces when the traces are completely unhelpful.

[knusbaum]

@ckyko No problem, I've opened a proposal (#999) to add that option.

[knusbaum]

I looked more closely into this. Aside from the stack traces not being useful, the echo integration is doing some things wrongly that it shouldn't:

• Recording any returned error as an error in the span - this should only apply to 5xx errors.
• Calling c.Error() - We called it to get the error set on the request. However, this function is not idempotent, and calling it here could mess up echo or other middleware.

Unfortunately, we can't know the final value of the status code or the final error, but we can make a good guess based on what is returned from the downstream middleware and handlers.

[kevin521]

Any resolution on this? We're trying to clean up our APM and only have 500s for our echo implementation.

Happy to help in any way to get the PR merged.