imapsieve removeflag ignored

Sat Oct 8 07:49:26 UTC 2022

Hi,

Dňa Fri, 7 Oct 2022 08:19:33 +0300 (EEST) Aki Tuomi
<aki.tuomi at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: UID COPY
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: COPY event
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: Matched static mailbox rule [2]
Oct 08 09:22:09 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Loading script /etc/dovecot/sieve/imap/report-spam.sieve
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Script binary /etc/dovecot/sieve/imap/report-spam.svbin successfully loaded
Oct 08 09:22:09 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Executing script from `/etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Started running script `/etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:09 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: action execute: running program: bogofilter
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Created
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: USER=user at example.org
Oct 08 09:22:09 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 882: Opened mail because: mail stream
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Establishing connection
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Forked child process
Oct 08 09:22:09 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Disconnected
Oct 08 09:22:09 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382929): Destroy
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Info: sieve: DEBUG: Learned SPAM (only)
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Finished running script `/etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 882: Opened mail because: mail stream
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connection created
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Created
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Add recipient
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Send
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Start
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Add transaction
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected
Oct 08 09:22:09 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connecting
Oct 08 09:22:09 imap(user at 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 at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Sending EHLO handshake
Oct 08 09:22:09 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received handshake reply
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received server capabilities
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connection ready
Oct 08 09:22:09 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Start next transaction
Oct 08 09:22:09 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Submitted
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending recipients
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Submitted
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending data
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Submitted
Oct 08 09:22:09 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Sent: RCPT TO:<user+learn at example.org>
Oct 08 09:22:09 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Start timeout
Oct 08 09:22:09 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Reset timeout
Oct 08 09:22:09 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Reset timeout
Oct 08 09:22:09 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: rcpt <user+learn at example.org>: Aborted
Oct 08 09:22:09 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Initiate next transaction
Oct 08 09:22:09 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: rcpt <user+learn at example.org>: Finished
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Finished
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Destroy
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Abort
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Abort transaction
Oct 08 09:22:09 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected
Oct 08 09:22:09 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Destroy
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=882: report action: sent `abuse' report to <user+learn at example.org>
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=882: left message in mailbox 'Junk'
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): Started userdb lookup
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): auth USER input: user at 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 at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): Finished userdb lookup (username=user at 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 at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox=learn.alerty
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/autoexpunge=30d
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/name=learn.alerty
Oct 08 09:22:09 indexer-worker(user at 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 at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota root: name=User quota backend=count args=
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Oct 08 09:22:09 indexer-worker(user at 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 at 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 at 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 at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Quota grace: root=User quota bytes=52428800
Oct 08 09:22:09 indexer-worker(user at 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 at 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 at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: owner = 1
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:09 indexer-worker(user at 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 at 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 at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: owner = 0
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:09 indexer-worker(user at 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 at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: fts: Indexes disabled for namespace 'Zdieľané.%u.'
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: owner = 0
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:09 indexer-worker(user at 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 at 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 at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl: owner = 1
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: Mailbox opened because: indexing
Oct 08 09:22:09 indexer-worker(user at 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 at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 126: Opened mail because: prefetch
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 126: Opened mail because: access
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 126: Opened mail because: precache
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 126: Opened mail because: fts indexing
Oct 08 09:22:09 indexer-worker(user at example.org)<382818><aE1ZHiElQWP11gUAAzoamQ:eNQ9ICElQWNi1wUAAzoamQ>: Info: Indexed 1 messages in learn (UIDs 126..126)
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX.tabletka: FLAG event (changed flags: \Deleted)
Oct 08 09:22:09 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: SELECT
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: UID COPY
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: quota count
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: quota count
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: COPY event
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: Matched static mailbox rule [3]
Oct 08 09:22:13 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Loading script /etc/dovecot/sieve/imap/report-ham.sieve
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Script binary /etc/dovecot/sieve/imap/report-ham.svbin successfully loaded
Oct 08 09:22:13 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Executing script from `/etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Started running script `/etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: action execute: running program: bogofilter
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Created
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: USER=user at example.org
Oct 08 09:22:13 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: UID 38627: Opened mail because: mail stream
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Establishing connection
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Forked child process
Oct 08 09:22:13 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Disconnected
Oct 08 09:22:13 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382938): Destroy
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Info: sieve: DEBUG: Learned HAM (and unlearned)
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Finished running script `/etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=38627: left message in mailbox 'INBOX'
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): Started userdb lookup
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): auth USER input: user at 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 at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): Finished userdb lookup (username=user at 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 at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox=learn.alerty
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/autoexpunge=30d
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/name=learn.alerty
Oct 08 09:22:13 indexer-worker(user at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota root: name=User quota backend=count args=
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Oct 08 09:22:13 indexer-worker(user at 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 at 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 at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Quota grace: root=User quota bytes=52428800
Oct 08 09:22:13 indexer-worker(user at 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 at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: owner = 1
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:13 indexer-worker(user at 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 at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: owner = 0
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:13 indexer-worker(user at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: fts: Indexes disabled for namespace 'Zdieľané.%u.'
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: owner = 0
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:13 indexer-worker(user at 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 at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl: owner = 1
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: Mailbox opened because: indexing
Oct 08 09:22:13 indexer-worker(user at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38627: Opened mail because: prefetch
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38627: Opened mail because: access
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38627: Opened mail because: fts indexing
Oct 08 09:22:13 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:UL7gASUlQWNi1wUAAzoamQ>: Info: Indexed 1 messages in INBOX (UIDs 38627..38627)
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: FLAG event (changed flags: \Deleted)
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: SELECT
Oct 08 09:22:13 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: FLAG event (changed flags: $Junk)
Oct 08 09:22:19 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count
Oct 08 09:22:19 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: quota count
Oct 08 09:22:20 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: SELECT
Oct 08 09:22:20 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Trash: Mailbox opened because: SELECT
Oct 08 09:22:20 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: SELECT
Oct 08 09:22:20 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: SELECT
Oct 08 09:22:20 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Verejné.Novinky: Mailbox opened because: STATUS
Oct 08 09:22:20 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Virtual.Dôležité: Mailbox opened because: STATUS
Oct 08 09:22:20 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: virtual mailbox Virtual.Dôležité: STATUS
Oct 08 09:22:20 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox system: Mailbox opened because: virtual mailbox Virtual.Dôležité: STATUS
Oct 08 09:22:20 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: virtual mailbox Virtual.Dôležité: STATUS
Oct 08 09:22:20 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Virtual.Prílohy: Mailbox opened because: STATUS
Oct 08 09:22:21 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: virtual mailbox Virtual.Prílohy: STATUS
Oct 08 09:22:21 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox system: Mailbox opened because: virtual mailbox Virtual.Prílohy: STATUS
Oct 08 09:22:21 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX.tabletka: Mailbox opened because: virtual mailbox Virtual.Prílohy: STATUS
Oct 08 09:22:21 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: virtual mailbox Virtual.Prílohy: STATUS
Oct 08 09:22:21 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Virtual.Prílohy: Mailbox opened because: SELECT
Oct 08 09:22:21 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: virtual mailbox Virtual.Prílohy: SELECT
Oct 08 09:22:21 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox learn: Mailbox opened because: virtual mailbox Virtual.Prílohy: SELECT
Oct 08 09:22:21 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: SELECT
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: UID COPY
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: COPY event
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: Matched static mailbox rule [2]
Oct 08 09:22:25 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Loading script /etc/dovecot/sieve/imap/report-spam.sieve
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Script binary /etc/dovecot/sieve/imap/report-spam.svbin successfully loaded
Oct 08 09:22:25 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Executing script from `/etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Started running script `/etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:25 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: action execute: running program: bogofilter
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Created
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: USER=user at example.org
Oct 08 09:22:25 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 883: Opened mail because: mail stream
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Establishing connection
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Forked child process
Oct 08 09:22:25 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Disconnected
Oct 08 09:22:25 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382939): Destroy
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Info: sieve: DEBUG: Learned SPAM (and unlearned)
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Finished running script `/etc/dovecot/sieve/imap/report-spam.svbin'
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: UID 883: Opened mail because: mail stream
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connection created
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Created
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Add recipient
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Send
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Start
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Add transaction
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected
Oct 08 09:22:25 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connecting
Oct 08 09:22:25 imap(user at 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 at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Sending EHLO handshake
Oct 08 09:22:25 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received handshake reply
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Received server capabilities
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Connection ready
Oct 08 09:22:25 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Start next transaction
Oct 08 09:22:25 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command MAIL: Submitted
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending recipients
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Submitted
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Sending data
Oct 08 09:22:25 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command BDAT: Submitted
Oct 08 09:22:25 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: command RCPT: Sent: RCPT TO:<user+learn at example.org>
Oct 08 09:22:25 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Start timeout
Oct 08 09:22:26 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Reset timeout
Oct 08 09:22:26 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Reset timeout
Oct 08 09:22:26 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: rcpt <user+learn at example.org>: Aborted
Oct 08 09:22:26 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Initiate next transaction
Oct 08 09:22:26 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: rcpt <user+learn at example.org>: Finished
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Finished
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Destroy
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: transaction: Abort
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Abort transaction
Oct 08 09:22:26 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Disconnected
Oct 08 09:22:26 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: smtp-client: conn 127.0.0.1:25 [1]: Destroy
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=883: report action: sent `abuse' report to <user+learn at example.org>
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=883: left message in mailbox 'Junk'
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): Started userdb lookup
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): auth USER input: user at 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 at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): Finished userdb lookup (username=user at 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 at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox=learn.alerty
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/autoexpunge=30d
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/name=learn.alerty
Oct 08 09:22:26 indexer-worker(user at 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 at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: Quota root: name=User quota backend=count args=
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Oct 08 09:22:26 indexer-worker(user at 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 at 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 at 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 at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: Quota grace: root=User quota bytes=52428800
Oct 08 09:22:26 indexer-worker(user at 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 at 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 at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: owner = 1
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user at 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 at 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 at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: owner = 0
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user at 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 at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: fts: Indexes disabled for namespace 'Zdieľané.%u.'
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: owner = 0
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user at 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 at 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 at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl: owner = 1
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: Mailbox learn: Mailbox opened because: indexing
Oct 08 09:22:26 indexer-worker(user at 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 at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 127: Opened mail because: prefetch
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 127: Opened mail because: access
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 127: Opened mail because: precache
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Debug: Mailbox learn: UID 127: Opened mail because: fts indexing
Oct 08 09:22:26 indexer-worker(user at example.org)<382818><UF5DCTIlQWP11gUAAzoamQ:ELA5CzIlQWNi1wUAAzoamQ>: Info: Indexed 1 messages in learn (UIDs 127..127)
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: FLAG event (changed flags: \Deleted)
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox Junk: Mailbox opened because: SELECT
Oct 08 09:22:26 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: FLAG event (changed flags: $NotJunk)
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: UID COPY
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: quota count
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: COPY event
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: Matched static mailbox rule [3]
Oct 08 09:22:30 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Loading script /etc/dovecot/sieve/imap/report-ham.sieve
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Script binary /etc/dovecot/sieve/imap/report-ham.svbin successfully loaded
Oct 08 09:22:30 imap(user at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Executing script from `/etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Started running script `/etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: action execute: running program: bogofilter
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Created
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Pass environment: USER=user at example.org
Oct 08 09:22:30 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: UID 38628: Opened mail because: mail stream
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Establishing connection
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter: Forked child process
Oct 08 09:22:30 imap(user at 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 at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Disconnected
Oct 08 09:22:30 imap(user at 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 at 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 at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: program exec:/usr/local/lib/dovecot/sieve-bin/bogofilter (382948): Destroy
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Info: sieve: DEBUG: Learned HAM (and unlearned)
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: Finished running script `/etc/dovecot/sieve/imap/report-ham.svbin'
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: sieve: uid=38628: left message in mailbox 'INBOX'
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): Started userdb lookup
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): auth USER input: user at 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 at example.org)<382818><>: Debug: auth-master: userdb lookup(user at example.org): Finished userdb lookup (username=user at 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 at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox=learn.alerty
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/autoexpunge=30d
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><>: Debug: Added userdb setting: namespace/inbox/mailbox/learn.alerty/name=learn.alerty
Oct 08 09:22:30 indexer-worker(user at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: Quota root: name=User quota backend=count args=
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: Quota rule: root=User quota mailbox=* bytes=3221225472 messages=0
Oct 08 09:22:30 indexer-worker(user at 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 at 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 at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: Quota grace: root=User quota bytes=52428800
Oct 08 09:22:30 indexer-worker(user at 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 at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: owner = 1
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user at 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 at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: owner = 0
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: shared: root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: fts: Indexes disabled for namespace 'Zdieľané.%u.'
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: owner = 0
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user at 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 at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: initializing backend with data: vfile:/etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: acl username = user at example.org
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl: owner = 1
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: acl vfile: Global ACL file: /etc/dovecot/dovecot-acl
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: quota: quota_over_flag check: quota_over_script unset - skipping
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: Mailbox opened because: indexing
Oct 08 09:22:30 indexer-worker(user at 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 at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38628: Opened mail because: prefetch
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38628: Opened mail because: access
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Debug: Mailbox INBOX: UID 38628: Opened mail because: fts indexing
Oct 08 09:22:30 indexer-worker(user at example.org)<382818><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB:qJISDTYlQWNi1wUAAzoamQ>: Info: Indexed 1 messages in INBOX (UIDs 38628..38628)
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox Junk: FLAG event (changed flags: \Deleted)
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: Mailbox INBOX: Mailbox opened because: SELECT
Oct 08 09:22:30 imap(user at example.org)<382680><tRbzgIDqprsgAQRwW4EAEAAAAAAAAQAB>: Debug: imapsieve: mailbox INBOX: FLAG event (changed flags: $Junk)
Oct 08 09:22:36 imap(user at 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 at 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 at example.org";
}

Sieve trace files, originally four files:

Sieve trace log for IMAPSIEVE:

  Username: user at 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 at 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 at 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 at example.org"
  26: jumping to line 31
  31: report action
  31:   report incoming message as `abuse' to address <user+learn at example.org>
      ## Finished executing script 'report-spam'

Sieve trace log for IMAPSIEVE:

  Username: user at 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 at 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 at 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 at 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 at example.org"
  26: jumping to line 31
  31: report action
  31:   report incoming message as `abuse' to address <user+learn at example.org>
      ## Finished executing script 'report-spam'

Sieve trace log for IMAPSIEVE:

  Username: user at 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
-------------- next part --------------
A non-text attachment was scrubbed...
Name: mail_debug.log
Type: text/x-log
Size: 79974 bytes
Desc: not available
URL: <https://dovecot.org/pipermail/dovecot/attachments/20221008/38fae0b2/attachment-0001.bin>
-------------- next part --------------
A non-text attachment was scrubbed...
Name: not available
Type: application/pgp-signature
Size: 488 bytes
Desc: Digit��lny podpis OpenPGP
URL: <https://dovecot.org/pipermail/dovecot/attachments/20221008/38fae0b2/attachment-0001.sig>