It's a testing install my main goal is to make it work. I will play
around with password encryption before going live.
I have enabled all possible debugging yet I can's see the value you
mentioned in the log file. Could you please point me?
Aug 29 01:46:04 mx dovecot: master: Dovecot v2.3.13 (89f716dc2) starting
up for pop3, imap, sieve, lmtp (core dumps disabled)
Aug 29 01:46:30 mx dovecot: auth: Debug: Loading modules from directory:
/usr/lib/dovecot/modules/auth
Aug 29 01:46:30 mx dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Aug 29 01:46:30 mx dovecot: auth: Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 29 01:46:30 mx dovecot: auth: Debug: Read auth token secret from
/run/dovecot/auth-token-secret.dat
Aug 29 01:46:30 mx dovecot: auth: Debug: passwd-file
/etc/dovecot/dovecot-master-users: Read 1 users in 0 secs
Aug 29 01:46:30 mx dovecot: auth: Debug: auth client connected
(pid=648541)
Aug 29 01:46:30 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=Y+4ayVrnJ9VV/kpz#011lip=217.199.121.254#011rip=xx.xx.xx.xx#011lport=993#011rport=54567#011resp=AHBvc3RtYXN0ZXJAbWFpbGNpdGFkZWwueHl6ADJoZWt1cWUy
(previous base64 data may contain sensitive data)
Aug 29 01:46:30 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): Performing
passdb lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: Loading modules
from directory: /usr/lib/dovecot/modules/auth
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/lib20_auth_var_expand_crypt.so
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: Module loaded:
/usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: passwd-file
/etc/dovecot/dovecot-master-users: Read 1 users in 0 secs
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): Server accepted connection
(fd=15)
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): Sending version handshake
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>: Handling PASSV
request
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): Performing
passdb lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:30 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): Finished passdb
lookup
Aug 29 01:46:30 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,xx.xx.xx.xx,): Auth request
finished
Aug 29 01:46:30 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): Finished passdb
lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<1>: Finished
Aug 29 01:46:30 mx dovecot: auth: Debug: master in:
REQUEST#0111167065089#011648541#0111#0119960b0ca9068c3c686e5310a3c9fb9e7#011session_pid=648544#011request_auth_token
Aug 29 01:46:30 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): Performing
userdb lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>: Handling USER
request
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): Performing
userdb lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): Finished userdb
lookup
Aug 29 01:46:30 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<2>: Finished
Aug 29 01:46:30 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,xx.xx.xx.xx,): Finished userdb
lookup
Aug 29 01:46:30 mx dovecot: auth: Debug: master userdb out:
USER#0111167065089#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=7933ad17f03af83724ece6df2635483b7dadf3b4
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster/
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster//Maildir, index=,
indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster//Maildir, alt=
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl: owner =
1
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl: owner =
0
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster//Maildir/dovecot-acl not
found
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Mailbox
Sent: Mailbox opened because: SELECT
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/p/o/s/postmaster//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:46:30 mx dovecot:
imap(myuser@mydomain.xyz)<648544>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot: auth: Debug: auth client connected
(pid=648548)
Aug 29 01:46:58 mx dovecot: auth: Debug: auth client connected
(pid=648549)
Aug 29 01:46:58 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=e27BylrnOq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44602#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>: Handling PASSV
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>:
sql(myuser@mydomain.xyz,127.0.0.1,): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<3>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,): Auth request
finished
Aug 29 01:46:58 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot: auth: Debug: master in:
REQUEST#011656408577#011648548#0111#011a0ccbf759f343f0dddc21d76e549f523#011session_pid=648550#011request_auth_token
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>: Handling USER
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>:
sql(myuser@mydomain.xyz,127.0.0.1,): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<4>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug: master userdb out:
USER#011656408577#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=337bc511c6d68fee766b06b089f9ebf60b79a31b
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:58 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=B9jBylrnPq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44606#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>: Handling PASSV
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>:
sql(myuser@mydomain.xyz,127.0.0.1,): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<5>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,): Auth request
finished
Aug 29 01:46:58 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot: auth: Debug: master in:
REQUEST#011245760001#011648549#0111#011515fb953bec25b1461c9e7ac64b2029b#011session_pid=648551#011request_auth_token
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>: Handling USER
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>:
sql(myuser@mydomain.xyz,127.0.0.1,): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<6>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug: master userdb out:
USER#011245760001#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=91ae717b4f4cdfa5583bb297479b1a0cfd764a78
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Sent/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Drafts/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Trash/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/.Junk/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Namespace
Shared/: Using permissions from : mode=0700 gid=default
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648551>: Debug: Mailbox
INBOX: UID 1: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:58 mx dovecot: auth: Debug: auth client connected
(pid=648554)
Aug 29 01:46:58 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=cZnGylrnQq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44610#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>: Handling PASSV
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>:
sql(myuser@mydomain.xyz,127.0.0.1,): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<7>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,): Auth request
finished
Aug 29 01:46:58 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot: auth: Debug: master in:
REQUEST#0112451439617#011648554#0111#01185950d6991c145f770031243a0ee85df#011session_pid=648555#011request_auth_token
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>: Handling USER
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>:
sql(myuser@mydomain.xyz,127.0.0.1,): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<8>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug: master userdb out:
USER#0112451439617#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=b219e107b4a03047bae29da5dfc9ff9d59040288
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648555>: Debug: Mailbox
INBOX: UID 1: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:58 mx dovecot: auth: Debug: auth client connected
(pid=648556)
Aug 29 01:46:58 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=O8LHylrnRK5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44612#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>: Handling PASSV
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>:
sql(myuser@mydomain.xyz,127.0.0.1,): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<9>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,): Auth request
finished
Aug 29 01:46:58 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot: auth: Debug: master in:
REQUEST#0111870004225#011648556#0111#011300d0a24af7cfc60ba31680ea2b48678#011session_pid=648557#011request_auth_token
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>: Handling USER
request
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>:
sql(myuser@mydomain.xyz,127.0.0.1,): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<10>: Finished
Aug 29 01:46:58 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:58 mx dovecot: auth: Debug: master userdb out:
USER#0111870004225#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=09e37aff8ca8d316bb3b98c62a4135a8a695c4cb
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl: owner =
1
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl: owner =
0
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:58 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Mailbox
INBOX: UID 2: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648557>: Debug: Mailbox
INBOX: UID 2: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:59 mx dovecot: auth: Debug: auth client connected
(pid=648558)
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Mailbox
INBOX: UID 1: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648550>: Debug: Mailbox
INBOX: UID 1: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:59 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=HVbWylrnTq5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44622#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>: Handling PASSV
request
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>:
sql(myuser@mydomain.xyz,127.0.0.1,): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<11>: Finished
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,): Auth request
finished
Aug 29 01:46:59 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot: auth: Debug: master in:
REQUEST#01175890689#011648558#0111#011b7f4aa7b3fbeca8198bd8b165d74bd56#011session_pid=648560#011request_auth_token
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>: Handling USER
request
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>:
sql(myuser@mydomain.xyz,127.0.0.1,): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<12>: Finished
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug: master userdb out:
USER#01175890689#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=f401b61b175bd41827a85265327b8136f7605b1c
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:59 mx dovecot: auth: Debug: auth client connected
(pid=648559)
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib15_notify_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mail_log_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib20_mailbox_alias_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Added userdb
setting: mail=maildir:~/Maildir
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Added userdb
setting: plugin/master_user=myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Added userdb
setting: plugin/quota_rule=*:bytes=1073741824
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Effective
uid=2000, gid=2000,
home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Quota root:
name=user backend=dict args=:proxy::quotadict
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Quota rule:
root=user mailbox=* bytes=1073741824 messages=0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Quota
warning: bytes=1073741824 (100%) messages=0 reverse=no
command=quota-warning 100 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Quota
warning: bytes=1020054732 (95%) messages=0 reverse=no
command=quota-warning 95 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Quota
warning: bytes=966367641 (90%) messages=0 reverse=no
command=quota-warning 90 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Quota
warning: bytes=912680550 (85%) messages=0 reverse=no
command=quota-warning 85 myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Quota grace:
root=user bytes=107374182 (10%)
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: quota-dict:
user=myuser@mydomain.xyz, uri=proxy::quotadict, noenforcing=0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Namespace :
type=private, prefix=, sep=/, inbox=yes, hidden=no, list=yes,
subscriptions=yes location=maildir:~/Maildir
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: maildir++:
root=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
index=, indexpvt=, control=,
inbox=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir,
alt=
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl: owner =
1
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Namespace :
type=shared, prefix=Shared/%u/, sep=/, inbox=no, hidden=no,
list=children, subscriptions=yes
location=maildir:%Lh/Maildir/:INDEX=%Lh/Maildir/Shared/%Ld/%Ln
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: shared:
root=/run/dovecot, index=, indexpvt=, control=, inbox=, alt=
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl:
initializing backend with data: vfile
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl: acl
username = myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl: owner =
0
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl vfile:
Global ACLs disabled
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: quota:
quota_over_flag check: quota_over_script unset - skipping
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Mailbox
INBOX: Mailbox opened because: SELECT
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: acl vfile:
file
/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15//Maildir/dovecot-acl
not found
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Mailbox
INBOX: UID 2: Opened mail because: prefetch
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648560>: Debug: Mailbox
INBOX: UID 2: Opened mail because: bodystructure (Mail has other cached
fields, reset_id=1661671904)
Aug 29 01:46:59 mx dovecot: auth: Debug: client in:
AUTH#0111#011PLAIN#011service=imap#011secured=tls#011session=zXvXylrnUK5/AAAB#011lip=127.0.0.1#011rip=127.0.0.1#011lport=143#011rport=44624#011local_name=127.0.0.1#011resp=AHRlc3RAbWFpbGNpdGFkZWwueHl6ADRIUFgxa3Q5IQ==
(previous base64 data may contain sensitive data)
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>: Handling PASSV
request
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>:
sql(myuser@mydomain.xyz,127.0.0.1,): query: SELECT
mailbox.password, mailbox.allow_nets FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<13>: Finished
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished passdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug:
auth(myuser@mydomain.xyz,127.0.0.1,): Auth request
finished
Aug 29 01:46:59 mx dovecot: auth: Debug: client passdb out:
OK#0111#011user=myuser@mydomain.xyz
Aug 29 01:46:59 mx dovecot: auth: Debug: master in:
REQUEST#0111075052545#011648559#0111#011df42e59d960b83fe8c29c0b4f9cac058#011session_pid=648561#011request_auth_token
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>: Handling USER
request
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>:
sql(myuser@mydomain.xyz,127.0.0.1,): Performing userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>:
sql(myuser@mydomain.xyz,127.0.0.1,): SELECT
LOWER('myuser@mydomain.xyz') AS master_user,
LOWER(CONCAT(mailbox.storagebasedirectory, '/', mailbox.storagenode,
'/', mailbox.maildir)) AS home, CONCAT(mailbox.mailboxformat, ':~/',
mailbox.mailboxfolder) AS mail, CONCAT('*:bytes=',
mailbox.quota*1048576) AS quota_rule FROM mailbox,domain WHERE
mailbox.username='myuser@mydomain.xyz' AND mailbox.enableimaptls
=1 AND
mailbox.active=1 AND mailbox.domain=domain.domain AND domain.backupmx=0
AND domain.active=1
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:59 mx dovecot: auth-worker(648543): Debug: conn
unix:auth-worker (pid=648542,uid=110): auth-worker<14>: Finished
Aug 29 01:46:59 mx dovecot: auth: Debug:
sql(myuser@mydomain.xyz,127.0.0.1,): Finished userdb
lookup
Aug 29 01:46:59 mx dovecot: auth: Debug: master userdb out:
USER#0111075052545#011myuser@mydomain.xyz#011master_user=myuser@mydomain.xyz#011home=/var/vmail/vmail1/mydomain.xyz/t/e/s/test-2022.08.28.03.26.15/#011mail=maildir:~/Maildir#011quota_rule=*:bytes=1073741824#011auth_mech=PLAIN#011auth_token=5d013003077f0353817d0da72fbb421968a97534
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561>: Debug: Loading
modules from directory: /usr/lib/dovecot/modules
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib01_acl_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib02_imap_acl_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_last_login_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_mail_crypt_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561>: Debug: Module
loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 29 01:46:59 mx dovecot:
imap(myuser@mydomain.xyz)<648561>