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.