Skip to content

Commit 0e6f855

Browse files
jevolkjevolk
authored
TestJumpToDateEndpoint: Guard the parallel boundary subtests against millisecond collisions. (#872)
* `TestJumpToDateEndpoint`: Guard the parallel boundary subtests against millisecond collisions. Both subtests sample `time.Now()` and immediately probe a homeserver that stamps events using its own millisecond clock; when the two readings land in the same millisecond, `/timestamp_to_event`'s inclusive boundary semantics return an event the subtest does not want. `should_find_event_after_given_timestamp` races the trailing createRoom state event ahead of the message that a forward search is expected to find; `should_find_nothing_before_the_earliest_timestamp` races `m.room.create` against a backward search expected to find nothing. Pause around the relevant samples so the next homeserver stamp lands in a strictly later millisecond. Both flakes have been observed across multiple homeserver implementations on otherwise green runs. Closes #868. Signed-off-by: Jason Volk <jason@zemos.net> * `TestJumpToDateEndpoint`: Reduce the boundary guard to 1ms and cover the remaining samples A whole-millisecond pause always carries a timestamp into the next millisecond bucket, so `tsBoundaryGuard` only needs to be 1ms. Extend the guard to the two same-timestamp topological subtests and to `createTestRoom`'s `eventB` sample for consistency, even though no case exercises a forward search from `eventB` yet. Signed-off-by: Jason Volk <jason@zemos.net> * `TestJumpToDateEndpoint`: Pair every timestamp sample with a guard sleep Take each `time.Now()` reading and pair `tsBoundaryGuard` with it so the homeserver always stamps the surrounding events in a strictly later millisecond, and apply the same pause to the `timeBeforeRoomCreation` samples the earlier commit left unguarded. `createTestRoom` no longer needs `timeAfterEventA`; `eventA`'s `AfterTimestamp` is now the `timeBeforeEventB` sample, which already sits a guard past `eventA`. Trim the `tsBoundaryGuard` doc comment to match. Signed-off-by: Jason Volk <jason@zemos.net> * `TestJumpToDateEndpoint`: Rewrite the boundary-guard comments for brevity and clarity Signed-off-by: Jason Volk <jason@zemos.net> --------- Signed-off-by: Jason Volk <jason@zemos.net>
1 parent 50044ed commit 0e6f855

1 file changed

Lines changed: 32 additions & 3 deletions

File tree

‎tests/room_timestamp_to_event_test.go‎

Lines changed: 32 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,9 @@ func TestJumpToDateEndpoint(t *testing.T) {
5656
t.Run("should find nothing before the earliest timestamp", func(t *testing.T) {
5757
t.Parallel()
5858
timeBeforeRoomCreation := time.Now()
59+
// Guard so createRoom cannot share this sample's millisecond; a
60+
// backward search there would return m.room.create instead of nothing.
61+
time.Sleep(tsBoundaryGuard)
5962
roomID, _, _ := createTestRoom(t, alice)
6063
mustCheckEventisReturnedForTime(t, alice, roomID, timeBeforeRoomCreation, "b", "")
6164
})
@@ -76,6 +79,9 @@ func TestJumpToDateEndpoint(t *testing.T) {
7679
deployment.GetFullyQualifiedHomeserverName(t, "hs1"),
7780
})
7881

82+
// Guard so the join cannot share a millisecond with the messages below.
83+
time.Sleep(tsBoundaryGuard)
84+
7985
// Send a couple messages with the same timestamp after the other test
8086
// messages in the room.
8187
timeBeforeMessageCreation := time.Now()
@@ -98,6 +104,9 @@ func TestJumpToDateEndpoint(t *testing.T) {
98104
deployment.GetFullyQualifiedHomeserverName(t, "hs1"),
99105
})
100106

107+
// Guard so the join cannot share a millisecond with the messages below.
108+
time.Sleep(tsBoundaryGuard)
109+
101110
// Send a couple messages with the same timestamp after the other test
102111
// messages in the room.
103112
timeBeforeMessageCreation := time.Now()
@@ -113,6 +122,7 @@ func TestJumpToDateEndpoint(t *testing.T) {
113122
t.Run("should not be able to query a private room you are not a member of", func(t *testing.T) {
114123
t.Parallel()
115124
timeBeforeRoomCreation := time.Now()
125+
time.Sleep(tsBoundaryGuard)
116126

117127
// Alice will create the private room
118128
roomID := alice.MustCreateRoom(t, map[string]interface{}{
@@ -141,6 +151,7 @@ func TestJumpToDateEndpoint(t *testing.T) {
141151
t.Run("should not be able to query a public room you are not a member of", func(t *testing.T) {
142152
t.Parallel()
143153
timeBeforeRoomCreation := time.Now()
154+
time.Sleep(tsBoundaryGuard)
144155

145156
// Alice will create the public room
146157
roomID := alice.MustCreateRoom(t, map[string]interface{}{
@@ -187,6 +198,7 @@ func TestJumpToDateEndpoint(t *testing.T) {
187198
t.Run("when looking backwards before the room was created, should be able to find event that was imported", func(t *testing.T) {
188199
t.Parallel()
189200
timeBeforeRoomCreation := time.Now()
201+
time.Sleep(tsBoundaryGuard)
190202
roomID, _, _ := createTestRoom(t, alice)
191203

192204
// Join from the application service bridge user so we can use it to send
@@ -331,6 +343,16 @@ type eventTime struct {
331343
AfterTimestamp time.Time
332344
}
333345

346+
// tsBoundaryGuard is a pause inserted around (before and after) where we create events
347+
// so that `time.Now()` samples and subsequent event `origin_server_ts` don't collide at
348+
// the same millisecond granularity. /timestamp_to_event returns the boundary event
349+
// inclusively (forward picks the earliest event with ts >= query, backward picks the
350+
// latest with ts <= query), so a shared millisecond between events means the wrong
351+
// event can be picked. Adding one whole millisecond to a timestamp always carries it
352+
// into the next millisecond bucket, so 1ms is enough to separate the sample from every
353+
// event stamped after the pause.
354+
const tsBoundaryGuard = 1 * time.Millisecond
355+
334356
func createTestRoom(t *testing.T, c *client.CSAPI) (roomID string, eventA, eventB *eventTime) {
335357
t.Helper()
336358

@@ -339,26 +361,33 @@ func createTestRoom(t *testing.T, c *client.CSAPI) (roomID string, eventA, event
339361
})
340362

341363
timeBeforeEventA := time.Now()
364+
time.Sleep(tsBoundaryGuard)
342365
eventAID := c.SendEventSynced(t, roomID, b.Event{
343366
Type: "m.room.message",
344367
Content: map[string]interface{}{
345368
"msgtype": "m.text",
346369
"body": "Message A",
347370
},
348371
})
349-
timeAfterEventA := time.Now()
350372

373+
// timeBeforeEventB doubles as eventA's after-timestamp, so guard it on
374+
// both sides to keep it between the two events.
375+
time.Sleep(tsBoundaryGuard)
376+
timeBeforeEventB := time.Now()
377+
time.Sleep(tsBoundaryGuard)
351378
eventBID := c.SendEventSynced(t, roomID, b.Event{
352379
Type: "m.room.message",
353380
Content: map[string]interface{}{
354381
"msgtype": "m.text",
355382
"body": "Message B",
356383
},
357384
})
385+
386+
time.Sleep(tsBoundaryGuard)
358387
timeAfterEventB := time.Now()
359388

360-
eventA = &eventTime{EventID: eventAID, BeforeTimestamp: timeBeforeEventA, AfterTimestamp: timeAfterEventA}
361-
eventB = &eventTime{EventID: eventBID, BeforeTimestamp: timeAfterEventA, AfterTimestamp: timeAfterEventB}
389+
eventA = &eventTime{EventID: eventAID, BeforeTimestamp: timeBeforeEventA, AfterTimestamp: timeBeforeEventB}
390+
eventB = &eventTime{EventID: eventBID, BeforeTimestamp: timeBeforeEventB, AfterTimestamp: timeAfterEventB}
362391

363392
return roomID, eventA, eventB
364393
}

0 commit comments

Comments
 (0)