GNOME Bugzilla – Bug 745914
Stall when marking emails as read
Last modified: 2015-03-10 21:16:47 UTC
There's now a slight stall (~1s) every time an email is marked as read. The entire UI freezes before resuming again and updating the email's status. There also seem to be delays both on startup and shutdown, but I haven't really characterized them yet. I've marked this as engine since git bisect blames 70bc00c6 (Fix find_boundaries_async in search, imap-engine Folder impl's). I've looked at the code, but I don't know enough about it to say anything useful.
How many messages do you have in your Inbox (or whatever folder you're in when this delay occurs)?
Many. I've given up on sorting and rely on searching. Running `SELECT COUNT(id) FROM "main"."messagelocationtable" WHERE folder_id = '5'` on my geary.db returns 16389. (Folder #5 is my inbox, it seems.)
And now it isn't happening anymore. Weird.
Is it possible it only happens when you've scrolled down the conversation list a bunch and have loaded a lot of emails? My current theory is that the hang is due to find_boundaries_async() iterating over a whole lot of email identifiers.
Actually, it appears to be the opposite. Right now, when I switch to the inbox, I get nearly a month worth of emails loaded in. I'm not sure why that is happening, and I hadn't noticed it before. When I scroll to the bottom, it doesn't trigger additional loading Here's my debug log from switching folders to my inbox. At first, the usual number of conversations load, but the spinner keeps spinning and a second or two later, a bunch more get loaded in. [deb] 16:06:44 7.109641 geary-controller.vala:1290: Folder Gmail:rschroll@gmail.com:INBOX (open_count=1 remote_opened=true) selected [deb] 16:06:44 0.000016 geary-controller.vala:1338: Switching to Gmail:rschroll@gmail.com:INBOX (open_count=1 remote_opened=true)... [deb] 16:06:44 0.002260 imap-engine-minimal-folder.vala:883: Closing replay queue for Gmail:rschroll@gmail.com:[Gmail]/Sent Mail (open_count=0 remote_opened=true) (flush_pending=true): ReplayQueue:Gmail:rschroll@gmail.com:[Gmail]/Sent Mail (open_count=0 remote_opened=true) (notification=0 local=0 local_active=true remote=0 remote_active=false) [deb] 16:06:44 0.000598 imap-engine-replay-queue.vala:452: ReplayQueue.do_replay_local_async ReplayQueue:Gmail:rschroll@gmail.com:[Gmail]/Sent Mail (open_count=0 remote_opened=true) (notification=0 local=0 local_active=false remote=1 remote_active=false) exiting [deb] 16:06:44 0.052078 imap-engine-minimal-folder.vala:543: Not opening Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true): already open [deb] 16:06:44 0.071517 geary-controller.vala:1423: Switched to Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) [deb] 16:06:44 0.000088 imap-engine-replay-queue.vala:561: ReplayQueue.do_replay_remote_async ReplayQueue:Gmail:rschroll@gmail.com:[Gmail]/Sent Mail (open_count=0 remote_opened=true) (notification=0 local=0 local_active=false remote=0 remote_active=false) exiting [deb] 16:06:44 0.000095 app-conversation-monitor.vala:309: ConversationMonitor seeding with local email for Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) [deb] 16:06:44 0.052334 imap-engine-minimal-folder.vala:886: Closed replay queue for Gmail:rschroll@gmail.com:[Gmail]/Sent Mail (open_count=0 remote_opened=true): ReplayQueue:Gmail:rschroll@gmail.com:[Gmail]/Sent Mail (open_count=0 remote_opened=true) (notification=0 local=0 local_active=false remote=0 remote_active=false) [deb] 16:06:44 0.000171 imap-engine-minimal-folder.vala:943: Folder Gmail:rschroll@gmail.com:[Gmail]/Sent Mail (open_count=0 remote_opened=false) closed [deb] 16:06:44 0.118055 imap-engine-minimal-folder.vala:989: Not reestablishing connection to Gmail:rschroll@gmail.com:[Gmail]/Sent Mail (open_count=0 remote_opened=false): closed [deb] 16:06:45 0.318387 conversation-list-store.vala:427: Adding 25 conversations. [deb] 16:06:45 0.017712 conversation-list-store.vala:433: Added 25/25 conversations. [deb] 16:06:45 0.026359 app-conversation-monitor.vala:315: ConversationMonitor seeded for Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) [deb] 16:06:45 0.013116 conversation-list-store.vala:211: Loading 25 previews... [deb] 16:06:45 0.000036 app-email-store.vala:160: EmailStore Gmail:rschroll@gmail.com running GearyAppListOperation on 25 emails [deb] 16:06:45 0.008025 app-email-store.vala:160: EmailStore Gmail:rschroll@gmail.com running GearyAppListOperation on 2 emails [deb] 16:06:45 0.017731 geary-controller.vala:2703: Error checking for what operations are supported in the selected conversations: Async transaction cancelled [deb] 16:06:45 0.000859 app-email-store.vala:182: EmailStore opening Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) for GearyAppListOperation on 25 emails [deb] 16:06:45 0.000007 imap-engine-minimal-folder.vala:543: Not opening Gmail:rschroll@gmail.com:INBOX (open_count=3 remote_opened=true): already open [deb] 16:06:45 0.001334 app-email-store.vala:182: EmailStore opening Gmail:rschroll@gmail.com:INBOX (open_count=3 remote_opened=true) for GearyAppListOperation on 2 emails [deb] 16:06:45 0.000007 imap-engine-minimal-folder.vala:543: Not opening Gmail:rschroll@gmail.com:INBOX (open_count=4 remote_opened=true): already open [deb] 16:06:45 0.031032 app-conversation-monitor.vala:700: ConversationMonitor (already opened) reseeding starting from Email ID [46243/39374] on opened Gmail:rschroll@gmail.com:INBOX (open_count=4 remote_opened=true) [deb] 16:06:46 0.773093 app-email-store.vala:193: EmailStore closed Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) after GearyAppListOperation on 25 emails [deb] 16:06:46 0.000641 app-email-store.vala:219: EmailStore Gmail:rschroll@gmail.com done running GearyAppListOperation on 25 emails [deb] 16:06:46 0.000105 conversation-list-store.vala:214: Loaded 25 previews... [deb] 16:06:46 0.000019 conversation-list-store.vala:194: Displaying 25 previews for Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true)... [deb] 16:06:46 0.013024 conversation-list-store.vala:202: Displayed 25 previews for Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) [deb] 16:06:46 0.000149 app-email-store.vala:193: EmailStore closed Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) after GearyAppListOperation on 2 emails [deb] 16:06:46 0.000106 app-email-store.vala:219: EmailStore Gmail:rschroll@gmail.com done running GearyAppListOperation on 2 emails [deb] 16:06:49 3.489458 app-conversation-set.vala:164: Merging 2 conversations due new email associating with all... [deb] 16:06:49 0.000174 app-conversation-set.vala:311: Removing email [47098/40007] evaporates conversation [#8853] (0 emails) [deb] 16:06:49 0.072298 app-conversation-set.vala:164: Merging 2 conversations due new email associating with all... [deb] 16:06:49 0.000163 app-conversation-set.vala:311: Removing email [46697/39703] evaporates conversation [#8966] (0 emails) [deb] 16:06:49 0.065500 app-conversation-set.vala:164: Merging 2 conversations due new email associating with all... [deb] 16:06:49 0.000155 app-conversation-set.vala:311: Removing email [42733/null] evaporates conversation [#9132] (0 emails) [deb] 16:06:49 0.032563 app-conversation-set.vala:164: Merging 2 conversations due new email associating with all... [deb] 16:06:49 0.000218 app-conversation-set.vala:311: Removing email [46202/null] evaporates conversation [#9165] (0 emails) [deb] 16:06:49 0.032395 conversation-list-store.vala:427: Adding 357 conversations. [deb] 16:06:50 0.396787 conversation-list-store.vala:433: Added 357/357 conversations. [deb] 16:06:50 0.411342 conversation-list-store.vala:211: Loading 357 previews... [deb] 16:06:50 0.000026 app-email-store.vala:160: EmailStore Gmail:rschroll@gmail.com running GearyAppListOperation on 357 emails [deb] 16:06:50 0.121498 app-email-store.vala:182: EmailStore opening Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) for GearyAppListOperation on 357 emails [deb] 16:06:50 0.000008 imap-engine-minimal-folder.vala:543: Not opening Gmail:rschroll@gmail.com:INBOX (open_count=3 remote_opened=true): already open [deb] 16:06:51 0.318404 app-email-store.vala:193: EmailStore closed Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true) after GearyAppListOperation on 357 emails [deb] 16:06:51 0.012062 app-email-store.vala:219: EmailStore Gmail:rschroll@gmail.com done running GearyAppListOperation on 357 emails [deb] 16:06:51 0.002487 conversation-list-store.vala:214: Loaded 357 previews... [deb] 16:06:51 0.000119 conversation-list-store.vala:194: Displaying 357 previews for Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true)... [deb] 16:06:51 0.132701 conversation-list-store.vala:202: Displayed 357 previews for Gmail:rschroll@gmail.com:INBOX (open_count=2 remote_opened=true)
Or maybe not. After restarting Geary, the stall is back and it's still loading too many messages. If I switch to a branch that doesn't include 70bc00c6, I get neither the stalls nor the over-full loading.
Robert, I've reverted that commit and am closing this ticket. If you still see this problem, please re-open. I still believe that patch is a bug fix, but it looks like it's triggering other problems elsewhere in the ConversationMonitor and possibly the EmailStore, and it's not worth the trouble at this point.