project-robius / robrix

A Matrix chat client written in pure Rust using the Makepad UI toolkit and the Robius app dev framework
MIT License
67 stars 11 forks source link

Timeline is almost entirely cleared when receiving a new message update after previously finishing a back pagination. #140

Open kevinaboos opened 1 week ago

kevinaboos commented 1 week ago

I'm not sure if this is a problem with the Matrix SDK or with the way that we are processing Timeline diffs on the background task, but this is both surprising and annoying, and also a new bug.

Relevant log:

src/sliding_sync.rs:788:17 -   483.69 Received an update. Summary: UpdateSummary { lists: [], rooms: ["!IemiTbwVankHTFiEoh:matrix.org"] }
src/sliding_sync.rs:810:13 - 
"!IemiTbwVankHTFiEoh:matrix.org" --> Some("Element Web/Desktop") has an update
                display_name: Ok(Named("Element Web/Desktop")),
                topic: None,
                is_synced: false, is_state_fully_synced: false,
                is_space: false,
                create: Some(RoomCreateWithCreatorEventContent { creator: "@matthew:matrix.org", federate: true, room_version: V11, predecessor: Some(PreviousRoom { room_id: "!YTvKGNlinIzlkMTVRl:matrix.org", event_id: "$2bFuAcX7nxeUm6ocKTyQrKwUg-btQoo7HAbucqEWwUo" }), room_type: None }),
                canonical-alias: None,
                alt_aliases: [],
                guest_access: "forbidden",
                history_visibility: "world_readable",
                is_public: true,
                join_rule: Public,
                latest_event: Some(LatestEvent { event: SyncTimelineEvent { event: RawEvent { event_id: "$bj4HuyULOoymLvt1fys9E3XVxzDRF3GH7MYG0r8y-kk", event_type: "m.room.message", .. }, push_actions: [Notify, SetTweak(Highlight(false))] }, sender_profile: Some(Original(OriginalMinimalStateEvent { content: RoomMemberEventContent { avatar_url: Some("mxc://matrix.org/jQwLrIOQruulVxbdEXbwUCbA"), displayname: Some("DoofusCanadensis πŸ‡¨πŸ‡¦πŸ§Š"), is_direct: None, membership: "join", third_party_invite: None, blurhash: None, reason: None, join_authorized_via_users_server: None }, event_id: Some("$Uc3D0FP3YlxGgmpd4MreIA0sIW0YcRzGHSocVTKK_4o") })), sender_name_is_ambiguous: None })

2024-09-04T23:39:10.268314Z  INFO local_echo_handler{room_id="!IemiTbwVankHTFiEoh:matrix.org"}: matrix_sdk_ui::timeline::builder: spawned the local echo handler!
src/home/rooms_list.rs:330:17 - RoomsList: processed 1 updates to the list of all rooms
src/home/room_screen.rs:1489:25 - TEST: 479 items -> 26 items, find_new_item_matching_current_item() returned None
src/home/room_screen.rs:1526:29 - Timeline::handle_event(): jumping to bottom: curr_first_id 412 is out of bounds for 26 new items

Note that the important part is that the number of items went from 479 items to 26 items, indicating that we had done roughly ~10 rounds of back pagination before the new message was received, and once it was received all of the previously-paginated items were cleared mysteriously.

kevinaboos commented 1 week ago

Another example. This is very easy to repro.

src/sliding_sync.rs:275:50 - Completed backwards pagination request for room !IemiTbwVankHTFiEoh:matrix.org, hit start of timeline? no
src/sliding_sync.rs:242:41 - ### Timeline !IemiTbwVankHTFiEoh:matrix.org back pagination status: Idle { hit_start_of_timeline: false }
/Users/kevinboos/robius/makepad/widgets/src/portal_list.rs:563:13 - item_rect: Rect { pos: DVec2 { x: 468.0, y: 6.746880054473877 }, size: DVec2 { x: 812.0, y: 134.6673583984375 } }, self_rect: Rect { pos: DVec2 { x: 468.0, y: 84.9616 }, size: DVec2 { x: 812.0, y: 659.0485942232734 } }
src/home/room_screen.rs:1797:17 - Found matching event ID $WaWQ2A8Y6fZMFT6NzJY8krT8B9OIM5zMxTDq25afTR8 at index 842 in new items list, corresponding to current item index 792 at pos offset -78.21471994552613
src/home/room_screen.rs:1489:25 - TEST: 814 items -> 864 items, find_new_item_matching_current_item() returned Some((792, 842, -78.21471994552613, "$WaWQ2A8Y6fZMFT6NzJY8krT8B9OIM5zMxTDq25afTR8"))
src/home/room_screen.rs:1532:33 - Timeline::handle_event(): jumping view from event index 792 to new index 842, scroll -78.21471994552613, event ID $WaWQ2A8Y6fZMFT6NzJY8krT8B9OIM5zMxTDq25afTR8
src/home/room_screen.rs:1592:17 - TODO: hide topspace loading animation for room !IemiTbwVankHTFiEoh:matrix.org
2024-09-04T23:48:02.572924Z  WARN matrix_sdk_crypto::backups: Trying to backup room keys but no backup key was found
src/sliding_sync.rs:788:17 -  1016.01 Received an update. Summary: UpdateSummary { lists: [], rooms: ["!IemiTbwVankHTFiEoh:matrix.org"] }
src/sliding_sync.rs:810:13 - 
"!IemiTbwVankHTFiEoh:matrix.org" --> Some("Element Web/Desktop") has an update
                display_name: Ok(Named("Element Web/Desktop")),
                topic: None,
                is_synced: false, is_state_fully_synced: false,
                is_space: false,
                create: Some(RoomCreateWithCreatorEventContent { creator: "@matthew:matrix.org", federate: true, room_version: V11, predecessor: Some(PreviousRoom { room_id: "!YTvKGNlinIzlkMTVRl:matrix.org", event_id: "$2bFuAcX7nxeUm6ocKTyQrKwUg-btQoo7HAbucqEWwUo" }), room_type: None }),
                canonical-alias: None,
                alt_aliases: [],
                guest_access: "forbidden",
                history_visibility: "world_readable",
                is_public: true,
                join_rule: Public,
                latest_event: Some(LatestEvent { event: SyncTimelineEvent { event: RawEvent { event_id: "$kturaRIZfvSibi-jKeFXnQAxh-cqy3tbgXawSt8NoLA", event_type: "m.room.message", .. }, push_actions: [Notify, SetTweak(Highlight(false))] }, sender_profile: Some(Original(OriginalMinimalStateEvent { content: RoomMemberEventContent { avatar_url: Some("mxc://matrix.org/jQwLrIOQruulVxbdEXbwUCbA"), displayname: Some("DoofusCanadensis πŸ‡¨πŸ‡¦πŸ§Š"), is_direct: None, membership: "join", third_party_invite: None, blurhash: None, reason: None, join_authorized_via_users_server: None }, event_id: Some("$Uc3D0FP3YlxGgmpd4MreIA0sIW0YcRzGHSocVTKK_4o") })), sender_name_is_ambiguous: None })

2024-09-04T23:48:02.595600Z  INFO local_echo_handler{room_id="!IemiTbwVankHTFiEoh:matrix.org"}: matrix_sdk_ui::timeline::builder: spawned the local echo handler!
src/home/rooms_list.rs:330:17 - RoomsList: processed 1 updates to the list of all rooms
/Users/kevinboos/robius/makepad/widgets/src/portal_list.rs:563:13 - item_rect: Rect { pos: DVec2 { x: 468.0, y: 6.746880054473877 }, size: DVec2 { x: 812.0, y: 134.6673583984375 } }, self_rect: Rect { pos: DVec2 { x: 468.0, y: 84.9616 }, size: DVec2 { x: 812.0, y: 659.0485942232734 } }
src/home/room_screen.rs:1797:17 - Found matching event ID $WaWQ2A8Y6fZMFT6NzJY8krT8B9OIM5zMxTDq25afTR8 at index 11 in new items list, corresponding to current item index 842 at pos offset -78.21471994552613
src/home/room_screen.rs:1489:25 - TEST: 864 items -> 34 items, find_new_item_matching_current_item() returned Some((842, 11, -78.21471994552613, "$WaWQ2A8Y6fZMFT6NzJY8krT8B9OIM5zMxTDq25afTR8"))
src/home/room_screen.rs:1526:29 - Timeline::handle_event(): jumping to bottom: curr_first_id 842 is out of bounds for 34 new items