diff --git a/cmd/swarm/swarm-smoke/feed_upload_and_sync.go b/cmd/swarm/swarm-smoke/feed_upload_and_sync.go index 9823dc0542..2bfb3016e5 100644 --- a/cmd/swarm/swarm-smoke/feed_upload_and_sync.go +++ b/cmd/swarm/swarm-smoke/feed_upload_and_sync.go @@ -307,9 +307,7 @@ func feedUploadAndSync(c *cli.Context) error { } func fetchFeed(topic string, user string, endpoint string, original []byte, ruid string) error { - ctx, cancel := context.WithCancel(context.Background()) - defer cancel() - ctx, sp := spancontext.StartSpan(ctx, "feed-and-sync.fetch") + ctx, sp := spancontext.StartSpan(context.Background(), "feed-and-sync.fetch") defer sp.Finish() log.Trace("sleeping", "ruid", ruid) @@ -317,7 +315,7 @@ func fetchFeed(topic string, user string, endpoint string, original []byte, ruid log.Trace("http get request (feed)", "ruid", ruid, "api", endpoint, "topic", topic, "user", user) - tn := time.Now() + var tn time.Time reqUri := endpoint + "/bzz-feed:/?topic=" + topic + "&user=" + user req, _ := http.NewRequest("GET", reqUri, nil) @@ -326,62 +324,14 @@ func fetchFeed(topic string, user string, endpoint string, original []byte, ruid opentracing.HTTPHeaders, opentracing.HTTPHeadersCarrier(req.Header)) - trace := &httptrace.ClientTrace{ - GetConn: func(_ string) { - log.Trace("http get request (feed) - GetConn") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.getconn", nil).Update(time.Since(tn)) - }, - GotConn: func(_ httptrace.GotConnInfo) { - log.Trace("http get request (feed) - GotConn") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.gotconn", nil).Update(time.Since(tn)) - }, - PutIdleConn: func(err error) { - log.Trace("http get request (feed) - PutIdleConn", "err", err) - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.putidle", nil).Update(time.Since(tn)) - }, - GotFirstResponseByte: func() { - log.Trace("http get request (feed) - GotFirstResponseByte") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.firstbyte", nil).Update(time.Since(tn)) - }, - Got100Continue: func() { - log.Trace("http get request (feed) - Got100Continue") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.got100continue", nil).Update(time.Since(tn)) - }, - DNSStart: func(_ httptrace.DNSStartInfo) { - log.Trace("http get request (feed) - DNSStart") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.dnsstart", nil).Update(time.Since(tn)) - }, - DNSDone: func(_ httptrace.DNSDoneInfo) { - log.Trace("http get request (feed) - DNSDone") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.dnsdone", nil).Update(time.Since(tn)) - }, - ConnectStart: func(network, addr string) { - log.Trace("http get request (feed) - ConnectStart", "network", network, "addr", addr) - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.connectstart", nil).Update(time.Since(tn)) - }, - ConnectDone: func(network, addr string, err error) { - log.Trace("http get request (feed) - ConnectDone", "network", network, "addr", addr, "err", err) - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.connectdone", nil).Update(time.Since(tn)) - }, - WroteHeaders: func() { - log.Trace("http get request (feed) - WroteHeaders(request)") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.wroteheaders", nil).Update(time.Since(tn)) - }, - Wait100Continue: func() { - log.Trace("http get request (feed) - Wait100Continue") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.wait100continue", nil).Update(time.Since(tn)) - }, + trace := getClientTrace("feed-and-sync", ruid, &tn) - WroteRequest: func(_ httptrace.WroteRequestInfo) { - log.Trace("http get request (feed) - WroteRequest") - metrics.GetOrRegisterResettingTimer("feed-and-sync.fetch.clienttrace.wroterequest", nil).Update(time.Since(tn)) - }, - } - req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace)) + req = req.WithContext(httptrace.WithClientTrace(ctx, trace)) transport := http.DefaultTransport //transport.TLSClientConfig = &tls.Config{InsecureSkipVerify: true} + tn = time.Now() res, err := transport.RoundTrip(req) if err != nil { log.Error(err.Error(), "ruid", ruid) diff --git a/cmd/swarm/swarm-smoke/main.go b/cmd/swarm/swarm-smoke/main.go index bf0d4762ed..bcd9212c9b 100644 --- a/cmd/swarm/swarm-smoke/main.go +++ b/cmd/swarm/swarm-smoke/main.go @@ -18,13 +18,16 @@ package main import ( "fmt" + "net/http/httptrace" "os" "sort" + "time" "github.com/ethereum/go-ethereum/cmd/utils" gethmetrics "github.com/ethereum/go-ethereum/metrics" "github.com/ethereum/go-ethereum/metrics/influxdb" swarmmetrics "github.com/ethereum/go-ethereum/swarm/metrics" + "github.com/ethereum/go-ethereum/swarm/tracing" "github.com/ethereum/go-ethereum/log" @@ -119,6 +122,8 @@ func main() { swarmmetrics.MetricsInfluxDBHostTagFlag, }...) + app.Flags = append(app.Flags, tracing.Flags...) + app.Commands = []cli.Command{ { Name: "upload_and_sync", @@ -136,6 +141,12 @@ func main() { sort.Sort(cli.FlagsByName(app.Flags)) sort.Sort(cli.CommandsByName(app.Commands)) + + app.Before = func(ctx *cli.Context) error { + tracing.Setup(ctx) + return nil + } + app.After = func(ctx *cli.Context) error { return emitMetrics(ctx) } @@ -166,3 +177,57 @@ func emitMetrics(ctx *cli.Context) error { return nil } + +func getClientTrace(testName, ruid string, tn *time.Time) *httptrace.ClientTrace { + trace := &httptrace.ClientTrace{ + GetConn: func(_ string) { + log.Trace(testName+" - http get", "event", "GetConn", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.getconn", nil).Update(time.Since(*tn)) + }, + GotConn: func(_ httptrace.GotConnInfo) { + log.Trace(testName+" - http get", "event", "GotConn", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.gotconn", nil).Update(time.Since(*tn)) + }, + PutIdleConn: func(err error) { + log.Trace(testName+" - http get", "event", "PutIdleConn", "ruid", ruid, "err", err) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.putidle", nil).Update(time.Since(*tn)) + }, + GotFirstResponseByte: func() { + log.Trace(testName+" - http get", "event", "GotFirstResponseByte", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.firstbyte", nil).Update(time.Since(*tn)) + }, + Got100Continue: func() { + log.Trace(testName+" - http get", "event", "Got100Continue", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.got100continue", nil).Update(time.Since(*tn)) + }, + DNSStart: func(_ httptrace.DNSStartInfo) { + log.Trace(testName+" - http get", "event", "DNSStart", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.dnsstart", nil).Update(time.Since(*tn)) + }, + DNSDone: func(_ httptrace.DNSDoneInfo) { + log.Trace(testName+" - http get", "event", "DNSDone", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.dnsdone", nil).Update(time.Since(*tn)) + }, + ConnectStart: func(network, addr string) { + log.Trace(testName+" - http get", "event", "ConnectStart", "ruid", ruid, "network", network, "addr", addr) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.connectstart", nil).Update(time.Since(*tn)) + }, + ConnectDone: func(network, addr string, err error) { + log.Trace(testName+" - http get", "event", "ConnectDone", "ruid", ruid, "network", network, "addr", addr, "err", err) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.connectdone", nil).Update(time.Since(*tn)) + }, + WroteHeaders: func() { + log.Trace(testName+" - http get", "event", "WroteHeaders(request)", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.wroteheaders", nil).Update(time.Since(*tn)) + }, + Wait100Continue: func() { + log.Trace(testName+" - http get", "event", "Wait100Continue", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.wait100continue", nil).Update(time.Since(*tn)) + }, + WroteRequest: func(_ httptrace.WroteRequestInfo) { + log.Trace(testName+" - http get", "event", "WroteRequest", "ruid", ruid) + gethmetrics.GetOrRegisterResettingTimer(testName+".fetch.clienttrace.wroterequest", nil).Update(time.Since(*tn)) + }, + } + return trace +} diff --git a/cmd/swarm/swarm-smoke/upload_and_sync.go b/cmd/swarm/swarm-smoke/upload_and_sync.go index 15dfee3cf6..1524b82a5c 100644 --- a/cmd/swarm/swarm-smoke/upload_and_sync.go +++ b/cmd/swarm/swarm-smoke/upload_and_sync.go @@ -138,16 +138,14 @@ func uploadAndSync(c *cli.Context) error { // fetch is getting the requested `hash` from the `endpoint` and compares it with the `original` file func fetch(hash string, endpoint string, original []byte, ruid string) error { - ctx, cancel := context.WithCancel(context.Background()) - defer cancel() - ctx, sp := spancontext.StartSpan(ctx, "upload-and-sync.fetch") + ctx, sp := spancontext.StartSpan(context.Background(), "upload-and-sync.fetch") defer sp.Finish() log.Trace("sleeping", "ruid", ruid) time.Sleep(3 * time.Second) log.Trace("http get request", "ruid", ruid, "api", endpoint, "hash", hash) - tn := time.Now() + var tn time.Time reqUri := endpoint + "/bzz:/" + hash + "/" req, _ := http.NewRequest("GET", reqUri, nil) @@ -156,61 +154,14 @@ func fetch(hash string, endpoint string, original []byte, ruid string) error { opentracing.HTTPHeaders, opentracing.HTTPHeadersCarrier(req.Header)) - trace := &httptrace.ClientTrace{ - GetConn: func(_ string) { - log.Trace("http get request - GetConn") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.getconn", nil).Update(time.Since(tn)) - }, - GotConn: func(_ httptrace.GotConnInfo) { - log.Trace("http get request - GotConn") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.gotconn", nil).Update(time.Since(tn)) - }, - PutIdleConn: func(err error) { - log.Trace("http get request - PutIdleConn", "err", err) - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.putidle", nil).Update(time.Since(tn)) - }, - GotFirstResponseByte: func() { - log.Trace("http get request - GotFirstResponseByte") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.firstbyte", nil).Update(time.Since(tn)) - }, - Got100Continue: func() { - log.Trace("http get request - Got100Continue") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.got100continue", nil).Update(time.Since(tn)) - }, - DNSStart: func(_ httptrace.DNSStartInfo) { - log.Trace("http get request - DNSStart") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.dnsstart", nil).Update(time.Since(tn)) - }, - DNSDone: func(_ httptrace.DNSDoneInfo) { - log.Trace("http get request - DNSDone") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.dnsdone", nil).Update(time.Since(tn)) - }, - ConnectStart: func(network, addr string) { - log.Trace("http get request - ConnectStart", "network", network, "addr", addr) - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.connectstart", nil).Update(time.Since(tn)) - }, - ConnectDone: func(network, addr string, err error) { - log.Trace("http get request - ConnectDone", "network", network, "addr", addr, "err", err) - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.connectdone", nil).Update(time.Since(tn)) - }, - WroteHeaders: func() { - log.Trace("http get request - WroteHeaders(request)") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.wroteheaders", nil).Update(time.Since(tn)) - }, - Wait100Continue: func() { - log.Trace("http get request - Wait100Continue") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.wait100continue", nil).Update(time.Since(tn)) - }, - WroteRequest: func(_ httptrace.WroteRequestInfo) { - log.Trace("http get request - WroteRequest") - metrics.GetOrRegisterResettingTimer("upload-and-sync.fetch.clienttrace.wroterequest", nil).Update(time.Since(tn)) - }, - } - req = req.WithContext(httptrace.WithClientTrace(req.Context(), trace)) + trace := getClientTrace("upload-and-sync", ruid, &tn) + + req = req.WithContext(httptrace.WithClientTrace(ctx, trace)) transport := http.DefaultTransport //transport.TLSClientConfig = &tls.Config{InsecureSkipVerify: true} + tn = time.Now() res, err := transport.RoundTrip(req) if err != nil { log.Error(err.Error(), "ruid", ruid)