[Perf] User story 1: Time lags navigating through different app views after log in when user has a lot of sent/received messages

[Serhy]

Type: Bug

Summary: When user logs in into account, application becomes unresponsive for some time. It depends from how many messages user sent or received - more messages cause more time for app to hung up.
It's also visible that application retrieves all the messages user sent/received in chats it had before log out.
For example, in my case with Samsung J7 I had user with about 150 received messages. With such amount, when I logged out and logged back in - it took ~3 minutes since I could with no lags navigate through different views (chats, Profile, Wallet etc). Below TF session session attached.
On video it's especially visible when Profile screen hides during 01:30-02:00.

On iPhone X it's also visible (50 sent messages is enough to have before log in to account)

TF logs: https://app.testfairy.com/projects/4803622-status/builds/7397034/sessions/4/?accessToken=DCNt-8FbqXifdFksvbCKKRoFwlw

Expected behavior

No time lags while navigating through different app screens after user logged in

Actual behavior

Time lags while navigating through different app screens after user logged in

Reproduction

Precondition: User exist and has more than 100 messages sent/received (actually it's even enough 20 messages - depends from device)

• Open Status
• Log in to account
• Navigate through different screen (Profile, 1-1 chat, Wallet, etc)

Additional Information

• Status version: Develop 0.9.10-493-g77b966c8+
• Operating System: Android 7.0 (Samsung J7 real device), iOS 11.1.2 (iPhone X)

[oskarth]

Thanks for this @Serhy! Will try to reproduce tomorrow.

[oskarth]

Able to reproduce on iPhone X, recent develop build.

• Sent 100 messages to some test user

• Logout and login again

• Clicking Sign in takes ~3

• Immediately clicking on the user chat takes 5s for screen to load

• Clicking on other chat with ~3 messages takes maybe ~200ms

• Subsequent clicks on bad chats are pretty much instant

• Also notice scrolling quickly up through messages leads to a janky experience, at least first scroll

Suspected culprit: realm loading of messages into memory

cc @janherich FYI

[oskarth]

Did some further investigation to see where problem is.

Rough notes

On iPhone 6s simulator on latest develop.

A New chat

1. Add contact, send one message, logout

2. From click 'sign in' there are maybe ~50 events and can't copy paste, but nothing that takes crazy long time. Longest:

360ms: add-contacts
330ms: initialize-chats
190ms: change-account-handler
111ms: choose-predefined-expandable-height

B Same chat, ~20 messages:

~100 events, same big ones:

add-contacts, initialize-chats, choose-predefined-exanpable-height

But a bunch in ~100ms range, most notably update-message-status

Filtering by events it seems liek update-message-status happens for every single message, ~20+ events, and it ranges from 20ms to 160ms, so at 50ms average that's 1s right there.

Plus after each update-message-status there is incoming-message, only about 5ms though.

Login takes ~9s, loading of messages instant

C Same chat, ~50 messages:

14s to login

Update-message-status ranging from 12ms to 200ms, and ~50 of them I(+ small incoming message).

Conclusion

Three problems

1. update-message-status blocks login
2. update-message-status O(n), should batch
3. update-message-status sometimes slow (200ms?!)

[janherich]

@oskarth I investigated the issue and here are my findings:
On the sender side, :update-message-status indeed takes dominant chunk of the time when user logs in and a lot of messages are to be sent.
The handling of that event is very ineffective and clumpy in develop, it should be more efficient in my outstanding branch currently tested (#2807).
If even that will not be sufficient, I will introduce either async realm writes, or realm write batching (most probably combination of both).
On the receiver side, dominant time factor with lot of messages received is the :send-seen! + :set-message-shown events and those are a lot worse time wise then the sender situation, blocking chat for ~5 seconds (with 50 new received messages) even on iOS simulator !
I'm afraid it's more complicated there as it seems to be tied to the protocol (:send-seen! always fires off new whisper ack message with shh-keys/get-sym-key call in message preparation) so I need to experiment with it little bit and isolate the most perf problematic part of code in that scenario.

[dmitryn]

One more easy/fast way to reproduce the issue:

• Join #status public channel
• Log out
• Log in back
• App is completely unresponsive (real device android or ios simulator)
• Watch events spamming log file: :incoming-message, :chat-received-message/add
  .. wait for app to be responsive
• Go to public chat
• Bunch of send-seen events (@janherich already commented on that above)
• App is unresponive again

[oskarth]

Workaround, doesn't address underlying problem at all: #2941

Root problem: @janherich and @dmitryn are looking into it AFAIK. What do you guys think about splitting it into receiving / sending problem? Since events etc are different. And maybe if there's a 3rd problem.

[oskarth]

Also see #2941 (comment)

[churik]

App freezes when a lot unread messages come in background (~100 in my case)
Summary: app freezes if a lot of messages (~100 in my case) come when app is in background.
Relaunch doesn't help (3 attempts)

Expected behavior

app is responsive; chats are synchronised;

Actual behavior

app is unresponsive; only part of messages are synchronised (17 in my case)

Reproduction

Precondition:

• User A, User B, User C are contacts (different devices)
• Status app (User A) is in background (during 1-6)

1. open Status (User B)
2. log in to account
3. start group chat with (add User A, User C)
4. send 30+ messages
5. open 1-1 chat with User A, send 30+ messages
6. repeat 1, 2, 5 with User C so User A has 30+ new messages in group chat, 30+ new messages in 1-1 chats (with User B, User C)
7. open Status (User A)
8. try to navigate through different screens

Additional Information

Noticed that phone temperature increased from 28,7 to 33,3 degrees during 6 short sessions (up to 10 min each).

• Status version: PR-2910 build (0.9.10-529-ga3f61690+ (2086) 09/01 - daily)
• Operating System: Android 7.0 (Samsung Galxy S7 real device)

Logs

TF session (after 6 relaunch): https://app.testfairy.com/projects/4803622-status/builds/7462315/sessions/8/?accessToken=y2XoMALLYD1Bc-MNvGRl7O/AqeU

[churik]

@janherich it shouldn't be closed, I added comment here, it is reproducible in build with PR as well as in develop

[janherich]

@churik My bad, the issue was automatically closed because the related PR was merged.

[oskarth]

"can't verify because more critical blocks it #2990 Lags and app crash if have two 1-1 chats [Android, release]:
because on Android app crashes even without lots of messages in 1-2 minutes after launch
so can’t test lags are better or not for more advanced scenario " -- Anna

[Serhy]

Tested this with latest release version (Android: http://artifacts.status.im:8081/artifactory/nightlies-local/im.status.ethereum-132082.apk
iOS: https://i.diawi.com/fHejaj) on Samsung J7 (Android 7.0 real device) and iPhoneX.

Unfortunately, I can't say it became better.
On Android device with the user having ~170 text/emoji messages (only 1-1 chats used) - after log in almost freezing the app for 35-40 seconds.
TF session: https://app.testfairy.com/projects/4803622-status/builds/7490826/sessions/21/?accessToken=M6-kUEyoZtzAAwNj2cWFkvrVCVY -> check there 00:50 - 01:30 time interval. App is unresponsive.

Same with iPhoneX.

[oskarth]

@Serhy Can

On Android device with the user having ~170 text/emoji messages (only 1-1 chats used) - after log in almost freezing the app for 35-40 seconds.
TF session: https://app.testfairy.com/projects/4803622-status/builds/7490826/sessions/21/?accessToken=M6-kUEyoZtzAAwNj2cWFkvrVCVY -> check there 00:50 - 01:30 time interval. App is unresponsive.

be reproduced on 0.9.12? What is behavior there?

[Serhy]

On 0.9.12 it looks really well. I can't say this issue is a problem on 0.9.12.

With >150 messages after log in on 0.9.12 I almost don't see lags - navigation through different screens not laggy (well lags are up to 1 second) on Samsung J7 (same device used when reported the issue)