It is weird. At first, it seems that the logs are going fine. It goes like this for many minutes:
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field hdr.IN-REPLY-TO from
mail cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field hdr.MESSAGE-ID from
mail cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field hdr.SUBJECT from mail
cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field hdr.TO from mail
cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field hdr.X-PRIORITY from
mail cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field hdr.BCC from mail
cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field hdr.REPLY-TO from
mail cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field
hdr.DISPOSITION-NOTIFICATION-TO from mail cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Looked up field hdr.LIST-POST from
mail cache
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: multi-script: Start execute sequence
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: Executing script from
/var/mail/vmail/mail/sieve/global/report-ham.svbin' May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: multi-script: Run script /var/mail/vmail/mail/sieve/global/report-ham.svbin'
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: Started running script
/var/mail/vmail/mail/sieve/global/report-ham.svbin' May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>: Debug: sieve: Finished running script ok'
(status=/var/mail/vmail/mail/sieve/global/report-ham.svbin, resource
usage: no usage recorded)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: multi-script: Execute result
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Executing result (status=ok, commit=no)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Starting execution of actions
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Executing actions
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Executing pipe action
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: action pipe: running program: sa-learn-ham.sh
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Created
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Pass
environment: USER=francis@mydomain.com
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
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 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Pass
environment: HOST=fb58607074fd
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: Mailbox Archive: UID 25719: Opened mail because: mail stream
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Finished executing pipe action (status=ok,
keep=implicit)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Finished executing actions (status=ok,
keep=implicit)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Finished executing result (no commit,
status=ok, keep=yes)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: multi-script: Sequence active
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: multi-script: Finishing sequence (status=ok)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Executing result (status=ok, commit=yes)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Starting execution of actions
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Executing actions
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Finished executing actions (status=ok,
keep=implicit)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Execute implicit keep (failure=no)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Start storing into mailbox Archive
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Executing implicit keep action
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Execute storing into mailbox 'Archive'
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Updated existing mail in mailbox 'Archive'
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Finished executing implicit keep action
(status=ok)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Finalizing actions
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Finalize pipe action (status=ok,
action_status=ok, commit_status=ok, pre-commit=yes)
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: sieve: uid=25719: Commit pipe action
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh:
Establishing connection
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh: Forked
child process
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416):
Connected to program
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416):
Finished streaming payload to program
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416):
Finished input to program
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416):
Disconnected
May 01 14:20:04 imap(francis@mydomain.com)<226><zNW3d2MX9uku45qA>:
Debug: program
exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (416):
Waiting for program to finish after 6 msecs (timeout = 9994 msecs)
The client stays just like «Moving 1 of 4000 messages».
Then the logs start to go like this:
May 01 14:43:09 imap: Error: ERROR: the Bayes learn function returned an
error, please re-run with -D for more information at /usr/bin/sa-learn
line 500.
May 01 14:43:12 imap: Error: ERROR: the Bayes learn function returned an
error, please re-run with -D for more information at /usr/bin/sa-learn
line 500.
^C
root@fb58607074fd:/# tail -f /var/log/dovecot.log | grep Error
May 01 14:43:15 imap: Error: plugin: eval failed: interrupted at
/usr/bin/sa-learn line 513.
May 01 14:43:15 imap: Error: ERROR: the Bayes learn function returned an
error, please re-run with -D for more information at /usr/bin/sa-learn
line 500.
May 01 14:43:15 imap(francis@mydomain.com)<295><TwG1fGMXCuou45qA>:
Error: sieve: failed to pipe message to program sa-learn-ham.sh': refer to server log for more information. [2024-05-01 14:43:15] May 01 14:43:15 imap(francis@mydomain.com)<295><TwG1fGMXCuou45qA>: Error: sieve: Execution of script /var/mail/vmail/mail/sieve/global/report-ham.sieve failed May 01 14:43:16 imap(francis@mydomain.com)<292><Ei2ofGMXBeou45qA>: Error: program exec:/var/mail/vmail/mail/sieve/global/scripts/sa-learn-ham.sh (2978): Forcibly terminated with signal 15 May 01 14:43:16 imap(francis@mydomain.com)<292><Ei2ofGMXBeou45qA>: Error: sieve: failed to pipe message to program sa-learn-ham.sh': refer
to server log for more information. [2024-05-01 14:43:16]
May 01 14:43:16 imap(francis@mydomain.com)<292><Ei2ofGMXBeou45qA>:
Error: sieve: Execution of script
/var/mail/vmail/mail/sieve/global/report-ham.sieve failed
May 01 14:43:17 imap: Error: plugin: eval failed: interrupted at
/usr/bin/sa-learn line 513.
May 01 14:43:17 imap: Error: ERROR: the Bayes learn function returned an
error, please re-run with -D for more information at /usr/bin/sa-learn
line 500.
For many minutes, the mail client gets an error about reaching the max connections from ip, and the logs go on and on with the errors above.
What could be the issue?
Best, Francis
Francis Augusto Medeiros-Logeay Oslo, Norway