Fix binary logging bug which logs a server header on a trailers only response (#5763)

Author: zasweq

gcp/observability/logging_test.go

@@ -608,9 +608,9 @@ func (s) TestBothClientAndServerRPCEvents(t *testing.T) {
 		t.Fatalf("unexpected error: %v, expected an EOF error", err)
 	}
 	fle.mu.Lock()
-	if len(fle.entries) != 17 {
+	if len(fle.entries) != 16 {
 		fle.mu.Unlock()
-		t.Fatalf("Unexpected length of entries %v, want 17 (collective of client and server)", len(fle.entries))
+		t.Fatalf("Unexpected length of entries %v, want 16 (collective of client and server)", len(fle.entries))
 	}
 	fle.mu.Unlock()
 }
@@ -936,24 +936,13 @@ func (s) TestPrecedenceOrderingInConfiguration(t *testing.T) {
 			SequenceID:  2,
 			Authority:   ss.Address,
 		},
-		{
-			Type:        eventTypeServerHeader,
-			Logger:      loggerClient,
-			ServiceName: "grpc.testing.TestService",
-			MethodName:  "FullDuplexCall",
-			SequenceID:  3,
-			Authority:   ss.Address,
-			Payload: payload{
-				Metadata: map[string]string{},
-			},
-		},
 		{
 			Type:        eventTypeServerTrailer,
 			Logger:      loggerClient,
 			ServiceName: "grpc.testing.TestService",
 			MethodName:  "FullDuplexCall",
 			Authority:   ss.Address,
-			SequenceID:  4,
+			SequenceID:  3,
 			Payload: payload{
 				Metadata: map[string]string{},
 			},

internal/transport/transport.go

@@ -43,6 +43,10 @@ import (
 	"google.golang.org/grpc/tap"
 )
 
+// ErrNoHeaders is used as a signal that a trailers only response was received,
+// and is not a real error.
+var ErrNoHeaders = errors.New("stream has no headers")
+
 const logLevel = 2
 
 type bufferPool struct {
@@ -366,9 +370,15 @@ func (s *Stream) Header() (metadata.MD, error) {
 		return s.header.Copy(), nil
 	}
 	s.waitOnHeader()
+
 	if !s.headerValid {
 		return nil, s.status.Err()
 	}
+
+	if s.noHeaders {
+		return nil, ErrNoHeaders
+	}
+
 	return s.header.Copy(), nil
 }
 

stream.go

@@ -752,17 +752,25 @@ func (cs *clientStream) withRetry(op func(a *csAttempt) error, onSuccess func())
 
 func (cs *clientStream) Header() (metadata.MD, error) {
 	var m metadata.MD
+	noHeader := false
 	err := cs.withRetry(func(a *csAttempt) error {
 		var err error
 		m, err = a.s.Header()
+		if err == transport.ErrNoHeaders {
+			noHeader = true
+			return nil
+		}
 		return toRPCErr(err)
 	}, cs.commitAttemptLocked)
+
 	if err != nil {
 		cs.finish(err)
 		return nil, err
 	}
-	if len(cs.binlogs) != 0 && !cs.serverHeaderBinlogged {
-		// Only log if binary log is on and header has not been logged.
+
+	if len(cs.binlogs) != 0 && !cs.serverHeaderBinlogged && !noHeader {
+		// Only log if binary log is on and header has not been logged, and
+		// there is actually headers to log.
 		logEntry := &binarylog.ServerHeader{
 			OnClientSide: true,
 			Header:       m,

test/end2end_test.go

@@ -8259,8 +8259,8 @@ func (s) TestGlobalBinaryLoggingOptions(t *testing.T) {
 		t.Fatalf("unexpected error: %v, expected an EOF error", err)
 	}
 
-	if csbl.mml.events != 9 {
-		t.Fatalf("want 9 client side binary logging events, got %v", csbl.mml.events)
+	if csbl.mml.events != 8 {
+		t.Fatalf("want 8 client side binary logging events, got %v", csbl.mml.events)
 	}
 	if ssbl.mml.events != 8 {
 		t.Fatalf("want 8 server side binary logging events, got %v", ssbl.mml.events)