I noticed that my sieve rules are taking a very long time when archiving messages. I can see on my logs that every message takes about two-three seconds to be evaluated.
My sieve for the Archive is this:
cat /var/mail/vmail/mail/sieve/global/report-ham.sieve require ["vnd.dovecot.pipe", "copy", "imapsieve", "environment", "variables"];
if environment :matches "imap.mailbox" "*" { set "mailbox" "${1}"; }
if string "${mailbox}" "Trash" { stop; }
if environment :matches "imap.user" "*" { set "username" "${1}"; }
pipe :copy "sa-learn-ham.sh" [ "${username}" ];
And my sa-learn-ham.sh is this:
#!/bin/sh export PATH="/usr/sbin:/usr/bin:/usr/local/bin:/usr/local/sbin:$PATH" exec /usr/bin/sa-learn -u ${1} —ham
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: multi-script: Start execute sequence
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: Executing script from /var/mail/vmail/mail/sieve/global/report-ham.svbin' May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: multi-script: Run script /var/mail/vmail/mail/sieve/global/report-ham.svbin'
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: Started running script /var/mail/vmail/mail/sieve/global/report-ham.svbin' May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: Finished running script ok' (status=/var/mail/vmail/mail/sieve/global/report-ham.svbin, resource usage: no usage recorded)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: multi-script: Execute result
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Executing result (status=ok, commit=no)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Starting execution of actions
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Executing actions
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Executing pipe action
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: action pipe: running program: sa-learn-ham.sh
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Created
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Pass environment: USER=francis@med-lo.eu
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Pass environment: HOME=/var/mail/vmail/med-lo.eu/francis
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Pass environment: HOST=fb58607074fd
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: Mailbox Archive: UID 191458: Opened mail because: mail stream
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Finished executing pipe action (status=ok, keep=implicit)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Finished executing actions (status=ok, keep=implicit)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Finished executing result (no commit, status=ok, keep=yes)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: multi-script: Sequence active
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: multi-script: Finishing sequence (status=ok)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Executing result (status=ok, commit=yes)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Starting execution of actions
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Executing actions
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Finished executing actions (status=ok, keep=implicit)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Execute implicit keep (failure=no)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Start storing into mailbox Archive
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Executing implicit keep action
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Execute storing into mailbox 'Archive'
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Updated existing mail in mailbox 'Archive'
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Finished executing implicit keep action (status=ok)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Finalizing actions
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Finalize pipe action (status=ok, action_status=ok, commit_status=ok, pre-commit=yes)
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: sieve: uid=191458: Commit pipe action
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Establishing connection
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Forked child process
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (9354): Connected to program
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (9354): Finished streaming payload to program
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (9354): Finished input to program
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (9354): Disconnected
May 09 09:17:10 imap(francis@med-lo.eu)<9349><4gm6NAAYsagKCige>: Debug: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (9354): Waiting for program to finish after 4 msecs (timeout = 9996 msecs)
I also noticed this happens for a few accounts. Do you know what could be causing this?
Best, Francis