Add more tests for receiving events while resyncing for a partial join #419

squahtx · 2022-07-21T19:06:00Z

Add tests for three cases where a homeserver receives a latest event with missing prev events while it is still resyncing state after a partial join.

Namely:

... <-- M <-- A <-- B

        +---------+
        v          \
... <-- M <-- A <-- B

and

        +---------+
        v          \
... <-- M <-- A <-- B <-- C

where event M is the last event the homeserver knows about and the rightmost event is the one it receives.

The last case tests the code path mentioned in matrix-org/synapse#13002

Best reviewed commit by commit.

`testReceiveEventDuringPartialStateJoin()` sends an event over federation, checks that a client can see it and checks the state at the event.

…isisng_events` requests

squahtx · 2022-07-21T19:07:31Z

tests/federation_room_join_partial_state_test.go

+	var prevEvents interface{}
+	if prevEventIDs == nil {
+		prevEvents = nil
+	} else {
+		prevEvents = prevEventIDs
+	}


We do this because interface{}(nil) is not equal to []string(nil)

squahtx · 2022-07-21T19:10:36Z

tests/federation_room_join_partial_state_test.go

+			// since we have not yet given the homeserver the full state at the join event and allowed
+			// the partial join to complete, it can't possibly know the full state at the last event.
+			// While it may be possible for the response to be correct by some accident of state res,
+			// the homeserver is still wrong in spirit.
+			t.Fatalf("/state_ids request for event %s did not block when it should have", event.EventID())


This part tests matrix-org/synapse#13002 . If Synapse does not correctly flag that it does not have partial state in the CanReceiveEventsWithMissingPrevWithHalfMissingPrevsDuringPartialStateJoin test case, it will erroneously return state (which was derived via state res and only happens to be correct) instead of blocking.

squahtx · 2022-07-21T19:11:11Z

tests/federation_room_join_partial_state_test.go

+	})
+
+	// we should be able to receive events with missing prevs over federation during the resync
+	t.Run("CanReceiveEventsWithMissingPrevWithHalfMissingPrevsDuringPartialStateJoin", func(t *testing.T) {


Suggestions for better names are welcome.

maybe "can receive events with some missing grandparents" or something?

…lete

… event

… missing and one known prev event

richvdh

looks generally good, a few suggestions.

richvdh · 2022-07-22T10:58:08Z

tests/federation_room_join_partial_state_test.go

@@ -143,66 +143,8 @@ func TestPartialStateJoin(t *testing.T) {

 		// derek sends an event in the room
 		event := psjResult.CreateMessageEvent(t, "derek", nil)
-		psjResult.Server.MustSendTransaction(t, deployment, "hs1", []json.RawMessage{event.JSON()}, nil)
 		t.Logf("Derek sent event event ID %s", event.EventID())


s/sent/created/ here

richvdh · 2022-07-22T11:25:51Z

tests/federation_room_join_partial_state_test.go

+	// fire off a /state_ids request for the last event.
+	// it must either:
+	//   * block because the homeserver does not have full state at the last event
+	//   * or 403 because the homeserver does not have full state yet and does not consider the
+	//     Complement homeserver to be in the room


shouldn't we know which, and test for that specifically?

Right now only the last test case blocks instead of 403s. I'm somewhat reluctant to be more specific in the tests, because it feels like an implementation detail of synapse (which will change when we get around to matrix-org/synapse#13288).

If you're really keen on being more specific, I'm happy to add a boolean parameter or suchlike. (It's not easy to move this part of the test out, since it needs to happen after the /event request above has succeeded)

ah right. tbh I don't think either blocking or returning a 403 is correct behaviour, though I'm not quite sure what is.

It would be very useful to add a link to #13288 and say that this is somewhat temporary until we solve it properly.

hm, is there a better way to test whether synapse thinks an event has partial state?
this part of the test was intended to check that _resolve_state_at_missing_prevs calculates the partial state flag correctly and it sounds like it's not a good idea to rely on /state_ids

none that I can immediately think of. The ideal thing would be to check that after the resync, /state_ids returns some result that would have been impossible without the information conveyed during the resync - but that sounds rather fiddly for a test (and, probably, a hard-to-understand test failure if it later turns out not to be true).

richvdh · 2022-07-22T11:26:44Z

tests/federation_room_join_partial_state_test.go

+	select {
+	case <-time.After(1 * time.Second):
+		t.Logf("/state_ids request for event %s blocked as expected", event.EventID())
+		defer func() { <-stateIdsResponseChan }()


what does this defer thing do?

when the /state_ids request blocks, the send of the response happens some time later, perhaps even after the test ends.
If we don't read from the channel, the goroutine above blocks on sending into the channel and complement gets very unhappy 10 minutes later because it's still not finished.

right, so we're making sure we read from the channel so that the goroutine doesn't block. Can you add a comment to that effect?

richvdh · 2022-07-22T11:35:14Z

tests/federation_room_join_partial_state_test.go

+		if err := psjResult.Server.SendFederationRequest(deployment, stateReq, &respStateIDs); err != nil {
+			httpErr, ok := err.(gomatrix.HTTPError)
+			t.Logf("%v", httpErr)
+			if ok && httpErr.Code == 403 {
+				stateIdsResponseChan <- nil
+				return
+			}
+			t.Errorf("/state_ids request returned non-200: %s", err)
+			return
+		}
+		stateIdsResponseChan <- &respStateIDs


rather than matching for the 403 here and sending a nil magic value down the channel, I suggest you define

type stateIDsResult struct { RespStateIDs gomatrixserverlib.RespStateIDs Error error }

... and then send that back down the channel, and do the matching in the main thread.

richvdh · 2022-07-22T11:41:07Z

tests/federation_room_join_partial_state_test.go

+		result.ServerRoom,
+		result.fedStateIdsRequestReceivedWaiter,
+		result.fedStateIdsSendResponseWaiter,
+		result.fedStateIdsAllowedEvents,


I think it might be easier to flip this around, and have handleStateIdsRequests only match /state_ids requests for the last event before the join event? That's what I did in #418, in 687ad36.

That looks a lot cleaner. I've borrowed that commit and it works great. Do we want to split that change into a separate PR?

yeah, I'll do that.

richvdh · 2022-07-22T11:45:55Z

tests/federation_room_join_partial_state_test.go

+	})
+
+	// we should be able to receive events with missing prevs over federation during the resync
+	t.Run("CanReceiveEventsWithMissingPrevWithHalfMissingPrevsDuringPartialStateJoin", func(t *testing.T) {


maybe "can receive events with some missing grandparents" or something?

richvdh · 2022-07-22T11:47:01Z

tests/federation_room_join_partial_state_test.go

+		t.Logf("Derek sent event A with ID %s", eventA.EventID())
+		t.Logf("Derek sent event B with ID %s", eventB.EventID())
+		t.Logf("Derek sent event C with ID %s", eventC.EventID())


s/sent/created/. He hasn't sent them to hs1 yet.

…the channel too

… to complete" This reverts commit 2cbeaae.

I'm going to add a test which will involve *multiple* /state and /state_ids requests, so we need to make the registered handlers more selective.

richvdh

lgtm

richvdh · 2022-07-22T14:16:26Z

tests/federation_room_join_partial_state_test.go

+		// read from the channel and discard the result, so that the goroutine above doesn't block
+		// indefinitely on the send


(I'm a bit surprised that closing the channel isn't sufficient for this, but fair enough)

We get a panic: send on closed channel without this. To clarify:

no close and no read -> complement times out after 10 minutes
defer close + no read -> panic
defer close + defer read -> complement is happy

I don't really see why this is done in a goroutine at all - is this because SendFederationRequest can block indefinitely? There is a default 30s timeout - if that is too long then you need to send a custom context with a timeout here -

complement/internal/federation/server.go

Line 227 in d842670

return httpClient.DoRequestAndParseResponse(context.Background(), httpReq, resBody)

- currently this is context.Background() so it won't ever expire, but you can change that easily by doing:

ctx, cancel := context.WithTimeout(context.Background(), time.Second) defer cancel() httpClient.DoRequestAndParseResponse(ctx, httpReq, resBody)

This will require a change to Complement's API to:

func (s *Server) SendFederationRequest(ctx context.Context, deployment *docker.Deployment, req gomatrixserverlib.FederationRequest, resBody interface{}) error {

but that's fine.

Thanks for the suggestion, that's a lot cleaner!

…ns_calculate_partial_state_flag_for_backfill

squahtx · 2022-07-22T15:54:44Z

// fire off a /state_ids request for the last event.
// it must either:
//   * block because the homeserver does not have full state at the last event
//   * or 403 because the homeserver does not have full state yet and does not consider the
//     Complement homeserver to be in the room
hm, is there a better way to test whether synapse thinks an event has partial state? this part of the test was intended to check that _resolve_state_at_missing_prevs calculates the partial state flag correctly and it sounds like it's not a good idea to rely on /state_ids

Before we merge, is there a better way to check that Synapse has calculated the partial state flag for an event correctly?

kegsay · 2022-07-25T10:18:22Z

tests/federation_room_join_partial_state_test.go

+		if time.Since(start) > time.Second {
+			t.Fatalf("timeout waiting for received event to be visible")
+		}
+		res := alice.DoFunc(t, "GET", []string{"_matrix", "client", "r0", "rooms", psjResult.ServerRoom.RoomID, "event", event.EventID()})


You can now use WithRetryUntil in your DoFunc so you can remove the for loop etc. It would look a bit like:

res := alice.DoFunc(t, "GET", []string{"_matrix", "client", "r0", "rooms", psjResult.ServerRoom.RoomID, "event", event.EventID()}, client.WithRetryUntil(time.Second, func(res *http.Response) bool { if res.StatusCode == 200 { return true } eventResBody := client.ParseJSON(t, res) if res.StatusCode == 404 && gjson.GetBytes(eventResBody, "errcode").String() == "M_NOT_FOUND" { return false } t.Fatalf("GET /event failed with %d: %s", res.StatusCode, string(eventResBody)) return false })

kegsay

Use client.WithRetryUntil and add a context to SendFederationRequest and you should be able to remove a fair chunk of boilerplate here, and help other test authors.

richvdh

lgtm otherwise.

richvdh · 2022-07-26T11:02:24Z

.vscode/settings.json

+{
+    "go.testEnvVars": {
+        "COMPLEMENT_BASE_IMAGE": "complement-synapse"
+    }
+}


not sure if we should be commiting this?

Ideally not, as it will make Dendrite people sad.

Good spot! I must have added it by accident while merging in main.

squahtx · 2022-07-26T11:28:20Z

Thank you both for the reviews!

Sean Quah added 3 commits July 21, 2022 16:26

Factor out CreateMessageEvent() function

a07b041

Factor out testReceiveEventDuringPartialStateJoin() function

7b483be

`testReceiveEventDuringPartialStateJoin()` sends an event over federation, checks that a client can see it and checks the state at the event.

Add handleGetMissingEventsRequests() function to respond to `/get_m…

bd2b688

…isisng_events` requests

squahtx requested a review from a team July 21, 2022 19:06

squahtx commented Jul 21, 2022

View reviewed changes

This was referenced Jul 21, 2022

Faster room joins: avoid blocking when pulling events with missing prevs matrix-org/synapse#13355

Merged

Faster joins: check for partial state when handling backfill matrix-org/synapse#13002

Closed

Sean Quah added 5 commits July 21, 2022 21:43

Test whether the homeserver thinks it has full state at a received event

d085f11

Allow explicitly specified /state and /state_ids requests to comp…

2cbeaae

…lete

Add simple test for receiving an event with a missing prev event

894d755

Add a test for receiving an event with one missing and one known prev…

0643979

… event

Add a test for receiving an event with a missing prev event, with one…

5e38528

… missing and one known prev event

squahtx force-pushed the squah/faster_room_joins_calculate_partial_state_flag_for_backfill branch from 6b43730 to 5e38528 Compare July 21, 2022 20:43

richvdh self-assigned this Jul 22, 2022

richvdh mentioned this pull request Jul 22, 2022

Regression test for infinite-loop-in-resync #418

Merged

richvdh reviewed Jul 22, 2022

View reviewed changes

richvdh removed their assignment Jul 22, 2022

Sean Quah and others added 8 commits July 22, 2022 13:32

fixup: s/sent/created/

2979d24

fixup: define StateIDsResult struct and send /state_id failures down …

a5b3c71

…the channel too

fixup: rename new tests to use parents/grandparents terminology

8f5b930

Revert "Allow explicitly specified /state and /state_ids requests…

49e35b4

… to complete" This reverts commit 2cbeaae.

Faster joins tests: make request handlers more specific

1adf5aa

I'm going to add a test which will involve *multiple* /state and /state_ids requests, so we need to make the registered handlers more selective.

fixup: Add explicit /state_id and /state handlers instead

74dc057

Log which /state_ids request is being replied to

5a9832f

fixup: explain purpose of deferred channel read

d437bfb

squahtx requested a review from richvdh July 22, 2022 14:06

richvdh approved these changes Jul 22, 2022

View reviewed changes

Sean Quah added 2 commits July 22, 2022 16:51

fixup: link to synapse#13288

8abc0e8

Merge remote-tracking branch 'origin/main' into squah/faster_room_joi…

8f0b234

…ns_calculate_partial_state_flag_for_backfill

kegsay reviewed Jul 25, 2022

View reviewed changes

kegsay requested changes Jul 25, 2022

View reviewed changes

Sean Quah added 2 commits July 25, 2022 22:27

fixup: Use WithRetryUntil to retry /event

98907c0

Use Context.WithTimeout instead of a SendFederationRequest goroutine

47ce7ba

squahtx requested a review from a team as a code owner July 25, 2022 21:44

Add comment explaining purpose of early /state_ids request

1a0fa9f

squahtx requested a review from kegsay July 25, 2022 23:37

richvdh approved these changes Jul 26, 2022

View reviewed changes

kegsay approved these changes Jul 26, 2022

View reviewed changes

fixup: Remove .vscode/settings.json

e3d8197

squahtx merged commit 3d09f94 into main Jul 26, 2022

squahtx deleted the squah/faster_room_joins_calculate_partial_state_flag_for_backfill branch July 26, 2022 11:35

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add more tests for receiving events while resyncing for a partial join #419

Add more tests for receiving events while resyncing for a partial join #419

squahtx commented Jul 21, 2022 •

edited

Loading

squahtx Jul 21, 2022

squahtx Jul 21, 2022

squahtx Jul 21, 2022

richvdh Jul 22, 2022

richvdh left a comment

richvdh Jul 22, 2022

richvdh Jul 22, 2022

squahtx Jul 22, 2022

richvdh Jul 22, 2022

squahtx Jul 22, 2022 •

edited

Loading

richvdh Jul 25, 2022

richvdh Jul 22, 2022

squahtx Jul 22, 2022

richvdh Jul 22, 2022

richvdh Jul 22, 2022

richvdh Jul 22, 2022

squahtx Jul 22, 2022

richvdh Jul 22, 2022

richvdh Jul 22, 2022

richvdh Jul 22, 2022

richvdh Jul 22, 2022

richvdh left a comment

richvdh Jul 22, 2022

squahtx Jul 22, 2022

kegsay Jul 25, 2022

squahtx Jul 26, 2022

squahtx commented Jul 22, 2022

kegsay Jul 25, 2022

kegsay left a comment

richvdh left a comment

richvdh Jul 26, 2022

kegsay Jul 26, 2022

squahtx Jul 26, 2022

squahtx commented Jul 26, 2022

		// read from the channel and discard the result, so that the goroutine above doesn't block
		// indefinitely on the send

Add more tests for receiving events while resyncing for a partial join #419

Add more tests for receiving events while resyncing for a partial join #419

Conversation

squahtx commented Jul 21, 2022 • edited Loading

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

richvdh 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

squahtx Jul 22, 2022 • edited Loading

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

richvdh 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

squahtx commented Jul 22, 2022

Choose a reason for hiding this comment

kegsay left a comment

Choose a reason for hiding this comment

richvdh 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

squahtx commented Jul 26, 2022

squahtx commented Jul 21, 2022 •

edited

Loading

squahtx Jul 22, 2022 •

edited

Loading