Add spans and drop large size high volume trace logs

Signed-off-by: Kirtana Ashok <kiashok@microsoft.com>

cmd/containerd-shim-runhcs-v1/exec_hcs.go

@@ -48,7 +48,7 @@ func newHcsExec(
 		"eid":    id, // Init exec ID is always same as Task ID
 		"bundle": bundle,
 		"wcow":   isWCOW,
-	}).Debug("newHcsExec")
+	}).Trace("newHcsExec")
 
 	he := &hcsExec{
 		events:      events,

internal/gcs/bridge.go

@@ -16,9 +16,11 @@ import (
 	"time"
 
 	"github.com/sirupsen/logrus"
+	"go.opencensus.io/trace"
 	"golang.org/x/sys/windows"
 
 	"github.com/Microsoft/hcsshim/internal/log"
+	"github.com/Microsoft/hcsshim/internal/oc"
 )
 
 const (
@@ -286,6 +288,9 @@ func isLocalDisconnectError(err error) bool {
 }
 
 func (brdg *bridge) recvLoop() error {
+	_, span := oc.StartSpan(context.Background(), "bridge receive", oc.WithClientSpanKind)
+	defer span.End()
+
 	br := bufio.NewReader(brdg.conn)
 	for {
 		id, typ, b, err := readMessage(br)
@@ -298,7 +303,11 @@ func (brdg *bridge) recvLoop() error {
 		brdg.log.WithFields(logrus.Fields{
 			"payload":    string(b),
 			"type":       typ.String(),
-			"message-id": id}).Debug("bridge receive")
+			"message-id": id}).Trace("bridge receive")
+		span.AddAttributes(
+			trace.StringAttribute("type", typ.String()),
+			trace.Int64Attribute("message-id", id))
+
 		switch typ & msgTypeMask {
 		case msgTypeResponse:
 			// Find the request associated with this response.
@@ -372,6 +381,10 @@ func (brdg *bridge) sendLoop() {
 }
 
 func (brdg *bridge) writeMessage(buf *bytes.Buffer, enc *json.Encoder, typ msgType, id int64, req interface{}) error {
+	_, span := oc.StartSpan(context.Background(), "bridge send", oc.WithClientSpanKind)
+	defer span.End()
+	span.AddAttributes(trace.StringAttribute("type", typ.String()))
+
 	// Prepare the buffer with the message.
 	var h [hdrSize]byte
 	binary.LittleEndian.PutUint32(h[hdrOffType:], uint32(typ))
@@ -384,7 +397,7 @@ func (brdg *bridge) writeMessage(buf *bytes.Buffer, enc *json.Encoder, typ msgTy
 	// Update the message header with the size.
 	binary.LittleEndian.PutUint32(buf.Bytes()[hdrOffSize:], uint32(buf.Len()))
 
-	if brdg.log.Logger.GetLevel() >= logrus.DebugLevel {
+	if brdg.log.Logger.GetLevel() > logrus.DebugLevel {
 		b := buf.Bytes()[hdrSize:]
 		switch typ {
 		// container environment vars are in rpCreate for linux; rpcExecuteProcess for windows
@@ -399,8 +412,9 @@ func (brdg *bridge) writeMessage(buf *bytes.Buffer, enc *json.Encoder, typ msgTy
 		brdg.log.WithFields(logrus.Fields{
 			"payload":    string(b),
 			"type":       typ.String(),
-			"message-id": id}).Debug("bridge send")
+			"message-id": id}).Trace("bridge send")
 	}
+	span.AddAttributes(trace.Int64Attribute("message-id", id))
 
 	// Write the message.
 	_, err = buf.WriteTo(brdg.conn)

internal/guest/bridge/bridge.go

@@ -310,7 +310,7 @@ func (b *Bridge) ListenAndServe(bridgeIn io.ReadCloser, bridgeOut io.WriteCloser
 					trace.StringAttribute("cid", base.ContainerID))
 
 				entry := log.G(ctx)
-				if entry.Logger.GetLevel() >= logrus.DebugLevel {
+				if entry.Logger.GetLevel() > logrus.DebugLevel {
 					s := string(message)
 					switch header.Type {
 					case prot.ComputeSystemCreateV1:
@@ -320,7 +320,7 @@ func (b *Bridge) ListenAndServe(bridgeIn io.ReadCloser, bridgeOut io.WriteCloser
 							entry.WithError(err).Warning("could not scrub bridge payload")
 						}
 					}
-					entry.WithField("message", s).Debug("request read message")
+					entry.WithField("message", s).Trace("request read message")
 				}
 				requestChan <- &Request{
 					Context:     ctx,
@@ -365,7 +365,12 @@ func (b *Bridge) ListenAndServe(bridgeIn io.ReadCloser, bridgeOut io.WriteCloser
 	// Process each bridge response sync. This channel is for request/response and publish workflows.
 	go func() {
 		var resperr error
+		var err error
 		for resp := range b.responseChan {
+			_, span := oc.StartSpan(context.Background(), "request write response", oc.WithClientSpanKind)
+			defer span.End()
+			defer func() { oc.SetSpanStatus(span, err) }()
+
 			responseBytes, err := json.Marshal(resp.response)
 			if err != nil {
 				resperr = errors.Wrapf(err, "bridge: failed to marshal JSON for response \"%v\"", resp.response)
@@ -384,7 +389,7 @@ func (b *Bridge) ListenAndServe(bridgeIn io.ReadCloser, bridgeOut io.WriteCloser
 
 			s := trace.FromContext(resp.ctx)
 			if s != nil {
-				log.G(resp.ctx).WithField("message", string(responseBytes)).Debug("request write response")
+				log.G(resp.ctx).WithField("message", string(responseBytes)).Trace("request write response")
 				s.End()
 			}
 		}