Re: Failing to archive many messages
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
I see report-ham, instead of archiving? I am not entirely sure if this is an efficient approach to archiving. My users can only set a flag for 'auto archiving' via sieve and then 3 months after every year messages are being moved by cron jobs, and modification logs are put into their accounts. This all is only happening in 'dead hours'.
If you want to analyze emails, why not do it with scheduled crons after they are archived?
Francis Augusto Medeiros-Logeay via dovecot skrev den 2024-05-09 12:29:
If you want to analyze emails, why not do it with scheduled crons after they are archived?
maybe ask for skip older then one day in here https://github.com/isbg/isbg/tree/master
while roundcube just set the needed flag for retest ?
wouldn't it reanalyze all archived messages anyway?
sometimes email is ham at recpt stage, while its spam later on test, this is why isbg is made imho :)
participants (3)
-
Benny Pedersen
-
Francis Augusto Medeiros-Logeay
-
Marc