element-android icon indicating copy to clipboard operation
element-android copied to clipboard

New messages taking a long time to load

Open kittykat opened this issue 4 years ago • 10 comments

Steps to reproduce

  1. Receive a new message, see new message content in the notification
  2. Click on the notification to open room
  3. In room, see no new content and the top "loading" bar animated

Outcome

What did you expect?

New messages are loaded quickly

What happened instead?

I can't see the new messages and it takes more than 5 minutes for messages to load

Marking as S-Critical because I can't use the Android app at all because messages take too long to load and am having to rely on the web app.

Your phone model

No response

Operating system version

No response

Application version and app store

1.3.8 (879e6ef5)

Homeserver

No response

Will you send logs?

No

kittykat avatar Nov 24 '21 11:11 kittykat

Needs investigation as to why this might be happening, then we can establish how often this might be happening to users...

daniellekirkwood avatar Nov 24 '21 13:11 daniellekirkwood

from my understanding, this can be caused by slow incremental syncs, I'm able to reproduce the same behaviour by putting a delay within the sync logic

The content within the notification skips the sync by directly querying the homeserver for the specific event.

@kittykat after waiting for the initial load and then repeating the issue steps, does the issue still occur? this will help determine if it is an increment sync issue

also, would you say you have a large account? (lots of rooms or large amounts of new messages between app opens)

ouchadam avatar Nov 25 '21 14:11 ouchadam

The content within the notification skips the sync by directly querying the homeserver for the specific event.

As a user, I would find the delay a lot less frustrating if I could read the message that I saw in the notification while the rest load - it's usually seeing an interesting notification that causes me to click on it to open the app rather than any notification

@kittykat after waiting for the initial load and then repeating the issue steps, does the issue still occur? this will help determine if it is an increment sync issue

I can't reproduce it today, but yesterday and the day before, it was a problem every time I wanted to check messages. I think there were a few rooms which were more active than usual.

also, would you say you have a large account? (lots of rooms or large amounts of new messages between app opens)

I wouldn't say so, but I did join maybe 10-15 quiet rooms in the last couple of weeks. I usually have notifications from 1-6 rooms on my phone and maximum 20 new message in the busiest (much more common to have 1-5 new messages per room).

If I had to guess, I'd say I'm probably in 100 group rooms and have 100 DM rooms, of which 5-10 are active at any given time.

kittykat avatar Nov 25 '21 14:11 kittykat

As a user, I would find the delay a lot less frustrating if I could read the message that I saw in the notification while the rest load - it's usually seeing an interesting notification that causes me to click on it to open the app rather than any notification

could be interesting to display what we have straight away, might lead to some jumping around though once the data loads in :thinking:

I'm wondering if we should start including some performance metrics in our rageshakes, tracking the time taken to sync could be really helpful for this scenario, what do you think @bmarty ?

ouchadam avatar Nov 25 '21 15:11 ouchadam

The content within the notification skips the sync by directly querying the homeserver for the specific event.

Actually this is the case only if the content is unencrypted, otherwise it won't. But yes, maybe in this case we could populate also an in-memory store accessible for timeline, not sure how we can manage that without too much trouble (ordering, reactions, redactions...)

ganfra avatar Nov 26 '21 17:11 ganfra

it looks like we do try to handle encrypted events but I guess there's a low chance of it working if there hasn't been a sync recently GetEventTask

ouchadam avatar Nov 29 '21 10:11 ouchadam

as the original message is not included in the room it means the incremental sync triggered by the push hasn't finished yet when the room is opened

assuming the load times when receiving messages after the first loading completes is quick, I'm going to downgrade from critical to major.

The scenario is

  • The app hasn't synced for some time~ and the first sync is slow
  • Android syncs only occur when receiving a push notification or by having the app open in the foreground

this affects users who don't sync often (either by opening the app or receiving push notifications), one option could be for us to eagerly schedule background syncs periodically to avoid long periods of being without a sync

ouchadam avatar Nov 30 '21 09:11 ouchadam

I'm taking over this issue. Performing an incr sync with 66 rooms and 66 toDevice Events, here are some logs with interesting timestamps:

1: 2022-08-22T10:11:07936GMT+00:00Z 26735 D/ /SYNC/SyncTask: Start incremental sync request with since token XXX 2: 2022-08-22T10:11:13681GMT+00:00Z 26735 D/ /SYNC/SyncTask: Incremental sync request parsing, 66 room(s) 66 toDevice(s). Got nextBatch: YYY

6s for the server to compute and send the sync response, I guess this is acceptable

3: 2022-08-22T10:11:16*691GMT+00:00Z 26939 V/ /Tag: Finish handling toDevice in 3002 ms

3s to handle (mainly parsing) 66 toDevice Events, OK

4: 2022-08-22T10:11:21*687GMT+00:00Z 26739 V/ /Tag: Finish handling rooms in 4995 ms

5s to handle (parsing and storing) at max 10 messages from 66 rooms, this is fine.

5: 2022-08-22T10:12:11559GMT+00:00Z 26963 V/ /Tag: On sync completed 6: 2022-08-22T10:12:11569GMT+00:00Z 26735 D/ /SYNC/SyncTask: Sync task finished on Thread: DefaultDispatcher-worker-45

Here we've got 50 seconds of crypto logs that I am currently investigating

The loading on the top bar on screen is now hidden.

bmarty avatar Aug 22 '22 12:08 bmarty

Maybe duplicate of #6027 (?). I am not closing this issue for now, but I am preparing a fix for #6027.

bmarty avatar Aug 23 '22 08:08 bmarty

Still experiencing this one over here

kittykat avatar Aug 31 '22 13:08 kittykat