Bug 733314 – [IMAPx] Starved FETCH when using IDLE

After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.

Bug 733314 - [IMAPx] Starved FETCH when using IDLE


Summary:	[IMAPx] Starved FETCH when using IDLE


Status:	RESOLVED DUPLICATE of bug 733081

Product:	evolution-data-server
Classification:	Platform
Component:	Mailer
Version:	3.13.x (obsolete)
Hardware:	Other Linux

Importance:	Normal normal
Target Milestone:	---
Assigned To:	evolution-mail-maintainers
QA Contact:	Evolution QA team

URL:
Whiteboard:

Depends on:
Blocks:

Reported:	2014-07-17 12:31 UTC by Yanko Kaneti
Modified:	2014-07-18 09:49 UTC

See Also:
GNOME target:	---
GNOME version:	---

Attachments
Camel debug log (44.72 KB, text/x-log) 2014-07-17 12:31 UTC, Yanko Kaneti	Details
debug patch (6.40 KB, text/plain) 2014-07-17 14:59 UTC, Milan Crha	Details
debug patch ][ (6.78 KB, text/plain) 2014-07-17 16:20 UTC, Milan Crha	Details
debug patch ]I[ (7.72 KB, text/plain) 2014-07-17 17:03 UTC, Milan Crha	Details

Description Yanko Kaneti 2014-07-17 12:31:12 UTC

Created attachment 280967 [details]
Camel debug log

Attaching the last 1000 lines of a imapx:commmand debug log where imapx was waiting for a result of a FETCH that wasn't comming.

This is with e-d-s at e60f804e9e116ae99c4103048332d04d40875ba3 the lates imapx fix.

Comment 1 Yanko Kaneti 2014-07-17 12:34:25 UTC

(gdb) p camel_imapx_store_dump_queue_status(imapx_store)

   Queue status for server 0x2cba840: jobs:1 queued:0 active:1 done:0
      Content of 'jobs':
         [0] job:0x433c230 (type:0x10 REFRESH_INFO) with pending commands:0
      Content of 'active':
         [0] command:0x7ff164361650 for job:0x433c230 (type:0x10 REFRESH_INFO)

Comment 2 Yanko Kaneti 2014-07-17 12:38:44 UTC

(gdb) bt full

+ Trace 233835

#0 syscall
at ../sysdeps/unix/sysv/linux/x86_64/syscall.S line 38
#1 g_cond_wait
at gthread-posix.c line 1390
#2 camel_imapx_job_wait
at camel-imapx-job.c line 194
#3 camel_imapx_job_run
at camel-imapx-job.c line 258
#4 camel_imapx_server_refresh_info
at camel-imapx-server.c line 8597
#5 imapx_refresh_info_sync
at camel-imapx-folder.c line 852
#6 camel_folder_refresh_info_sync
at camel-folder.c line 3480
#7 refresh_folders_exec
at mail-send-recv.c line 1263
#8 mail_msg_proxy
at mail-mt.c line 373
#9 g_thread_pool_thread_proxy
at gthreadpool.c line 307
#10 g_thread_proxy
at gthread.c line 764
#11 start_thread
at pthread_create.c line 310
#12 clone
at ../sysdeps/unix/sysv/linux/x86_64/clone.S line 109

Comment 3 Milan Crha 2014-07-17 14:59:17 UTC

Created attachment 281007 [details]
debug patch

for evolution-data-server;

Maybe it'll help on its own (I did one change there), but it'll give some mapping what is going on in the background at least. Please try with it, but also beware, it'll be very chatty on its own.

Comment 4 Yanko Kaneti 2014-07-17 15:27:25 UTC

With attachemnt 281007 I am getting errors (the error bar in evolution pops up) from time to time  that I wasn't getting before.

Example:
"Error while Retrieving folder list for yaneti@declera.com.
Error fetching folders: got response tag unexpectedly: DONE"

Here is the end of a strace of the server process at the time this happens, I'll shorten everyting but the reads and writes to fd 1:
.....
write(1, "* STATUS INBOX (MESSAGES 33790 UIDNEXT 717504 UIDVALIDITY 125388"..., 130) = 130
read(0, "D00661 IDLE\r\n", 4308)        = 13
write(1, "+ idling\r\n", 10)            = 10
read(0, "DONE\r\n", 4295)               = 6
write(1, "D00661 OK Idle completed.\r\n", 27) = 27
read(0, "D00662 STATUS INBOX.BG (MESSAGES UNSEEN UIDVALIDITY UIDNEXT HIGH"..., 4289) = 204
write(1, "* STATUS INBOX.BG (MESSAGES 1 UIDNEXT 3 UIDVALIDITY 1253885558 U"..., read(0, "", 4085)                       = 0
write(2, "imap(yaneti): Info: Connection closed in=12297 out=6514255\n", 59) = 59

Comment 5 Milan Crha 2014-07-17 16:20:31 UTC

Created attachment 281017 [details]
debug patch ][

maybe now?

Comment 6 Milan Crha 2014-07-17 17:03:05 UTC

Created attachment 281022 [details]
debug patch ]I[

A follow-up debug patch. The previous version was willing to issue DONE command multiple times (in yaneti's case twice) in a row. This should be avoided now.

Comment 7 Milan Crha 2014-07-18 09:49:26 UTC

I've got a confirmation from Yaneti on IRC, thus I follow what I suggested at bug #733081 comment #10.

*** This bug has been marked as a duplicate of bug 733081 ***