Dovecot mail-crypt webmail can't read encrypted messages
Serveria Support
support at serveria.com
Mon Aug 29 06:26:41 UTC 2022
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 at 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 at 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 at mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): Finished passdb
lookup
Aug 29 01:46:30 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at 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 at mydomain.xyz,xx.xx.xx.xx,<Y+4ayVrnJ9VV/kpz>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:30 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:30 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:30 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl: owner =
1
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:30 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl: owner =
0
Aug 29 01:46:30 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:30 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:30 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:46:30 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<e27BylrnOq5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser at 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 at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<B9jBylrnPq5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Namespace
Shared/: Using permissions from : mode=0700 gid=default
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648551><B9jBylrnPq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<cZnGylrnQq5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648555><cZnGylrnQq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<O8LHylrnRK5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648557><O8LHylrnRK5/AAAB>: Debug: Mailbox
INBOX: UID 2: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648550><e27BylrnOq5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<HVbWylrnTq5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648560><HVbWylrnTq5/AAAB>: Debug: Mailbox
INBOX: UID 2: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<zXvXylrnUK5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:46:59 mx dovecot:
imap(myuser at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648561><zXvXylrnUK5/AAAB>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:03 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<2aYSy1rnXK5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:03 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:03 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:03 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:03 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:03 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:03 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:47:03 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:03 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648581><2aYSy1rnXK5/AAAB>: Debug: Mailbox
Sent: UID 1: Opened mail because: prefetch
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:04 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<u68ly1rnZK5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Mailbox
Sent: UID 1: Opened mail because: prefetch
Aug 29 01:47:04 mx dovecot:
imap(myuser at mydomain.xyz)<648583><u68ly1rnZK5/AAAB>: Debug: Mailbox
Sent: UID 1: Opened mail because: header stream
Aug 29 01:47:04 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:06 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<LstCy1rnaK5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Mailbox
Sent: UID 2: Opened mail because: prefetch
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648585><LstCy1rnaK5/AAAB>: Debug: Mailbox
Sent: UID 2: Opened mail because: header stream
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): Finished passdb
lookup
Aug 29 01:47:06 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<JJBEy1rnaq5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Mailbox
Sent: UID 2: Opened mail because: prefetch
Aug 29 01:47:06 mx dovecot:
imap(myuser at mydomain.xyz)<648587><JJBEy1rnaq5/AAAB>: Debug: Mailbox
Sent: UID 2: Opened mail because: header stream
Aug 29 01:47:06 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at 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 at mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): Finished passdb
lookup
Aug 29 01:47:08 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,</u5by1rncK5/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:47:08 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:47:08 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:47:08 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl: owner =
1
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:08 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl: owner =
0
Aug 29 01:47:08 mx dovecot:
imap(myuser at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:47:08 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:47:08 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:47:08 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648589></u5by1rncK5/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:52:08 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): Finished passdb
lookup
Aug 29 01:55:50 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<uIx96lrnELB/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:55:50 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:55:50 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:55:50 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl: owner =
1
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:55:50 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl: owner =
0
Aug 29 01:55:50 mx dovecot:
imap(myuser at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:55:50 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648815><uIx96lrnELB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:55:50 mx dovecot:
imap(myuser at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser at 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 at mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): Finished passdb
lookup
Aug 29 01:56:59 mx dovecot: auth: Debug:
auth(myuser at 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 at 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 at 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 at 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 at 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 at mydomain.xyz,127.0.0.1,<bWmc7lrnVrB/AAAB>): SELECT
LOWER('myuser at 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 at 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 at 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 at 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 at mydomain.xyz#011master_user=myuser at 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 at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:56:59 mx dovecot:
imap(myuser at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Added userdb
setting: plugin/master_user=myuser at mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:56:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser at mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser at mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser at mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser at mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: quota-dict:
user=myuser at mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:56:59 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl: owner =
1
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:56:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl: acl
username = myuser at mydomain.xyz
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl: owner =
0
Aug 29 01:56:59 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:56:59 mx dovecot:
imap(myuser at 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 at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:56:59 mx dovecot:
imap(myuser at 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 at 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 at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 02:02:10 mx dovecot:
imap(myuser at mydomain.xyz)<648870><bWmc7lrnVrB/AAAB>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 02:02:50 mx dovecot:
imap(myuser at mydomain.xyz)<648544><Y+4ayVrnJ9VV/kpz>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
On 2022-08-29 07:56, Aki Tuomi wrote:
>> On 28/08/2022 09:20 EEST Serveria Support <support at serveria.com>
>> wrote:
>>
>>
>> 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 at 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
More information about the dovecot
mailing list