[Bug] incorrect span segment when enhancing the Gin framework about skywalking HOT 7 CLOSED

span will be created by the first HandlerFunc and closed by the last HandlerFunc,

What was wrong? This sentence is not clear.

from skywalking.

span will be created by the first HandlerFunc and closed by the last HandlerFunc,

What was wrong? This sentence is not clear.

I found that the Gin plugin has been changed to func (c *Context) Next(). However, this method will be handled multiple times by multiple middleware handlerFuncs in the route.
As a result, CreateEntrySpan is called every handlerFuncs and propagated by Invocation.SetContext() closed by the last handlerFunc, causing the segment to be incorrectly interrupted prematurely when customizing Gin middleware.

from skywalking.

Could you put a graph to explain this? You are using an instance level dynamic field, this should not be helpful is a handler instance repeatedly used in the process.

from skywalking.

when customize middleware in Gin, the trace info will lost , such as

router := gin.Default()
router.Use(func(c *gin.Context) {
        logger.Info("do something before handler")
	c.Next()
	logger.Info("do something after handler")
})

and the log like this, after has no trace info

2024-01-31 16:56:02 | info | [email protected]/context.go:174 | do something before handler | {"SW_CTX": "[Your_ApplicationName,[email protected],8ad58d8ac01611eea4c42672e7982bed.36.39184449623780005,8ad58d8ac01611eea4c42672e7982bed.36.39184449623780006,0]"}
2024-01-31 16:56:02 | info | [email protected]/context.go:174 | handle | {"SW_CTX": "[Your_ApplicationName,[email protected],8ad58d8ac01611eea4c42672e7982bed.36.39184449623780005,8ad58d8ac01611eea4c42672e7982bed.36.39184449623780006,0]"}
2024-01-31 16:56:02 | info | [email protected]/context.go:174 | do something after handler | {"SW_CTX": "[Your_ApplicationName,[email protected],N/A,N/A,-1]"}
[GIN] 2024/01/31 - 16:56:02 | 200 |       179.3µs |             ::1 | GET      "/hello"

from skywalking.

I could understand your case now, then, when the context gets reset in the after? Is it caused by stop span at the end of #Next, or somewhere else?

from skywalking.

because every middleware handlerFuncs could call #Next, then it will call #CreateEntrySpan in #BeforeInvoke and call span.End() in #AfterInvoke many times, but after span.End() first be Called by the last middleware handlerFunc, the TracingContext in current goroutine will be cleared, so the other handlerfuncs cannot get the TraceContext for use.

from skywalking.

OK, then there is typically solution for this, you should put a counter in the context of the chain. This counter increases one in before and minus one in after. Then, create span when the counter created, and stop span when counter back to zero.

Note, the counter should be kept in the request context.

from skywalking.