GNOME Bugzilla – Bug 737733
[IMAPx] Prevent "Stream has outstanding operation" error
Last modified: 2014-10-20 13:32:51 UTC
When sending a message Evo gives this error: Your message was sent, but an error occurred during post-processing. The reported error was "Failed to append to INBOX/Sent: Error appending message: Stream has outstanding operation Appending to local 'Sent' folder instead.". This account is set up with IMAP, previously in version 3.10 this error did not occur.
Created attachment 287764 [details] Screenshot of folder setup This screenshot shows how I have my sent folder setup for this account. This is how I've always had it even from many years ago and there was never an issue of sent mail being written to the correct folder. Only since upgrading to Gnome 3.12 has this started.
Thanks for a bug report. You are currently using 3.12.6, as you wrote in the evolution-list. Could you run evolution from a console like this: $ CAMEL_DEBUG=imapx:io evolution &>log.txt reproduce the issue and attach the log here, please? Please note it will contain raw communication between evolution and your server (by the way, what is your server), thus it exposes any private information it can.
Created attachment 288140 [details] Evo debug log file from the CAMEL_DEBUG=imapx:io evolution &>log.txt command
Thanks for the log. I see there are done four appends at the end of the log, all into Inbox/Sent on your Courier IMAP server. The first append is successful, then there's an update of the Inbox/Sent folder and the appended message is read back. Then the second APPEND is invoked (like 22 seconds later from the first). The server says the append was successful and then the third append into Inbox/Sent is started (about 11 seconds from the second). This append is also acknowledged as successful. Finally the fourth APPEND is invoked (about 15 seconds later from the third) and this fails with: > [imapx:A] Data read failed with error 'Stream has outstanding operation' This makes the connection give up and the IMAPx reconnects to the server (as expected). As far as i can tell the log doesn't show anything obviously wrong on the IMAP protocol side. The four appends look suspicious, but I guess you just sent three messages - each of them had a different ID. From that I would be afraid of some "new behaviour" of GLib streams. What is your GLib version, please? Fedora has it packaged as glib2, maybe your distribution too. I use 2.40.0 currently and this is the first time I see this particular error message.
I briefly checked GLib's code and I found one possibility to get the error. Could you try to run evolution from a command line under gdb with this command, please: $ gdb evolution --ex "b g_output_stream_flush_async" --ex r --ex "bt" with installed debuginfo packages for glib2, evolution-data-server and evolution. The gdb will ask you something like this: > Make breakpoint pending on future shared library load? (y or [n]) just answer [y], thus the breakpoint will be added later. Then reproduce the error. If it'll be it, then evolution will become unresponsive, due to a prompt in the gdb, which will also print a backtrace from where the function was called. I do not see it directly called in the IMAP or evolution-data-server call, that's why I'd like to verify it being it. Please copy the backtrace here. Then run these gdb commands: (gdb) d br 1 (gdb) c (gdb) q which should (in this order) delete the breakpoint, continue the running session and once you close evolution also quit from the gdb itself.
I filled bug #738277 for GLib. Whether it's related to your issue depends on the results of the investigation from comment #5.
I've attached the output of the command you sent. Note: it took 12 tries of sending a message to myself before the error appeared. Sometimes it will happen on the first post sometimes it takes more.
Created attachment 288221 [details] Output of command gdb evolution --ex "b g_output_stream_flush_async" --ex r --ex "bt" Output of command gdb evolution --ex "b g_output_stream_flush_async" --ex r --ex "bt" also, I'm not sure how to find what version of Glib I have running.
Thanks for the update. So this is not the same as bug #738277, the function wasn't reached at all. (In reply to comment #8) > I'm not sure how to find what version of Glib I have running. For rpm based distribution just run: $ rpm -q glib2 but if you've a different distribution, then the command is different. It's a question for Google to find it out.
Since Ubuntu is Debian based I googled and found this command on the Ubuntu questions site: chris@localhost:~$ sudo apt-cache show libc6 Package: libc6 Priority: required Section: libs Installed-Size: 10497 Maintainer: Ubuntu Developers <ubuntu-devel-discuss@lists.ubuntu.com> Original-Maintainer: GNU Libc Maintainers <debian-glibc@lists.debian.org> Architecture: amd64 Source: eglibc Version: 2.19-0ubuntu6.3 Replaces: libc6-amd64 Provides: glibc-2.19-1 Depends: libgcc1 Suggests: glibc-doc, debconf | debconf-2.0, locales Conflicts: prelink (<= 0.0.20090311-1), tzdata (<< 2007k-1), tzdata-etch Breaks: hurd (<< 1:0.5.git20140203-1), lsb-core (<= 3.2-27), nscd (<< 2.19) Filename: pool/main/e/eglibc/libc6_2.19-0ubuntu6.3_amd64.deb Size: 4735860 MD5sum: 4a8eb1fdda51d79c19ff7b3dc10ff4cf SHA1: 685ad16b180557493d3c706a34ccb906d6ff55e8 SHA256: 5a22935ae658583d4093487440a08e18af48efa2738535870dd1e12560330322 Description-en: Embedded GNU C Library: Shared libraries Contains the standard libraries that are used by nearly all programs on the system. This package includes shared versions of the standard C library and the standard math library, as well as many others. Description-md5: 5089b4da6684d7432ab618fb5b79cec5 Multi-Arch: same Homepage: http://www.eglibc.org Bugs: https://bugs.launchpad.net/ubuntu/+filebug Origin: Ubuntu Supported: 5y Task: minimal Package: libc6 Priority: required Section: libs Installed-Size: 10496 Maintainer: Ubuntu Developers <ubuntu-devel-discuss@lists.ubuntu.com> Original-Maintainer: GNU Libc Maintainers <debian-glibc@lists.debian.org> Architecture: amd64 Source: eglibc Version: 2.19-0ubuntu6 Replaces: libc6-amd64 Provides: glibc-2.19-1 Depends: libgcc1 Suggests: glibc-doc, debconf | debconf-2.0, locales Conflicts: prelink (<= 0.0.20090311-1), tzdata (<< 2007k-1), tzdata-etch Breaks: hurd (<< 1:0.5.git20140203-1), lsb-core (<= 3.2-27), nscd (<< 2.19) Filename: pool/main/e/eglibc/libc6_2.19-0ubuntu6_amd64.deb Size: 4729214 MD5sum: 3a4619b64715f14e0e94725adcab1839 SHA1: 267fd1c9b3555e740f63fec5f55ee8d3a509bac3 SHA256: d82bcd1f16a43b1dc4fa35a738d87c5dd25d6a87f8e0a529b2c188e984866ded Description-en: Embedded GNU C Library: Shared libraries Contains the standard libraries that are used by nearly all programs on the system. This package includes shared versions of the standard C library and the standard math library, as well as many others. Description-md5: 5089b4da6684d7432ab618fb5b79cec5 Multi-Arch: same Homepage: http://www.eglibc.org Bugs: https://bugs.launchpad.net/ubuntu/+filebug Origin: Ubuntu Supported: 5y Task: minimal Does that look correct?
(In reply to comment #10) > Does that look correct? Unfortunately not. The 'libc' is different from 'glib'. This seems to be the GLib package: https://launchpad.net/ubuntu/+source/glib2.0
It took major Googling to find how to check Glib version. Hopefully this is the correct information: root@localhost:~# dpkg -l libglib* | grep ii ii libglib-perl 3:1.304-1 amd64 interface to the GLib and GObject libraries ii libglib2.0-0:amd64 2.40.2-0ubuntu1 amd64 GLib library of C routines ii libglib2.0-0:i386 2.40.2-0ubuntu1 i386 GLib library of C routines ii libglib2.0-bin 2.40.2-0ubuntu1 amd64 Programs for the GLib library ii libglib2.0-cil 2.12.10-5 amd64 CLI binding for the GLib utility library 2.12 ii libglib2.0-data 2.40.2-0ubuntu1 all Common files for GLib library ii libglibmm-2.4-1c2a:amd64 2.39.93-0ubuntu1 amd64 C++ wrapper for the GLib toolkit (shared libraries) root@localhost:~#
Yes, this is fine, you've a 2.40.2 version. I use 2.40.0 currently, which is partially close to your version. Nonetheless, I'm still unsure how to debug this further. I didn't get any response in bug #738277 too.
I'm currently installing your version of GLib, but I'm still unsure whether I'll be able to reproduce the error. Could you run one more gdb session for me, please? It'll show what the other threads are doing in time of the error. The gdb command is: $ gdb evolution --ex "b camel-imapx-server.c:7600 if local_error" \ --ex r --ex "p local_error->message" --ex "t a a bt full" \ --ex c --ex q which should stop when the error is discovered, print its message and then show what all the threads are doing. The backtrace will be pretty detailed, thus make sure you'll not expose any private information, like passwords, email addresses, server addresses and such .I usually search for "pass" at least (quotes for clarity only).
Milan, here is the backtrace. Notice that even though the 'INBOX/directory' folder is still ticked (I checked to make sure before running the command) that it's still being reported as does not exist or must be subscribed to. chris@localhost:~$ gdb evolution --ex "b camel-imapx-server.c:7600 if local_error" \--ex r --ex "p local_error->message"--ex "t a a bt full" \--ex c --ex q GNU gdb (Ubuntu 7.7-0ubuntu3.2) 7.7 Copyright (C) 2014 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-linux-gnu". Type "show configuration" for configuration details. For bug reporting instructions, please see: <http://www.gnu.org/software/gdb/bugs/>. Find the GDB manual and other documentation resources online at: <http://www.gnu.org/software/gdb/documentation/>. For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from evolution...(no debugging symbols found)...done. /home/chris/t a a bt full: No such file or directory. No symbol table is loaded. Use the "file" command. Make breakpoint pending on future shared library load? (y or [n]) Starting program: /usr/bin/evolution [Thread debugging using libthread_db enabled] Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1". [New Thread 0x7fffdfdc7700 (LWP 18728)] [New Thread 0x7fffdef49700 (LWP 18729)] [New Thread 0x7fffdd096700 (LWP 18730)] [New Thread 0x7fffdc895700 (LWP 18731)] [New Thread 0x7fffcf34b700 (LWP 18732)] [New Thread 0x7fffceb4a700 (LWP 18733)] (evolution:18724): camel-WARNING **: Failed to initialize NSS SQL database in sql:/etc/pki/nssdb: NSS error -8126 (evolution:18724): camel-WARNING **: Cannot load summary file '/home/chris/.local/share/evolution/mail/1283386590.6219.2@localhost/.ev-store-summary': Unknown error [New Thread 0x7fff72e40700 (LWP 18739)] [New Thread 0x7fff7263f700 (LWP 18740)] [New Thread 0x7fff71e3e700 (LWP 18741)] [New Thread 0x7fff7163d700 (LWP 18742)] [New Thread 0x7fff70e3c700 (LWP 18743)] [New Thread 0x7fff6bfff700 (LWP 18745)] [New Thread 0x7fff6b7fe700 (LWP 18747)] [New Thread 0x7fff6affd700 (LWP 18748)] [New Thread 0x7fff6a7fc700 (LWP 18749)] [New Thread 0x7fff69ffb700 (LWP 18750)] [New Thread 0x7fff697fa700 (LWP 18751)] [New Thread 0x7fff68ff9700 (LWP 18752)] [New Thread 0x7fff47fff700 (LWP 18753)] [New Thread 0x7fff477fe700 (LWP 18756)] [Thread 0x7fff7163d700 (LWP 18742) exited] [Thread 0x7fff68ff9700 (LWP 18752) exited] [Thread 0x7fff69ffb700 (LWP 18750) exited] [Thread 0x7fff6affd700 (LWP 18748) exited] [Thread 0x7fff6bfff700 (LWP 18745) exited] [Thread 0x7fff71e3e700 (LWP 18741) exited] [Thread 0x7fff6a7fc700 (LWP 18749) exited] [Thread 0x7fff6b7fe700 (LWP 18747) exited] [Thread 0x7fff70e3c700 (LWP 18743) exited] [Thread 0x7fff697fa700 (LWP 18751) exited] [New Thread 0x7fff697fa700 (LWP 18758)] [New Thread 0x7fff70e3c700 (LWP 18759)] [New Thread 0x7fff6b7fe700 (LWP 18760)] [New Thread 0x7fff6a7fc700 (LWP 18761)] [New Thread 0x7fff6bfff700 (LWP 18762)] [New Thread 0x7fff6affd700 (LWP 18763)] [New Thread 0x7fff69ffb700 (LWP 18764)] [New Thread 0x7fff68ff9700 (LWP 18765)] [New Thread 0x7fff3f9b5700 (LWP 18766)] [New Thread 0x7fff3f1b4700 (LWP 18767)] [New Thread 0x7fff3e9b3700 (LWP 18768)] [New Thread 0x7fff3e1b2700 (LWP 18769)] [New Thread 0x7fff3d9b1700 (LWP 18770)] [New Thread 0x7fff3d1b0700 (LWP 18771)] [New Thread 0x7fff3c9af700 (LWP 18772)] [New Thread 0x7fff3c1ae700 (LWP 18773)] [New Thread 0x7fff3b9ad700 (LWP 18774)] [New Thread 0x7fff3b1ac700 (LWP 18775)] [New Thread 0x7fff3a9ab700 (LWP 18776)] [New Thread 0x7fff3a1aa700 (LWP 18777)] [New Thread 0x7fff399a9700 (LWP 18778)] [New Thread 0x7fff391a8700 (LWP 18779)] [New Thread 0x7fff389a7700 (LWP 18780)] [New Thread 0x7fff381a6700 (LWP 18781)] [New Thread 0x7fff379a5700 (LWP 18782)] [New Thread 0x7fff371a4700 (LWP 18783)] [New Thread 0x7fff369a3700 (LWP 18784)] [New Thread 0x7fff361a2700 (LWP 18785)] [Thread 0x7fff361a2700 (LWP 18785) exited] [Thread 0x7fff68ff9700 (LWP 18765) exited] [Thread 0x7fff389a7700 (LWP 18780) exited] [Thread 0x7fff381a6700 (LWP 18781) exited] [Thread 0x7fff399a9700 (LWP 18778) exited] [Thread 0x7fff369a3700 (LWP 18784) exited] [Thread 0x7fff3c1ae700 (LWP 18773) exited] [Thread 0x7fff69ffb700 (LWP 18764) exited] [Thread 0x7fff3b9ad700 (LWP 18774) exited] [Thread 0x7fff72e40700 (LWP 18739) exited] [Thread 0x7fff3f9b5700 (LWP 18766) exited] [Thread 0x7fff3e1b2700 (LWP 18769) exited] [Thread 0x7fff47fff700 (LWP 18753) exited] [Thread 0x7fff697fa700 (LWP 18758) exited] [Thread 0x7fff391a8700 (LWP 18779) exited] [Thread 0x7fff3e9b3700 (LWP 18768) exited] [Thread 0x7fff371a4700 (LWP 18783) exited] [Thread 0x7fff6bfff700 (LWP 18762) exited] [Thread 0x7fff3b1ac700 (LWP 18775) exited] [Thread 0x7fff3f1b4700 (LWP 18767) exited] [Thread 0x7fff3d1b0700 (LWP 18771) exited] [Thread 0x7fff3c9af700 (LWP 18772) exited] [Thread 0x7fff6affd700 (LWP 18763) exited] [Thread 0x7fff3a1aa700 (LWP 18777) exited] [Thread 0x7fff3a9ab700 (LWP 18776) exited] [Thread 0x7fff6a7fc700 (LWP 18761) exited] [Thread 0x7fff379a5700 (LWP 18782) exited] [New Thread 0x7fff379a5700 (LWP 18787)] [Thread 0x7fff3d9b1700 (LWP 18770) exited] (evolution:18724): evolution-mail-WARNING **: Failed to refresh folder 'ChrisP: INBOX/directory': Error refreshing folder: Mailbox does not exist, or must be subscribed to. [New Thread 0x7fff3d9b1700 (LWP 18788)] [New Thread 0x7fff6a7fc700 (LWP 18789)] [Thread 0x7fff3d9b1700 (LWP 18788) exited] [Thread 0x7fff379a5700 (LWP 18787) exited] [Thread 0x7fff6a7fc700 (LWP 18789) exited] [Thread 0x7fff7263f700 (LWP 18740) exited] [New Thread 0x7fff7263f700 (LWP 18799)] [Thread 0x7fff7263f700 (LWP 18799) exited] [New Thread 0x7fff7263f700 (LWP 18811)] [New Thread 0x7fff6a7fc700 (LWP 18812)] ** (evolution:18724): WARNING **: Shell not finalized on exit [Thread 0x7fffceb4a700 (LWP 18733) exited] [Thread 0x7fff6a7fc700 (LWP 18812) exited] [Thread 0x7fff7263f700 (LWP 18811) exited] [Thread 0x7fff6b7fe700 (LWP 18760) exited] [Thread 0x7fff70e3c700 (LWP 18759) exited] [Thread 0x7fff477fe700 (LWP 18756) exited] [Thread 0x7fffcf34b700 (LWP 18732) exited] [Thread 0x7fffdc895700 (LWP 18731) exited] [Thread 0x7fffdd096700 (LWP 18730) exited] [Thread 0x7fffdef49700 (LWP 18729) exited] [Thread 0x7fffdfdc7700 (LWP 18728) exited] [Inferior 1 (process 18724) exited normally] No symbol "local_error" in current context. The program is not being run. chris@localhost:~$
I've attached the imapd debug log. Note: On line 331 the folder "INBOX.sent-mail" does not exist in my Maildir folder on anywhere on the system that I can find. It's also listed in the folder list in Evo. The only other issue I can find is lines 37715-37716 which apparently occurs intermittently when a message is sent.
Created attachment 288616 [details] Courier IMAP daemon debug log
(In reply to comment #16) > I've attached the imapd debug log. Note: On line 331 the folder > "INBOX.sent-mail" does not exist in my Maildir folder on anywhere on the system > that I can find. It's also listed in the folder list in Evo. It's because the server reports it as a subscribed folder: * LSUB (\HasNoChildren) "." "INBOX.sent-mail" I didn't think of it before, but it's possible that some servers store subscriptions separately and when a user deletes a folder they do not remove the subscription for that folder. Kind of a bug on the server side, reporting subscriptions for non-existing folders. To fix this create a sent-mail folder and unsubscribe from it. Contrary the INBOX.directory exists in both LIST and LSUB responses, thus the folder exists. > The only other issue I can find is lines 37715-37716 which apparently occurs > intermittently when a message is sent. I found your thread with courier developers on the SourceForce project page [1], and I agree that the evolution(-data-server) is to be blamed for some parts of your issue. One of them asked whether evolution's IMAP code sends a slash in the folder name, and the answer is no. From your server log (the first line is the end of the previous command): > A00472 OK FETCH completed. > READ: ATOM: A00474 > READ: ATOM: STATUS > READ: ATOM: INBOX.directory > WRITE: A00474 NO Mailbox does not exist, or must be subscribed to. Which means that the command looks like: A00474 STATUS INBOX.directory which is, as far as I can tell, correct. Can we try the same using telnet, thus avoiding evolution completely, please? You can connect to your server as described here [2], which can look like this: $ telnet localhost 143 a01 login user password a02 STATUS INBOX.directory a03 logout The interesting part is what is shown after the a02 line. It may return the same error as in evolution. The other issue with "Stream has outstanding operation" is truly evolution's bug. How much it is related to the returned error I cannot tell for sure. I'll investigate this further. [1] http://sourceforge.net/p/courier/mailman/message/32899710/ [2] http://www.courier-mta.org/authlib/README.authdebug.html search for "to debug IMAP"
So I looked once again where this "Stream has outstanding operation" error comes from and that's from the output streams. I suspect that a thread interleaving on your machine is so good that there happen multiple writes into the same output stream at the same time, which this error tries to avoid. The below commit will fix it, by guarding writes with a lock. Please ask your distribution to include it for you for testing, or build evolution-data-server on your own. Ans as the last, but not least, thanks for your help on this. Created commit 783623d in eds master (3.13.7+) [1] Created commit 449b31b in eds evolution-data-server-3-12 (3.12.8+) [1] https://git.gnome.org/browse/evolution-data-server/commit/?id=783623d
You're very welcome Milan. Seeing as this is a patch I assume, what file do I patch? Or, if it's not so easy as just applying a patch do you know whom I would contact about this at Ubuntu?
It's "just" about applying the patch and recompile evolution-data-server, but if you didn't do that before, then it might be complicated (also due to dependencies and so on). I would also rather ask someone at your distro to help you do that, but as I do not use Ubuntu I've no idea whom to ask in particular. Maybe check who maintains the package there and ask him/her.
Thank you Milan, I've posted on both the Ubuntu mailing list and at askubuntu.com about the fix but seems like no one wants to reply. At first when I asked about the problem on askubuntu.com I received only one reply: Since you are using an unsuported repository you should contact the maintainer or file a bug againts the PPA. I'll continue my search today to see if I can find someone, somewhere to contact.