GOCBC-1135: Set net and cmd spans to nil on req cancellation

Motivation
----------
It's possible for a request cancel to race with a response completion.
When this happens there is a gap on the memdclient side between
releasing the request lock and setting request completion to 1. The
same is effectively true for the opposite also, after we have handled
cancelling a request we can continue handling it as an error case in
the memdclient. The effect of this is that we end up cancelling the
net and cmd traces twice.

Changes
-------
Update cancelReqTrace to call stopCmdTrace and stopNetTrace
respectively so that relevant attributes are added to the spans
and the cmd and net spans are then set to nil.
Update StartNetTrace to lock around checking if the cmd trace
is nil.

Change-Id: Iff0c23266b57f236bf8c8a35fd5766fad823eefc
Reviewed-on: http://review.couchbase.org/c/gocbcore/+/156991
Tested-by: Charles Dixon <chvckd@gmail.com>
Reviewed-by: Brett Lawson <brett19@gmail.com>

memdqpackets.go

@@ -219,12 +219,16 @@ func (req *memdQRequest) internalCancel(err error) bool {
 		queuedWith.Remove(req)
 	}
 
+	var localAddr string
+	var remoteAddr string
 	waitingIn := (*memdClient)(atomic.LoadPointer(&req.waitingIn))
 	if waitingIn != nil {
 		waitingIn.CancelRequest(req, err)
+		localAddr = waitingIn.LocalAddress()
+		remoteAddr = waitingIn.Address()
 	}
 
-	cancelReqTrace(req)
+	cancelReqTrace(req, localAddr, remoteAddr)
 	req.processingLock.Unlock()
 
 	return true

tracing.go

@@ -155,16 +155,18 @@ func (tc *tracerComponent) StartCmdTrace(req *memdQRequest) {
 }
 
 func (tc *tracerComponent) StartNetTrace(req *memdQRequest) {
+	req.processingLock.Lock()
 	if req.cmdTraceSpan == nil {
+		req.processingLock.Unlock()
 		return
 	}
 
 	if req.netTraceSpan != nil {
+		req.processingLock.Unlock()
 		logWarnf("Attempted to start net tracing on traced request")
 		return
 	}
 
-	req.processingLock.Lock()
 	req.netTraceSpan = tc.tracer.RequestSpan(req.cmdTraceSpan.Context(), spanNameDispatchToServer)
 	req.processingLock.Unlock()
 }
@@ -202,13 +204,13 @@ func stopCmdTrace(req *memdQRequest) {
 	req.cmdTraceSpan = nil
 }
 
-func cancelReqTrace(req *memdQRequest) {
+func cancelReqTrace(req *memdQRequest, local, remote string) {
 	if req.cmdTraceSpan != nil {
 		if req.netTraceSpan != nil {
-			req.netTraceSpan.End()
+			stopNetTrace(req, nil, local, remote)
 		}
 
-		req.cmdTraceSpan.End()
+		stopCmdTrace(req)
 	}
 }
 
@@ -224,8 +226,10 @@ func stopNetTrace(req *memdQRequest, resp *memdQResponse, localAddress, remoteAd
 
 	req.netTraceSpan.SetAttribute(spanAttribDBSystemKey, spanAttribDBSystemValue)
 	req.netTraceSpan.SetAttribute(spanAttribNetTransportKey, spanAttribNetTransportValue)
-	req.netTraceSpan.SetAttribute(spanAttribOperationIDKey, strconv.Itoa(int(resp.Opaque)))
-	req.netTraceSpan.SetAttribute(spanAttribLocalIDKey, resp.sourceConnID)
+	if resp != nil {
+		req.netTraceSpan.SetAttribute(spanAttribOperationIDKey, strconv.Itoa(int(resp.Opaque)))
+		req.netTraceSpan.SetAttribute(spanAttribLocalIDKey, resp.sourceConnID)
+	}
 	localName, localPort, err := net.SplitHostPort(localAddress)
 	if err != nil {
 		logDebugf("Failed to split host port: %s", err)
@@ -240,7 +244,7 @@ func stopNetTrace(req *memdQRequest, resp *memdQResponse, localAddress, remoteAd
 	req.netTraceSpan.SetAttribute(spanAttribNetHostPortKey, localPort)
 	req.netTraceSpan.SetAttribute(spanAttribNetPeerNameKey, remoteName)
 	req.netTraceSpan.SetAttribute(spanAttribNetPeerPortKey, remotePort)
-	if resp.Packet.ServerDurationFrame != nil {
+	if resp != nil && resp.Packet.ServerDurationFrame != nil {
 		req.netTraceSpan.SetAttribute(spanAttribServerDurationKey, resp.Packet.ServerDurationFrame.ServerDuration)
 	}