Re: imapsieve removeflag ignored

8 Oct 2022


      Hi,
Dňa Fri, 7 Oct 2022 08:19:33 +0300 (EEST) Aki Tuomi
aki.tuomi@open-xchange.com napísal:
...
We gave this a try and it seems to work just fine. Can you provide us
with mail_debug=yes logs, and also
plugin {
sieve_trace_debug = yes
sieve_trace_dir = ~/sieve_debug/
sieve_trace_level = matching
}
I did four IMAP actions, move to Junk and move from Junk twice, hope
that is what you need to see. I changed all occurrences of user
and domain in results only, no other changes.
dovecot debug log (without LMTP, it is in separate file, i don't know
if that is important) -- beware, in between are reports received, but i
leave that intact:
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: UID COPY
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: COPY event
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: Matched static mailbox rule [2]
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: file storage: Using Sieve script path: /etc/dovecot/sieve/imap/report-spam.sieve
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: file storage: script: Opened script report-spam' from /etc/dovecot/sieve/imap/report-spam.sieve'
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Opening script 1 of 1 from /etc/dovecot/sieve/imap/report-spam.sieve' Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Loading script /etc/dovecot/sieve/imap/report-spam.sieve Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Script binary /etc/dovecot/sieve/imap/report-spam.svbin successfully loaded Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: binary /etc/dovecot/sieve/imap/report-spam.svbin: save: not saving binary, because it is already stored Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Executing script from /etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Started running script /etc/dovecot/sieve/imap/report-spam.svbin' Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 882: Opened mail because: header Return-Path (Mail has other cached fields, reset_id=1544995471) Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: action execute: running program: bogofilter Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Created Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: USER=user@example.org Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: HOME=/srv/vmail/example.org/user Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: HOST=dovex.skk Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 882: Opened mail because: mail stream Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Establishing connection Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Forked child process Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Connected to program Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Finished streaming payload to program Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Finished input to program Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Disconnected Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Waiting for program to finish after 0 msecs (timeout = 10000 msecs) Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Child process ended Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Destroy Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Info: sieve: DEBUG: Learned SPAM (only) Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Finished running script /etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 882: Opened mail because: mail stream
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connection created
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Created
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Add recipient
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Send
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Start
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Add transaction
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Looking up IP address
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connecting to 127.0.0.1:25
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connecting
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Waiting for connect (fd=34) to finish for max 0 msecs
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Client connected (fd=34)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connected to server (from 127.0.0.1:58182)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received greeting from server: 220 dovex.skk ESMTP Sat, 08 Oct 2022 09:22:09 +0200
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Sending EHLO handshake
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command EHLO: Submitted with priority
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command EHLO: Sent: EHLO dovex.skk
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command EHLO: Got reply (1/1): 250 dovex.skk Hello localhost [127.0.0.1] SIZE 52428800 8BITMIME PIPELINING CHUNKING STARTTLS PRDR HELP (1 commands pending, 0 commands queued)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received handshake reply
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received server capabilities
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connection ready
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command EHLO: Destroy (0 commands pending, 0 commands queued)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Start next transaction
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Connecton is ready for transaction
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending MAIL command
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Submitted
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending recipients
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Submitted
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending data
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Submitted
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: RCPT replies are still pending (1/1)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Sent: MAIL FROM:<>
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Sent: RCPT TO:user+learn@example.org
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Finished reading payload stream
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Finished sending payload
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Sent: BDAT 1972 LAST
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Start timeout
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Got reply (1/1): 250 OK (3 commands pending, 0 commands queued)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Reset timeout
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Got MAIL reply: 250 OK
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Destroy (2 commands pending, 0 commands queued)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Got reply (1/1): 250 Accepted (2 commands pending, 0 commands queued)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Reset timeout
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Got RCPT reply: 250 Accepted
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: rcpt user+learn@example.org: Aborted
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Got all RCPT replies and transaction is complete
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Initiate next transaction
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Destroy (1 commands pending, 0 commands queued)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Got reply (1/1): 250  1972 byte chunk, total 1972 OK id=1oh49x-001bcI-9l (1 commands pending, 0 commands queued)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: No commands pending; stop timeout
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: rcpt user+learn@example.org: Finished
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Finished
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Destroy
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Abort
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Abort transaction
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Destroy (0 commands pending, 0 commands queued)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected: Connection closed (fd=34)
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Destroy
Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=882: report action: sent abuse' report to <user+learn@example.org> Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=882: left message in mailbox 'Junk' Oct 08 09:22:09 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): Started userdb lookup Oct 08 09:22:09 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): auth USER input: user@example.org uid=130 gid=130 namespace/inbox/mailbox=learn.alerty namespace/inbox/mailbox/learn.alerty/name=learn.alerty namespace/inbox/mailbox/learn.alerty/autoexpunge=30d Oct 08 09:22:09 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): Finished userdb lookup (username=user@example.org uid=130 gid=130 namespace/inbox/mailbox=learn.alerty namespace/inbox/mailbox/learn.alerty/name=learn.alerty namespace/inbox/mailbox/learn.alerty/autoexpunge=30d) Oct 08 09:22:09 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox=learn.alerty Oct 08 09:22:09 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/autoexpunge=30d Oct 08 09:22:09 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/name=learn.alerty Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Effective uid=130, gid=130, home=/srv/vmail/example.org/user Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota root: name=User quota backend=count args= Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=Trash bytes=+52428800 messages=0 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=Junk bytes=+104857600 messages=0 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=Sent bytes=+104857600 messages=0 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota grace: root=User quota bytes=52428800 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: maildir++: root=/srv/vmail/example.org/user/Maildir, index=, indexpvt=, control=, inbox=/srv/vmail/example.org/user/Maildir, alt= Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: acl username = user@example.org Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: owner = 1 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Namespace pub: type=public, prefix=Verejné., sep=., inbox=no, hidden=no, list=yes, subscriptions=no location=maildir:/srv/vmail-public:INDEXPVT=~/public:UTF-8 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: maildir++: root=/srv/vmail-public, index=, indexpvt=/srv/vmail/example.org/user/public, control=, inbox=, alt= Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: acl username = user@example.org Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: owner = 0 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Namespace share: type=shared, prefix=Zdieľané.%u., sep=., inbox=no, hidden=no, list=children, subscriptions=no location=maildir:%h/Maildir:INDEXPVT=~/shared/%u Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt= Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: fts: Indexes disabled for namespace 'Zdieľané.%u.' Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: acl username = user@example.org Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: owner = 0 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Namespace Virtual: type=private, prefix=Virtual., sep=., inbox=no, hidden=no, list=yes, subscriptions=no location=virtual:/usr/local/etc/vmail/virtual:INDEX=~/virtual:UTF-8 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: fs: root=/usr/local/etc/vmail/virtual, index=/srv/vmail/example.org/user/virtual, indexpvt=, control=, inbox=, alt= Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: acl username = user@example.org Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: owner = 1 Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: Mailbox opened because: indexing Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: file /srv/vmail/example.org/user/Maildir/.learn/dovecot-acl not found Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 126: Opened mail because: prefetch Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 126: Opened mail because: access Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 126: Opened mail because: precache Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 126: Opened mail because: fts indexing Oct 08 09:22:09 indexer-worker(user@example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Info: Indexed 1 messages in learn (UIDs 126..126) Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX.tabletka: FLAG event (changed flags: \Deleted) Oct 08 09:22:09 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: SELECT Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: UID COPY Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: quota count Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: quota count Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: COPY event Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: Matched static mailbox rule [3] Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: file storage: Using Sieve script path: /etc/dovecot/sieve/imap/report-ham.sieve Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: file storage: script: Opened script report-ham' from /etc/dovecot/sieve/imap/report-ham.sieve' Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Opening script 1 of 1 from /etc/dovecot/sieve/imap/report-ham.sieve'
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Loading script /etc/dovecot/sieve/imap/report-ham.sieve
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Script binary /etc/dovecot/sieve/imap/report-ham.svbin successfully loaded
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: binary /etc/dovecot/sieve/imap/report-ham.svbin: save: not saving binary, because it is already stored
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Executing script from /etc/dovecot/sieve/imap/report-ham.svbin' Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Started running script /etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: action execute: running program: bogofilter
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Created
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: USER=user@example.org
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: HOME=/srv/vmail/example.org/user
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: HOST=dovex.skk
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: UID 38627: Opened mail because: mail stream
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Establishing connection
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Forked child process
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Connected to program
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Finished streaming payload to program
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Finished input to program
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Disconnected
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Waiting for program to finish after 1 msecs (timeout = 9999 msecs)
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Child process ended
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Destroy
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Info: sieve: DEBUG: Learned HAM (and unlearned)
Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Finished running script /etc/dovecot/sieve/imap/report-ham.svbin' Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=38627: left message in mailbox 'INBOX' Oct 08 09:22:13 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): Started userdb lookup Oct 08 09:22:13 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): auth USER input: user@example.org uid=130 gid=130 namespace/inbox/mailbox=learn.alerty namespace/inbox/mailbox/learn.alerty/name=learn.alerty namespace/inbox/mailbox/learn.alerty/autoexpunge=30d Oct 08 09:22:13 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): Finished userdb lookup (username=user@example.org uid=130 gid=130 namespace/inbox/mailbox=learn.alerty namespace/inbox/mailbox/learn.alerty/name=learn.alerty namespace/inbox/mailbox/learn.alerty/autoexpunge=30d) Oct 08 09:22:13 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox=learn.alerty Oct 08 09:22:13 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/autoexpunge=30d Oct 08 09:22:13 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/name=learn.alerty Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Effective uid=130, gid=130, home=/srv/vmail/example.org/user Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota root: name=User quota backend=count args= Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=Trash bytes=+52428800 messages=0 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=Junk bytes=+104857600 messages=0 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=Sent bytes=+104857600 messages=0 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota grace: root=User quota bytes=52428800 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: maildir++: root=/srv/vmail/example.org/user/Maildir, index=, indexpvt=, control=, inbox=/srv/vmail/example.org/user/Maildir, alt= Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: acl username = user@example.org Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: owner = 1 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Namespace pub: type=public, prefix=Verejné., sep=., inbox=no, hidden=no, list=yes, subscriptions=no location=maildir:/srv/vmail-public:INDEXPVT=~/public:UTF-8 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: maildir++: root=/srv/vmail-public, index=, indexpvt=/srv/vmail/example.org/user/public, control=, inbox=, alt= Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: acl username = user@example.org Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: owner = 0 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Namespace share: type=shared, prefix=Zdieľané.%u., sep=., inbox=no, hidden=no, list=children, subscriptions=no location=maildir:%h/Maildir:INDEXPVT=~/shared/%u Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt= Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: fts: Indexes disabled for namespace 'Zdieľané.%u.' Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: acl username = user@example.org Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: owner = 0 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Namespace Virtual: type=private, prefix=Virtual., sep=., inbox=no, hidden=no, list=yes, subscriptions=no location=virtual:/usr/local/etc/vmail/virtual:INDEX=~/virtual:UTF-8 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: fs: root=/usr/local/etc/vmail/virtual, index=/srv/vmail/example.org/user/virtual, indexpvt=, control=, inbox=, alt= Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: acl username = user@example.org Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: owner = 1 Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: Mailbox opened because: indexing Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: file /srv/vmail/example.org/user/Maildir/dovecot-acl not found Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38627: Opened mail because: prefetch Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38627: Opened mail because: access Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38627: Opened mail because: fts indexing Oct 08 09:22:13 indexer-worker(user@example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Info: Indexed 1 messages in INBOX (UIDs 38627..38627) Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: FLAG event (changed flags: \Deleted) Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: SELECT Oct 08 09:22:13 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: FLAG event (changed flags: $Junk) Oct 08 09:22:19 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count Oct 08 09:22:19 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: quota count Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: SELECT Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Trash: Mailbox opened because: SELECT Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: SELECT Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: SELECT Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: UID 126: Opened mail because: 8/8 headers not cached (first=CC) (Cache file is empty, reset_id=1599412799) Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Verejné.Novinky: Mailbox opened because: STATUS Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Virtual.Dôležité: Mailbox opened because: STATUS Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: virtual mailbox Virtual.Dôležité: STATUS Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox system: Mailbox opened because: virtual mailbox Virtual.Dôležité: STATUS Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: virtual mailbox Virtual.Dôležité: STATUS Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: virtual mailbox Virtual.Dôležité: STATUS Oct 08 09:22:20 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Virtual.Dôležité: Recreated /srv/vmail/example.org/user/virtual/Dôležité/dovecot.index because: .log read 25232..16820 > rewrite_min_log_bytes 8192 Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Virtual.Prílohy: Mailbox opened because: STATUS Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: virtual mailbox Virtual.Prílohy: STATUS Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox system: Mailbox opened because: virtual mailbox Virtual.Prílohy: STATUS Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: virtual mailbox Virtual.Prílohy: STATUS Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: virtual mailbox Virtual.Prílohy: STATUS Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Virtual.Prílohy: Mailbox opened because: SELECT Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: virtual mailbox Virtual.Prílohy: SELECT Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: virtual mailbox Virtual.Prílohy: SELECT Oct 08 09:22:21 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: UID 126: Opened mail because: 8/8 headers not cached (first=CC) (Cache file is empty, reset_id=1599412799) Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: SELECT Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: UID COPY Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: COPY event Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: Matched static mailbox rule [2] Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: file storage: Using Sieve script path: /etc/dovecot/sieve/imap/report-spam.sieve Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: file storage: script: Opened script report-spam' from /etc/dovecot/sieve/imap/report-spam.sieve' Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Opening script 1 of 1 from /etc/dovecot/sieve/imap/report-spam.sieve'
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Loading script /etc/dovecot/sieve/imap/report-spam.sieve
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Script binary /etc/dovecot/sieve/imap/report-spam.svbin successfully loaded
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: binary /etc/dovecot/sieve/imap/report-spam.svbin: save: not saving binary, because it is already stored
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Executing script from /etc/dovecot/sieve/imap/report-spam.svbin' Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Started running script /etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 883: Opened mail because: header Return-Path (Mail has other cached fields, reset_id=1544995471)
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: action execute: running program: bogofilter
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Created
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: USER=user@example.org
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: HOME=/srv/vmail/example.org/user
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: HOST=dovex.skk
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 883: Opened mail because: mail stream
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Establishing connection
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Forked child process
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Connected to program
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Finished streaming payload to program
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Finished input to program
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Disconnected
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Waiting for program to finish after 1 msecs (timeout = 9999 msecs)
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Child process ended
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Destroy
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Info: sieve: DEBUG: Learned SPAM (and unlearned)
Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Finished running script /etc/dovecot/sieve/imap/report-spam.svbin' Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 883: Opened mail because: mail stream Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connection created Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Created Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Add recipient Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Send Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Start Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Add transaction Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Looking up IP address Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connecting to 127.0.0.1:25 Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connecting Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Waiting for connect (fd=37) to finish for max 0 msecs Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Client connected (fd=37) Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connected to server (from 127.0.0.1:58184) Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received greeting from server: 220 dovex.skk ESMTP Sat, 08 Oct 2022 09:22:25 +0200 Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Sending EHLO handshake Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command EHLO: Submitted with priority Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command EHLO: Sent: EHLO dovex.skk Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command EHLO: Got reply (1/1): 250 dovex.skk Hello localhost [127.0.0.1] SIZE 52428800 8BITMIME PIPELINING CHUNKING STARTTLS PRDR HELP (1 commands pending, 0 commands queued) Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received handshake reply Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received server capabilities Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connection ready Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command EHLO: Destroy (0 commands pending, 0 commands queued) Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Start next transaction Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Connecton is ready for transaction Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending MAIL command Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Submitted Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending recipients Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Submitted Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending data Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Submitted Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: RCPT replies are still pending (1/1) Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Sent: MAIL FROM:<> Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Sent: RCPT TO:<user+learn@example.org> Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Finished reading payload stream Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Finished sending payload Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Sent: BDAT 1972 LAST Oct 08 09:22:25 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Start timeout Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Got reply (1/1): 250 OK (3 commands pending, 0 commands queued) Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Reset timeout Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Got MAIL reply: 250 OK Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Destroy (2 commands pending, 0 commands queued) Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Got reply (1/1): 250 Accepted (2 commands pending, 0 commands queued) Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Reset timeout Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Got RCPT reply: 250 Accepted Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: rcpt <user+learn@example.org>: Aborted Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Got all RCPT replies and transaction is complete Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Initiate next transaction Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Destroy (1 commands pending, 0 commands queued) Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Got reply (1/1): 250  1972 byte chunk, total 1972 OK id=1oh4AD-001bcS-UW (1 commands pending, 0 commands queued) Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: No commands pending; stop timeout Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: rcpt <user+learn@example.org>: Finished Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Finished Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Destroy Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Abort Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Abort transaction Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Destroy (0 commands pending, 0 commands queued) Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected: Connection closed (fd=37) Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Destroy Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=883: report action: sent abuse' report to user+learn@example.org
Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=883: left message in mailbox 'Junk'
Oct 08 09:22:26 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): Started userdb lookup
Oct 08 09:22:26 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): auth USER input: user@example.org uid=130 gid=130 namespace/inbox/mailbox=learn.alerty namespace/inbox/mailbox/learn.alerty/name=learn.alerty namespace/inbox/mailbox/learn.alerty/autoexpunge=30d
Oct 08 09:22:26 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): Finished userdb lookup (username=user@example.org uid=130 gid=130 namespace/inbox/mailbox=learn.alerty namespace/inbox/mailbox/learn.alerty/name=learn.alerty namespace/inbox/mailbox/learn.alerty/autoexpunge=30d)
Oct 08 09:22:26 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox=learn.alerty
Oct 08 09:22:26 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/autoexpunge=30d
Oct 08 09:22:26 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/name=learn.alerty
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Effective uid=130, gid=130, home=/srv/vmail/example.org/user
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Quota root: name=User quota backend=count args=
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Quota rule: root=User quota mailbox=Trash bytes=+52428800 messages=0
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Quota rule: root=User quota mailbox=Junk bytes=+104857600 messages=0
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Quota rule: root=User quota mailbox=Sent bytes=+104857600 messages=0
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Quota grace: root=User quota bytes=52428800
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: maildir++: root=/srv/vmail/example.org/user/Maildir, index=, indexpvt=, control=, inbox=/srv/vmail/example.org/user/Maildir, alt=
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: acl username = user@example.org
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: owner = 1
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Namespace pub: type=public, prefix=Verejné., sep=., inbox=no, hidden=no, list=yes, subscriptions=no location=maildir:/srv/vmail-public:INDEXPVT=~/public:UTF-8
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: maildir++: root=/srv/vmail-public, index=, indexpvt=/srv/vmail/example.org/user/public, control=, inbox=, alt=
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: acl username = user@example.org
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: owner = 0
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Namespace share: type=shared, prefix=Zdieľané.%u., sep=., inbox=no, hidden=no, list=children, subscriptions=no location=maildir:%h/Maildir:INDEXPVT=~/shared/%u
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: fts: Indexes disabled for namespace 'Zdieľané.%u.'
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: acl username = user@example.org
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: owner = 0
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Namespace Virtual: type=private, prefix=Virtual., sep=., inbox=no, hidden=no, list=yes, subscriptions=no location=virtual:/usr/local/etc/vmail/virtual:INDEX=~/virtual:UTF-8
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: fs: root=/usr/local/etc/vmail/virtual, index=/srv/vmail/example.org/user/virtual, indexpvt=, control=, inbox=, alt=
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: acl username = user@example.org
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl: owner = 1
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Mailbox learn: Mailbox opened because: indexing
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: acl vfile: file /srv/vmail/example.org/user/Maildir/.learn/dovecot-acl not found
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Mailbox learn: UID 127: Opened mail because: prefetch
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Mailbox learn: UID 127: Opened mail because: access
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Mailbox learn: UID 127: Opened mail because: precache
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Debug: Mailbox learn: UID 127: Opened mail because: fts indexing
Oct 08 09:22:26 indexer-worker(user@example.org)<382818>UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ: Info: Indexed 1 messages in learn (UIDs 127..127)
Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: FLAG event (changed flags: \Deleted)
Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: SELECT
Oct 08 09:22:26 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: FLAG event (changed flags: $NotJunk)
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: UID COPY
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: COPY event
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: Matched static mailbox rule [3]
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: file storage: Using Sieve script path: /etc/dovecot/sieve/imap/report-ham.sieve
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: file storage: script: Opened script report-ham' from /etc/dovecot/sieve/imap/report-ham.sieve'
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Opening script 1 of 1 from /etc/dovecot/sieve/imap/report-ham.sieve' Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Loading script /etc/dovecot/sieve/imap/report-ham.sieve Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Script binary /etc/dovecot/sieve/imap/report-ham.svbin successfully loaded Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: binary /etc/dovecot/sieve/imap/report-ham.svbin: save: not saving binary, because it is already stored Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Executing script from /etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Started running script /etc/dovecot/sieve/imap/report-ham.svbin' Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: action execute: running program: bogofilter Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Created Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: USER=user@example.org Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: HOME=/srv/vmail/example.org/user Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: HOST=dovex.skk Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: UID 38628: Opened mail because: mail stream Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Establishing connection Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Forked child process Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Connected to program Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Finished streaming payload to program Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Finished input to program Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Disconnected Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Waiting for program to finish after 0 msecs (timeout = 10000 msecs) Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Child process ended Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Destroy Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Info: sieve: DEBUG: Learned HAM (and unlearned) Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Finished running script /etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=38628: left message in mailbox 'INBOX'
Oct 08 09:22:30 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): Started userdb lookup
Oct 08 09:22:30 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): auth USER input: user@example.org uid=130 gid=130 namespace/inbox/mailbox=learn.alerty namespace/inbox/mailbox/learn.alerty/name=learn.alerty namespace/inbox/mailbox/learn.alerty/autoexpunge=30d
Oct 08 09:22:30 indexer-worker(user@example.org)<382818><>: Debug: auth-master: userdb lookup(user@example.org): Finished userdb lookup (username=user@example.org uid=130 gid=130 namespace/inbox/mailbox=learn.alerty namespace/inbox/mailbox/learn.alerty/name=learn.alerty namespace/inbox/mailbox/learn.alerty/autoexpunge=30d)
Oct 08 09:22:30 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox=learn.alerty
Oct 08 09:22:30 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/autoexpunge=30d
Oct 08 09:22:30 indexer-worker(user@example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/name=learn.alerty
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Effective uid=130, gid=130, home=/srv/vmail/example.org/user
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Quota root: name=User quota backend=count args=
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Quota rule: root=User quota mailbox=Trash bytes=+52428800 messages=0
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Quota rule: root=User quota mailbox=Junk bytes=+104857600 messages=0
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Quota rule: root=User quota mailbox=Sent bytes=+104857600 messages=0
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Quota grace: root=User quota bytes=52428800
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Namespace inbox: type=private, prefix=, sep=., inbox=yes, hidden=no, list=yes, subscriptions=yes location=maildir:~/Maildir
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: maildir++: root=/srv/vmail/example.org/user/Maildir, index=, indexpvt=, control=, inbox=/srv/vmail/example.org/user/Maildir, alt=
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: acl username = user@example.org
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: owner = 1
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Namespace pub: type=public, prefix=Verejné., sep=., inbox=no, hidden=no, list=yes, subscriptions=no location=maildir:/srv/vmail-public:INDEXPVT=~/public:UTF-8
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: maildir++: root=/srv/vmail-public, index=, indexpvt=/srv/vmail/example.org/user/public, control=, inbox=, alt=
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: acl username = user@example.org
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: owner = 0
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Namespace share: type=shared, prefix=Zdieľané.%u., sep=., inbox=no, hidden=no, list=children, subscriptions=no location=maildir:%h/Maildir:INDEXPVT=~/shared/%u
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: fts: Indexes disabled for namespace 'Zdieľané.%u.'
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: acl username = user@example.org
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: owner = 0
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Namespace Virtual: type=private, prefix=Virtual., sep=., inbox=no, hidden=no, list=yes, subscriptions=no location=virtual:/usr/local/etc/vmail/virtual:INDEX=~/virtual:UTF-8
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: fs: root=/usr/local/etc/vmail/virtual, index=/srv/vmail/example.org/user/virtual, indexpvt=, control=, inbox=, alt=
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: acl username = user@example.org
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl: owner = 1
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Mailbox INBOX: Mailbox opened because: indexing
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: acl vfile: file /srv/vmail/example.org/user/Maildir/dovecot-acl not found
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Mailbox INBOX: UID 38628: Opened mail because: prefetch
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Mailbox INBOX: UID 38628: Opened mail because: access
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Debug: Mailbox INBOX: UID 38628: Opened mail because: fts indexing
Oct 08 09:22:30 indexer-worker(user@example.org)<382818>tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ: Info: Indexed 1 messages in INBOX (UIDs 38628..38628)
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: FLAG event (changed flags: \Deleted)
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: SELECT
Oct 08 09:22:30 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: FLAG event (changed flags: $Junk)
Oct 08 09:22:36 imap(user@example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count
(lines will be wrapped, thus i attached it too).
I used slightly different sieve script -- the removeflag is moved after
condition with both Junk related flags, here are full scripts (report
targed changed):

report-ham.sieve:

require ["vnd.dovecot.report", "vnd.dovecot.execute", "vnd.dovecot.debug"];
require ["environment", "imapsieve", "variables", "imap4flags"];
if anyof (environment "imap.mailbox" "Trash",
environment "imap.mailbox" "Junk") {
# Putting spam to Trash or copying inside Junk is not significant
stop;
}
if hasflag "$Junk" {
execute :pipe "bogofilter" ["-Sn"];
debug_log "Learned HAM (and unlearned)";
} else {
execute :pipe "bogofilter" ["-n"];
debug_log "Learned HAM (only)";
}
# mark as learned
removeflag "$Junk $NotJunk";
addflag "$NotJunk";
if header :is "X-Spam-Status" "Yes" {
if environment :matches "imap.user" "*" {
set "username" "${1}";
} else {
set "username" "Unknown";
}
report "not-spam" "Používateľ ${username} označil správu ako HAM." "user@example.org";
}

report-spam.sieve

require ["vnd.dovecot.report", "vnd.dovecot.execute", "vnd.dovecot.debug"];
require ["environment", "imap4flags", "imapsieve", "variables", "mime"];
# prevent reports loop
if allof(header  :is "Return-Path" "<>",
header  :mime :contenttype "Content-Type" "multipart/report",
exists  :mime ["X-Sieve", "Auto-Submitted"],
header  :mime :anychild :contenttype "Content-Type" "message/feedback-report",
header  :mime :anychild :contenttype "Content-Type" "message/rfc822") {
stop;
}
if hasflag "$NotJunk" {
execute :pipe "bogofilter" ["-Ns"];
debug_log "Learned SPAM (and unlearned)";
} else {
execute :pipe "bogofilter" ["-s"];
debug_log "Learned SPAM (only)";
}
# mark as learned
removeflag "$NotJunk $Junk";
addflag "$Junk";
if not header :is "X-Spam-Status" "Yes" {
if environment :matches "imap.user" "*" {
set "username" "${1}";
} else {
set "username" "Unknown";
}
report "abuse" "Používateľ ${username} označil správu ako SPAM." "user@example.org";
}
Sieve trace files, originally four files:
Sieve trace log for IMAPSIEVE:
Username: user@example.org
Session ID: tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB
Source mailbox: INBOX.tabletka
Destination mailbox: Junk
Cause: COPY
Filtering message:
UID: 882
  ## Started executing script 'report-spam'
5: header test
5:   starting :is' match with i;ascii-casemap' comparator:
5:   extracting Return-Path' headers from message    5:   matching value user@example.org'
5:     with key <>' => 0    5:   finishing match with result: not matched    5: jump if result is false    5:   jumping to line 13   13: hasflag test   13:   starting :is' match with i;ascii-casemap' comparator:   13:   matching value $HasNoAttachment'
13:     with key $NotJunk' => 0   13:   finishing match with result: not matched   13: jump if result is false   13:   jumping to line 16   17: execute action   17:   execute program bogofilter'
17:   executed program successfully
18: debug_log "Learned SPAM (only)"
21: removeflag command
21:   remove flags $NotJunk $Junk'   22: addflag command   22:   add flags $Junk'
24: header test
24:   starting :is' match with i;ascii-casemap' comparator:
24:   extracting X-Spam-Status' headers from message   24:   finishing match with result: not matched   24: jump if result is true   24:   not jumping   25: environment test   25:   starting :matches' match with i;ascii-casemap' comparator:   25:   matching value user@example.org'
25:     with key *' => 1   25:   finishing match with result: matched   25: jump if result is false   25:   not jumping   26: set command   26:   assign username' [0] = "user@example.org"
26: jumping to line 31
31: report action
31:   report incoming message as `abuse' to address user+learn@example.org
## Finished executing script 'report-spam'
Sieve trace log for IMAPSIEVE:
Username: user@example.org
Session ID: tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB
Source mailbox: Junk
Destination mailbox: INBOX
Cause: COPY
Filtering message:
UID: 38627
  ## Started executing script 'report-ham'
4: environment test
4:   starting :is' match with i;ascii-casemap' comparator:
4:   matching value INBOX'    4:     with key Trash' => 0
4:   finishing match with result: not matched
4: jump if result is true
4:   not jumping
5: environment test
5:   starting :is' match with i;ascii-casemap' comparator:
5:   matching value INBOX'    5:     with key Junk' => 0
5:   finishing match with result: not matched
5: jump if result is true
5:   not jumping
5: jumping to line 10
10: hasflag test
10:   starting :is' match with i;ascii-casemap' comparator:
10:   matching value $HasNoAttachment'   10:     with key $Junk' => 0
10:   matching value $Junk'   10:     with key $Junk' => 1
10:   finishing match with result: matched
10: jump if result is false
10:   not jumping
11: execute action
11:   execute program bogofilter'   11:   executed program successfully   12: debug_log "Learned HAM (and unlearned)"   12: jumping to line 18   18: removeflag command   18:   remove flags $Junk $NotJunk'
19: addflag command
19:   add flags $NotJunk'   21: header test   21:   starting :is' match with i;ascii-casemap' comparator:   21:   extracting X-Spam-Status' headers from message
21:   finishing match with result: not matched
21: jump if result is false
21:   jumping to line 28
## Finished executing script 'report-ham'
Sieve trace log for IMAPSIEVE:
Username: user@example.org
Session ID: tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB
Source mailbox: INBOX
Destination mailbox: Junk
Cause: COPY
Filtering message:
UID: 883
  ## Started executing script 'report-spam'
5: header test
5:   starting :is' match with i;ascii-casemap' comparator:
5:   extracting Return-Path' headers from message    5:   matching value user@example.org'
5:     with key <>' => 0    5:   finishing match with result: not matched    5: jump if result is false    5:   jumping to line 13   13: hasflag test   13:   starting :is' match with i;ascii-casemap' comparator:   13:   matching value $HasNoAttachment'
13:     with key $NotJunk' => 0   13:   matching value $Junk'
13:     with key $NotJunk' => 0   13:   matching value $NotJunk'
13:     with key $NotJunk' => 1   13:   finishing match with result: matched   13: jump if result is false   13:   not jumping   14: execute action   14:   execute program bogofilter'
14:   executed program successfully
15: debug_log "Learned SPAM (and unlearned)"
15: jumping to line 21
21: removeflag command
21:   remove flags $NotJunk $Junk'   22: addflag command   22:   add flags $Junk'
24: header test
24:   starting :is' match with i;ascii-casemap' comparator:
24:   extracting X-Spam-Status' headers from message   24:   finishing match with result: not matched   24: jump if result is true   24:   not jumping   25: environment test   25:   starting :matches' match with i;ascii-casemap' comparator:   25:   matching value user@example.org'
25:     with key *' => 1   25:   finishing match with result: matched   25: jump if result is false   25:   not jumping   26: set command   26:   assign username' [0] = "user@example.org"
26: jumping to line 31
31: report action
31:   report incoming message as `abuse' to address user+learn@example.org
## Finished executing script 'report-spam'
Sieve trace log for IMAPSIEVE:
Username: user@example.org
Session ID: tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB
Source mailbox: Junk
Destination mailbox: INBOX
Cause: COPY
Filtering message:
UID: 38628
  ## Started executing script 'report-ham'
4: environment test
4:   starting :is' match with i;ascii-casemap' comparator:
4:   matching value INBOX'    4:     with key Trash' => 0
4:   finishing match with result: not matched
4: jump if result is true
4:   not jumping
5: environment test
5:   starting :is' match with i;ascii-casemap' comparator:
5:   matching value INBOX'    5:     with key Junk' => 0
5:   finishing match with result: not matched
5: jump if result is true
5:   not jumping
5: jumping to line 10
10: hasflag test
10:   starting :is' match with i;ascii-casemap' comparator:
10:   matching value $HasNoAttachment'   10:     with key $Junk' => 0
10:   matching value $NotJunk'   10:     with key $Junk' => 0
10:   matching value $Junk'   10:     with key $Junk' => 1
10:   finishing match with result: matched
10: jump if result is false
10:   not jumping
11: execute action
11:   execute program bogofilter'   11:   executed program successfully   12: debug_log "Learned HAM (and unlearned)"   12: jumping to line 18   18: removeflag command   18:   remove flags $Junk $NotJunk'
19: addflag command
19:   add flags $NotJunk'   21: header test   21:   starting :is' match with i;ascii-casemap' comparator:   21:   extracting X-Spam-Status' headers from message
21:   finishing match with result: not matched
21: jump if result is false
21:   jumping to line 28
## Finished executing script 'report-ham'
After that, the fetch command shows both Junk related flags:
doveadm fetch -u user "hdr.subject flags" mailbox Trash guid ...
hdr.subject: sieve test
flags: \Seen $HasNoAttachment $Junk $NotJunk
Hope that is all what you want and as you want ;-)
regards
--
Slavko
https://www.slavino.sk