WIP, resty

logger.go

@@ -572,12 +572,16 @@ func (line *Line) Template(template string) {
 	line.log.hasActivity(true)
 }
 
+// Msg sends a log line.  After Msg(), no further use of the *Line
+// is allowed.  Without calling Msg(), Template(), Msgf(), Msgs(),
+// or Static(), the log line will not be sent or output.
 func (line *Line) Msg(msg string) {
 	line.line.Msg(msg)
 	line.log.span.linePool.Put(line)
 	line.log.hasActivity(true)
 }
 
+// Msgf sends a log line, using fmt.Sprintf()-style formatting.
 func (line *Line) Msgf(msg string, v ...interface{}) {
 	if !line.skip {
 		line.Msg(fmt.Sprintf(msg, v...))
@@ -593,6 +597,8 @@ func (line *Line) Static(msg string) {
 	line.log.hasActivity(true)
 }
 
+// Line starts a log line at the specified log level.  If the log level
+// is below the minimum log level, the line will be discarded.
 func (log *Log) Line(level xopnum.Level) *Line { return log.logLine(level) }
 func (log *Log) Debug() *Line                  { return log.Line(xopnum.DebugLevel) }
 func (log *Log) Trace() *Line                  { return log.Line(xopnum.TraceLevel) }

trace/trace.go

@@ -69,17 +69,17 @@ func NewTrace() Trace {
 
 var traceRE = regexp.MustCompile(`^([a-fA-F0-9]{2})-([a-fA-F0-9]{32})-([a-fA-F0-9]{16})-([a-fA-F0-9]{2})$`)
 
-func TraceFromString(s string) Trace {
+func TraceFromString(s string) (Trace, bool) {
 	m := traceRE.FindStringSubmatch(s)
 	if m == nil {
-		return NewTrace()
+		return NewTrace(), false
 	}
 	var trace Trace
 	trace.Version().SetString(m[1])
 	trace.TraceID().SetString(m[2])
 	trace.SpanID().SetString(m[3])
 	trace.Flags().SetString(m[4])
-	return trace
+	return trace, true
 }
 
 func (t *Trace) Version() WrappedHexBytes1 {

xopmiddle/utils.go

@@ -13,8 +13,8 @@ import (
 // "traceparent" header
 // Example: 00-0af7651916cd43dd8448eb211c80319c-b7ad6b7169203331-01
 func SetByTraceParentHeader(b *trace.Bundle, h string) {
-	parent := trace.TraceFromString(h)
-	if parent.IsZero() {
+	parent, ok := trace.TraceFromString(h)
+	if !ok {
 		b.Trace = trace.NewTrace()
 		b.Trace.TraceID().SetRandom()
 		b.Trace.SpanID().SetRandom()

xopresty/resty.go

@@ -3,9 +3,14 @@ package xopresty adds to the resty package to
 propagate xop context to through an HTTP request.
 
 The resty package does not provide a clean way to
-pass in a logger or context.  To get around that,
-we'll have to wrap the resty *Client on a per-request
-basis.
+pass in a logger or context.  To get around this 
+we'll need a fresh resty client for each request.
+
+Another challenge with resty is that the resty Logger
+is per-Client, not per-Requet.
+
+Thiw would all be simpler if there was a Copy method
+for resty Clients, but there isn't.
 */
 package xopresty
 
@@ -25,15 +30,25 @@ func (rl restyLogger) Errorf(format string, v ...interface{}) { rl.log.Error().M
 func (rl restyLogger) Warnf(format string, v ...interface{})  { rl.log.Warn().Msgf(format, v...) }
 func (rl restyLogger) Debugf(format string, v ...interface{}) { rl.log.Debug().Msgf(format, v...) }
 
-func Wrap(log *xop.Log, client *resty.Client, description string) *resty.Client {
+func wrap(log *xop.Log, client *resty.Client, description string) *resty.Client {
 	log = log.Sub().Step(description)
-	defer log.Done()
+	var b3Sent bool
+	var b3Trace trace.Trace
+	var response bool
+	defer func() {
+		if b3Sent && !response {
+			log.Info().Link("span.far_side_id", b3Trace).Static("span id set with B3")
+			log.Span().Link("span.far_side_id", b3Trace)
+		}
+		log.Done()
+	}
+
 	// c := *client
 	// c.Header = client.Header.Clone()
 	// clinet = &c
 	return client.
 		SetLogger(restyLogger{log: log}).
-		OnBeforeRequest(func(client *Client, r *Request) error {
+		OnBeforeRequest(func(_ *Client, r *Request) error {
 			log.Span().EmbeddedEnum(xopconst.SpanTypeHTTPClientRequest)
 			log.Span().String(xopconst.URL, r.URL.String())
 			log.Span().String(xopconst.HTTPMethod, r.Method)
@@ -45,14 +60,44 @@ func Wrap(log *xop.Log, client *resty.Client, description string) *resty.Client
 				r.Header.Set("state", log.Span().TraceState().String())
 			}
 			if log.Config().UseB3 {	
-				trace := log.Span().Bundle().Trace
-				farSideSpan = trace.NewRandomSpanID()
+				b3Trace := log.Span().Bundle().Trace
+				b3Trace.SpanID().SetRandom()
 				r.Header.Set("b3",
-					log.Span().Trace().GetTraceID().String()+"-"+
-						farSideSpan.String()+"-"+
-						log.Span().Trace().GetFlags().String()[1:2]+"-"+
-						log.Span().Trace().GetSpanID().String())
+					b3Trace.GetTraceID().String()+"-"+
+					b3Trace.TraceID().String()+"-"+
+					b3Trace.GetFlags().String()[1:2]+"-"+
+					log.Span().Trace().GetSpanID().String())
+			}
+			return nil
+		}).
+		OnAfterResponse(func(_ *Client, r *Response) error {
+			tr := r.Header().Get("traceresponse") 
+			if tr != "" {
+				trace, ok := trace.TraceFromString(tr)
+				if ok {	
+					response = true
+					log.Info().Link("span.far_side_id", trace).Static("traceresponse")
+					log.Span().Link("span.far_side_id", trace)
+				} else {
+					log.Warn().String("header", tr).Static("invalid traceresponse received")
+				}
+			}
+			if res != nil {
+				log.Info().Any("response", r.Result())
+			}
+			ti := r.Request.TraceInfo()
+			log.Info().
+				Duration("request_time.total", ti.TotalTime).
+				Duration("request_time.server", ti.ServerTime).
+				Duration("request_time.dns", ti.DNSLookup).
+				Static("timings")
+
 
+			return nil
+		}).
+		EnableTrace().
+
+
 
 
 }