diff --git a/proxy/proxy.go b/proxy/proxy.go index 209e9ec9e8..342f16bd1f 100644 --- a/proxy/proxy.go +++ b/proxy/proxy.go @@ -28,6 +28,7 @@ import ( "github.com/zalando/skipper/metrics" "github.com/zalando/skipper/ratelimit" "github.com/zalando/skipper/routing" + "github.com/zalando/skipper/tracing" ) const ( @@ -193,6 +194,7 @@ type Params struct { } var ( + hostname = "" errMaxLoopbacksReached = errors.New("max loopbacks reached") errRouteLookupFailed = &proxyError{err: errors.New("route lookup failed")} errCircuitBreakerOpen = &proxyError{ @@ -539,6 +541,8 @@ func WithParams(p Params) *Proxy { openTracingInitialSpan = "ingress" } + hostname = os.Getenv("HOSTNAME") + return &Proxy{ routing: p.Routing, roundTripper: tr, @@ -575,11 +579,19 @@ func tryCatch(p func(), onErr func(err interface{})) { // applies filters to a request func (p *Proxy) applyFiltersToRequest(f []*routing.RouteFilter, ctx *context) []*routing.RouteFilter { + if len(f) == 0 { + return f + } + filtersStart := time.Now() + filtersSpan := tracing.CreateSpan("request_filters", ctx.request.Context(), p.openTracer) + defer filtersSpan.Finish() + var filters = make([]*routing.RouteFilter, 0, len(f)) for _, fi := range f { start := time.Now() + filtersSpan.LogKV(fi.Name, "start") tryCatch(func() { ctx.setMetricsPrefix(fi.Name) fi.Request(ctx) @@ -594,6 +606,7 @@ func (p *Proxy) applyFiltersToRequest(f []*routing.RouteFilter, ctx *context) [] p.log.Errorf("error while processing filter during request: %s: %v", fi.Name, err) }) + filtersSpan.LogKV(fi.Name, "done") filters = append(filters, fi) if ctx.deprecatedShunted() || ctx.shunted() { @@ -707,18 +720,12 @@ func (p *Proxy) makeBackendRequest(ctx *context) (*http.Response, *proxyError) { return nil, &proxyError{handled: true} } - ingress := ot.SpanFromContext(req.Context()) bag := ctx.StateBag() spanName, ok := bag[tracingfilter.OpenTracingProxySpanKey].(string) if !ok { spanName = "proxy" } - - if ingress == nil { - ctx.proxySpan = p.openTracer.StartSpan(spanName) - } else { - ctx.proxySpan = p.openTracer.StartSpan(spanName, ot.ChildOf(ingress.Context())) - } + ctx.proxySpan = tracing.CreateSpan(spanName, req.Context(), p.openTracer) ext.SpanKindRPCClient.Set(ctx.proxySpan) ctx.proxySpan.SetTag("skipper.route_id", ctx.route.Id) ctx.proxySpan.SetTag("skipper.route", ctx.route.String()) @@ -909,9 +916,7 @@ func (p *Proxy) do(ctx *context) error { } else { done, allow := p.checkBreaker(ctx) if !allow { - if span := ot.SpanFromContext(ctx.Request().Context()); span != nil { - span.LogKV(`circuit_breaker`, `open`) - } + tracing.LogKV("circuit_breaker", "open", ctx.request.Context()) return errCircuitBreakerOpen } @@ -938,6 +943,8 @@ func (p *Proxy) do(ctx *context) error { ctx.proxySpan = nil } + tracing.LogKV("retry", ctx.route.Id, ctx.Request().Context()) + perr = nil var perr2 *proxyError rsp, perr2 = p.makeBackendRequest(ctx) @@ -1124,6 +1131,7 @@ func (p *Proxy) ServeHTTP(w http.ResponseWriter, r *http.Request) { err = p.do(ctx) if err != nil { + ext.Error.Set(span, true) p.errorResponse(ctx, err) return } @@ -1150,6 +1158,7 @@ func (p *Proxy) setCommonSpanInfo(u *url.URL, r *http.Request, s ot.Span) { ext.Component.Set(s, "skipper") ext.HTTPUrl.Set(s, u.String()) ext.HTTPMethod.Set(s, r.Method) + s.SetTag("hostname", hostname) s.SetTag("http.remote_addr", r.RemoteAddr) s.SetTag("http.path", u.Path) s.SetTag("http.host", r.Host) diff --git a/tracing/tracing.go b/tracing/tracing.go index a69337015c..8d4831f63b 100644 --- a/tracing/tracing.go +++ b/tracing/tracing.go @@ -50,6 +50,7 @@ package tracing import ( + "context" "errors" "fmt" "path/filepath" @@ -129,3 +130,19 @@ func LoadPlugin(pluginDir string, opts []string) (ot.Tracer, error) { } return tracer, nil } + +// CreateSpan creates a started span from an optional given parent from context +func CreateSpan(name string, ctx context.Context, openTracer ot.Tracer) ot.Span { + parentSpan := ot.SpanFromContext(ctx) + if parentSpan == nil { + return openTracer.StartSpan(name) + } + return openTracer.StartSpan(name, ot.ChildOf(parentSpan.Context())) +} + +// LogKV will add a log to the span from the given context +func LogKV(k, v string, ctx context.Context) { + if span := ot.SpanFromContext(ctx); span != nil { + span.LogKV(k, v) + } +}