imapsieve wrong matches on APPEND cause
Hello,
I'm experiencing some strange problem with imapsieve mailbox rules matching. I have Ubuntu Server 18.04.1 LTS with Postfix 3.3.0, Dovecot 2.2.33.2 and Rspamd 1.7.9. The problem occurs with Microsoft Outlook 2016 mail client. When moving with Outlook, APPEND event is logged instead of MOVE. However, when moving with another client, MOVE event is logged.
So without APPEND event in causes in plugin section of dovecot.conf no rule is matched at all. If I add APPEND event into causes in plugin section of dovecot.conf, then for some reason imapsieve matches both rules on move from Inbox to Spam and no rules on move from Spam to Inbox. Matching both rules attempts to run both learn_spam and learn_ham. First one works and second logs error (which is correct). On attempt to move message from Spam to Inbox imapsieve not matching any rule at all and thus learning is not working.
Could you please let me know how to fix this?
More details. Here is what I have in my plugin section of dovecot.conf: ---------------------------------------- %<
plugin { imapsieve_mailbox1_before = file:/var/vmail/sieve/global/learn-spam.sieve imapsieve_mailbox1_causes = COPY APPEND imapsieve_mailbox1_from = Inbox imapsieve_mailbox1_name = Spam imapsieve_mailbox2_before = file:/var/vmail/sieve/global/learn-ham.sieve imapsieve_mailbox2_causes = COPY APPEND imapsieve_mailbox2_from = Spam imapsieve_mailbox2_name = Inbox sieve = file:/var/vmail/sieve/%d/%n/scripts;active=/var/vmail/sieve/%d/%n/active-scr ipt.sieve sieve_before = /var/vmail/sieve/global/spam-global.sieve sieve_global_dir = /var/vmail/sieve/global/ sieve_global_extensions = +vnd.dovecot.pipe +vnd.dovecot.environment +vnd.dovecot.debug sieve_pipe_bin_dir = /usr/bin sieve_plugins = sieve_imapsieve sieve_extprograms } ---------------------------------------- %<
I also have Trash, Drafts, Sent and Spam mailboxes defined in dovecot.conf. So when I try to move actual spam message from Inbox to Spam folder, this is what I see in dovecot.log: ---------------------------------------- %<
Debug: imapsieve: mailbox Spam: APPEND event ---------------------------------------- %<
So before I added "APPEND" into above imapsieve_mailbox1_causes and imapsieve_mailbox2_causes imapsieve was not matching rules at all. But after I added APPEND, here is what happens. In case I move message from Inbox to Spam both rules are matched and dovecot attempts to run both rules: ---------------------------------------- %<
Debug: INBOX: Mailbox opened because: SELECT
Debug: Spam: Mailbox opened because: SELECT
Debug: imapsieve: mailbox Spam: APPEND event
Debug: sieve: Pigeonhole version 0.4.21 (92477967) initializing
Debug: sieve: Sieve imapsieve plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: sieve: Sieve Extprograms plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: imapsieve: Static mailbox rule [1]: mailbox=Spam' from=*'
causes=(APPEND) => before=file:/var/vmail/sieve/global/learn-spam.sieve' after=(none) Debug: imapsieve: Static mailbox rule [2]: mailbox=*' from=Spam' causes=(APPEND) => before=file:/var/vmail/sieve/global/learn-ham.sieve'
after=(none)
Debug: imapsieve: Matched static mailbox rule [2]
Debug: imapsieve: Matched static mailbox rule [1]
Debug: sieve: file storage: Using Sieve script path:
/var/vmail/sieve/global/learn-spam.sieve
Debug: sieve: file script: Opened script learn-spam' from /var/vmail/sieve/global/learn-spam.sieve'
Debug: sieve: file storage: Using Sieve script path:
/var/vmail/sieve/global/learn-ham.sieve
Debug: sieve: file script: Opened script learn-ham' from /var/vmail/sieve/global/learn-ham.sieve'
Debug: sieve: Opening script 1 of 2 from
/var/vmail/sieve/global/learn-spam.sieve' Debug: sieve: Loading script /var/vmail/sieve/global/learn-spam.sieve Debug: sieve: Script binary /var/vmail/sieve/global/learn-spam.svbin successfully loaded Debug: sieve: binary save: not saving binary /var/vmail/sieve/global/learn-spam.svbin, because it is already stored Debug: sieve: Executing script from /var/vmail/sieve/global/learn-spam.svbin'
Debug: sieve: action pipe: running program: rspamc
Debug: Mailbox Spam: Opened mail UID=12 because: mail stream
Debug: waiting for program /usr/bin/rspamc' to finish after 0 msecs Debug: sieve: Opening script 2 of 2 from /var/vmail/sieve/global/learn-ham.sieve'
Debug: sieve: Loading script /var/vmail/sieve/global/learn-ham.sieve
Debug: sieve: Script binary /var/vmail/sieve/global/learn-ham.svbin
successfully loaded
Debug: sieve: binary save: not saving binary
/var/vmail/sieve/global/learn-ham.svbin, because it is already stored
Debug: sieve: Executing script from
`/var/vmail/sieve/global/learn-ham.svbin'
Debug: Spam: Mailbox opened because: lib-lda delivery
Debug: Spam: Mailbox opened because: SELECT
---------------------------------------- %<
And of course I'm getting the following in the log file: ---------------------------------------- %<
Error: sieve: learn-ham: line 2: duplicate pipe "rspamc" action not allowed (previously triggered one was here: learn-spam: line 3) Error: sieve: Execution of script /var/vmail/sieve/global/learn-ham.sieve failed ---------------------------------------- %<
In case I move message from Spam to Inbox on rule is matched at all: ---------------------------------------- %<
Debug: INBOX: Mailbox opened because: SELECT
Debug: imapsieve: mailbox INBOX: APPEND event
Debug: sieve: Pigeonhole version 0.4.21 (92477967) initializing
Debug: sieve: Sieve imapsieve plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: sieve: Sieve Extprograms plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: imapsieve: Static mailbox rule [1]: mailbox=Spam' from=*'
causes=(APPEND) => before=file:/var/vmail/sieve/global/learn-spam.sieve' after=(none) Debug: imapsieve: Static mailbox rule [2]: mailbox=*' from=Spam' causes=(APPEND) => before=file:/var/vmail/sieve/global/learn-ham.sieve'
after=(none)
Debug: INBOX: Mailbox opened because: SELECT
---------------------------------------- %<
With best regards, Alex
Hi,
Can you enable mail_log plugin, try again, and send updated logs? Aki
Sure, but logs contain same info.
- When I move a message from Inbox to Spam it matches both rules and sieve executing both scripts in sequence:
Debug: Spam: Mailbox opened because: SELECT
Debug: imapsieve: mailbox Spam: APPEND event
Debug: sieve: Pigeonhole version 0.4.21 (92477967) initializing
Debug: sieve: Sieve imapsieve plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: sieve: Sieve Extprograms plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: imapsieve: Static mailbox rule [1]: mailbox=Spam' from=*'
causes=(COPY APPEND) =>
before=file:/var/vmail/sieve/global/learn-spam.sieve' after=(none) Debug: imapsieve: Static mailbox rule [2]: mailbox=*' from=Spam' causes=(COPY APPEND) => before=file:/var/vmail/sieve/global/learn-ham.sieve' after=(none)
Debug: imapsieve: Matched static mailbox rule [2]
Debug: imapsieve: Matched static mailbox rule [1]
Debug: sieve: file storage: Using Sieve script path:
/var/vmail/sieve/global/learn-spam.sieve
Debug: sieve: file script: Opened script learn-spam' from /var/vmail/sieve/global/learn-spam.sieve'
Debug: sieve: file storage: Using Sieve script path:
/var/vmail/sieve/global/learn-ham.sieve
Debug: sieve: file script: Opened script learn-ham' from /var/vmail/sieve/global/learn-ham.sieve'
Debug: sieve: Opening script 1 of 2 from
`/var/vmail/sieve/global/learn-spam.sieve'
Debug: sieve: Loading script /var/vmail/sieve/global/learn-spam.sieve
Debug: Spam: Mailbox opened because: lib-lda delivery
Debug: Spam: Mailbox opened because: SELECT
- When I move a message from Spam to Inbox none of the rules matched and thus nothing executed:
Debug: INBOX: Mailbox opened because: SELECT
Debug: imapsieve: mailbox INBOX: APPEND event
Debug: sieve: Pigeonhole version 0.4.21 (92477967) initializing
Debug: sieve: Sieve imapsieve plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: sieve: Sieve Extprograms plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: imapsieve: Static mailbox rule [1]: mailbox=Spam' from=*'
causes=(COPY APPEND) =>
before=file:/var/vmail/sieve/global/learn-spam.sieve' after=(none) Debug: imapsieve: Static mailbox rule [2]: mailbox=*' from=Spam' causes=(COPY APPEND) => before=file:/var/vmail/sieve/global/learn-ham.sieve' after=(none)
Debug: INBOX: Mailbox opened because: SELECT
Here is plugin section from dovecot.conf:
plugin {
sieve_global_dir = /var/vmail/sieve/global/
sieve_plugins = sieve_imapsieve sieve_extprograms
sieve_before = /var/vmail/sieve/global/spam-global.sieve
sieve =file:/var/vmail/sieve/%d/%n/scripts;active=/var/vmail/sieve/%d/%n/active-scr ipt.sieve
#------------------------
# Spam learning
#------------------------
# From elsewhere to Spam folder
imapsieve_mailbox1_name = Spam
imapsieve_mailbox1_causes = COPY APPEND
imapsieve_mailbox1_before =file:/var/vmail/sieve/global/learn-spam.sieve
# From Spam folder to elsewhere
imapsieve_mailbox2_name = *
imapsieve_mailbox2_from = Spam
imapsieve_mailbox2_causes = COPY APPEND
imapsieve_mailbox2_before = file:/var/vmail/sieve/global/learn-ham.sieve
sieve_pipe_bin_dir = /usr/bin
sieve_global_extensions = +vnd.dovecot.pipe +vnd.dovecot.environment+vnd.dovecot.debug
mail_log_events = delete undelete expunge save copy mailbox_createmailbox_delete mailbox_rename mail_log_fields = uid box msgid size flags vsize from subject }
Thanks, Alex
Hello again,
Does anybody have any comments on how to solve this?
Thanks, Alex
-----Original Message----- From: dovecot [mailto:dovecot-bounces@dovecot.org] On Behalf Of Alex Cherevko Sent: Tuesday, August 14, 2018 2:01 PM To: 'Aki Tuomi' <aki.tuomi@dovecot.fi>; dovecot@dovecot.org Subject: RE: imapsieve wrong matches on APPEND cause
Hi,
Can you enable mail_log plugin, try again, and send updated logs? Aki
Sure, but logs contain same info.
- When I move a message from Inbox to Spam it matches both rules and sieve executing both scripts in sequence:
Debug: Spam: Mailbox opened because: SELECT
Debug: imapsieve: mailbox Spam: APPEND event
Debug: sieve: Pigeonhole version 0.4.21 (92477967) initializing
Debug: sieve: Sieve imapsieve plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: sieve: Sieve Extprograms plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: imapsieve: Static mailbox rule [1]: mailbox=Spam' from=*'
causes=(COPY APPEND) =>
before=file:/var/vmail/sieve/global/learn-spam.sieve' after=(none) Debug: imapsieve: Static mailbox rule [2]: mailbox=*' from=Spam' causes=(COPY APPEND) => before=file:/var/vmail/sieve/global/learn-ham.sieve' after=(none)
Debug: imapsieve: Matched static mailbox rule [2]
Debug: imapsieve: Matched static mailbox rule [1]
Debug: sieve: file storage: Using Sieve script path:
/var/vmail/sieve/global/learn-spam.sieve
Debug: sieve: file script: Opened script learn-spam' from /var/vmail/sieve/global/learn-spam.sieve'
Debug: sieve: file storage: Using Sieve script path:
/var/vmail/sieve/global/learn-ham.sieve
Debug: sieve: file script: Opened script learn-ham' from /var/vmail/sieve/global/learn-ham.sieve'
Debug: sieve: Opening script 1 of 2 from
`/var/vmail/sieve/global/learn-spam.sieve'
Debug: sieve: Loading script /var/vmail/sieve/global/learn-spam.sieve
Debug: Spam: Mailbox opened because: lib-lda delivery
Debug: Spam: Mailbox opened because: SELECT
- When I move a message from Spam to Inbox none of the rules matched and thus nothing executed:
Debug: INBOX: Mailbox opened because: SELECT
Debug: imapsieve: mailbox INBOX: APPEND event
Debug: sieve: Pigeonhole version 0.4.21 (92477967) initializing
Debug: sieve: Sieve imapsieve plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: sieve: Sieve Extprograms plugin for Pigeonhole version 0.4.21
(92477967) loaded
Debug: imapsieve: Static mailbox rule [1]: mailbox=Spam' from=*'
causes=(COPY APPEND) =>
before=file:/var/vmail/sieve/global/learn-spam.sieve' after=(none) Debug: imapsieve: Static mailbox rule [2]: mailbox=*' from=Spam' causes=(COPY APPEND) => before=file:/var/vmail/sieve/global/learn-ham.sieve' after=(none)
Debug: INBOX: Mailbox opened because: SELECT
Here is plugin section from dovecot.conf:
plugin {
sieve_global_dir = /var/vmail/sieve/global/
sieve_plugins = sieve_imapsieve sieve_extprograms
sieve_before = /var/vmail/sieve/global/spam-global.sieve
sieve =file:/var/vmail/sieve/%d/%n/scripts;active=/var/vmail/sieve/%d/%n/active-scr ipt.sieve
#------------------------
# Spam learning
#------------------------
# From elsewhere to Spam folder
imapsieve_mailbox1_name = Spam
imapsieve_mailbox1_causes = COPY APPEND
imapsieve_mailbox1_before =file:/var/vmail/sieve/global/learn-spam.sieve
# From Spam folder to elsewhere
imapsieve_mailbox2_name = *
imapsieve_mailbox2_from = Spam
imapsieve_mailbox2_causes = COPY APPEND
imapsieve_mailbox2_before = file:/var/vmail/sieve/global/learn-ham.sieve
sieve_pipe_bin_dir = /usr/bin
sieve_global_extensions = +vnd.dovecot.pipe +vnd.dovecot.environment+vnd.dovecot.debug
mail_log_events = delete undelete expunge save copy mailbox_createmailbox_delete mailbox_rename mail_log_fields = uid box msgid size flags vsize from subject }
Thanks, Alex
Hi,
Op 09/08/2018 om 22:09 schreef Alex Cherevko:
Ehmm, that probably means Microsoft decided to do a COPY by doing FETCH
- APPEND instead. You should use rawlog to confirm (https://wiki.dovecot.org/Debugging/Rawlog). I really want to see what it is doing there. It could be a bug in IMAPSieve, but I don't see how a MOVE/COPY event could magically become an APPEND.
So without APPEND event in causes in plugin section of dovecot.conf no rule is matched at all.
Not strange when there is no COPY event happening.
I notice Inbox is mentioned in the configuration above (see below).
This tells me this log run with a different configuration than what you present above. There is no talk of INBOX, only '*'.
Debug: imapsieve: Matched static mailbox rule [2]
Debug: imapsieve: Matched static mailbox rule [1]
Which is correct. For an APPEND event "mailbox" and "from" mailboxes are the same.
So: Rule [1] matches because mailbox == "Spam" Rule [2] matches any mailbox and from == mailbox == "Spam"
Which is correct. Rule [1] doesn't match because mailbox == "Inbox" Rule [2] matches any mailbox, but from == mailbox == "Inbox", so it doesn't match either.
First of all, we should get a view on what Microsoft is doing by obtaining a rawlog, and then we can maybe find out why it is doing that. There may even be a way to disable that behavior.
Regards,
Stephan.
participants (3)
-
Aki Tuomi
-
Alex Cherevko
-
Stephan Bosch