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

check for anr in chatlist #1085

Closed
r10s opened this issue Mar 18, 2021 · 5 comments · Fixed by #1138
Closed

check for anr in chatlist #1085

r10s opened this issue Mar 18, 2021 · 5 comments · Fixed by #1138
Assignees
Labels

Comments

@r10s
Copy link
Member

r10s commented Mar 18, 2021

sometimes, there are anr in charlist and chat, maybe because of incoming messages, maybe because of markseen, not sure, this does not happens always and i did not find a way to reproduce that, unfortunately.

a symptom of that is that views may be opened several times, eg. when hitting the "open chat" button during an anr several times, the chat is opened several times as well (you need to hit "back" several times to go back to the chatlist then). however, idea is to get anr fixed, not the symptom :)

@r10s r10s transferred this issue from deltachat/interface Mar 18, 2021
@r10s r10s added the bug label Mar 18, 2021
@r10s
Copy link
Member Author

r10s commented Mar 19, 2021

@dignifiedquire reported that the used sqlite-core-library in combination with the limited number of threads may cause problems:

due to async, sql-requests are scheduled over the threads available, the scheduler does not take care much about the calling thread - so it may happen, that a theoretically fast call takes some seconds as it is randomly in the same thread-queue as eg. some longer taking operation that is done before (on android/desktop this is less an issue as there are more threads available (ios has only 7))

the "real" fix could be sth. as using sqlx in core, however, we could mitigate the issue by avoiding calls to core in ui-thread (where possible) and also by taking care not doing lots unneeded core calls (we had that here and there by these "computed properties" where sth.text does not look like an expensive call - but in reality is a long-taking core call that is evaluated over and over. also, that is easily mixed with lazy ... i consider "computed properties" harmful meanwhile ;)

@dignifiedquire is that summary roughly correct? i am not sure if i got it correctly :)

@r10s
Copy link
Member Author

r10s commented Mar 29, 2021

meanwhile, there is sqlx coming, so we should reconsider that once deltachat/deltachat-core-rust#2089 is merged and/or in use on ios.

@r10s
Copy link
Member Author

r10s commented Apr 5, 2021

after some days of running sqlx on my testphone, note sure, if sqlx helps on these anr, at least not alone.

first, i had the feeling, things are a bit faster, but that seemed to be a false impression, resulting just from the restart of the app.

to reproduce, it is needed that the app is running for some hours, then from inside the app, hit the home button (not: swipe away to exit) and the hit the app-icon. that results in an anr of sometimes several seconds pretty reliably (at least on my 3gig db).
unfortunately, i do not know of an easier/faster way to get the anr.

general impression is, that i got anr only for the top-level viewcontrollers, so, qr, chatlist, top-settings. being eg. in the chat, things are smoother.

meanwhile, i dived a bit in the code:

  • in appDelegate, there is a maybeNetwork that should be moved to a thread, again, that alone is not the solution
  • ChatlistViewModel::refreshData is called often, maybe we should debounce that

might be, the anr is not solvable by a single code-change.

maybe, the power of all these optimisations plus sqlx is needed at the end.

@r10s
Copy link
Member Author

r10s commented Apr 7, 2021

k, getting closer: for whatever reason, dc_get_chatlist() is called several times after getting back from foreground:

21:41:52.684 💙 INFO ⬅️ applicationDidEnterBackground
21:41:54.805 💙 INFO ➡️ applicationWillEnterForeground
21:41:54.852 💙 INFO event: src/context.rs:158: starting IO
21:41:54.853 💙 INFO event: src/context.rs:160: IO is already running
21:41:54.854 💙 INFO event: src/imap/idle.rs:97: Idle wait was interrupted
21:41:54.855 💙 INFO event: src/imap/idle.rs:97: Idle wait was interrupted
21:41:54.856 💙 INFO event: src/imap/idle.rs:97: Idle wait was interrupted
21:41:54.857 💙 INFO event: src/scheduler.rs:283: smtp fake idle - interrupted
21:41:54.857 💙 INFO event: src/job.rs:1272: loading job for Smtp-thread
21:41:54.858 💙 INFO event: src/scheduler.rs:281: smtp fake idle - started
21:41:55.138 💙 INFO event: src/job.rs:1272: loading job for Imap-thread
21:41:55.273 💙 INFO event: src/imap/mod.rs:742: 0 mails read from "DeltaChat".
21:41:55.274 💙 INFO event: src/imap/mod.rs:742: 0 mails read from "Sent".
21:41:55.417 💙 INFO event: src/imap/idle.rs:71: DeltaChat: Idle entering wait-on-remote state
21:41:55.660 💙 INFO event: src/imap/mod.rs:742: 0 mails read from "INBOX".
21:41:55.777 💙 INFO ⏰ getChatlist: 0.6517320871353149 s
21:41:55.864 💙 INFO event: src/imap/idle.rs:71: INBOX: Idle entering wait-on-remote state
21:41:56.004 💙 INFO event: src/imap/idle.rs:71: Sent: Idle entering wait-on-remote state
21:41:56.081 💙 INFO ⏰ getChatlist: 0.30365610122680664 s
21:41:56.274 💙 INFO ⏰ getChatlist: 0.19255101680755615 s
21:41:56.579 💙 INFO ⏰ getChatlist: 0.3051760196685791 s
21:41:56.890 💙 INFO ⏰ getChatlist: 0.31047606468200684 s
21:41:57.209 💙 INFO ⏰ getChatlist: 0.318713903427124 s
21:41:57.534 💙 INFO ⏰ getChatlist: 0.3240540027618408 s
21:41:57.841 💙 INFO ⏰ getChatlist: 0.30630695819854736 s
21:41:58.030 💙 INFO ⏰ getChatlist: 0.1887890100479126 s
21:41:58.340 💙 INFO ⏰ getChatlist: 0.30981409549713135 s
21:41:58.661 💙 INFO ⏰ getChatlist: 0.3202739953994751 s
21:41:58.996 💙 INFO ⏰ getChatlist: 0.33481502532958984 s
21:41:58.997 💙 INFO ⬅️ no longer in background

a single call is okayish with 300ms (rembember: this is a 3gig db with several hundreds chats), however, calling it 10 times is not okay.

@r10s r10s changed the title check for anr check for anr in chatlist Apr 7, 2021
@r10s
Copy link
Member Author

r10s commented Apr 8, 2021

i found the issue: every time the view controller come is displayed, a new foregroundObserver/applicationDidBecomeActive is created - and each one is called when the app becomes active.

reasons seems to be that the removeObserver does not work as expected, we probably have to call removeObserver(self) for observers that to take a member and not a closure.

@r10s r10s self-assigned this Apr 8, 2021
@r10s r10s mentioned this issue Apr 8, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

1 participant