SkyAPM / go2sky

Distributed tracing and monitor SDK in Go for Apache SkyWalking APM
https://skywalking.apache.org/
Apache License 2.0
448 stars 123 forks source link

Unexcepted parentSpanID when parent span is ended #166

Closed matianjun1 closed 2 years ago

matianjun1 commented 2 years ago

Describe the bug In async, start the first span, then end it and start a sub span from it. There are two TraceSegmentID, but the sub span is the same level of the first span.

To Reproduce

package main

import (
    "fmt"
    "log"
    "net/http"
    "time"

    "github.com/SkyAPM/go2sky"
    v3 "github.com/SkyAPM/go2sky-plugins/gin/v3"
    "github.com/SkyAPM/go2sky/reporter"
    "github.com/gin-gonic/gin"
)

func main() {
    // Use gRPC reporter for production
    re, err := reporter.NewGRPCReporter("127.0.0.1:11800")
    // re, err := reporter.NewLogReporter()
    if err != nil {
        log.Fatalf("new reporter error %v \n", err)
    }
    defer re.Close()

    tracer, err := go2sky.NewTracer("gin-server", go2sky.WithReporter(re))
    if err != nil {
        log.Fatalf("create tracer error %v \n", err)
    }

    r := gin.Default()
    r.HandleMethodNotAllowed = true

    router := r.Group("/", v3.Middleware(r, tracer))

    router.GET("/hello/:name", func(c *gin.Context) {
        name := c.Param("name")

        ctx := c.Request.Context()
        fmt.Printf("ctx TraceID %s; SpanID %d; TraceSegmentID %s\n", go2sky.TraceID(ctx), go2sky.SpanID(ctx), go2sky.TraceSegmentID(ctx))

        s, ctx1, err := tracer.CreateLocalSpan(ctx, go2sky.WithOperationName("Sync Local Span"))
        if err != nil {
            log.Fatalf("create sync local span error %v \n", err)
        }
        time.Sleep(time.Millisecond * 200)
        fmt.Printf("ctx1 TraceID %s; SpanID %d; TraceSegmentID %s\n", go2sky.TraceID(ctx1), go2sky.SpanID(ctx1), go2sky.TraceSegmentID(ctx1))
        s.End()

        go func() {
            time.Sleep(time.Second)
            s, ctx2, err := tracer.CreateLocalSpan(ctx, go2sky.WithOperationName("Async Local Span"))
            if err != nil {
                log.Fatalf("create async local span error %v \n", err)
            }
            time.Sleep(time.Millisecond * 200)
            fmt.Printf("ctx2 TraceID %s; SpanID %d; TraceSegmentID %s\n", go2sky.TraceID(ctx2), go2sky.SpanID(ctx2), go2sky.TraceSegmentID(ctx2))
            s.End()

        }()

        time.Sleep(time.Millisecond * 500)
        c.String(http.StatusOK, "Hello "+name)
    })

    r.Run(":8081")
}
ctx TraceID 8bab82643efa11ed929aacde48001122; SpanID 0; TraceSegmentID 8bab82aa3efa11ed929aacde48001122
ctx1 TraceID 8bab82643efa11ed929aacde48001122; SpanID 1; TraceSegmentID 8bab82aa3efa11ed929aacde48001122
[GIN] 2022/09/28 - 14:55:33 | 200 |  701.260744ms |       127.0.0.1 | GET      "/hello/name"
go2sky-log2022/09/28 14:55:33 Segment-8bab82aa3efa11ed929aacde48001122: [{"Refs":null,"StartTime":"2022-09-28T14:55:32.437286+08:00","EndTime":"2022-09-28T14:55:32.638352+08:00","OperationName":"Sync Local Span","Peer":"","Layer":0,"ComponentID":0,"Tags":null,"Logs":null,"IsError":false,"SpanType":2,"TraceID":"8bab82643efa11ed929aacde48001122","SegmentID":"8bab82aa3efa11ed929aacde48001122","SpanID":1,"ParentSpanID":0,"ParentSegmentID":"8bab82aa3efa11ed929aacde48001122","CorrelationContext":{}},{"Refs":null,"StartTime":"2022-09-28T14:55:32.437254+08:00","EndTime":"2022-09-28T14:55:33.138485+08:00","OperationName":"/GET/hello/:name","Peer":"","Layer":3,"ComponentID":5006,"Tags":[{"key":"http.method","value":"GET"},{"key":"url","value":"127.0.0.1:8081/hello/name"},{"key":"status_code","value":"200"}],"Logs":null,"IsError":false,"SpanType":0,"TraceID":"8bab82643efa11ed929aacde48001122","SegmentID":"8bab82aa3efa11ed929aacde48001122","SpanID":0,"ParentSpanID":-1,"ParentSegmentID":"","CorrelationContext":{}}]
ctx2 TraceID 8bab82643efa11ed929aacde48001122; SpanID 0; TraceSegmentID 8c62e9043efa11ed929aacde48001122
go2sky-log2022/09/28 14:55:33 Segment-8c62e9043efa11ed929aacde48001122: [{"Refs":null,"StartTime":"2022-09-28T14:55:33.639143+08:00","EndTime":"2022-09-28T14:55:33.839778+08:00","OperationName":"Async Local Span","Peer":"","Layer":0,"ComponentID":0,"Tags":null,"Logs":null,"IsError":false,"SpanType":2,"TraceID":"8bab82643efa11ed929aacde48001122","SegmentID":"8c62e9043efa11ed929aacde48001122","SpanID":0,"ParentSpanID":-1,"ParentSegmentID":"8bab82aa3efa11ed929aacde48001122","CorrelationContext":{}}]

trace-list

image

Expected behavior

image

Desktop (please complete the following information):

github.com/SkyAPM/go2sky v1.5.0 github.com/SkyAPM/go2sky-plugins/gin/v3 v3.0.0-20220803071639-79cf2aadcd70 github.com/gin-gonic/gin v1.8.1

Additional context Add any other context about the problem here.

matianjun1 commented 2 years ago

I think the second segment refs should not be null.