Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Status takes 5-30 sec to get back to online after going back from sleep mode #9755

Closed
churik opened this issue Jan 6, 2020 · 13 comments
Closed

Comments

@churik
Copy link
Member

churik commented Jan 6, 2020

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: #9568 (comment)

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

@churik churik added the bug label Jan 6, 2020
@churik
Copy link
Member Author

churik commented Jan 6, 2020

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

@churik churik changed the title Status takes 5-30 sec to get back to offline after going back from sleep mode Status takes 5-30 sec to get back to online after going back from sleep mode Jan 6, 2020
@rachelhamlin
Copy link
Contributor

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

@churik
Copy link
Member Author

churik commented Jan 7, 2020

@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

@hesterbruikman
Copy link
Contributor

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

@cammellos
Copy link
Contributor

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)

@rachelhamlin
Copy link
Contributor

Not able to repro on nightly today in London.

@churik
Copy link
Member Author

churik commented Jan 8, 2020

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

@churik
Copy link
Member Author

churik commented Jan 24, 2020

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 #9269, however, I didn't pin mailserver.

@churik
Copy link
Member Author

churik commented Jan 24, 2020

added v1 release label as users during dogfooding are experiencing this

@yenda
Copy link
Contributor

yenda commented Jan 27, 2020

@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

@flexsurfer
Copy link
Member

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

@flexsurfer
Copy link
Member

related issue #9943

@rachelhamlin
Copy link
Contributor

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)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants