Issue E-Mail-Security failed to pipe message to "es-learn-spam.sh"

[Puschendorf]

Server operating system version

Ubuntu 20.04.6

Plesk version and microupdate number

18.0.73

English: The email security plugin generates an error, which means that spam emails are not detected and moved. However, this only affects around 15 out of 200 email accounts. I have already checked the permissions for the folders and files.

Deutsch: Das E-Mail-Security-Plugin erzeugt einen Error und Spam-Mails werden dadurch nicht erkannt und verschoben. Das betrifft aber nur ca. 15 von 200 E-Mail-Postfächern. Die Rechte der Ordner und Dateien habe ich schon überprüft.

Error in mail.err:
Oct 28 08:14:12 xxxxx dovecot: service=imap, user=[email protected], ip=[xx.xxx.xx.xx]. Error: sieve: failed to pipe message to program 'es-learn-spam.sh': refer to server log for more information. [2025-10-28 08:14:12]
Oct 28 08:14:12 xxxxx dovecot: service=imap, user=[email protected], ip=[xx.xxx.xx.xx]. Error: sieve: Execution of script 'report-spam/es-report-spam' failed

 

[Sebahat.hadzhi]

Hello, @Puschendorf . Are the affected mailboxes significantly larger than the rest or they get abnormal amount of spam messages that are moved at once? It is possible for the issue to occur due to a timeout of the es-learn-spam.sh process.

 

[Puschendorf]

Hey Sebahat. Thanks for the quick response. A timeout error is certainly possible, but there are not a large number of spam emails. A single spam email arrives and triggers the error. The email accounts are of normal size. There were about 80 incidents in 24 hours - spread over the entire period. 14 mailboxes (out of 400) were affected.

 

[Sebahat.hadzhi]

Thank you for the confirmation. Can you please double-check /etc/dovecot/conf.d/96-email-security.conf and confirm if there is limit specified for sieve_extension_exec_timeout?

 

[Puschendorf]

No.

protocol imap {
mail_plugins {
imap_sieve = yes
}
}

sieve_plugins {
sieve_imapsieve = yes
sieve_extprograms = yes
}

sieve_global_extensions {
vnd.dovecot.pipe = yes
}

sieve_pipe_bin_dir = /usr/local/bin/dovecot-sieve
sieve_script global-after {
type = after
path = /var/qmail/popuser/es-global.sieve
}
namespace inbox {
mailbox Spam {
sieve_script report-spam {
type = before
cause = copy
path = /var/qmail/popuser/es-report-spam.sieve
}
}
imapsieve_from Spam {
sieve_script report-ham {
type = before
cause = copy
path = /var/qmail/popuser/es-report-ham.sieve
}
}
}

 

[Sebahat.hadzhi]

Thank you for the update. Could you please temporarily enable debug mode in Dovecot and double-check if there any more details in the logs?

 

[Puschendorf]

Oct 29 18:29:01 xxxxxxx.xx dovecot[12345]: service=imap, user=[email protected], ip=[xx.xx.xxx.xxx]. Debug: sieve: action pipe: executable path '/usr/local/bin/dovecot-sieve/es-learn-spam.sh' for program 'es-learn-spam.sh' not found


Here is the complete section:
Debug: Mailbox INBOX.Spam: imapsieve: MOVE event
Debug: Mailbox INBOX: UID 4241: Expunge requested
Debug: duplicate db: Initialize
Debug: sieve: Pigeonhole version 2.4.1-4 (0a86619f) initializing
Debug: Loading modules from directory: /usr/lib/dovecot/modules/sieve
Debug: Module loaded: /usr/lib/dovecot/modules/sieve/lib90_sieve_extprograms_plugin.so
Debug: Module loaded: /usr/lib/dovecot/modules/sieve/lib90_sieve_imapsieve_plugin.so
Debug: sieve: Sieve imapsieve plugin for Pigeonhole version 2.4.1-4 (0a86619f) loaded
Debug: sieve: Sieve Extprograms plugin for Pigeonhole version 2.4.1-4 (0a86619f) loaded
Debug: Mailbox INBOX.Spam: imapsieve: storage report-spam: file: Using Sieve script path: /var/qmail/popuser/es-report-spam.sieve
Debug: Mailbox INBOX.Spam: imapsieve: storage report-spam: file: script 'es-report-spam': Opened from 'report-spam'
Debug: Mailbox INBOX.Spam: Mailbox opened
Debug: sieve: multi-script: Start execute sequence
Debug: sieve: Opening script 1 of 1 from 'report-spam/es-report-spam'
Debug: sieve: Loading script 'report-spam/es-report-spam'
Debug: sieve: Script binary /var/qmail/popuser/es-report-spam.svbin successfully loaded
Debug: Mailbox INBOX.Spam: imapsieve: storage report-spam: file: script 'es-report-spam': Saving binary to '/var/qmail/popuser/es-report-spam.svbin'
Debug: sieve: binary /var/qmail/popuser/es-report-spam.svbin: save: not saving binary, because it is already stored
Debug: sieve: Executing script from '/var/qmail/popuser/es-report-spam.svbin'
Debug: sieve: multi-script: Run script '/var/qmail/popuser/es-report-spam.svbin'
Debug: sieve: Started running script '/var/qmail/popuser/es-report-spam.svbin'
Debug: sieve: Finished running script '/var/qmail/popuser/es-report-spam.svbin' (status=ok, resource usage: no usage recorded)
Debug: sieve: multi-script: Execute result
Debug: sieve: uid=946: Executing result (status=ok, commit=no)
Debug: sieve: uid=946: Starting execution of actions
Debug: sieve: uid=946: Executing actions
Debug: sieve: uid=946: Executing pipe action
Debug: sieve: action pipe: running program: es-learn-spam.sh
Debug: sieve: action pipe: executable path '/usr/local/bin/dovecot-sieve/es-learn-spam.sh' for program 'es-learn-spam.sh' not found
Debug: sieve: uid=946: Finished executing pipe action (status=ok, keep=implicit)
Debug: sieve: uid=946: Finished executing actions (status=ok, keep=implicit, executed=yes)
Debug: sieve: uid=946: Finished executing result (no commit, status=ok, keep=yes)
Debug: sieve: multi-script: Sequence active
Debug: sieve: multi-script: Finishing sequence (status=ok)
Debug: sieve: uid=946: Executing result (status=ok, commit=yes)
Debug: sieve: uid=946: Starting execution of actions
Debug: sieve: uid=946: Executing actions
Debug: sieve: uid=946: Finished executing actions (status=ok, keep=implicit, executed=yes)
Debug: sieve: uid=946: Execute implicit keep (status=ok)
Debug: sieve: uid=946: Start storing into mailbox INBOX.Spam
Debug: sieve: uid=946: Executing implicit keep action
Debug: sieve: uid=946: Execute storing into mailbox 'INBOX.Spam'
Debug: Mailbox INBOX.Spam: Mailbox opened
Debug: sieve: uid=946: Updated existing mail in mailbox 'INBOX.Spam'
Debug: sieve: uid=946: Finished executing implicit keep action (status=ok)
Debug: sieve: uid=946: Finalizing actions
Debug: sieve: uid=946: Finalize pipe action (status=ok, action_status=ok, commit_status=ok, pre-commit=yes)
Debug: sieve: uid=946: Commit pipe action
Error: sieve: failed to pipe message to program 'es-learn-spam.sh': refer to server log for more information. [2025-10-29 18:29:01]
Debug: sieve: uid=946: Finished finalizing actions (status=failure, keep=implicit, committed=no)
Debug: sieve: uid=946: Switch to failure implicit keep
Debug: sieve: uid=946: Roll back implicit keep action
Debug: sieve: uid=946: Roll back storing into mailbox 'INBOX.Spam'
Debug: sieve: uid=946: left message in mailbox 'INBOX.Spam'
Debug: sieve: uid=946: Execute implicit keep (status=failure)
Debug: sieve: uid=946: Start storing into mailbox INBOX.Spam
Debug: sieve: uid=946: Executing implicit keep action
Debug: sieve: uid=946: Execute storing into mailbox 'INBOX.Spam'
Debug: Mailbox INBOX.Spam: Mailbox opened
Debug: sieve: uid=946: Updated existing mail in mailbox 'INBOX.Spam'
Debug: sieve: uid=946: Finished executing implicit keep action (status=ok)
Debug: sieve: uid=946: Finalize implicit keep (status=failure)
Debug: sieve: uid=946: Finalize implicit keep action(status=ok, action_status=ok, commit_status=ok)
Debug: sieve: uid=946: Commit implicit keep action
Debug: sieve: uid=946: Commit storing into mailbox 'INBOX.Spam'
Debug: sieve: uid=946: left message in mailbox 'INBOX.Spam'
Debug: sieve: uid=946: Finish implicit keep action
Debug: sieve: uid=946: Finishing actions
Debug: sieve: uid=946: Finish pipe action
Debug: sieve: uid=946: Finished executing result (final, status=failure, keep=yes)
Debug: sieve: multi-script: Sequence finished (status=failure, keep=yes)
Debug: sieve: multi-script: Destroy
Error: sieve: Execution of script 'report-spam/es-report-spam' failed
Debug: Mailbox INBOX: UID 4241: Mail expunged