Skip to content

Commit

Permalink
Fix binary logging bug which logs a server header on a trailers only …
Browse files Browse the repository at this point in the history
…response (grpc#5763)
  • Loading branch information
zasweq authored and jronak committed Nov 21, 2022
1 parent 83720b6 commit 4e9de21
Show file tree
Hide file tree
Showing 4 changed files with 25 additions and 18 deletions.
17 changes: 3 additions & 14 deletions gcp/observability/logging_test.go
Expand Up @@ -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()
}
Expand Down Expand Up @@ -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{},
},
Expand Down
10 changes: 10 additions & 0 deletions internal/transport/transport.go
Expand Up @@ -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 {
Expand Down Expand Up @@ -385,9 +389,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
}

Expand Down
12 changes: 10 additions & 2 deletions stream.go
Expand Up @@ -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,
Expand Down
4 changes: 2 additions & 2 deletions test/end2end_test.go
Expand Up @@ -8360,8 +8360,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)
Expand Down

0 comments on commit 4e9de21

Please sign in to comment.