Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

client: fix binary logging bug which logs a server header on a trailers only response #5763

Merged
merged 1 commit into from Nov 2, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
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 @@ -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
}

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 @@ -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)
Expand Down