GNOME Bugzilla – Bug 793296
[IMAPx] Randomly putting non-junk into Junk
Last modified: 2018-03-06 14:44:57 UTC
Since upgrading to 3.26.4, Evolution seems to randomly putting things that my mail system's Spamassassin has NOT marked as spam in the Junk vFolder. To clarify, I have "Preferences->Mail Preferences->Junk->General->Check incoming messages for junk" set and "...->Check custom headers for Junk" set with "X-Spam-Status" Contains Value "Yes," and even message that have "X-Spam-Status: No," in their headers are being put into the Junk vFolder.
Please see https://wiki.gnome.org/Apps/Evolution/Debugging and provide a log.
I did this: $ CAMEL_DEBUG=junk evolution 2>&1 | tee tmp/evolution-junk.debug Nothing turned up in the log: $ grep -v -e "^$" -e "Reading RSS" -e "Failed to get orig uid" -e feed\ -e Memory\ pressure tmp/evolution-junk.debug RSS Plugin enabled (evolution 3.26, evolution-rss 0.3.95) soup init() (evolution:7427): GLib-CRITICAL **: Source ID 4887 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 17725 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 18630 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 19907 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 20996 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 25540 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 34903 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 56321 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 61760 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 65265 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 66951 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 69146 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 77244 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 83067 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 86205 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 88868 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 95307 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 99921 was not found when attempting to remove it Gtk-Message: GtkDialog mapped without a transient parent. This is discouraged. [00005614f20c2410] core libvlc: Running vlc with the default interface. Use 'cvlc' to use vlc without interface. QObject::~QObject: Timers cannot be stopped from another thread [0000563ce8135410] core libvlc: Running vlc with the default interface. Use 'cvlc' to use vlc without interface. QObject::~QObject: Timers cannot be stopped from another thread [0000564f2d964410] core libvlc: Running vlc with the default interface. Use 'cvlc' to use vlc without interface. QObject::~QObject: Timers cannot be stopped from another thread (evolution:7427): GLib-CRITICAL **: Source ID 102331 was not found when attempting to remove it (evolution:7427): camel-CRITICAL **: camel_vee_folder_get_location: assertion 'vinfo != NULL' failed (evolution:7427): camel-CRITICAL **: camel_folder_get_parent_store: assertion 'CAMEL_IS_FOLDER (folder)' failed (evolution:7427): camel-CRITICAL **: camel_folder_get_full_name: assertion 'CAMEL_IS_FOLDER (folder)' failed (evolution:7427): camel-CRITICAL **: camel_service_get_display_name: assertion 'CAMEL_IS_SERVICE (service)' failed (evolution:7427): camel-CRITICAL **: camel_vee_folder_get_location: assertion 'vinfo != NULL' failed (evolution:7427): camel-CRITICAL **: camel_folder_get_parent_store: assertion 'CAMEL_IS_FOLDER (folder)' failed (evolution:7427): camel-CRITICAL **: camel_folder_get_full_name: assertion 'CAMEL_IS_FOLDER (folder)' failed (evolution:7427): camel-CRITICAL **: camel_service_get_display_name: assertion 'CAMEL_IS_SERVICE (service)' failed (evolution:7427): camel-CRITICAL **: camel_vee_folder_get_location: assertion 'vinfo != NULL' failed (evolution:7427): camel-CRITICAL **: camel_folder_get_parent_store: assertion 'CAMEL_IS_FOLDER (folder)' failed (evolution:7427): camel-CRITICAL **: camel_folder_get_full_name: assertion 'CAMEL_IS_FOLDER (folder)' failed (evolution:7427): camel-CRITICAL **: camel_service_get_display_name: assertion 'CAMEL_IS_SERVICE (service)' failed (evolution:7427): GLib-CRITICAL **: Source ID 116961 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 134719 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 140159 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 144807 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 148274 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 152791 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 156302 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 159727 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 163331 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 167144 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 180014 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 182366 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 185788 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 189534 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 192585 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 195617 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 201438 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 205328 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 209486 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 216505 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 220553 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 225435 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 228883 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 230878 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 233635 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 242912 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 245857 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 248021 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 249735 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 253846 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 255820 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 257903 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 259584 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 263475 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 265645 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 267948 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 269828 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 274224 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 276274 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 278219 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 279878 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 284137 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 286105 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 288135 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 289757 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 294020 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 295815 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 298036 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 299719 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 303926 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 305548 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 307631 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 311252 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 315210 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 316845 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 318532 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 320349 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 324415 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 326199 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 328371 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 330041 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 334581 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 336908 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 339195 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 340910 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 345441 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 347309 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 349824 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 352381 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 356992 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 358520 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 360655 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 362659 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 366982 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 369217 was not found when attempting to remove it (evolution:7427): GLib-CRITICAL **: Source ID 371520 was not found when attempting to remove it opening https://bugzilla.gnome.org/show_bug.cgi?id=793296 Created new window in existing browser session. and I have a number mis-Junk'd messages now.
Thanks for a bug report. As long as it's a virtual folder it means that the message has set Junk flag on it. It would not be there otherwise. Do you see this with an IMAP account, or with other? If with IMAP, could you capture this log, please: $ CAMEL_DEBUG=imapx:io evolution &>log.txt Then right-click the headers in the message list, like above the "Subject" word, and pick "Add column..." adn add there Location and UID columns by drag&dropping the name above the table header in the Junk folder. This will help to identify the message and search for its changes in the log. When you notice the misbehaviour, then write down the message's Location and UID. Then close Evolution and search for the UID in the log. The flag changes on it may give a clue, I hope.
Some time later I did get some of these: Sender '[redacted]' in book? 0 Message is determined to be clean Sender '[redacted]' in book? 0 Message is determined to be clean Sender '[redacted]' in book? 0 Message is determined to be clean Message has a Junk flag set already, skipping junk test... Message is determined to be *JUNK* Sender '[redacted]' in book? 0 Message is determined to be clean Sender '[redacted]' in book? 0 Message is determined to be clean Sender '[redacted]' in book? 0 Message is determined to be clean but that is not really helpful in telling me why a message is being set to Junk.
(In reply to Milan Crha from comment #3) > Thanks for a bug report. As long as it's a virtual folder it means that the > message has set Junk flag on it. It would not be there otherwise. Of course. The problem is that according to my "is it Junk" settings (the X-Spam-Status" header contents the message is not Junk, so why is Evolution setting the Junk flag on it? > Do you see this with an IMAP account, or with other? IMAP. > If with IMAP, could you capture this log, please: > > $ CAMEL_DEBUG=imapx:io evolution &>log.txt > > Then right-click the headers in the message list, like above the "Subject" > word, and pick "Add column..." adn add there Location and UID columns by > drag&dropping the name above the table header in the Junk folder. This will > help to identify the message and search for its changes in the log. When you > notice the misbehaviour, then write down the message's Location and UID. > Then close Evolution and search for the UID in the log. The flag changes on > it may give a clue, I hope. Will do.
So here are all of the imapx:io messages with the relevant UID in them: $ grep 1515686 tmp/evolution-imapx\:io.txt [imapx:A] I/O: 'A02150 UID FETCH 1515686:* (UID FLAGS)' [imapx:A] I/O: '* 4570 FETCH (FLAGS () UID 1515686) [imapx:A] I/O: 'A02151 UID FETCH 1515686 (RFC822.SIZE RFC822.HEADER FLAGS)' [imapx:A] I/O: '* 4570 FETCH (FLAGS () UID 1515686 RFC822.SIZE 48951 RFC822.HEADER {2427} [imapx:A] I/O: 'A02152 UID FETCH 1:1515686 (UID FLAGS)' * 4570 FETCH (FLAGS () UID 1515686) [imapx:A] I/O: 'A02154 UID FETCH 1515686 (BODY.PEEK[])' [imapx:A] I/O: '* 4570 FETCH (UID 1515686 BODY[] {48951} [imapx:A] I/O: '* 4570 FETCH (FLAGS (Junk) UID 1515686 MODSEQ (892392))' Let me know if you need more detail about any of those or any other information. For obvious reasons, I can't send you the whole file but I am happy to do any spelunking you need and send back the results.
Thanks for the update. We had a chat on IRC too. I checked the code, but I do not see anything obvious. It seems you are able to reproduce this after some time, which might be a good clue at least. What if I provide any changes to evolution-data-server, to add some debugging prints and such, will you be able to test with it? In case you are on Fedora, I can provide a test build of it very easily. I cannot do the same for any other distribution, I'm sorry.
Yes, happy to test test builds on Fedora 27.
I forgot whether you are on x86_64 or i386, thus I built both, just in case [1]. Please make sure you install/update also the debuginfo/debugsource packages, because the test build will print also backtraces in certain circumstances. Otherwise run evolution as before, with the CAMEL_DEBUG=imapx:io,junk and once you notice something is wrong search the log for the given UID. You may eventually see lines with "changed Junk flag state for message" text, those are interesting and are followed with the backtrace of the place of the change. Another important text is "switched its junk state within save attempt", which you might not ideally see, and the last new text is "doesn't match returned UID", which might be partly related and should not be ideally seen as well. Thanks in advance. [1] https://koji.fedoraproject.org/koji/taskinfo?taskID=24969310
No luck since the last test build yet?
Yes, sorry. Was away for a week. Here's some info from "imapx:io,junk" debug for a message mis-marked as Junk: [imapx:E] I/O: 'E01197 UID FETCH 1518556:* (UID FLAGS)' [imapx:E] I/O: '* 4601 FETCH (FLAGS () UID 1518556) E01197 OK Completed (0.000 sec)' [imapx:E] I/O: 'E01198 UID FETCH 1518556 (RFC822.SIZE RFC822.HEADER FLAGS)' [imapx:E] I/O: '* 4601 FETCH (FLAGS () UID 1518556 RFC822.SIZE 54674 RFC822.HEADER {2310} [ e-mail header ] ) E01198 OK Completed (0.010 sec)' [imapx:E] I/O: 'E01199 UID FETCH 1:1518556 (UID FLAGS)' [imapx:E] I/O: '* 1 FETCH (FLAGS (\Answered \Seen Old) UID 88841) ... * 522 ' Sender '[redacted]' of message '1518556' in book? 0 ... * 4601 FETCH (FLAGS () UID 1518556) E01199 OK Completed (0.010 sec)' ... [imapx:F] I/O: 'F01205 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 (1,2415,3873,4359,4521,4575,4593 88841,1126639,1410269,1496397,1513674,1516121,1518492)))' [imapx:F] I/O: '* 4601 EXISTS * 0 RECENT * FLAGS (\Answered \Flagged \Draft \Deleted \Seen Junk $Label1 $Label2 $Label3 $Label4 $Label5 Old receipt-handled NotJunk 1 #ce921333eccc #ffff00000000 $has_cal redirected list $Forwarded $MDNSent NonJunk spam $Labellater $Labeltodo $NotJunk $Junk) * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen Junk $Label1 $Label2 $Label3 $Label4 $Label5 Old receipt-handled NotJunk 1 #ce921333eccc #ffff00000000 $has_cal redirected list $Forwarded $MDNSent NonJunk spam $Labellater $Labeltodo $NotJunk $Junk \*)] Ok * OK [UNSEEN 92] Ok * OK [UIDVALIDITY 957666537] Ok * OK [UIDNEXT 1518557] Ok * OK [HIGHESTMODSEQ 898523] Ok * OK [URLMECH INTERNAL] Ok * 4601 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) F01205 OK [READ-WRITE] Completed' [imapx:F] I/O: 'F01206 UID FETCH 1518556 (BODY.PEEK[])' [imapx:F] I/O: '* 4601 FETCH (UID 1518556 BODY[] {54674} [ message header and body ] [imapx:F] I/O: ') F01206 OK Completed (0.000 sec)' Message '1518556' is determined to be clean [imapx:E] I/O: 'E01207 NOOP' [imapx:E] I/O: '* 4601 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) E01207 OK Completed' message_info_base_set_flags: changed Junk flag state for message '1518556': at camel_message_info_set_flags() by imapx_update_message_info_flags() by imapx_untagged_fetch() by imapx_untagged() by camel_imapx_server_process_command_sync() by camel_imapx_server_noop_sync() by imapx_server_idle_thread() by g_thread_proxy() by start_thread() by __clone() [imapx:E] I/O: 'E01208 IDLE' [imapx:E] I/O: '+ idling' [imapx:E] I/O: '' [imapx:E] I/O: 'DONE' [imapx:E] I/O: '' [imapx:E] I/O: 'E01208 OK Completed' [imapx:E] I/O: 'E01209 IDLE' [imapx:E] I/O: '+ idling' [imapx:E] I/O: '' [imapx:E] I/O: 'DONE' [imapx:E] I/O: '' [imapx:E] I/O: 'E01209 OK Completed' [imapx:E] I/O: 'E01210 IDLE' [imapx:E] I/O: '+ idling' ... [imapx:E] I/O: 'E01216 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 (1,2414,3872,4358,4520,4574,4592 88841,1126629,1410263,1496396,1513672,1516118,1518487)))' [imapx:E] I/O: '* OK [CLOSED] Ok * 4600 EXISTS * 0 RECENT * FLAGS (\Answered \Flagged \Draft \Deleted \Seen Junk $Label1 $Label2 $Label3 $Label4 $Label5 Old receipt-handled NotJunk 1 #ce921333eccc #ffff00000000 $has_cal redirected list $Forwarded $MDNSent NonJunk spam $Labellater $Labeltodo $NotJunk $Junk) * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen Junk $Label1 $Label2 $Label3 $Label4 $Label5 Old receipt-handled NotJunk 1 #ce921333eccc #ffff00000000 $has_cal redirected list $Forwarded $MDNSent NonJunk spam $Labellater $Labeltodo $NotJunk $Junk \*)] Ok * OK [UNSEEN 92] Ok * OK [UIDVALIDITY 957666537] Ok * OK [UIDNEXT 1518557] Ok * OK [HIGHESTMODSEQ 898524] Ok * OK [URLMECH INTERNAL] Ok * VANISHED (EARLIER) 1518555 * 4600 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) E01216 OK [READ-WRITE] Completed' imapx_untagged_fetch: indexed (4599) UID '(null)' doesn't match returned UID '1518556' by the server [imapx:E] I/O: 'E01217 IDLE' [imapx:E] I/O: '+ idling' ... [imapx:E] I/O: 'E01224 UID STORE 1518556 +FLAGS.SILENT (\SEEN)' [imapx:E] I/O: '* 4600 FETCH (FLAGS (\Seen Junk) UID 1518556 MODSEQ (898525)) E01224 OK Completed' message_info_base_set_flags: changed Junk flag state for message '68': at camel_message_info_set_flags() by message_info_load() by imapx_message_info_load() by camel_message_info_load() by camel_read_mir_callback() by sqlite3_exec() by cdb_sql_exec() by camel_db_select() by camel_db_read_message_info_record_with_uid() by message_info_from_uid() by vee_message_info_get_date_received() by camel_message_info_get_date_received() by latest_foreach() by for_node_and_subtree_if_collapsed() by ml_tree_value_at_ex.isra.26() by cmp_array_uids() by msort_with_tmp() by msort_with_tmp() by msort_with_tmp() by msort_r() by message_list_regen_thread() by run_in_thread() by io_job_thread() by g_task_thread_pool_thread() by g_thread_pool_thread_proxy() by g_thread_proxy() by start_thread() by __clone() message_info_base_set_flags: changed Junk flag state for message '67': at camel_message_info_set_flags() by message_info_load() by imapx_message_info_load() by camel_message_info_load() by camel_read_mir_callback() by sqlite3_exec() by cdb_sql_exec() by camel_db_select() by camel_db_read_message_info_record_with_uid() by message_info_from_uid() by vee_message_info_get_date_received() by camel_message_info_get_date_received() by latest_foreach() by for_node_and_subtree_if_collapsed() by ml_tree_value_at_ex.isra.26() by cmp_array_uids() by msort_with_tmp() by msort_with_tmp() by msort_with_tmp() by msort_with_tmp() by msort_r() by message_list_regen_thread() by run_in_thread() by io_job_thread() by g_task_thread_pool_thread() by g_thread_pool_thread_proxy() by g_thread_proxy() by start_thread() by __clone() [imapx:E] I/O: 'E01229 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 (1,2414,3872,4358,4520,4574,4592 88841,1126629,1410263,1496396,1513672,1516118,1518487)))' [imapx:E] I/O: '* OK [CLOSED] Ok * 4600 EXISTS * 0 RECENT * FLAGS (\Answered \Flagged \Draft \Deleted \Seen Junk $Label1 $Label2 $Label3 $Label4 $Label5 Old receipt-handled NotJunk 1 #ce921333eccc #ffff00000000 $has_cal redirected list $Forwarded $MDNSent NonJunk spam $Labellater $Labeltodo $NotJunk $Junk) * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen Junk $Label1 $Label2 $Label3 $Label4 $Label5 Old receipt-handled NotJunk 1 #ce921333eccc #ffff00000000 $has_cal redirected list $Forwarded $MDNSent NonJunk spam $Labellater $Labeltodo $NotJunk $Junk \*)] Ok * OK [UNSEEN 92] Ok * OK [UIDVALIDITY 957666537] Ok * OK [UIDNEXT 1518557] Ok * OK [HIGHESTMODSEQ 898525] Ok * OK [URLMECH INTERNAL] Ok * VANISHED (EARLIER) 1518555 * 4600 FETCH (FLAGS (\Seen Junk) UID 1518556 MODSEQ (898525)) E01229 OK [READ-WRITE] Completed' imapx_untagged_fetch: indexed (4599) UID '(null)' doesn't match returned UID '1518556' by the server [imapx:E] I/O: 'E01230 IDLE' [imapx:E] I/O: '+ idling' [imapx:A] I/O: ''
I should have mentioned, there are lots more of mis-flagged Junk in case that one above is not helpful. Just let me know if that's the case and I will try pulling the information from another.
I'm sorry for the delay, I've got distracted by some other work. From the log: > * 4601 FETCH (FLAGS () UID 1518556 RFC822.SIZE 54674 ... > .... > * 4601 FETCH (FLAGS () UID 1518556) > E01199 OK Completed (0.010 sec) > .... > * 4601 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) > .... > imapx_untagged_fetch: indexed (4599) UID '(null)' doesn't > match returned UID '1518556' by the server > .... > E01224 UID STORE 1518556 +FLAGS.SILENT (\SEEN) > * 4600 FETCH (FLAGS (\Seen Junk) UID 1518556 MODSEQ (898525)) ... If I read it properly, IMAP noticed a new message with UID 1518556 and downloaded it (it's the first FETCH above), then there was a refresh of the content of that folder, which still shows that the message was just unread (the second FETCH, including "FLAGS ()". Suddenly, the third FETCH receives from the server that the message is already marked as Junk. Then there's that "imapx_untagged_fetch" print, which is suspicious, but let's leave it for now. Finally the IMAPX code marks the message as \SEEN with the UID STORE command and the change is confirmed with the fourth FETCH response, which contains both Junk and \SEEN flags. Unless you accidentally skipped a UID STORE command between the second and the third FETCH responses (the one without Junk flag and the one with it), then something else marked the message as Junk on the server and IMAPx only received the change from the server. I doubt it though, I think there was some UID STORE which had been for a set of UIDs, thus not naming that 1518556 specifically; maybe something like: > UID STORE 1518555:1518557 +FLAGS.SILENT (Junk) while the range or the set of flags to be set can differ. > at camel_message_info_set_flags() > by message_info_load() Pity you do not have installed debuginfo packages for the scratch build as well, that would provide also line numbers, which gives more accurate reference of the place in the code in the above part of the log. Missing debuginfo is usually the reason for this, but maybe the package should install also other libraries to have this working (or the split into debuginfo and debugsource packages in Fedora caused this, I do not know).
(In reply to Milan Crha from comment #13) > I'm sorry for the delay, I've got distracted by some other work. No worries. > Unless you accidentally skipped a > UID STORE command between the second and the third FETCH responses (the one > without Junk flag and the one with it), then something else marked the > message as Junk on the server I don't think I have any other MUAs that use the Junk flag other than evolution. However I do have two evolution instances on this same mailbox. I will go disable the other one until we have this issue nailed down, just to be sure it's not the other instance. > and IMAPx only received the change from the > server. I doubt it though, I think there was some UID STORE which had been > for a set of UIDs, thus not naming that 1518556 specifically; maybe > something like: > > UID STORE 1518555:1518557 +FLAGS.SILENT (Junk) > while the range or the set of flags to be set can differ. So, here is the output of "grep -e \ STORE\ -e 1518556 ~/tmp/evolution-imapx\:io\,junk.txt" so that you can see all operations involving this message or any STORE in the time window (I believe, please let me know if you think the window is too small): [imapx:E] I/O: '* 4601 FETCH (FLAGS () UID 1518556 RFC822.SIZE 54674 [imapx:E] I/O: 'E01199 UID FETCH 1:1518556 (UID FLAGS)' Sender '[redacted]' of message '1518556' in book? 0 * 4601 FETCH (FLAGS () UID 1518556) [imapx:F] I/O: 'F01205 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 * 4601 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) [imapx:F] I/O: 'F01206 UID FETCH 1518556 (BODY.PEEK[])' [imapx:F] I/O: '* 4601 FETCH (UID 1518556 BODY[] {54674} Message '1518556' is determined to be clean [imapx:E] I/O: '* 4601 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) message_info_base_set_flags: changed Junk flag state for message '1518556': [imapx:E] I/O: 'E01216 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 * 4600 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) '1518556' by the server [imapx:E] I/O: 'E01224 UID STORE 1518556 +FLAGS.SILENT (\SEEN)' [imapx:E] I/O: '* 4600 FETCH (FLAGS (\Seen Junk) UID 1518556 MODSEQ (898525)) [imapx:E] I/O: 'E01229 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 * 4600 FETCH (FLAGS (\Seen Junk) UID 1518556 MODSEQ (898525)) '1518556' by the server [imapx:E] I/O: 'E01197 UID FETCH 1518556:* (UID FLAGS)' [imapx:E] I/O: '* 4601 FETCH (FLAGS () UID 1518556) [imapx:E] I/O: 'E01198 UID FETCH 1518556 (RFC822.SIZE RFC822.HEADER FLAGS)' [imapx:E] I/O: '* 4601 FETCH (FLAGS () UID 1518556 RFC822.SIZE 54674 [imapx:E] I/O: 'E01199 UID FETCH 1:1518556 (UID FLAGS)' Sender '[redacted]' of message '1518556' in book? 0 * 4601 FETCH (FLAGS () UID 1518556) [imapx:F] I/O: 'F01205 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 * 4601 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) [imapx:F] I/O: 'F01206 UID FETCH 1518556 (BODY.PEEK[])' [imapx:F] I/O: '* 4601 FETCH (UID 1518556 BODY[] {54674} Message '1518556' is determined to be clean [imapx:E] I/O: '* 4601 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) message_info_base_set_flags: changed Junk flag state for message '1518556': [imapx:E] I/O: 'E01216 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 * 4600 FETCH (FLAGS (Junk) UID 1518556 MODSEQ (898523)) '1518556' by the server [imapx:E] I/O: 'E01224 UID STORE 1518556 +FLAGS.SILENT (\SEEN)' [imapx:E] I/O: '* 4600 FETCH (FLAGS (\Seen Junk) UID 1518556 MODSEQ (898525)) [imapx:E] I/O: 'E01229 SELECT INBOX (QRESYNC (957666537 898521 88841:1518556 * 4600 FETCH (FLAGS (\Seen Junk) UID 1518556 MODSEQ (898525)) '1518556' by the server [imapx:J] I/O: 'J08580 UID STORE 1515904,1518468 +FLAGS.SILENT (\DELETED)' [imapx:J] I/O: 'J08581 UID STORE 1515904 +FLAGS.SILENT (\SEEN)' [imapx:J] I/O: 'J08584 UID STORE 1518620 +FLAGS.SILENT (\SEEN)' [imapx:J] I/O: 'J08590 UID STORE 1518584,1518588,1518591,1518595,1518603,1518605 [imapx:J] I/O: 'J08591 UID STORE 1518584,1518588,1518591,1518595,1518603,1518605 * 4600 FETCH (FLAGS (\Seen Junk) UID 1518556) [imapx:J] I/O: 'J08605 UID STORE 1518617:1518619 +FLAGS.SILENT (\DELETED)' [imapx:J] I/O: 'J08606 UID STORE 1518617:1518619 +FLAGS.SILENT (\SEEN)' [imapx:J] I/O: 'J08615 UID STORE 56598,56608:56609 +FLAGS.SILENT (\DELETED)' [imapx:J] I/O: 'J08616 UID STORE 56598,56608:56609 +FLAGS.SILENT (\SEEN)' [imapx:J] I/O: 'J08618 UID STORE 1518613,1518615 +FLAGS.SILENT (\DELETED)' [imapx:J] I/O: 'J08619 UID STORE 1518613,1518615 +FLAGS.SILENT (\SEEN)' [imapx:J] I/O: 'J08624 UID STORE 56607 +FLAGS.SILENT (\DELETED)' [imapx:J] I/O: 'J08625 UID STORE 56607 +FLAGS.SILENT (\SEEN)' [imapx:J] I/O: 'J08629 UID STORE 56606 +FLAGS.SILENT (\SEEN)' * 4600 FETCH (FLAGS (\Seen Junk) UID 1518556) * 4600 FETCH (FLAGS (\Seen Junk) UID 1518556) * 4600 FETCH (FLAGS (\Seen Junk) UID 1518556) > Pity you do not have installed debuginfo packages for the scratch build as > well, that would provide also line numbers, which gives more accurate > reference of the place in the code in the above part of the log. Missing > debuginfo is usually the reason for this, but maybe the package should > install also other libraries to have this working (or the split into > debuginfo and debugsource packages in Fedora caused this, I do not know). I will get that debuginfo installed also.
The log window is fine, it shows at the top that the message flags had changes (Junk added) after two received FETCH-es without the Junk flag and no UID STORE command in between, thus it truly could be set by some other software. What was the other Evolution version? Maybe if you could install the debug version there as well, and gather similar log, then we'll find the cause.
Did the close of the other instance help, thus we can expect the issue being with the other (and older) instance, not with your main instance of Evolution?
Yeah. I think so. I wanted to give it a few days to make sure, but it seems like it's been long enough to know now. A bit of an explanation in case you are interested... So, over on that other machine (the one that was mis-marking spam), spam handling is a bit different. More about that in a bit... On the first machine (i.e. the one I was reporting about and debugging on in this ticket) where I was seeing the problem, spam detection and reporting is all done on the server with spamassassin. Each person has a "Junk" and "Not Junk" folder that they put spam (and mis-marked non-spam) into to teach the server what spam is and what is not. I'd love nothing more than to be able to hook up the Junk and Not-Junk buttons in Evolution to doing those moves but that's not possible. On the second machine, that was apparently the one that was (mis-)marking the e-mails as Junk in the INBOX on my personal server, spam (for a different INBOX) is reported to IT by forwarding the spam to an e-mail address. Frankly, it doesn't really seem to work. It doesn't matter how many times I forward spams, I continue to get the same ones over and over again. But still, I go through the motions hoping that one day it will magically start working. If I don't keep trying I won't ever know if/when that happens. In order to make the process of forwarding the e-mails to the given address consistent, I have a script which is API compatible with "bogofilter" but instead takes the given spam and forwards it to the server for reporting. I actually name this script bogofilter and put it into my $PATH. I then install evolution-bogofilter so that the Junk/Not-Junk buttons know to use (something called) bogofilter to report spam. Installing evolution-bogofilter (by RPM) of course pulls in the real bogofilter. So once all of the RPM installation is done I do a "mv .../bogofilter{,.dist}" on the real bogofilter to make sure it doesn't get called instead of my replacement one, despite what might be in $PATH. Of course, that needs to be done every time bogofilter is updated and sometimes I forget[1]. I can only assume that the real bogofilter was being used to determine spam and it was mis-determining. [1] I realise that I could put my own "bogofilter-compatible" script into an RPM with a trigger scriptlet (on the bogofilter RPM) that does the real-bogofilter renaming so that it is renamed every time it is updated, bug again, it's a level of effort that is just not justifiable with everything else to do. Ultimately, it would just be nice if Evolution had an option for completely user-configurable actions for the Junk/Not-Junk buttons along the lines of the actions that can be defined for message filtering perhaps. Maybe a lot of that code is re-usable for Junk/Not-Junk configurability. I'm sure there are tickets open on this already. I'm sure I have opened at least one about it. :-) Anyway, many thanks for your patience and help on this ticket. It really is much appreciated.
Thanks for the update. The 'Mark as Junk' button just sets the Junk flag on it and when you've done that in an account which supports real junk folder, like IMAP, which can be configures to use the real Junk folder instead of virtual, then the account moves the message there when saving changes. There is no such option for Not Junk behaviour. I think, since some semi-recent version, when you mark message as not junk in the real Junk folder, then it is moved to the Inbox. Maybe, instead of abusing the bogofilter, you can create a filter which will "Pipe To Program" and when it'll return certain value, then it'll do something, like moving the message to the appropriate folder. The only downside is that the message processing through the program would be done twice, once for each "is junk"/"is not junk" filter.
(In reply to Milan Crha from comment #18) > Thanks for the update. The 'Mark as Junk' button just sets the Junk flag on > it and when you've done that in an account which supports real junk folder, > like IMAP, which can be configures to use the real Junk folder instead of > virtual, then the account moves the message there when saving changes. There > is no such option for Not Junk behaviour. I think, since some semi-recent > version, when you mark message as not junk in the real Junk folder, then it > is moved to the Inbox. That's can't be completely true. Pressing the Junk button must trigger an external action, either bogofilter (which I am abusing) or spamassassin to "learn" that the message is actually spam. Likewise the Not-Junk button must do the same except that it's telling bogofilter/spamassassin to learn the message as ham. IIUC, that's the functionality that the evolution-{bogofilter|spamassassin} packages add to evolution. The fact that I can replace bogofilter with a script which gets a copy of the spam when I press the Junk button corroborates that. I have done the same with spamassassin in the past also. > Maybe, instead of abusing the bogofilter, you can create a filter which will > "Pipe To Program" and when it'll return certain value, then it'll do > something, like moving the message to the appropriate folder. The only > downside is that the message processing through the program would be done > twice, once for each "is junk"/"is not junk" filter. How would I invoke such a filter on demand for only certain messages? To be clear, the workflow here is that I am reading through my e-mail and I find an e-mail that is spam but was not detected as such by the mail server. So I need to give that message to the server to be processed as "this is spam that you didn't detect, please learn from it". On my personal server this is done by my putting the e-mail into a folder named "Junk" (which is different from the evolution Junk vFolder) which the server then picks up and runs through it's instance of spamassassin with the "this is junk" flag. I'm not sure how evolution filters can be applied to that workflow.
(In reply to Brian J. Murrell from comment #19) > IIUC, that's the functionality that the evolution-{bogofilter|spamassassin} > packages add to evolution. Yes, the plugins are used to learn spam and ham to the background process (bogofilter or smapassassin), but also to automatically recognize the spam when it is received. > How would I invoke such a filter on demand for only certain messages? > > To be clear, the workflow here is... I see. I thought you can somehow recognize spam with a code, not manually. That makes my suggestion void, because even you can disable filtering for the account and apply filter manually only (Ctrl+Y), you cannot apply one filter now and another filter another time. With respect of customizable actions when "Mark as Junk" and "Mark as Not Junk" is pressed, one may create its own junk filtering plugin [1] and set it to be used in Edit->preferences->Mail Preferences->Junk tab instead of bogofilter and spamassassin. I do not know how much that special processing of these two buttons would work, like what actions might be configurable there? Should it also run the learn spam/ham for the message? Should it do before or after processing the message through that special code? I believe that having there just "Pipe To Program" is not enough. Using specifically named filters might be confusing (like when a user created a filter named "learn-junk", then this would be run for messages which were marked as junk, in addition to the usual behaviour; similarly with "learn-not-junk" named filter). I'm just giving quick ideas, it's nothing to be done. I'm even not sure how that would work from the user point of view. I definitely do not want to duplicate filter actions code for this. [1] for example by copy&paste code from there: https://git.gnome.org/browse/evolution/tree/src/modules/bogofilter but rename it both internal structures then also the name of the plugin: https://git.gnome.org/browse/evolution/tree/src/modules/bogofilter/evolution-bogofilter.c#n535
(In reply to Milan Crha from comment #20) > > With respect of customizable actions when "Mark as Junk" and "Mark as Not > Junk" is pressed, one may create its own junk filtering plugin [1] and set > it to be used in Edit->preferences->Mail Preferences->Junk tab instead of > bogofilter and spamassassin. Sure. If one can code (which I can) but I think I was thinking of the greater userbase, many of whom cannot code and just want to define for themselves what actions Junk/Not-Junk do. > I do not know how much that special processing > of these two buttons would work, like what actions might be configurable > there? Should it also run the learn spam/ham for the message? Should it do > before or after processing the message through that special code? I believe > that having there just "Pipe To Program" is not enough. Agree. I think you probably want the full flexibility of the current filtering actions since for some people, learning spam/ham can be executing a command. For others, it's forwarding the e-mail somewhere, and for others still it's moving it to a folder. There are likely other workflows that some of the current filtering actions can handle. > Using specifically > named filters might be confusing (like when a user created a filter named > "learn-junk", then this would be run for messages which were marked as junk, > in addition to the usual behaviour; similarly with "learn-not-junk" named > filter). Yes, the (2) filters created for Junk and Not-Junk need to be separate from the ctrl-y type filters and only trigger from the Junk/Not-Junk buttons. > I'm just giving quick ideas, it's nothing to be done. Yes, understood. > I'm even not > sure how that would work from the user point of view. I definitely do not > want to duplicate filter actions code for this. Not duplicate, no. Of course not. Re-use. :-)
Would you mind to open a bug for it, against evolution, please? I'm still quite unsure how to handle this in a sane way and whether the spamassassin/bogofilter should be replaced by those specific filters, or they might run in addition, or the filters only after spamassassin/bogofilter, or before, or... And where to edit these filters. Probably Edit->Preferences->Mail Preferences->Junk tab is the best place, two buttons, one for "When [ Mark as Junk ] is pressed, execute also this action" and one for "When [ Mark as Not Junk ] is pressed, execute also this action", where the text in [] is meant as a button, which would open the filter rule editing dialog. But these "sentences" feel quite bad, they require better wording, ideally not being split by the "edit filter" button.
Bug #794121.