client: synchronously verify server preface in newClientTransport #5731

dfawley · 2022-10-18T20:45:59Z

Add grpcsync.OnceFunc, which is a pattern I also needed in the ORCA PR (orca: create ORCA producer for LB policies to use to receive OOB load reports #5669).
Fix some transport tests that were not writing a server preface.
We had one e2e test that was validating a deadline was set during the handshake. This was moved to be a transport test, and can verify that newClientTransport honors context cancelation in addition to just the deadline. This might make the goal of making ClientConn.Close() block until all resources are released easier -- previously, if a connection was in flight it would take 20+s for it to stop, which would/should delay that return. With these changes it will stop very quickly.

RELEASE NOTES: none

easwars · 2022-10-19T00:36:36Z

internal/grpcsync/oncefunc.go

+
+// OnceFunc returns a function wrapping f which ensures f is only executed
+// once even if the returned function is executed multiple times.
+func OnceFunc(f func()) func() {


I understand this is super trivial, but given that it is exported and can be used from non-test code, adding a test would be good.

internal/transport/http2_client.go

easwars · 2022-10-19T01:19:02Z

internal/transport/http2_client.go

 		return
 	}
-	t.onPrefaceReceipt()
+	close(errCh) // received settings frame


Is closing this channel here any different to pushing a nil error? I believe not. Should we instead push a nil error here instead of closing.

🤷

They're equivalent. I'm okay either way but this seems fine and I see no compelling arguments in favor of pushing a nil explicitly. Is there a better primitive for this purpose than a channel, perhaps?

WDYT about this (see diffs) refactor into another function?

internal/transport/http2_client.go

easwars · 2022-10-19T01:38:02Z

internal/transport/http2_client.go

+	// Monitor context; close connection if expired or canceled before returning.
+	ctxMonitorDone := grpcsync.NewEvent()
+	newClientCtx, newClientDone := context.WithCancel(connectCtx)
+	defer func() {
+		newClientDone()
+		// Wait for the goroutine to exit.  If we do not wait before returning,
+		// the caller could cancel the connectCtx after we return, but we might
+		// see this and close the connection.
+		<-ctxMonitorDone.Done()
+	}()
+	go func(conn net.Conn) {
+		defer ctxMonitorDone.Fire() // Signal this goroutine has exited.
+		<-newClientCtx.Done()
+		if connectCtx.Err() == nil {
+			// Only newClientCtx was canceled; success.
+			return
+		}
+		// connectCtx expired.  Hard close the connection.
+		conn.Close()
+	}(conn)


This block of code was not easy to read and parse and understand. All your comments make absolute sense after I understood what the code is doing. But it did not help initially to understand what is happening in here and why.

In fact my other comment (and concern) about the deadline not being set on the underlying conn is cleared now that I understand what is happening in here. But I think if I come back to this piece of code after 6 months, I will again spend a lot of time trying to understand what is happening.

Could you please be a little more verbose in the comments here. Thanks.

internal/transport/http2_client.go

clientconn.go

dfawley

Thanks for the comments. Responses inline.

internal/transport/http2_client.go

clientconn.go

dfawley · 2022-10-19T16:01:30Z

internal/transport/http2_client.go

+	// Monitor context; close connection if expired or canceled before returning.
+	ctxMonitorDone := grpcsync.NewEvent()
+	newClientCtx, newClientDone := context.WithCancel(connectCtx)
+	defer func() {
+		newClientDone()
+		// Wait for the goroutine to exit.  If we do not wait before returning,
+		// the caller could cancel the connectCtx after we return, but we might
+		// see this and close the connection.
+		<-ctxMonitorDone.Done()
+	}()
+	go func(conn net.Conn) {
+		defer ctxMonitorDone.Fire() // Signal this goroutine has exited.
+		<-newClientCtx.Done()
+		if connectCtx.Err() == nil {
+			// Only newClientCtx was canceled; success.
+			return
+		}
+		// connectCtx expired.  Hard close the connection.
+		conn.Close()
+	}(conn)


internal/transport/http2_client.go

dfawley · 2022-10-19T16:21:48Z

internal/transport/http2_client.go

 		return
 	}
-	t.onPrefaceReceipt()
+	close(errCh) // received settings frame


🤷

They're equivalent. I'm okay either way but this seems fine and I see no compelling arguments in favor of pushing a nil explicitly. Is there a better primitive for this purpose than a channel, perhaps?

WDYT about this (see diffs) refactor into another function?

easwars · 2022-10-19T18:59:31Z

internal/grpcsync/oncefunc_test.go

+	block.Fire()                 // Unblock them.
+	wg.Wait()                    // Wait for them to complete.
+	if v != 1 {
+		t.Fatalf("v = %v; want 1", v)


Nit:

t.Fatalf("OnceFunc() called %v times, want 1", v)

easwars · 2022-10-19T19:05:42Z

internal/transport/transport_test.go

+			_, err := sfr.ReadFrame()
+			if err != nil {


Nit: combine the two lines.

easwars · 2022-10-19T20:59:24Z

internal/transport/http2_client.go

+func (t *http2Client) reader(errCh chan<- error) {
+	defer close(t.readerDone)
+
+	t.readServerPreface(errCh)


Should we instead make readServerPreface() return an error and handle it here (push it on to the channel and return)? Currently, readServerPreface() might have run into an error and pushed something on to the channel. But since we don't have a return value from it, we continue in this function instead of returning early.

I mostly liked it this way because it could defer the channel closure. But we probably should be returning early from this function even though it's okay not to (it will exit when a connection error occurs). Maybe it's not that useful to be a separate function, but I'll leave it. Reworked.

internal/transport/transport_test.go

easwars · 2022-10-19T22:08:47Z

internal/transport/transport_test.go

+	copts := ConnectOptions{ChannelzParentID: channelz.NewIdentifierForTesting(channelz.RefSubChannel, time.Now().Unix(), nil)}
+	_, err = NewClientTransport(connectCtx, context.Background(), resolver.Address{Addr: lis.Addr().String()}, copts, func(GoAwayReason) {}, func() {})
+	t.Logf("NewClientTransport() = _, %v", err)
+	if time.Now().Sub(timeBefore) > 2*time.Second {


Where does this 2s and 1.5s come from. The connectCtx is canceled in 100ms.

Fixed to say "1.9". I tried different values here to balance the test running quickly with not having false failures/successes.

I still don't understand why we want to be so generous with the time it takes to return from NewClientTransport. We cancel the context in 100ms. Do we really have to give it 2s?

The tighter you make this check, the more likely you are to have a spurious failure caused by it taking too long to exit, which could be due to a hiccup on github actions / etc. Ultimately, if we require that it is less than the deadline (3s) then we should be able to distinguish the reason it exited. And actually, I'll extend the deadline and loosen this slightly since we're not concerned about how long it takes to work if it fails.

And, since there is no secondary cancelation mechanism in the second case, I just removed the time check entirely; the only failure is if no error is returned or if it never returns and times out because it's not honoring the context.

easwars · 2022-10-19T22:09:13Z

internal/transport/transport_test.go

+	_, err = NewClientTransport(connectCtx, context.Background(), resolver.Address{Addr: lis.Addr().String()}, copts, func(GoAwayReason) {}, func() {})
+	t.Logf("NewClientTransport() = _, %v", err)
+	if time.Now().Sub(timeBefore) > 2*time.Second {
+		t.Fatalf("NewClientTransport returned > 1.5s after context deadline")


Same comments for this block.

Fixed this, too. Couldn't find this comment in the diffs view for some reason.

easwars · 2022-10-19T23:12:57Z

internal/transport/transport_test.go

+	copts := ConnectOptions{ChannelzParentID: channelz.NewIdentifierForTesting(channelz.RefSubChannel, time.Now().Unix(), nil)}
+	_, err = NewClientTransport(connectCtx, context.Background(), resolver.Address{Addr: lis.Addr().String()}, copts, func(GoAwayReason) {}, func() {})
+	t.Logf("NewClientTransport() = _, %v", err)
+	if time.Now().Sub(timeBefore) > 2*time.Second {


I still don't understand why we want to be so generous with the time it takes to return from NewClientTransport. We cancel the context in 100ms. Do we really have to give it 2s?

easwars · 2022-10-19T23:13:43Z

internal/transport/transport_test.go

+
+	// Test context cancelation.
+	timeBefore := time.Now()
+	connectCtx, cancel := context.WithTimeout(context.Background(), 3*time.Second)


Could we please use defaultTestTimeout which is defined for this package instead of a hard-coded value. We usually end up with different values in different tests over time. Thanks.

Done. If it ever changes to a value less than 3s then this test becomes broken, though, so it is more sensitive to the value than most other tests.

client: synchronously verify server preface in newClientTransport

5f108a5

dfawley added the Type: Internal Cleanup Refactors, etc label Oct 18, 2022

dfawley added this to the 1.51 Release milestone Oct 18, 2022

dfawley requested a review from easwars October 18, 2022 20:45

dfawley assigned easwars Oct 18, 2022

dfawley added 3 commits October 18, 2022 14:20

fix race

ee68c92

detect if onCall was called before retaking the lock

0bcb70c

simplify

d51e224

easwars reviewed Oct 19, 2022

View reviewed changes

easwars assigned dfawley and unassigned easwars Oct 19, 2022

review comments

712b30f

dfawley commented Oct 19, 2022

View reviewed changes

dfawley assigned easwars and unassigned dfawley Oct 19, 2022

easwars reviewed Oct 19, 2022

View reviewed changes

easwars assigned dfawley and unassigned easwars Oct 19, 2022

review comments

194b254

dfawley assigned easwars and unassigned dfawley Oct 19, 2022

easwars approved these changes Oct 19, 2022

View reviewed changes

easwars assigned dfawley and unassigned easwars Oct 19, 2022

timeout

0020628

dfawley merged commit 9127159 into grpc:master Oct 20, 2022

dfawley deleted the syncpreface branch October 25, 2022 21:53

easwars mentioned this pull request Nov 18, 2022

Surface TLS errors to RPC errors #4163

Closed

github-actions bot locked as resolved and limited conversation to collaborators Apr 24, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

client: synchronously verify server preface in newClientTransport #5731

client: synchronously verify server preface in newClientTransport #5731

dfawley commented Oct 18, 2022

easwars Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

dfawley left a comment

dfawley Oct 19, 2022

dfawley Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

easwars Oct 19, 2022

easwars Oct 19, 2022

dfawley Oct 19, 2022

client: synchronously verify server preface in newClientTransport #5731

client: synchronously verify server preface in newClientTransport #5731

Conversation

dfawley commented Oct 18, 2022

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

dfawley left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment