Gotcha!!!!!!!!
It looks like you nailed it John! (Log and config attached)
The log looks now very different and my log entry is also shown.
Now I can continue working at this point. Adjusting the events i.e.
The reason was actually simple - but I spent a few evenings searching and was blind. I could have figured it out on my own! Thank you so much John for took such care of this issue!!!!!
Jens
imap(info@demo.example): Debug: Loading modules from directory: /usr/lib/dovecot/modules
imap(info@demo.example): Debug: Module loaded: /usr/lib/dovecot/modules/lib95_imap_sieve_plugin.so
imap(info@demo.example): Debug: Effective uid=10000, gid=10000, home=/var/mail/vhosts/demo.example/info
imap(info@demo.example): Debug: open(/proc/self/io) failed: Permission denied
imap(info@demo.example): Debug: Namespace inbox: type=private, prefix=INBOX/, sep=/, inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
imap(info@demo.example): Debug: maildir++: root=/var/mail/vhosts/demo.example/info/Maildir, index=, indexpvt=, control=, inbox=/var/mail/vhosts/demo.example/info/Maildir, alt=
imap(info@demo.example): Debug: Namespace : type=private, prefix=, sep=, inbox=no, hidden=yes, list=no, subscriptions=no location=fail::LAYOUT=none
imap(info@demo.example): Debug: none: root=, index=, indexpvt=, control=, inbox=, alt=
imap(info@demo.example): Debug: Mailbox INBOX/Junk: Mailbox opened
imap(info@demo.example): Debug: imapsieve: mailbox INBOX/Junk: APPEND event
imap(info@demo.example): Debug: duplicate db: Initialize
imap(info@demo.example): Debug: sieve: Pigeonhole version 0.5.19 (4eae2f79) initializing
imap(info@demo.example): Debug: sieve: include: sieve_global is not set; it is currently not possible to include `:global' scripts.
imap(info@demo.example): Debug: sieve: Sieve imapsieve plugin for Pigeonhole version 0.5.19 (4eae2f79) loaded
imap(info@demo.example): Debug: sieve: Sieve Extprograms plugin for Pigeonhole version 0.5.19 (4eae2f79) loaded
imap(info@demo.example): Debug: imapsieve: Static mailbox rule [1]: mailbox=INBOX/Junk' from=*' causes=(COPY APPEND) => before=`file:/usr/lib/dovecot/sieve/report-spam.sieve' after=(none)
imap(info@demo.example): Debug: imapsieve: Static mailbox rule [2]: mailbox=*' from=INBOX/Junk' causes=(COPY APPEND) => before=`file:/usr/lib/dovecot/sieve/report-ham.sieve' after=(none)
imap(info@demo.example): Debug: imapsieve: Matched static mailbox rule [2]
imap(info@demo.example): Debug: imapsieve: Matched static mailbox rule [1]
imap(info@demo.example): Debug: sieve: file storage: Using Sieve script path: /usr/lib/dovecot/sieve/report-spam.sieve
imap(info@demo.example): Debug: sieve: file storage: script: Opened script report-spam' from /usr/lib/dovecot/sieve/report-spam.sieve'
imap(info@demo.example): Debug: sieve: file storage: Using Sieve script path: /usr/lib/dovecot/sieve/report-ham.sieve
imap(info@demo.example): Debug: sieve: file storage: script: Opened script report-ham' from /usr/lib/dovecot/sieve/report-ham.sieve'
imap(info@demo.example): Debug: Mailbox INBOX/Junk: Mailbox opened
imap(info@demo.example): Debug: sieve: multi-script: Start execute sequence
imap(info@demo.example): Debug: sieve: Opening script 1 of 2 from `/usr/lib/dovecot/sieve/report-spam.sieve'
imap(info@demo.example): Debug: sieve: Loading script /usr/lib/dovecot/sieve/report-spam.sieve
imap(info@demo.example): Debug: sieve: Script binary /usr/lib/dovecot/sieve/report-spam.svbin successfully loaded
imap(info@demo.example): Debug: sieve: binary /usr/lib/dovecot/sieve/report-spam.svbin: save: not saving binary, because it is already stored
imap(info@demo.example): Debug: sieve: Executing script from `/usr/lib/dovecot/sieve/report-spam.svbin'
imap(info@demo.example): Debug: sieve: multi-script: Run script `/usr/lib/dovecot/sieve/report-spam.svbin'
imap(info@demo.example): Debug: sieve: Started running script `/usr/lib/dovecot/sieve/report-spam.svbin'
imap(info@demo.example): sieve: DEBUG: report-spam.sieve was running!
imap(info@demo.example): Debug: sieve: Finished running script `/usr/lib/dovecot/sieve/report-spam.svbin' (status=ok, resource usage: no usage recorded)
imap(info@demo.example): Debug: sieve: multi-script: Execute result
imap(info@demo.example): Debug: sieve: uid=3: Executing result (status=ok, commit=no)
imap(info@demo.example): Debug: sieve: uid=3: Starting execution of actions
imap(info@demo.example): Debug: sieve: uid=3: Executing actions
imap(info@demo.example): Debug: sieve: uid=3: Executing pipe action
imap(info@demo.example): Debug: sieve: action pipe: running program: sa-learn-spam.sh
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh: Created
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh: Pass environment: USER=info@demo.example
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh: Pass environment: HOME=/var/mail/vhosts/demo.example/info
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh: Pass environment: HOST=ServerIV-home.demo.example
imap(info@demo.example): Debug: Mailbox INBOX/Junk: UID 3: Opened mail because: mail stream
imap(info@demo.example): Debug: sieve: uid=3: Finished executing pipe action (status=ok, keep=implicit)
imap(info@demo.example): Debug: sieve: uid=3: Finished executing actions (status=ok, keep=implicit, executed=yes)
imap(info@demo.example): Debug: sieve: uid=3: Finished executing result (no commit, status=ok, keep=yes)
imap(info@demo.example): Debug: sieve: multi-script: Sequence active
imap(info@demo.example): Debug: sieve: Opening script 2 of 2 from `/usr/lib/dovecot/sieve/report-ham.sieve'
imap(info@demo.example): Debug: sieve: Loading script /usr/lib/dovecot/sieve/report-ham.sieve
imap(info@demo.example): Debug: sieve: Script binary /usr/lib/dovecot/sieve/report-ham.svbin successfully loaded
imap(info@demo.example): Debug: sieve: binary /usr/lib/dovecot/sieve/report-ham.svbin: save: not saving binary, because it is already stored
imap(info@demo.example): Debug: sieve: Executing script from `/usr/lib/dovecot/sieve/report-ham.svbin'
imap(info@demo.example): Debug: sieve: multi-script: Run script `/usr/lib/dovecot/sieve/report-ham.svbin'
imap(info@demo.example): Debug: sieve: Started running script `/usr/lib/dovecot/sieve/report-ham.svbin'
imap(info@demo.example): Debug: sieve: Finished running script `/usr/lib/dovecot/sieve/report-ham.svbin' (status=ok, resource usage: no usage recorded)
imap(info@demo.example): Debug: sieve: multi-script: Execute result
imap(info@demo.example): Debug: sieve: uid=3: Executing result (status=ok, commit=no)
imap(info@demo.example): Debug: sieve: uid=3: Starting execution of actions
imap(info@demo.example): Debug: sieve: uid=3: Executing actions
imap(info@demo.example): Debug: sieve: uid=3: Executing pipe action
imap(info@demo.example): Debug: sieve: action pipe: running program: sa-learn-ham.sh
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh: Created
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh: Pass environment: USER=info@demo.example
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh: Pass environment: HOME=/var/mail/vhosts/demo.example/info
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh: Pass environment: HOST=ServerIV-home.demo.example
imap(info@demo.example): Debug: sieve: uid=3: Finished executing pipe action (status=ok, keep=implicit)
imap(info@demo.example): Debug: sieve: uid=3: Finished executing actions (status=ok, keep=implicit, executed=yes)
imap(info@demo.example): Debug: sieve: uid=3: Finished executing result (no commit, status=ok, keep=yes)
imap(info@demo.example): Debug: sieve: multi-script: Sequence active
imap(info@demo.example): Debug: sieve: multi-script: Finishing sequence (status=ok)
imap(info@demo.example): Debug: sieve: uid=3: Executing result (status=ok, commit=yes)
imap(info@demo.example): Debug: sieve: uid=3: Starting execution of actions
imap(info@demo.example): Debug: sieve: uid=3: Executing actions
imap(info@demo.example): Debug: sieve: uid=3: Finished executing actions (status=ok, keep=implicit, executed=yes)
imap(info@demo.example): Debug: sieve: uid=3: Execute implicit keep (status=ok)
imap(info@demo.example): Debug: sieve: uid=3: Start storing into mailbox INBOX/Junk
imap(info@demo.example): Debug: sieve: uid=3: Executing implicit keep action
imap(info@demo.example): Debug: sieve: uid=3: Execute storing into mailbox 'INBOX/Junk'
imap(info@demo.example): Debug: Mailbox INBOX/Junk: Mailbox opened
imap(info@demo.example): Debug: sieve: uid=3: Updated existing mail in mailbox 'INBOX/Junk'
imap(info@demo.example): Debug: sieve: uid=3: Finished executing implicit keep action (status=ok)
imap(info@demo.example): Debug: sieve: uid=3: Finalizing actions
imap(info@demo.example): Debug: sieve: uid=3: Finalize pipe action (status=ok, action_status=ok, commit_status=ok, pre-commit=yes)
imap(info@demo.example): Debug: sieve: uid=3: Commit pipe action
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh: Establishing connection
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh: Forked child process
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh (2120): Connected to program
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh (2120): Finished streaming payload to program
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh (2120): Finished input to program
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh (2120): Disconnected
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh (2120): Waiting for program to finish after 0 msecs (timeout = 10000 msecs)
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh (2120): Child process ended
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-spam.sh (2120): Destroy
imap(info@demo.example): Debug: sieve: uid=3: pipe action: piped message to program `sa-learn-spam.sh'
imap(info@demo.example): Debug: sieve: uid=3: Finalize pipe action (status=ok, action_status=ok, commit_status=ok, pre-commit=yes)
imap(info@demo.example): Debug: sieve: uid=3: Commit pipe action
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh: Establishing connection
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh: Forked child process
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh (2121): Connected to program
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh (2121): Finished streaming payload to program
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh (2121): Finished input to program
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh (2121): Disconnected
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh (2121): Waiting for program to finish after 0 msecs (timeout = 10000 msecs)
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh (2121): Child process ended
imap(info@demo.example): Debug: program exec:/usr/lib/dovecot/sieve/sa-learn-ham.sh (2121): Destroy
imap(info@demo.example): Debug: sieve: uid=3: pipe action: piped message to program `sa-learn-ham.sh'
imap(info@demo.example): Debug: sieve: uid=3: Finished finalizing actions (status=ok, keep=implicit, committed=yes)
imap(info@demo.example): Debug: sieve: uid=3: Finalize implicit keep (status=ok)
imap(info@demo.example): Debug: sieve: uid=3: Finalize implicit keep action(status=ok, action_status=ok, commit_status=ok)
imap(info@demo.example): Debug: sieve: uid=3: Commit implicit keep action
imap(info@demo.example): Debug: sieve: uid=3: Commit storing into mailbox 'INBOX/Junk'
imap(info@demo.example): Debug: sieve: uid=3: left message in mailbox 'INBOX/Junk'
imap(info@demo.example): Debug: sieve: uid=3: Finish implicit keep action
imap(info@demo.example): Debug: sieve: uid=3: Finishing actions
imap(info@demo.example): Debug: sieve: uid=3: Finish pipe action
imap(info@demo.example): Debug: sieve: uid=3: Finish pipe action
imap(info@demo.example): Debug: sieve: uid=3: Finished executing result (final, status=ok, keep=yes)
imap(info@demo.example): Debug: sieve: multi-script: Sequence finished (status=ok, keep=yes)
imap(info@demo.example): Debug: sieve: multi-script: Destroy
imap(info@demo.example): Debug: Mailbox INBOX/Junk: Mailbox opened
imap(info@demo.example)<2107><Zu7qvEEcHyjAqB4a>: Debug: imapsieve: mailbox INBOX: FLAG event (changed flags: \Deleted)
imap(info@demo.example)<2107><Zu7qvEEcHyjAqB4a>: Debug: Mailbox INBOX: UID 3: Expunge requested
imap(info@demo.example)<2107><Zu7qvEEcHyjAqB4a>: Debug: Mailbox INBOX: UID 3: Mail expunged
#dovecot -n # 2.3.19.1 (9b53102964): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.19 (4eae2f79)
# OS: Linux 6.1.0-21-amd64 x86_64 Debian 12.5
# Hostname: ServerIV-home.demo.example
auth_mechanisms = plain login
mail_debug = yes
mail_location = maildir:~/Maildir
mail_privileged_group = mail
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope encoded-character vacation subaddress comparator-i;ascii-numeric relational regex imap4flags copy include variables body enotify environment mailbox date index ihave duplicate mime foreverypart extracttext imapsieve vnd.dovecot.imapsieve
namespace inbox {
hidden = no
ignore_on_failure = no
inbox = yes
list = yes
location =
mailbox Drafts {
auto = subscribe
special_use = \Drafts}
mailbox Junk {
auto = subscribe
special_use = \Junk}
mailbox Sent {
auto = subscribe
special_use = \Sent}
mailbox "Sent Messages" {
auto = subscribe
special_use = \Sent}
mailbox Trash {
auto = subscribe
special_use = \Trash}
prefix = INBOX/
separator = /
subscriptions = yes
type = private
}
passdb {
driver = pam
}
passdb {
args = scheme=CRYPT username_format=%u /etc/dovecot/users
driver = passwd-file
}
plugin {
imapsieve_mailbox1_before = file:/usr/lib/dovecot/sieve/report-spam.sieve
imapsieve_mailbox1_causes = COPY APPEND
imapsieve_mailbox1_name = INBOX/Junk
imapsieve_mailbox2_before = file:/usr/lib/dovecot/sieve/report-ham.sieve
imapsieve_mailbox2_causes = COPY APPEND
imapsieve_mailbox2_from = INBOX/Junk
imapsieve_mailbox2_name = *
sieve = file:~/sieve;active=~/.dovecot.sieve
sieve_after = /etc/dovecot/conf.d/custom-sieve/global_after.sieve
sieve_before = /etc/dovecot/conf.d/custom-sieve/global_before.sieve
sieve_global_extensions = +vnd.dovecot.pipe +vnd.dovecot.environment +vnd.dovecot.debug
sieve_pipe_bin_dir = /usr/lib/dovecot/sieve
sieve_plugins = sieve_imapsieve sieve_extprograms
}
protocols = imap lmtp sieve
service auth {
unix_listener /var/spool/postfix/private/auth {
mode = 0666}
}
service lmtp {
inet_listener lmtp {
address = 127.0.0.1 ::1
port = 24}
}
ssl_cert =
ssl_client_ca_dir = /etc/ssl/certs
ssl_dh = # hidden, use -P to show it
ssl_key = # hidden, use -P to show it
userdb {
driver = passwd
}
userdb {
args = username_format=%u /etc/dovecot/users
driver = passwd-file
}
verbose_proctitle = yes
protocol lmtp {
mail_plugins = " sieve"
}
protocol imap {
mail_plugins = " imap_sieve"
}
-----Ursprüngliche Nachricht----- Von: John Fawcett via dovecot dovecot@dovecot.org Gesendet: Dienstag, 2. Juli 2024 12:34 An: dovecot@dovecot.org Betreff: Re: AW: AW: AW: AW: IMAPSieve plugin will not run rspamd script
Hi Jens
just one update and some more insight looking at the code
Your causes should be COPY APPEND (whether applying proposed solution
(1) or (2). I updated inline below for solution (2).
Logic for that: I was testing from Thunderbird which is generating a MOVE event. In the imapsieve plugin code MOVE and COPY are treated almost the same, so my rule with COPY fire on MOVE too. In your case the event you're getting is APPEND, but none of your rules have that as a cause so won't match even if the mailbox matches.
John