imapsieve wrong matches on APPEND cause

[Stephan Bosch]

Hi,


Op 09/08/2018 om 22:09 schreef Alex Cherevko:
>
> 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.
>

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.

> 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-script.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 notice Inbox is mentioned in the configuration above (see below).

> 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)
>

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"

> 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
>
> ---------------------------------------- %< 
> ----------------------------------------
>

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.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://dovecot.org/pipermail/dovecot/attachments/20180816/d0502c1e/attachment-0001.html>