Golang apm DetachedContext before goroutine not record span

es7,apm server7

When use DetachedContext before (go func(...)) there is not record span
I saw #475

//use the zero framework redis quene
//in the consume task
func ProcessTask(ctx context.Context, t *asynq.Task) error{
   tx := apm.DefaultTracer().StartTransaction("name", "task")
   ctx = apm.ContextWithTransaction(ctx, tx) 
   defer tx.End()
   //http request ( it is can record)
   ....
   newctx := apm.DetachedContext(ctx) // I am not use it before sometimes will  context canceled
   go somefunc(newctx) // use http request there is not record span
}

somefunc(ctx ...) {
   //http request
   //
}

So, How can record span in goroutine

Hi @zt9788, welcome to the forum!

I can't see a problem with your code. Maybe it has to do with the "somfunc" function. Can you share a complete program that has the problem?

I just tested this, and it's working as expected:

package main

import (
        "context"
        "log"

        "github.com/kr/pretty"
        "go.elastic.co/apm/v2"
        "go.elastic.co/apm/v2/apmtest"
)

func main() {
        tracer := apmtest.NewRecordingTracer()
        tracer.SetExitSpanMinDuration(0)
        tracer.SetSpanCompressionEnabled(false)

        tx := tracer.StartTransaction("tx_name", "tx_type")
        ctx := apm.ContextWithTransaction(context.Background(), tx)
        ctx, cancel := context.WithCancel(ctx)
        dctx := apm.DetachedContext(ctx)
        cancel()
        tx.End()

        // detached context should not be affected by the cancel() above
        if err := dctx.Err(); err != nil {
                log.Fatal(err)
        }

        span, _ := apm.StartSpan(dctx, "span_name", "span_type")
        span.End()

        tracer.Flush(nil)
        pretty.Println(tracer.Payloads())
}
$ go run main.go
transporttest.Payloads{
    Errors:  nil,
    Metrics: nil,
    Spans:   {
        {
            Name:      "span_name",
            Timestamp: model.Time{
                wall: 0x14783048,
                ext:  63805469091,
                loc:  (*time.Location)(nil),
            },
            Duration:      0.004038,
            Type:          "span_type",
            Subtype:       "",
            Action:        "",
            ID:            {0x4e, 0xe5, 0x93, 0x13, 0xe5, 0xc9, 0xb3, 0x6f},
            TransactionID: {0x8b, 0x5e, 0xf8, 0x2d, 0xc4, 0x11, 0xdc, 0xdb},
            TraceID:       {0x8b, 0x5e, 0xf8, 0x2d, 0xc4, 0x11, 0xdc, 0xdb, 0x6, 0xa8, 0x18, 0x8a, 0x3b, 0x29, 0x5, 0x80},
            ParentID:      {0x8b, 0x5e, 0xf8, 0x2d, 0xc4, 0x11, 0xdc, 0xdb},
            SampleRate:    &float64(1),
            Context:       (*model.SpanContext)(nil),
            Stacktrace:    nil,
            Outcome:       "success",
            Composite:     (*model.CompositeSpan)(nil),
            Links:         nil,
            OTel:          (*model.OTel)(nil),
        },
    },
    Transactions: {
        {
            ID:        {0x8b, 0x5e, 0xf8, 0x2d, 0xc4, 0x11, 0xdc, 0xdb},
            TraceID:   {0x8b, 0x5e, 0xf8, 0x2d, 0xc4, 0x11, 0xdc, 0xdb, 0x6, 0xa8, 0x18, 0x8a, 0x3b, 0x29, 0x5, 0x80},
            ParentID:  {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0},
            Name:      "tx_name",
            Type:      "tx_type",
            Timestamp: model.Time{
                wall: 0x147818d8,
                ext:  63805469091,
                loc:  (*time.Location)(nil),
            },
            Duration:          0.003206,
            Result:            "",
            Context:           (*model.Context)(nil),
            Sampled:           (*bool)(nil),
            SampleRate:        &float64(1),
            SpanCount:         model.SpanCount{},
            DroppedSpansStats: nil,
            Outcome:           "success",
            OTel:              (*model.OTel)(nil),
            FAAS:              (*model.FAAS)(nil),
            Links:             nil,
        },
    },
    Profiles: nil,
}

the somefunc just to call a http request

the somefunc just to call a http request

OK. Have you instrumented the net/http.Client with apmhttp.WrapClient? I assume you are, but just checking. Are you closing the response body? If you don't close the response body, then the span won't be ended, and will never be sent.

Yes ,I have closed response :joy:

full code:


func HttpCall(ctx context.Context, method, url string, data []byte, header map[string]string) ([]byte, error) {
	if ctx != nil {
		ctx, _ = context.WithTimeout(ctx, time.Minute)
	} else {
		ctx, _ = context.WithTimeout(context.TODO(), time.Minute)
	}
	req, err := http.NewRequestWithContext(ctx, method, url, bytes.NewReader(data))
	if err != nil {
		return nil, err
	}
	for k, v := range header {
		req.Header.Set(k, v)
	}
	resp, err := tracingClient.Do(req)
	if err != nil {
		apm.CaptureError(req.Context(), err).Send()
		return nil, err
	}
	defer resp.Body.Close()
	if resp.StatusCode != http.StatusOK {
		return nil, fmt.Errorf("[%s]%s", resp.Status, url)
	}
	return ioutil.ReadAll(resp.Body)
}

This works for me:

package main                                                                                                   
                                                                                                               
import (                                                                                                       
        "bytes"                                                                                                
        "context"                                                                                              
        "fmt"                                                                                                  
        "io/ioutil"                                                                                            
        "log"                                                                                                  
        "net/http"                                                                                             
        "net/http/httptest"                                                                                    
        "time"                                                                                                 
                                                                                                               
        "github.com/kr/pretty"                                                                                 
        "go.elastic.co/apm/module/apmhttp/v2"                                                                  
        "go.elastic.co/apm/v2"                                                                                 
        "go.elastic.co/apm/v2/apmtest"                                                                         
)                                                                                                              
                                                                                                               
var tracingClient = apmhttp.WrapClient(nil)                                                                    
                                                                                                               
func HttpCall(ctx context.Context, method, url string, data []byte, header map[string]string) ([]byte, error) {
        if ctx != nil {                                                                                        
                ctx, _ = context.WithTimeout(ctx, time.Minute)                                                 
        } else {                                                                                               
                ctx, _ = context.WithTimeout(context.TODO(), time.Minute)                                      
        }                                                                                                      
        req, err := http.NewRequestWithContext(ctx, method, url, bytes.NewReader(data))                        
        if err != nil {                                                                                        
                return nil, err                                                                                
        }                                                                                                      
        for k, v := range header {                                                                             
                req.Header.Set(k, v)                                                                           
        }                                                                                                      
        resp, err := tracingClient.Do(req)                                                                     
        if err != nil {                                                                                        
                apm.CaptureError(req.Context(), err).Send()                                                    
                return nil, err                                                                                
        }                                                                                                      
        defer resp.Body.Close()                                                                                
        if resp.StatusCode != http.StatusOK {                                                                  
                return nil, fmt.Errorf("[%s]%s", resp.Status, url)                                             
        }                                                                                                      
        return ioutil.ReadAll(resp.Body)                                                                       
}                                                                                                              
                                                                                                               
func main() {                                                                                                  
        tracer := apmtest.NewRecordingTracer()                                                                 
        tracer.SetExitSpanMinDuration(0)                                                                       
        tracer.SetSpanCompressionEnabled(false)                                                                
                                                                                                               
        tx := tracer.StartTransaction("tx_name", "tx_type")                                                    
        ctx := apm.ContextWithTransaction(context.Background(), tx)                                            
        ctx, cancel := context.WithCancel(ctx)                                                                 
        dctx := apm.DetachedContext(ctx)                                                                       
        cancel()                                                                                               
        tx.End()                                                                                               
                                                                                                               
        // detached context should not be affected by the cancel() above                                       
        if err := dctx.Err(); err != nil {                                                                     
                log.Fatal(err)                                                                                 
        }                                                                                                      
                                                                                                               
        mux := http.NewServeMux()                                                                              
        mux.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {                                     
                w.Write([]byte("hello"))                                                                       
        })                                                                                                     
        srv := httptest.NewServer(mux)                                                                         
        defer srv.Close()                                                                                      
                                                                                                               
        data, err := HttpCall(dctx, "GET", srv.URL, nil, nil)                                                  
        if err != nil {                                                                                        
                log.Fatal(err)                                                                                 
        }                                                                                                      
        log.Printf("%s", data)                                                                                 
                                                                                                               
        tracer.Flush(nil)                                                                                      
        pretty.Println(tracer.Payloads())                                                                      
}                                                                                                              
transporttest.Payloads{
    Errors:  nil,
    Metrics: nil,
    Spans:   {
        {
            Name:      "GET 127.0.0.1:46875",
            Timestamp: model.Time{
                wall: 0x24085d8,
                ext:  63805478262,
                loc:  (*time.Location)(nil),
            },
            Duration:      0.742258,
            Type:          "external",
            Subtype:       "http",
            Action:        "",
            ID:            {0x1b, 0xe5, 0xac, 0x1b, 0x75, 0xcc, 0xcd, 0x68},
            TransactionID: {0xa9, 0xb1, 0xb0, 0x2c, 0x5c, 0xcc, 0x72, 0x93},
            TraceID:       {0xa9, 0xb1, 0xb0, 0x2c, 0x5c, 0xcc, 0x72, 0x93, 0xdb, 0x4e, 0x7b, 0x4b, 0xdc, 0x52, 0xb7, 0xbe},
            ParentID:      {0xa9, 0xb1, 0xb0, 0x2c, 0x5c, 0xcc, 0x72, 0x93},
            SampleRate:    &float64(1),
            Context:       &model.SpanContext{
                Destination: &model.DestinationSpanContext{
                    Address: "127.0.0.1",
                    Port:    46875,
                    Service: &model.DestinationServiceSpanContext{Type:"external", Name:"http://127.0.0.1:46875", Resource:"127.0.0.1:46875"},
                    Cloud:   (*model.DestinationCloudSpanContext)(nil),
                },
                Service: &model.ServiceSpanContext{
                    Target: &model.ServiceTargetSpanContext{Type:"http", Name:"127.0.0.1:46875"},
                },
                Database: (*model.DatabaseSpanContext)(nil),
                Message:  (*model.MessageSpanContext)(nil),
                HTTP:     &model.HTTPSpanContext{
                    URL: &url.URL{
                        Scheme:      "http",
                        Opaque:      "",
                        User:        (*url.Userinfo)(nil),
                        Host:        "127.0.0.1:46875",
                        Path:        "/",
                        RawPath:     "",
                        OmitHost:    false,
                        ForceQuery:  false,
                        RawQuery:    "",
                        Fragment:    "",
                        RawFragment: "",
                    },
                    StatusCode: 200,
                },
                Tags: nil,
            },
            Stacktrace: nil,
            Outcome:    "success",
            Composite:  (*model.CompositeSpan)(nil),
            Links:      nil,
            OTel:       (*model.OTel)(nil),
        },
    },
    Transactions: {
        {
            ID:        {0xa9, 0xb1, 0xb0, 0x2c, 0x5c, 0xcc, 0x72, 0x93},
            TraceID:   {0xa9, 0xb1, 0xb0, 0x2c, 0x5c, 0xcc, 0x72, 0x93, 0xdb, 0x4e, 0x7b, 0x4b, 0xdc, 0x52, 0xb7, 0xbe},
            ParentID:  {0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0},
            Name:      "tx_name",
            Type:      "tx_type",
            Timestamp: model.Time{
                wall: 0x23b9050,
                ext:  63805478262,
                loc:  (*time.Location)(nil),
            },
            Duration:          0.0027949999999999997,
            Result:            "",
            Context:           (*model.Context)(nil),
            Sampled:           (*bool)(nil),
            SampleRate:        &float64(1),
            SpanCount:         model.SpanCount{},
            DroppedSpansStats: nil,
            Outcome:           "success",
            OTel:              (*model.OTel)(nil),
            FAAS:              (*model.FAAS)(nil),
            Links:             nil,
        },
    },
    Profiles: nil,
}

This is too strange. As long as goroutine is not used, it can be recorded. If goroutine is used, there is no record.
Maybe my code has some bug.
I will test it again. :sob:
Thank you very much for your reply

This is too strange. As long as goroutine is not used, it can be recorded. If goroutine is used, there is no record.

When I change my test program to use a goroutine for calling HttpCall, and wait for it to complete before calling Flush, then I can still see a span.

Maybe my code has some bug.
I will test it again. :sob:
Thank you very much for your reply

You're welcome! If you can share a complete program that has demonstrates the problem, I can also try to see what the problem might be.

OK, I'll try to find a time recently to streamline the code flow and see if there are any problems

1 Like

This topic was automatically closed 20 days after the last reply. New replies are no longer allowed.