Dovecot mail-crypt webmail can't read encrypted messages
I'm trying to setup Dovecot with mail-crypt plugin with per-user encryption.
I have configured mail-crypt plugin as per official guide here: https://doc.dovecot.org/configuration_manual/mail_crypt_plugin/
After that I created a user and an encrypted key by running this command: doveadm -o \plugin/mail_crypt_private_password=12345 mailbox cryptokey generate -u mail@example.org -URf (replacing dummy data ofc)
I can log in to webmail (and Dovecot) just fine, emails are getting sent and delivered. I have also checked the storage and the messages seem to be stored encrypted.
However, I can't read the emails in webmail (just headers can be seen) and in Dovecot logs I can see the following error:
failed: Private key not available: Cannot decrypt key ### Cannot decrypt key ### <8632: Password not available (FETCH RFC822.HEADER)
There seems to be an issue with mySQL query. The query I'm using (Select username as "user", password,"%w" as userdb_mail_crypt_private_password from mailbox;) seems to work just fine, when run from mysql prompt it outputs the usernames and passwords, but the error is still there (Cannot decrypt key ### Password not available).
Any ideas? What am I missing?
Hi!
First of all, it's super-unsafe to use user's password like that as private password, at least run it through SHA256. This prevents dovecot from doing expansions on it by accident.
Secondly, enable mail_debug=yes and auth_debug=yes, run it again, and make sure the correct value gets added as 'plugin/mail_crypt_private_password' when using with webmail.
Aki
It's a testing install my main goal is to make it work. I will play around with password encryption before going live.
I have enabled all possible debugging yet I can's see the value you mentioned in the log file. Could you please point me?
Aug 29 01:46:04 mx dovecot: master: Dovecot v2.3.13 (89f716dc2) starting
up for pop3, imap, sieve, lmtp (core dumps disabled)
Aug 29 01:46:30 mx dovecot: auth: Debug: Loading modules from directory:
/usr/lib/dovecot/modules/auth
Aug 29 01:46:30 mx dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Aug 29 01:46:30 mx dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 29 01:46:30 mx dovecot: auth: Debug: Read auth token secret from
/run/dovecot/auth-token-secret.dat
Aug 29 01:46:30 mx dovecot: auth: Debug: passwd-file
/etc/dovecot/dovecot-master-users: Read 1 users in 0 secs
Aug 29 01:46:30 mx dovecot: auth: Debug: auth client connected
(pid=648541)
Aug 29 01:46:30 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=Y+4ayVrnJ9VV/kpz#011lip=217.199.121.254#011rip=xx.xx.xx.xx#011lport=993#011rport=54567#011resp=AHBvc3RtYXN0ZXJAbWFpbGNpdGFkZWwueHl6ADJoZWt1cWUy
(previous base64 data may contain sensitive data)
Aug 29 01:46:30 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Performing
passdb lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: Loading modules
from directory: /usr/lib/dovecot/modules/auth
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: passwd-file
/etc/dovecot/dovecot-master-users: Read 1 users in 0 secs
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): Server accepted connection
(fd=15)
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): Sending version handshake
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>: Handling PASSV
request
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Performing
passdb lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:30 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Finished passdb
lookup
Aug 29 01:46:30 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Auth request
finished
Aug 29 01:46:30 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Finished passdb
lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>: Finished
Aug 29 01:46:30 mx dovecot: auth: Debug: master in:
REQUEST#0111167065089#011648541#0111#0119960b0ca9068c3c686e5310a3c9fb9e7#011session_pid=648544#011request_auth_token
Aug 29 01:46:30 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Performing
userdb lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>: Handling USER
request
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Performing
userdb lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Finished userdb
lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>: Finished
Aug 29 01:46:30 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Finished userdb
lookup
Aug 29 01:46:30 mx dovecot: auth: Debug: master userdb out:
USER#0111167065089#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=7933ad17f03af83724ece6df2635483b7dadf3b4
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster/
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster//Maildir, index=,
indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster//Maildir, alt=
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl: owner =
1
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl: owner =
0
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster//Maildir/dovecot-acl not
found
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot: auth: Debug: auth client connected
(pid=648548)
Aug 29 01:46:58 mx dovecot: auth: Debug: auth client connected
(pid=648549)
Aug 29 01:46:58 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=e27BylrnOq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44602#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>: Handling PASSV
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Auth request
finished
Aug 29 01:46:58 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot: auth: Debug: master in:
REQUEST#011656408577#011648548#0111#011a0ccbf759f343f0dddc21d76e549f523#011session_pid=648550#011request_auth_token
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>: Handling USER
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug: master userdb out:
USER#011656408577#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=337bc511c6d68fee766b06b089f9ebf60b79a31b
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:58 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=B9jBylrnPq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44606#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>: Handling PASSV
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Auth request
finished
Aug 29 01:46:58 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot: auth: Debug: master in:
REQUEST#011245760001#011648549#0111#011515fb953bec25b1461c9e7ac64b2029b#011session_pid=648551#011request_auth_token
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>: Handling USER
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug: master userdb out:
USER#011245760001#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=91ae717b4f4cdfa5583bb297479b1a0cfd764a78
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Drafts/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Trash/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Junk/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Namespace
Shared/: Using permissions from : mode=0700 gid=default
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:58 mx dovecot: auth: Debug: auth client connected
(pid=648554)
Aug 29 01:46:58 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=cZnGylrnQq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44610#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>: Handling PASSV
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Auth request
finished
Aug 29 01:46:58 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot: auth: Debug: master in:
REQUEST#0112451439617#011648554#0111#01185950d6991c145f770031243a0ee85df#011session_pid=648555#011request_auth_token
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>: Handling USER
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug: master userdb out:
USER#0112451439617#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=b219e107b4a03047bae29da5dfc9ff9d59040288
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:58 mx dovecot: auth: Debug: auth client connected
(pid=648556)
Aug 29 01:46:58 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=O8LHylrnRK5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44612#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>: Handling PASSV
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Auth request
finished
Aug 29 01:46:58 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot: auth: Debug: master in:
REQUEST#0111870004225#011648556#0111#011300d0a24af7cfc60ba31680ea2b48678#011session_pid=648557#011request_auth_token
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>: Handling USER
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug: master userdb out:
USER#0111870004225#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=09e37aff8ca8d316bb3b98c62a4135a8a695c4cb
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Mailbox
INBOX: UID 2: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Mailbox
INBOX: UID 2: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:59 mx dovecot: auth: Debug: auth client connected
(pid=648558)
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:59 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=HVbWylrnTq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44622#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Performing passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>: Handling PASSV
request
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Performing passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>: Finished
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Auth request
finished
Aug 29 01:46:59 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot: auth: Debug: master in:
REQUEST#01175890689#011648558#0111#011b7f4aa7b3fbeca8198bd8b165d74bd56#011session_pid=648560#011request_auth_token
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Performing userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>: Handling USER
request
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Performing userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Finished userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>: Finished
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Finished userdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug: master userdb out:
USER#01175890689#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=f401b61b175bd41827a85265327b8136f7605b1c
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:59 mx dovecot: auth: Debug: auth client connected
(pid=648559)
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Mailbox
INBOX: UID 2: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Mailbox
INBOX: UID 2: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:59 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=zXvXylrnUK5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44624#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Performing passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>: Handling PASSV
request
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Performing passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>: Finished
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Auth request
finished
Aug 29 01:46:59 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot: auth: Debug: master in:
REQUEST#0111075052545#011648559#0111#011df42e59d960b83fe8c29c0b4f9cac058#011session_pid=648561#011request_auth_token
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Performing userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>: Handling USER
request
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Performing userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Finished userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>: Finished
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Finished userdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug: master userdb out:
USER#0111075052545#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=5d013003077f0353817d0da72fbb421968a97534
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:47:03 mx dovecot: auth: Debug: auth client connected
(pid=648580)
Aug 29 01:47:03 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=2aYSy1rnXK5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44636#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:47:03 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Performing passdb
lookup
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<15>: Handling PASSV
request
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<15>:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Performing passdb
lookup
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<15>:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<15>:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<15>: Finished
Aug 29 01:47:03 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:03 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Auth request
finished
Aug 29 01:47:03 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:47:03 mx dovecot: auth: Debug: master in:
REQUEST#011699531265#011648580#0111#011318e185cba03d08de530a2cb862dca4d#011session_pid=648581#011request_auth_token
Aug 29 01:47:03 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Performing userdb
lookup
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<16>: Handling USER
request
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<16>:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Performing userdb
lookup
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<16>:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<16>:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Finished userdb
lookup
Aug 29 01:47:03 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<16>: Finished
Aug 29 01:47:03 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Finished userdb
lookup
Aug 29 01:47:03 mx dovecot: auth: Debug: master userdb out:
USER#011699531265#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=d7d60cb4f5bc934a89b394a5966a70a08a01237c
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:47:03 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field flags decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: UID 1: Opened mail because: prefetch
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.Bcc decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.Cc decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.Date decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.From decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.In-Reply-To decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.Message-ID decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.Reply-To decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.Sender decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.Subject decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field hdr.To decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Changing field imap.bodystructure decision temp -> yes (uid=1)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: UID 1: Opened mail because: header stream
Aug 29 01:47:04 mx dovecot: auth: Debug: auth client connected
(pid=648582)
Aug 29 01:47:04 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=u68ly1rnZK5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44644#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:47:04 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Performing passdb
lookup
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<17>: Handling PASSV
request
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<17>:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Performing passdb
lookup
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<17>:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<17>:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<17>: Finished
Aug 29 01:47:04 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:04 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Auth request
finished
Aug 29 01:47:04 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:47:04 mx dovecot: auth: Debug: master in:
REQUEST#0112228225#011648582#0111#0118c40a8a1ef7dfc6e09cc3b139ab6d3b8#011session_pid=648583#011request_auth_token
Aug 29 01:47:04 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Performing userdb
lookup
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<18>: Handling USER
request
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<18>:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Performing userdb
lookup
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<18>:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<18>:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Finished userdb
lookup
Aug 29 01:47:04 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<18>: Finished
Aug 29 01:47:04 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Finished userdb
lookup
Aug 29 01:47:04 mx dovecot: auth: Debug: master userdb out:
USER#0112228225#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=9f18e23092d8e4afb09b8a9ecbe152a6e60d37e5
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Mailbox
Sent: UID 1: Opened mail because: prefetch
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Mailbox
Sent: UID 1: Opened mail because: header stream
Aug 29 01:47:04 mx dovecot:
imap(myuser@mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:47:06 mx dovecot: auth: Debug: auth client connected
(pid=648584)
Aug 29 01:47:06 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=LstCy1rnaK5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44648#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:47:06 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Performing passdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<19>: Handling PASSV
request
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<19>:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Performing passdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<19>:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<19>:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<19>: Finished
Aug 29 01:47:06 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:06 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Auth request
finished
Aug 29 01:47:06 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot: auth: Debug: master in:
REQUEST#0112930638849#011648584#0111#011c176cb34e2c20bad60d3203bd9a89c04#011session_pid=648585#011request_auth_token
Aug 29 01:47:06 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Performing userdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<20>: Handling USER
request
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<20>:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Performing userdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<20>:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<20>:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Finished userdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<20>: Finished
Aug 29 01:47:06 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Finished userdb
lookup
Aug 29 01:47:06 mx dovecot: auth: Debug: master userdb out:
USER#0112930638849#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=379d8162ba1592cdc3d2e770c52944169dbaf704
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Mailbox
Sent: UID 2: Opened mail because: prefetch
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Mailbox
Sent: UID 2: Opened mail because: header stream
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:47:06 mx dovecot: auth: Debug: auth client connected
(pid=648586)
Aug 29 01:47:06 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=JJBEy1rnaq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44650#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:47:06 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Performing passdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<21>: Handling PASSV
request
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<21>:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Performing passdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<21>:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<21>:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Finished passdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<21>: Finished
Aug 29 01:47:06 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Finished passdb
lookup
Aug 29 01:47:06 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Auth request
finished
Aug 29 01:47:06 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot: auth: Debug: master in:
REQUEST#0113705274369#011648586#0111#011ba734ab8cc663beb8f528fc91025f378#011session_pid=648587#011request_auth_token
Aug 29 01:47:06 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Performing userdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<22>: Handling USER
request
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<22>:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Performing userdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<22>:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<22>:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Finished userdb
lookup
Aug 29 01:47:06 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<22>: Finished
Aug 29 01:47:06 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Finished userdb
lookup
Aug 29 01:47:06 mx dovecot: auth: Debug: master userdb out:
USER#0113705274369#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=b0640ae9bdb037f719cb4d4e97bdf4df17dd3367
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Mailbox
Sent: UID 2: Opened mail because: prefetch
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Mailbox
Sent: UID 2: Opened mail because: header stream
Aug 29 01:47:06 mx dovecot:
imap(myuser@mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:47:08 mx dovecot: auth: Debug: auth client connected
(pid=648588)
Aug 29 01:47:08 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=/u5by1rncK5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44656#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:47:08 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Performing passdb
lookup
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<23>: Handling PASSV
request
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<23>:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Performing passdb
lookup
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<23>:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<23>:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<23>: Finished
Aug 29 01:47:08 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:08 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Auth request
finished
Aug 29 01:47:08 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:47:08 mx dovecot: auth: Debug: master in:
REQUEST#0112063597569#011648588#0111#011bac873a3503f02464a54ef68a928e482#011session_pid=648589#011request_auth_token
Aug 29 01:47:08 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Performing userdb
lookup
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<24>: Handling USER
request
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<24>:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Performing userdb
lookup
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<24>:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<24>:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Finished userdb
lookup
Aug 29 01:47:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<24>: Finished
Aug 29 01:47:08 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Finished userdb
lookup
Aug 29 01:47:08 mx dovecot: auth: Debug: master userdb out:
USER#0112063597569#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=a73a0f4869a242b4759f230f7bb6422ccb8869f8
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:47:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:48:08 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): Disconnected: Connection closed
(fd=-1)
Aug 29 01:51:59 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:52:08 mx dovecot:
imap(myuser@mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:55:50 mx dovecot: auth: Debug: Loading modules from directory:
/usr/lib/dovecot/modules/auth
Aug 29 01:55:50 mx dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Aug 29 01:55:50 mx dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 29 01:55:50 mx dovecot: auth: Debug: Read auth token secret from
/run/dovecot/auth-token-secret.dat
Aug 29 01:55:50 mx dovecot: auth: Debug: passwd-file
/etc/dovecot/dovecot-master-users: Read 1 users in 0 secs
Aug 29 01:55:50 mx dovecot: auth: Debug: auth client connected
(pid=648812)
Aug 29 01:55:50 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=uIx96lrnELB/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=45072#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:55:50 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Performing passdb
lookup
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: Loading modules
from directory: /usr/lib/dovecot/modules/auth
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: passwd-file
/etc/dovecot/dovecot-master-users: Read 1 users in 0 secs
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): Server accepted connection
(fd=15)
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): Sending version handshake
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>: Handling PASSV
request
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Performing passdb
lookup
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:55:50 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Finished passdb
lookup
Aug 29 01:55:50 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Auth request
finished
Aug 29 01:55:50 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Finished passdb
lookup
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>: Finished
Aug 29 01:55:50 mx dovecot: auth: Debug: master in:
REQUEST#0113702521857#011648812#0111#011e1ec3685eb1e4fd3a62ffd69272c4aec#011session_pid=648815#011request_auth_token
Aug 29 01:55:50 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Performing userdb
lookup
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>: Handling USER
request
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Performing userdb
lookup
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Finished userdb
lookup
Aug 29 01:55:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>: Finished
Aug 29 01:55:50 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Finished userdb
lookup
Aug 29 01:55:50 mx dovecot: auth: Debug: master userdb out:
USER#0113702521857#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=eb5eddfaab5110960c7915faf8e3e609bb64c17e
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl: owner =
1
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl: owner =
0
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:55:50 mx dovecot:
imap(myuser@mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:56:50 mx dovecot: auth-worker(648814): Debug: conn
unix:auth-worker (pid=648813,uid=110): Disconnected: Connection closed
(fd=-1)
Aug 29 01:56:59 mx dovecot: auth: Debug: auth client connected
(pid=648868)
Aug 29 01:56:59 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=bWmc7lrnVrB/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=45142#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:56:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Performing passdb
lookup
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: Loading modules
from directory: /usr/lib/dovecot/modules/auth
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: passwd-file
/etc/dovecot/dovecot-master-users: Read 1 users in 0 secs
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): Server accepted connection
(fd=15)
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): Sending version handshake
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>: Handling PASSV
request
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Performing passdb
lookup
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:56:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Finished passdb
lookup
Aug 29 01:56:59 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Auth request
finished
Aug 29 01:56:59 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Finished passdb
lookup
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<1>: Finished
Aug 29 01:56:59 mx dovecot: auth: Debug: master in:
REQUEST#0111804468225#011648868#0111#011c7cbc590470915728ffb8068dc2f5fb0#011session_pid=648870#011request_auth_token
Aug 29 01:56:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Performing userdb
lookup
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>: Handling USER
request
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Performing userdb
lookup
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Finished userdb
lookup
Aug 29 01:56:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): auth-worker<2>: Finished
Aug 29 01:56:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Finished userdb
lookup
Aug 29 01:56:59 mx dovecot: auth: Debug: master userdb out:
USER#0111804468225#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=1050b7d18f93722b4e25a03bebefe31a3d93c4d0
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl: owner =
1
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl: owner =
0
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:56:59 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:57:09 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:57:59 mx dovecot: auth-worker(648869): Debug: conn
unix:auth-worker (pid=648813,uid=110): Disconnected: Connection closed
(fd=-1)
Aug 29 02:02:01 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 02:02:10 mx dovecot:
imap(myuser@mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 02:02:50 mx dovecot:
imap(myuser@mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
On 2022-08-29 07:56, Aki Tuomi wrote:
Emm, sorry for the confusion, there are two users authenticating - master user "postmaster" and the second user called "test". I have just obfuscated users by replacing usernames with myuser. So no, this shouldn't be the issue.
Any other suggestions?
On 2022-08-29 10:30, Aki Tuomi wrote:
Hard to say.
If you are logging is master_user, there will be different password than normal user. Usually. With your setup, you can only access user's mail if you are using the exact same password that the user was using.
Your logs seem to indicate that you are logging as master_user, so you are probably unable to access mails.
Aki
Upon closer review, it seems you're probably right: both users are in fact marked master_user. How is that possible? I haven't marked new user as a master_user. Are users marked master_user by default? What's even more interesting, /etc/dovecot/dovecot-master-users doesn't contain this user's data. Is it possible to unset this master_user flag somehow? I browsed through the db in mySQL but wasn't able to locate any master_users as well. Sorry for being such a noob... :)
On 2022-08-29 11:33, Aki Tuomi wrote:
Update: I managed to remove the master user query so users are not getting marked as master_user on login. However, that doesn't seem to affect anything. I'm still unable to read encoded emails in webmail. No new errors are showing up in the log. I have even created a brand new user and all new keys via doveadm but still no go. Any suggestions?
On 2022-08-29 16:30, Serveria Support wrote:
That's exactly what I'm trying to do. Both userdb and passwdb are referring to dovecot-mysql.conf:
userdb { args = /etc/dovecot/dovecot-mysql.conf driver = sql } passdb { args = /etc/dovecot/dovecot-mysql.conf driver = sql }
dovecot-mysql.conf contains the following query only:
password_query = SELECT
username as "user", password,
'%w' AS userdb_mail_crypt_private_password
FROM mailbox WHERE username="%u";
It was taken from you tutorial (I was following this tutorial closely): https://doc.dovecot.org/configuration_manual/mail_crypt_plugin/
So what am I doing wrong? :)
On 2022-08-30 16:13, Aki Tuomi wrote:
Still banging my head against the wall...
Upon running this query: SELECT username as user, password, '%w' AS userdb_mail_crypt_private_password FROM mailbox;
I'm getting the following output:
+----------------------------+-----------------------------------------------------------------------------------------------------------+------------------------------------+
| user | password
|
userdb_mail_crypt_private_password |
+----------------------------+-----------------------------------------------------------------------------------------------------------+------------------------------------+
| user1@mydomain.xyz |
{SSHA512}1Z3spq1ySn4dmF2vgv5DRNW5KedMJH/Yspi+33PUTGe/9T6k8Uad62pAnKMUXOhGJliXSkPK24dHWs7UfHtMJFUpJdOX8kV9
| %w |
| user2@mydomain.xyz |
{SSHA512}xE+M7bD8nlbdfJl314iYmLgDjG0sud3oakQuxSYkcJYrLSoqgv9W7MD4ghtflZ32VgV6mnhcYIJrRK77tVCoDOG1dkA=
| %w |
| user3@mydomain.xyz |
{SSHA512}LgmL2XS1b+cb/g/SVjWaic8fMn4h8pwud1Ark7rkpfcSOuIcib4eeKVO2yKW3BivulHuj3DA7s5591VLYiURek6SCJhKiqHo
| %w |
| user4@mydomain.xyz |
{SSHA512}2e/VxDvjHbJZmBUMKYNlFM6Of7nbc5bDtm14Nz1IiFXQuq0VMgwOPCA8p9RTMav+KLX/tlCbKfkcbYzaNI/dHF2Nhiinyvnv
| %w |
| user5@mydomain.xyz |
{SSHA512}/WDzitklDJ6yZH1eeRHljQvN1/MEB+bdXftSx7Sw2VBSyH21WlxjRx5dp3fiibhTNrHeIL5qWiADaBifJyfmKhn0Zi0TSwvp
| %w |
+----------------------------+-----------------------------------------------------------------------------------------------------------+------------------------------------+
5 rows in set (0.000 sec)
As soon as I'm adding WHERE username='%u'; at the end, query returns 0 rows.
This is the exact contents of my file:
password_query = SELECT
username as user, password,
'%w' AS userdb_mail_crypt_private_password
FROM mailbox WHERE username="%u";
Is it ok to run it like this? Or should I construct a separate query "user_query=" ? It was like this in your tutorial...
On 2022-08-30 16:13, Aki Tuomi wrote:
I tried it but it doesn't seem to make any difference at all.
Can someone please assist me with reading logs? Does this log below mean Dovecot is trying to use master_user again or simply reading master_user password file?
Sep 2 15:35:33 mx dovecot: auth: Debug: Read auth token secret from /run/dovecot/auth-token-secret.dat Sep 2 15:35:33 mx dovecot: auth: Debug: passwd-file /etc/dovecot/dovecot-master-users: Read 1 users in 0 secs Sep 2 15:35:33 mx dovecot: auth: Debug: auth client connected (pid=900284) Sep 2 15:35:33 mx dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=Vfxm1bbnRo9/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=36678#011local_name=127.0.0.1#011resp=AHRlc3RvQG1haWxjaXRhZGVsLnh5egA0SFBYMWt0OSE= (previous base64 data may contain sensitive data)
Everything ok here?
Sep 2 15:25:34 mx dovecot: auth: Debug: auth client connected
(pid=899859)
Sep 2 15:25:34 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=97OusbbnXI1/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=36188#011local_name=127.0.0.1#011resp=AHRlc3RvQG1haWxjaXRhZGVsLnh5egA0SFBYMWt0OSE=
(previous base64 data may contain sensitive data)
Sep 2 15:25:34 mx dovecot: auth: Debug:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Performing passdb
lookup
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<3>: Handling PASSV
request
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<3>:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Performing passdb
lookup
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<3>:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='user1@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<3>:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Finished passdb
lookup
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<3>: Finished
Sep 2 15:25:34 mx dovecot: auth: Debug:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Finished passdb
lookup
Sep 2 15:25:34 mx dovecot: auth: Debug:
auth(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Auth request
finished
Sep 2 15:25:34 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=user1@mydomain.xyz
Sep 2 15:25:34 mx dovecot: auth: Debug: master in:
REQUEST#0111998585857#011899859#0111#01131314e9e09e38b194a05b78bfe279780#011session_pid=899860#011request_auth_token
Sep 2 15:25:34 mx dovecot: auth: Debug:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Performing userdb
lookup
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<4>: Handling USER
request
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<4>:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Performing userdb
lookup
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<4>:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): SELECT
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='user1@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<4>:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Finished userdb
lookup
Sep 2 15:25:34 mx dovecot: auth-worker(899854): Debug: conn
unix:auth-worker (pid=899853,uid=110): auth-worker<4>: Finished
Sep 2 15:25:34 mx dovecot: auth: Debug:
sql(user1@mydomain.xyz,127.0.0.1,<97OusbbnXI1/AAAB>): Finished userdb
lookup
Sep 2 15:25:34 mx dovecot: auth: Debug: master userdb out:
USER#0111998585857#011user1@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/xxxxx-2022.08.30.06.07.08/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=fac9c351492fd6073176272c79ff65b1b3e87f37
Sep 2 15:25:34 mx dovecot: imap(user1@mydomain.xyz)<899860><97OusbbnXI1/AAAB>: Debug: Added userdb setting: mail=maildir:~/Maildir Sep 2 15:25:34 mx dovecot: imap(user1@mydomain.xyz)<899860><97OusbbnXI1/AAAB>: Debug: Added userdb setting: plugin/quota_rule=*:bytes=1073741824 Sep 2 15:25:34 mx dovecot: imap(user1@mydomain.xyz)<899860><97OusbbnXI1/AAAB>: Debug: Effective uid=2000, gid=2000, home=/var/vmail/vmail1/mydomain.xyz/t/e/s/xxxxx-2022.08.30.06.07.08/
Any ideas?
On 2022-09-02 20:08, dovecot@ptld.com wrote:
Hi,
This log shows no errors. Running doveadm fetch command gives me this:
doveadm(user@mydomain.xyz): Error: fetch(text) failed for box=INBOX uid=15: read() failed: read(/var/vmail/vmail1/mydomain.xyz/a/b/d/xxxxxxxx-2022.09.09.05.52.29//Maildir/cur/1663034263.M491074P1457418.mx,S=2217,W=2266:2,S) failed: Private key not available: Cannot decrypt key fd98762c573b8c54805884838695bd5b7eaeb9e0b0d326434c2f63a95a905a89: Cannot decrypt key 10fed5d3e938ce19a20046b84f29e50a271f6404f0760037996b4cf2d1ecfeb7: Password not available
On 2022-09-13 14:43, hi@zakaria.website wrote:
On 2022-09-14 14:41, Serveria Support wrote:
Private key not available? Isn't clear enough?
Did you set the global private key in dovecot config?
The error is saying the private key that meant to be used to decrypt emails is not found, thus it must be the path you set in mail crypt plugin definition is incorrect or private key file have either wrong ownership or permissions.
Notice it has to be in .pem format as well.
How can I set the global private key in conf? I was following the official mail-crypt tutorial. This is what I have in dovecot.conf mail-crypt section:
mail_crypt_curve = secp521r1 mail_crypt_save_version = 2 mail_crypt_require_encrypted_user_key = yes
On 2022-09-14 17:23, hi@zakaria.website wrote:
On 2022-09-14 15:11, Serveria Support wrote:
Check RSA key section, in https://doc.dovecot.org/configuration_manual/mail_crypt_plugin/#rsa-key
On 2022-09-14 16:04, Serveria Support wrote:
Check the Base64-encoded Keys section, I think it says something about query the pem content from DB per user. Also, search for " Setting up individual encrypted user keys using mail-crypt-plugin " post in the mailing list, it touches on which variable name needs to be passed in the sql query for the user corresponding pub and priv key.
Encoding in base64 the content of PEM files seems to be important otherwise characters like % can cause problem in dovecot. I suggest to store the keys already encoded to ease the process of handling.
Zakaria.
Some notes here, after reading this thread again:
Keys are stored in mail_attributes file, which depends on your config, but usually is %h/dovecot-attributes, which means it'll be in user's home directory.
The key format is Dovecot Dcrypt Key, you can use
doveadm mailbox cryptokey export
to export them in PEM format. Only **global keys** expect PEM formatted keys, which you are not using.If you are using mail_crypt_private_password to encrypt the user key, you will need to provide this every time you want to access the user's emails, including using doveadm. Dovecot does not know what password you are using.
Your logs indicate that you are, still, using master userdb. This will not work. You cannot use master users with per-user encryption passwords in the way you do. If you want to use master users / master password, you must not encrypt the user key.
You should really focus on reading your logs, because they really do indicate that the userdb_mail_crypt_private_password is not exprted in anywhere, so clearly and obviously you are not able to access the mails.
Maybe consider removing the master user authentication completely?
Aki
Ok, big progress here! Specifying user password explicitly did the trick! The command that works is this:
doveadm -o plugin/mail_crypt_private_password=xxxxxxxxxx -Dv fetch -u user@mydomain.xyz text 1
Now I have to adjust/write a query which does the same in order to read/decrypt emails via webmail. I'm going to investigate the master user issue you mentioned.
On 2022-09-15 08:16, Aki Tuomi wrote:
Hi,
I'm here with a follow-up. I have managed to fix this issue!
I have rebuilt the entire project from scratch, using vanilla versions of Dovecot, Postfix, SOGO webmail etc and everything works as expected: emails are getting encrypted, I'm able to send, receive and read emails in webmail. I suspect the root of the issue was that I was using software package called iredmail. My guess is that all the master admin drama was caused by iredmail. Big thanks to you guys for the hints and ideas which eventually helped me troubleshoot this issue! I appreciate your assistance.
P.S. Btw, is there any way to hide plain text passwords from Dovecot log files? Disabling auth debugging won't help as the system may get compromised and the intruder can re-enable logs and grab the passwords from the logs. The only person who should know/see the password in clear text should be the respective mail user. Is there any way to achieve this?
On 2022-09-15 08:16, Aki Tuomi wrote:
I have rebuilt the entire project from scratch, using vanilla versions of Dovecot, Postfix, SOGO webmail etc and everything works as expected:
Hi, just wondering where do you find the vanilla version of only SOGO webmail? I thought SOGO webmail was distributed as a whole server package...
Sometimes not. If the data stored in mail accounts is more valuable than the server and control over it.
So this means passwords cannot be masked/hidden in the logs? You realize that it actually defeats the whole idea of encrypted storage? It's useless. I can think of lots of scenarios: malicious system administrator reading users mails and blackmailing them or selling their business secrets to competitors, corrupt law enforcement in some countries getting rid of political or business opponents by disclosing the contents of their mails and I can go on and on and on... There is no such thing as semi-privacy. Privacy is either there or it's not.
What exactly Dovecot does to hide passwords in logs?
I've studied mail-crypt plugin's docs and it's written there:
Also, it might be visible in debug logging. Suggested approaches are base64 encoding, hex encoding or hashing the password. With hashing, you get the extra benefit that password won’t be directly visible in logs.
So how can I make passwords to be not directly visible in logs?
On 2022-10-09 11:39, Aki Tuomi wrote:
Passwords are hidden in logs, mostly. Debug logging unfortunately can leak some password information.
Dovecot mail crypt plugin is primarily intended for securing storage, especially one that is remote, like NFS or object storage. It is not intended for securing your server against malicious admins.
In production use, customers usually use a site-wide global keypair to encrypt the information stored in non-local storage.
Yes, and mail crypt plugin is not intended for protecting these cases.
Turn on auth_debug=yes and see, you'll see passwords being masked.
Aki
Use hex encoding, base64 encoding or hashing the password, as it says. E.g. %{sha256,salt=%{user}:password}. Directly using user's password for mail crypt keys is unsafe anyways, due to % being an expansion character.
To add few more comments...
You speak about privacy that either you have it or not.
If you are not your own admin, the administrator will always be able to access your mails, there are only very limited ways for you to make it hard enough. With mail crypt, everything and all boils down to key management, which is more hard than you can imagine.
The decryption key must be somehow recoverable, otherwise the user cannot read their mail. So either it needs to be derived, or retrieved from somewhere. And at some point, it has to be in readable format. The only safe way to deal with decryption is to do it in a hardware device, and even this has problems.
To find out user's password you can turn on pre-login rawlogs, rawlogs in general, beef up logging, add various configurations that will assist in this. You can setup mitm attack with haproxy + dovecot to record all encrypted traffic in plaintext.
If you want your privacy, your best best is to be your own admin. Otherwise the house always win.
Aki
Yes, I agree, but why make bad guy's life easier? I mean you can do many things including renting a GPU cluster and bruteforcing the passwords but it takes time to do it and also expertise. Right now, all they need to do is make a few clicks and enable auth logging. Why don't just eliminate this extra attack vector?
On 2022-10-09 14:41, Aki Tuomi wrote:
Passwords are hidden in logs, mostly. Debug logging unfortunately can leak some password information.
So why not just get rid of this attack vector? Who needs users' plaintext passwords in debug logs anyway? I can't think of a situation when this is necessary. But that's just me of course.
Turn on auth_debug=yes and see, you'll see passwords being masked.
I have this value set to yes already and the passwords are not being masked. Perhaps you meant auth_debug_passwords = no?
Will this work in doveadm commands? Or it has to be done in a PHP script feeding login data to dovecot (like webmail/frontend)? Will it prevent passwords from showing in the logs?
On 2022-10-09 14:02, Aki Tuomi wrote:
On Sun, 9 Oct 2022, Serveria Support wrote:
If your attack scenario includes somebody owning your server, nothing prevents them from compiling/installing a custom version of dovecot (or any other tool you may be using, like PAM, etc.) which dumps the passwords in clear text to a suitable file, pipe, or socket.
So good luck with that requirement..
Cheers, Bernardo
Like I've already mentioned in my reply to Aki, I generally agree, but many of these methods require much time and expertise some bad guys don't have. You can also bruteforce the passwords but it can take years. With passwords showing in logs all they need to do is make a few clicks and enable auth logging. In most cases the attacker is really short on time and needs to act fast, before he is detected and locked out of the system.
On 2022-10-09 19:10, Bernardo Reino wrote:
On 2022-10-10 08:03, Serveria Support wrote:
Hey, I thought to recommend encrypting log file by your own.
Create service with executing bash script every second perhaps using while loop to encrypt dovecot logs file, add separater at end of log, so in following encryption cycles you can know whats being inserted new and needs encryption by decrypting the old and encrypting the decrypted old and new together.
Also, make sure to perform encryption in separate copy of logs temp file so to allow dovecot to pipe out logs without messing up the order of lines, and lastly, you probably want to disallow administrator account from accessing dovecot conf file perhaps by changing its permission and ownership, so they cant change logging path.
There you go, passwords are encrypted in log file and no one can read.
Zakaria.
Hi Benny,
Sorry I must have missed your email. Here's the output of doveconf -P | grep auth:
doveconf: Warning: NOTE: You can get a new clean config file with: doveconf -Pn > dovecot-new.conf doveconf: Warning: Obsolete setting in /etc/dovecot/dovecot.conf:25: 'imaps' protocol is no longer necessary, remove it auth_anonymous_username = anonymous auth_cache_negative_ttl = 1 hours auth_cache_size = 0 auth_cache_ttl = 1 hours auth_cache_verify_password_with_worker = no auth_debug = yes auth_debug_passwords = yes auth_default_realm = auth_failure_delay = 2 secs auth_gssapi_hostname = auth_krb5_keytab = auth_master_user_separator = auth_mechanisms = plain login auth_policy_check_after_auth = yes auth_policy_check_before_auth = yes auth_policy_hash_mech = sha256 auth_policy_hash_nonce = auth_policy_hash_truncate = 12 auth_policy_log_only = no auth_policy_reject_on_fail = no auth_policy_report_after_auth = yes auth_policy_request_attributes = login=%{requested_username} pwhash=%{hashed_password} remote=%{rip} device_id=%{client_id} protocol=%s session_id=%{session} auth_policy_server_api_header = auth_policy_server_timeout_msecs = 2000 auth_policy_server_url = auth_proxy_self = auth_realms = auth_socket_path = auth-userdb auth_ssl_require_client_cert = no auth_ssl_username_from_cert = no auth_stats = no auth_use_winbind = no auth_username_chars = abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ01234567890.-_@ auth_username_format = %Lu auth_username_translation = auth_verbose = yes auth_verbose_passwords = yes auth_winbind_helper_path = /usr/bin/ntlm_auth auth_worker_max_count = 30 disable_plaintext_auth = yes imap_urlauth_host = imap_urlauth_logout_format = in=%i out=%o imap_urlauth_port = 143 auth_verbose = default auth_verbose = default unix_listener anvil-auth-penalty { service auth-worker { executable = auth -w unix_listener auth-worker { service auth { executable = auth unix_listener /var/spool/postfix/private/auth { unix_listener auth-client { unix_listener auth-login { unix_listener auth-master { unix_listener auth-userdb { service imap-urlauth-login { executable = imap-urlauth-login unix_listener imap-urlauth { service imap-urlauth-worker { executable = imap-urlauth-worker unix_listener imap-urlauth-worker { service imap-urlauth { executable = imap-urlauth unix_listener token-login/imap-urlauth { auth_verbose = default auth_verbose = default
I'm not sure how it will help me edit source files though...
On 2022-10-10 22:33, Benny Pedersen wrote:
If you don't store cleartext passwords in your backend, how will an intruder get them??
On Tue, Oct 11, 2022 at 3:45 PM Serveria Support <support@serveria.com> wrote:
-- Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-)
Odhiambo Washington skrev den 2022-10-11 15:49:
If you don't store cleartext passwords in your backend, how will an intruder get them??
auth_debug = yes auth_debug_passwords = yes auth_verbose = yes auth_verbose_passwords = yes
then read log files if thats with world access
all the above should be no
first step to secure it
next step is to secure syslogs
I find this conversation "interesting".
Serveria, i think some can't see the attack scenario where the attacker's goal is simply to get email passwords, and nothing else. it would make sense for their strategy to do nothing else "bad" on the server to attract attention to their intrusion. In that case, all they would do is send back the treasure trove of passwords to their home server(s), and sit there, remaining possibly for years, hiding, exploiting the fact that dovecot, with no code modification, will allow them to grab email passwords. If a dovecot server has thousands of email accounts, that represents thousands of other devices they could target, which is worth much more to the attacker than a single dovecot server.
Oh well, food for thought.
On Tue, 2022-10-11 at 15:11 +0300, Serveria Support wrote:
Bingo! Great to see some like-minded person here John!
Yeah, it's such an obvious vulnerability, I'm kinda surprised most people here don't see an issue with that. If I were a Dovecot Pro OX customer, I'd be very concerned with this "feature".
Imagine hacking Protonmail's server, getting root access and seeing customers' password there in clear text? )))
On 2022-10-11 17:38, John Tulp wrote:
Yeah, it's such an obvious vulnerability, I'm kinda surprised most people here don't see an issue with that.
What people are trying to explain is the scenario you describe requires an attacker to have root privileges on the target server. If someone has root access to a server then your fears are moot and the suggestion to remove code logging passwords offers zero protection.
If someone has root they can just read the email storage files, no password needed.
If someone has root, and dovecot has no code showing passwords in logs, the attacker can build THEIR OWN version of dovecot that "key-logs" all passwords to a remote server WITHOUT displaying passwords in the logs.
This is what people mean when they say if someone has root you have bigger problems then dovecot logging.
If someone has root they can just read the email storage files, no password needed.
We are discussing Dovecot with encrypted mail storage here.
Please compare the time needed to: get in, enable debug logging, read the log file with: get in, enable debug logging, realize it's not working (some will stop here), consider your options, build THEIR OWN version of dovecot that "key-logs" all passwords to a remote server WITHOUT displaying passwords in the logs?
This is what people mean when they say if someone has root you have bigger problems then dovecot logging.
I generally agree but only if the mail storage is unencrypted. With encrypted storage I can think of many scenarios: corrupt law enforcement, malicious freelance admin, social engineering tricks etc etc etc when attackers will have not enough time/expertise to grab your passwords.
On 2022-10-11 18:16, dovecot@ptld.com wrote:
@Tulp - the attacker has to 0wn your server first. In which case they will have found a password to SSH in - regardless of dovecot being there or not. You will be dealing with a bigger problem than dovecot.
On Tue, Oct 11, 2022 at 5:39 PM John Tulp <johntulp@tulpholdings.com> wrote:
-- Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-)
What i'm saying is...
if the attackers goal is only to get passwords, you will not be dealing with a bigger problem. In that hypothetical there would not be a bigger problem or any other problem.
the only problem is passwords leaking in that case.
The attacker goes out of their way to not cause any other problems on the server.
they do this to avoid getting noticed by admins.
as long as admin does not know there is malware on their server, the malware could run for years harvesting passwords. That would be the hypothetical attackers only goal on that server - not to bother anything, just to harvest user email passwords.
and the admin will not be dealing with a "bigger problem", because the admin will not know they've been hacked, because hacker does not cause any problems on the server. admin will think everything is fine on their server.
there could be email servers right now that are compromised and yielding passwords in this way, and if dovecot suddenly started writing those passwords the logs in some scrambled way - the malware would suddenly stop being able to harvest clear text passwords. hacker then could either quietly go away, or start doing something else on the machine, which the admins may or may not become aware of. might get a big surprise that they've been hacked.
This type of "quiet" malware of course definitely exists in the real world, for example, on phones. Many people's phones have been hacked and they are unaware of it, and they continue using the phone for years without realizing it's been hacked.
Sometimes attackers mess up the devices they hack, sometimes they don't, they just quietly use the hacked device for their own purposes (which of course are the hacks to really worry about). whenever there are big announcements of hacks to major organizations, the story always unfolds that the hackers had access for quite a while before admins became aware. this is the timeframe that really puts one's "security efforts" to the test - after machine is compromised, but before admins are aware.
it makes no sense to make things easy for hackers during this time when they are operating in the target machines/network and the admins are not yet aware that devices have been compromised.
in mitigating such risk, why not go for the "low hanging fruit" by simply not storing passwords on disk in clear text ? unless there is some reason why clear text passwords actually have to be written to disk.
-- John Tulp <johntulp@tulpex.com> tulpex
On Tue, 2022-10-11 at 17:58 +0300, Odhiambo Washington wrote:
On 11.10.22 18:04, John Tulp wrote:
Authentication schemes like CRAM-MD5 require the server to have the plaintext password *available* for / prior to the authentication (it is therefor usually called a "shared secret" instead).
Before you ask, one benefit from using such schemes is that the password does not have to go through the wire, not even inside encryption (that a MitM may or may not be able to crack), so it's not a clear all-out FAIL to use those.
Whether the password is still in cleartext *when written to / read from disk* is another question, but that would be a negligible defense against someone who rooted your server.
Kind regards,
Jochen Bern Systemingenieur
Binect GmbH
"Serveria" == Serveria Support <support@serveria.com> writes:
Honestly, if the attacker has penetrated you to such an extent, then you're toast anyway, because they can just attach to the dovecot process with 'gdb' and dump the data directly as well.
Encryption is not a magic solution here, and there's no real way to secure the system so well that once an attacker can modify files and restart processes they are blocked. Because they honestly looks like an Admin doing work on the system.
On Mon, 10 Oct 2022, Serveria Support wrote:
You should search for "given password" in the source.
Hint: src/auth/passdb-pam.c, around lines 175-178. src/auth/auth-request.c, around lines 2311-2312.
This is with the latest source (2.3.19.1).
Cheers.
PS: But as I noted, nothing prevents $HACKER from bringing their own dovecot (BYOD :) with all debugging options enabled, etc. As others have noted, if the intruder owns your server, you have lost. Period.
Ok, this is something... let me check...
If you're you referring to these pieces of code:
if (path != NULL) { /* log this as error, since it probably is */ str = t_strdup_printf("%s (%s missing?)", str, path); e_error(authdb_event(request), "%s", str); } else if (status == PAM_AUTH_ERR) { str = t_strconcat(str, " ("AUTH_LOG_MSG_PASSWORD_MISMATCH"?)", NULL); if (request->set->debug_passwords) { str = t_strconcat(str, " (given password: ", request->mech_password, ")", NULL); }
and:
void auth_request_log_login_failure(struct auth_request *request, const char *subsystem, const char *message)
I'm not a programmer, let alone a C guru, but these extracts look like password failure logging. Are you sure they are recording successful authentications for the logs?
On 2022-10-11 17:07, Bernardo Reino wrote:
Please please stop top-posting. Makes a mess of everything!
On Tue, 11 Oct 2022, Serveria Support wrote:
OK. I thought the code would be the same. I *do* log failed passwords, so I sort of thought only about that string ("given password: ").
I enabled debug passwords on my server, to test, so I could see how it looks like in the log.
The "keyword" in the code seems to be "hide_pass", so if you search for that in the code, you find a few instances where passwords are (selectively) removed/replaced in a given line of text.
But at this point I think the easiest in this absurd (IMHO) quest of yours is to patch src/config/all-settings.c, and, around line 4141:
static bool login_settings_check(void *_set, pool_t pool, const char **error_r ATTR_UNUSED) { struct login_settings *set = _set;
set->log_format_elements_split =
p_strsplit(pool, set->login_log_format_elements, " ");
/* >>> INSERT HERE */ set->auth_debug_passwords = FALSE; /* */
if (set->auth_debug_passwords)
set->auth_debug = TRUE;
if (set->auth_debug)
set->auth_verbose = TRUE;
return TRUE;
}
If I'm right, this will just turn off the flag whenever dovecot checks the settings, i.e. regardless of what's in the actual dovecot.conf, so it should do the trick.
But at this point this feels like a useless homework assignment, so I think I'll stop (I used to be good with C, now I'm read/only, and my time is very limited).
(I do make a mental note of having a statically linked dovecot binary with forced password debugging. You never know when/where you might need it ;-)
Cheers and good luck, Bernardo
On Thu, Oct 13, 2022 at 5:40 PM Serveria Support <support@serveria.com> wrote:
- mkdir ~reinob/Sources
- cd ~reinob/Sources
- wget https://dovecot.org/releases/2.3/dovecot-2.3.19.1.tar.gz
- tar -xzvf dovecot-2.3.19.1.tar.gz
- cd dovecot-2.3.19.1 # make the changes to the file you want to patch
- ./configure --help # select your options
- ./configure --opt1 --opt2 --opt3, etc
- make install
-- Best regards, Odhiambo WASHINGTON, Nairobi,KE +254 7 3200 0004/+254 7 2274 3223 "Oh, the cruft.", egrep -v '^$|^.*#' ¯\_(ツ)_/¯ :-)
Thanks, worked like a charm!
I wonder if I can just copy the compiled binaries over to the working server? Or should I build a new server from scratch and compile Dovecot again? If it's possible to copy over, which files will be required? Just 'dovecot'? Also, in my testing environment I used a Dovecot apt package for Debian. Is it compatible with the vanilla Dovecot built from source? Thanks in advance.
On 2022-10-13 17:55, Odhiambo Washington wrote:
I wonder if I can just copy the compiled binaries over to the working server? Or should I build a new server from scratch and compile Dovecot again? If it's possible to copy over, which files will be required? Just 'dovecot'? Also, in my testing environment I used a Dovecot apt package for Debian. Is it compatible with the vanilla Dovecot built from source? Thanks in advance.
On 2022-10-12 21:44, spi wrote:
participants (16)
-
Aki Tuomi
-
Arjen de Korte
-
Benny Pedersen
-
Bernardo Reino
-
dovecot@ptld.com
-
George Asenov
-
hi@zakaria.website
-
Jochen Bern
-
John Stoffel
-
John Tulp
-
John Tulp
-
mabi
-
Odhiambo Washington
-
Serveria Support
-
spi
-
Stuart Henderson