Status-react: Status takes 5-30 sec to get back to online after going back from sleep mode

Created on 6 Jan 2020  ·  13Comments  ·  Source: status-im/status-react

Bug Report

Problem

For me (located in Valencia) and Sergey (located in Kyiv) when phone came back from sleep mode - it takes 5-30 sec to have app back online (on average for me ~15 sec).

Expected behavior

app go back online immidiately or at least during 1-2 sec (it is already a lot from my POV)

Actual behavior

Offline state is preserved for 30 sec (check out video https://drive.google.com/open?id=1fS21FKalXFpSkr6da3oBk28DTPGhgnpl)
Discussed here: https://github.com/status-im/status-react/pull/9568#issuecomment-571136362

Reproduction

  • login to Status
  • join any chat
  • lock phone
  • wait ~3 min (in my case sleep in "Lock screen" is set to "After 1 min of inactivity")
  • unlock phone

Additional Information

  • Status version:

  • Operating System: Android, iOS

Logs

19:14 - log-log.log

bug chat

All 13 comments

can be crucial for v1 because extremely visible
cc @hesterbruikman @rachelhamlin @Serhy

Hmm. Can't repro on iOS nightly in New York. Perhaps @cammellos can investigate?

@rachelhamlin as we found out with @hesterbruikman yesterday, it may be related to mailserver itself (in our case it is AMS) - so sometimes issue is constantly reproducible, sometimes - no.
As far as I kniow she also asked @jakubgs about it - and he confirmed that.

From DM:

Jakub's theory is that it might be on the Mailserver side, basically that it considers the client inactive and therefore the client is sort of lost when the phone wakes up

fyi: couldn't reproduce yesterday on Android and iOS. Will keep an eye out today as well.

This is not related to mailserver only:
Offline means that the peers count is 0, meaning that the client is not connected to any node in the cluster (including mailserver), so choice of mailserver should not really have a big impact on it (other than we include that node)

Not able to repro on nightly today in London.

Let's keep it open anyway to see if users during dogfooding will encounter it

After changing networks couldn't get connected to mailserver during ~5 mins - tried "Tap to reconnect" ~ 5 times.
After a while got connected.
Logs:
status_logs_conn.zip

Can be related to https://github.com/status-im/status-react/issues/9269, however, I didn't pin mailserver.

added v1 release label as users during dogfooding are experiencing this

@cammellos if I'm not mistaken based on the log it looks like it's the discovery protocol that takes some time to get peers back:

01-07 19:14:45.284 27427 27456 I CarrierServices: [2322] bxu.a: FiST: Wifi connectivity status true
...
01-07 19:14:53.142 30568 31065 D StatusModule: Signal event: {"type":"wallet","event":{"type":"newblock","blockNumber":9232777,"accounts":[]}}
...
01-07 19:14:54.266 30568 31059 D StatusModule: Signal event: {"type":"discovery.summary","event":[{"enode":"enode://914c0b30f27bab30c1dfd31dad7652a46fda9370542aee1b062498b1345ee0913614b8b9e3e84622e84a7203c5858ae1d9819f63aece13ee668e4f6668063989@167.99.19.148:30305?discport=0","id":"f0b65c67f9f388a435c8a20b926783822f812cb2704e7ee739dded817bb15928","name":"Statusd/v0.35.0/linux-amd64/go1.13.1","caps":["shh/6"],"network":{"localAddress":"192.168.1.35:41702","remoteAddress":"167.99.19.148:30305","inbound":false,"trusted":false,"static":true},"protocols":{"shh":"unknown"}}]}
...
01-07 19:14:54.294 30568 30628 D ReactNativeJS: DEBUG [status-im.utils.handlers:32] - Handling re-frame event:  :mailserver.callback/mark-trusted-peer-success
...
01-07 19:14:54.300 30568 30628 I ReactNativeJS: INFO [status-im.mailserver.core:356] - mailserver: request-messages for:   topics  #{"0xd7e32cfb" "0x897e1a65" "0x2281b863" "0x14bcc435"}  from  1578394868  force-to?  false  to  1578395694  range  806  cursor  nil  limit  2000

So messages are requested almost instantly after receiving the signal from discovery that we connected to a first peer.
There is a wallet signal before which indicates that status-go already uses the network, but only 1 sec. This can mean status-go gets the signal that we are back online late or it could just be because of block time. I will investigate that

I noticed that more active users we have, more history messages for 24h on mailservers , the probability of this issue increases.

Removing from v1.1 because we don't currently have a viable solution. From Andrea:

also not sure we can really fix it as of now, if discovery is slow it requires a bigger change, but maybe the issue is somewhere else and we are lucky (as generally is relatively fast)

Was this page helpful?
0 / 5 - 0 ratings