Wednesday, April 6, 2016

Dovecot Quotas are not recalculated nor is mail rejected if quota is exceeded



I'm trying to set up quotas in Dovecot. Currently Postfix is running together with Dovecot and postfixadmin, on Debian Jessie.



The problem I have is that the quotas are not applied, nor re-calculated. Even if I exceed the quota by 300% or more, mails still get delivered. Also when a new mail is received the value in the corresponding table quota2 never gets updated.



Here is what I've done so far:




I have edited my /etc/dovecot/dovecot.conf to enable quotas (well, at least I think I did so):




# 2.1.7: /etc/dovecot/dovecot.conf
# OS: Linux 3.2.0-4-amd64 x86_64 Debian 7.1
# Enable the quota plugin
mail_plugins = $mail_plugins quota

auth_mechanisms = plain login
log_timestamp = "%Y-%m-%d %H:%M:%S "


# We need more than 10 connections per ip
mail_max_userip_connections = 20

# Enable only imap
protocols = imap

# Certificates
ssl_cert=ssl_key=

passdb {
args = /etc/dovecot/dovecot-mysql.conf
driver = sql
}

userdb {
args = /etc/dovecot/dovecot-mysql.conf
driver = sql
}


service auth {
unix_listener /var/spool/postfix/private/auth_dovecot {
group = postfix
mode = 0660
user = postfix
}
unix_listener auth-master {
mode = 0600
user = vmail

}
user = root
}

# Enable the dict stuff for quotas
service dict {
unix_listener dict {
mode = 0600
user = vmail
}

}

# Enable imap_quota
protocol imap {
mail_plugins = quota imap_quota
}

plugin {
# Using SQL Tables to store current quota size
quota_grace = 10M

quota = dict:User quota::proxy::sqluserquota
quota_exceeded_message = Sorry, the mailbox of %u has exceeded the limit.
}

auth_debug = yes
auth_debug_passwords = yes
auth_verbose = yes
mail_debug = yes

dict {

sqluserquota = mysql:/etc/dovecot/dovecot-dict-sql-user.conf
}

protocol pop3 {
pop3_uidl_format = %08Xu%08Xv
}

protocol lda {
mail_plugins = quota
auth_socket_path = /var/run/dovecot/auth-master

postmaster_address = admin@domain
}


The file /etc/dovecot/dovecot-dict-sql-user.conf contains:




connect = host=localhost dbname=postfixadmin user=postfixadmin password=secret

map {

pattern = priv/quota/storage
table = quota2
username_field = username
value_field = bytes
}
map {
pattern = priv/quota/messages
table = quota2
username_field = username
value_field = messages

}


And the queries for the mailboxes and passwords in the file /etc/dovecot/dovecot-mysql.conf contain:




driver = mysql
connect = host=localhost dbname=postfixadmin user=postfixadmin password=secret
default_pass_scheme = PLAIN-MD5


password_query = SELECT CONCAT('*:bytes=', quota) AS userdb_quota_rule, password FROM mailbox WHERE username = '%u'

user_query = SELECT CONCAT('maildir:/var/vmail/',maildir) AS mail, CONCAT('*:bytes=', quota) AS quota_rule, 5000 AS uid, 5000 AS gid FROM mailbox WHERE username = '%u'


If I manually trigger a calculate of the quote things look reasonable:




root@zame:/etc/dovecot# doveadm quota recalc -u user@domain
root@zame:/etc/dovecot# doveadm quota get -u user@domain

Quota name Type Value Limit %
User quota STORAGE 37091 10000 370
User quota MESSAGE 126 - 0


If I enable the Display Quota Plugin in Thunderbird, Thunderbird also reports a usage of 371% of the quota. So the reading of the current values from the database seems to work.



But if I send a mail to that mailbox (where the quota is exceeded by 370%) the mail still gets delivered.



The log at /var/log/mail.log shows the following during a login (if I just start thunderbird):





Aug 21 17:27:01 zame dovecot: auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Aug 21 17:27:01 zame dovecot: auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 21 17:27:01 zame dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat
Aug 21 17:27:01 zame dovecot: auth: Debug: auth client connected (pid=22901)
Aug 21 17:27:01 zame dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured#011session=E54/5tMd9QBUSpxA#011lip=91.214.168.151#011rip=84.74.156.64#011lport=143#011rport=61173
Aug 21 17:27:01 zame dovecot: auth: Debug: client passdb out: CONT#0111
Aug 21 17:27:01 zame dovecot: auth: Debug: client in: CONT#0111#011AGVnQHphbWUuY2gANHBsVVRPX25pdW0= (previous base64 data may contain sensitive data)
Aug 21 17:27:01 zame dovecot: auth-worker(22905): Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth

Aug 21 17:27:01 zame dovecot: auth-worker(22905): Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 21 17:27:01 zame dovecot: auth-worker(22905): Debug: sql(eg@domain,84.74.156.64): query: SELECT CONCAT('*:bytes=', quota) AS userdb_quota_rule, password FROM mailbox WHERE username = 'eg@domain'
Aug 21 17:27:01 zame dovecot: auth: Debug: client passdb out: OK#0111#011user=eg@domain
Aug 21 17:27:01 zame dovecot: auth: Debug: master in: REQUEST#0111999634433#01122901#0111#011636e2ad86df15a637411ff278b1f4db9#011session_pid=22907#011request_auth_token
Aug 21 17:27:01 zame dovecot: auth-worker(22905): Debug: sql(eg@domain,84.74.156.64): SELECT CONCAT('maildir:/var/vmail/',maildir) AS mail, CONCAT('*:bytes=', quota) AS quota_rule, 5000 AS uid, 5000 AS gid FROM mailbox WHERE username = 'eg@domain'
Aug 21 17:27:01 zame dovecot: auth: Debug: master userdb out: USER#0111999634433#011eg@domain#011mail=maildir:/var/vmail/domain/eg/#011quota_rule=*:bytes=10240000#011uid=5000#011gid=5000#011auth_token=d6c1d88ed77a7ffaf8057151bb5db289c4815786
Aug 21 17:27:01 zame dovecot: imap-login: Login: user=, method=PLAIN, rip=84.74.156.64, lip=91.214.168.151, mpid=22907, TLS, session=
Aug 21 17:27:01 zame dovecot: imap: Debug: Loading modules from directory: /usr/lib/dovecot/modules
Aug 21 17:27:01 zame dovecot: imap: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so
Aug 21 17:27:01 zame dovecot: imap: Debug: Module loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so

Aug 21 17:27:01 zame dovecot: imap: Debug: Added userdb setting: mail=maildir:/var/vmail/domain/eg/
Aug 21 17:27:01 zame dovecot: imap: Debug: Added userdb setting: plugin/quota_rule=*:bytes=10240000
Aug 21 17:27:01 zame dovecot: imap(eg@domain): Debug: Effective uid=5000, gid=5000, home=
Aug 21 17:27:01 zame dovecot: imap(eg@domain): Debug: Quota root: name=User quota backend=dict args=:proxy::sqluserquota
Aug 21 17:27:01 zame dovecot: imap(eg@domain): Debug: Quota rule: root=User quota mailbox=* bytes=10240000 messages=0
Aug 21 17:27:01 zame dovecot: imap(eg@domain): Debug: Quota grace: root=User quota bytes=10485760
Aug 21 17:27:01 zame dovecot: imap(eg@domain): Debug: dict quota: user=eg@domain, uri=proxy::sqluserquota, noenforcing=0
Aug 21 17:27:01 zame dovecot: imap(eg@domain): Debug: maildir++: root=/var/vmail/domain/eg, index=, indexpvt=, control=, inbox=/var/vmail/domain/eg, alt=
Aug 21 17:27:14 zame dovecot: auth: Debug: auth client connected (pid=22910)
Aug 21 17:27:14 zame dovecot: auth: Debug: client in: AUTH#0111#011PLAIN#011service=imap#011secured#011session=OdQF59MdDQBUSpxA#011lip=91.214.168.151#011rip=84.74.156.64#011lport=143#011rport=61197

Aug 21 17:27:14 zame dovecot: auth: Debug: client passdb out: CONT#0111
Aug 21 17:27:14 zame dovecot: auth: Debug: client in: CONT#0111#011AGVnQHphbWUuY2gANHBsVVRPX25pdW0= (previous base64 data may contain sensitive data)
Aug 21 17:27:14 zame dovecot: auth-worker(22905): Debug: sql(eg@domain,84.74.156.64): query: SELECT CONCAT('*:bytes=', quota) AS userdb_quota_rule, password FROM mailbox WHERE username = 'eg@domain'
Aug 21 17:27:14 zame dovecot: auth: Debug: client passdb out: OK#0111#011user=eg@domain
Aug 21 17:27:14 zame dovecot: auth: Debug: master in: REQUEST#011213516289#01122910#0111#0119ed3b0c072c59928f45493e80687b82a#011session_pid=22911#011request_auth_token
Aug 21 17:27:14 zame dovecot: auth-worker(22905): Debug: sql(eg@domain,84.74.156.64): SELECT CONCAT('maildir:/var/vmail/',maildir) AS mail, CONCAT('*:bytes=', quota) AS quota_rule, 5000 AS uid, 5000 AS gid FROM mailbox WHERE username = 'eg@domain'
Aug 21 17:27:14 zame dovecot: auth: Debug: master userdb out: USER#011213516289#011eg@domain#011mail=maildir:/var/vmail/domain/eg/#011quota_rule=*:bytes=10240000#011uid=5000#011gid=5000#011auth_token=58a5177adf128ec45bf2e621abc97e43c9924530
Aug 21 17:27:14 zame dovecot: imap-login: Login: user=, method=PLAIN, rip=84.74.156.64, lip=91.214.168.151, mpid=22911, TLS, session=
Aug 21 17:27:14 zame dovecot: imap: Debug: Loading modules from directory: /usr/lib/dovecot/modules
Aug 21 17:27:14 zame dovecot: imap: Debug: Module loaded: /usr/lib/dovecot/modules/lib10_quota_plugin.so

Aug 21 17:27:14 zame dovecot: imap: Debug: Module loaded: /usr/lib/dovecot/modules/lib11_imap_quota_plugin.so
Aug 21 17:27:14 zame dovecot: imap: Debug: Added userdb setting: mail=maildir:/var/vmail/domain/eg/
Aug 21 17:27:14 zame dovecot: imap: Debug: Added userdb setting: plugin/quota_rule=*:bytes=10240000
Aug 21 17:27:14 zame dovecot: imap(eg@domain): Debug: Effective uid=5000, gid=5000, home=
Aug 21 17:27:14 zame dovecot: imap(eg@domain): Debug: Quota root: name=User quota backend=dict args=:proxy::sqluserquota
Aug 21 17:27:14 zame dovecot: imap(eg@domain): Debug: Quota rule: root=User quota mailbox=* bytes=10240000 messages=0
Aug 21 17:27:14 zame dovecot: imap(eg@domain): Debug: Quota grace: root=User quota bytes=10485760
Aug 21 17:27:14 zame dovecot: imap(eg@domain): Debug: dict quota: user=eg@domain, uri=proxy::sqluserquota, noenforcing=0
Aug 21 17:27:14 zame dovecot: imap(eg@domain): Debug: maildir++: root=/var/vmail/domain/eg, index=, indexpvt=, control=, inbox=/var/vmail/domain/eg, alt=



And the following while a mail is received (for the user where the quota is exceeded):




Aug 21 17:31:50 zame postfix/smtpd[22964]: connect from mout.gmx.net[212.227.15.19]
Aug 21 17:31:50 zame dovecot: auth: Debug: Loading modules from directory: /usr/lib/dovecot/modules/auth
Aug 21 17:31:50 zame dovecot: auth: Debug: Module loaded: /usr/lib/dovecot/modules/auth/libdriver_mysql.so
Aug 21 17:31:50 zame dovecot: auth: Debug: Read auth token secret from /var/run/dovecot/auth-token-secret.dat
Aug 21 17:31:50 zame dovecot: auth: Debug: auth client connected (pid=0)
Aug 21 17:31:50 zame postfix/smtpd[22964]: CB20237236F: client=mout.gmx.net[212.227.15.19]

Aug 21 17:31:50 zame postfix/cleanup[22971]: CB20237236F: message-id=
Aug 21 17:31:50 zame postfix/qmgr[22288]: CB20237236F: from=, size=2826, nrcpt=1 (queue active)
Aug 21 17:31:50 zame postfix/virtual[22972]: CB20237236F: to=, relay=virtual, delay=0.06, delays=0.04/0.02/0/0.01, dsn=2.0.0, status=sent (delivered to maildir)
Aug 21 17:31:50 zame postfix/qmgr[22288]: CB20237236F: removed
Aug 21 17:31:50 zame postfix/smtpd[22964]: disconnect from mout.gmx.net[212.227.15.19]


As mentioned before, the value of the column bytes doesn't get updated in the table quotas2.



So, I'm somehow missing how to link dovecot to take into account the quotas and update them when it tries to deliver a mail to one of the mailboxes at /var/vmail/.




I would be glad for any hints.



For completeness, here is the output of dovecot -n:




# 2.2.13: /etc/dovecot/dovecot.conf
# OS: Linux 3.2.0-4-amd64 x86_64 Debian 8.1
auth_debug = yes
auth_debug_passwords = yes

auth_mechanisms = plain login
auth_verbose = yes
dict {
sqluserquota = mysql:/etc/dovecot/dovecot-dict-sql-user.conf
}
log_timestamp = "%Y-%m-%d %H:%M:%S "
mail_debug = yes
mail_max_userip_connections = 20
mail_plugins = " quota"
passdb {

args = /etc/dovecot/dovecot-mysql.conf
driver = sql
}
plugin {
quota = dict:User quota::proxy::sqluserquota
quota_exceeded_message = Sorry, the mailbox of %u has exceeded the limit.
quota_grace = 10M
}
protocols = imap
service auth {

unix_listener /var/spool/postfix/private/auth_dovecot {
group = postfix
mode = 0660
user = postfix
}
unix_listener auth-master {
mode = 0600
user = vmail
}
user = root

}
service dict {
unix_listener dict {
mode = 0600
user = vmail
}
}
ssl_cert = ssl_key = userdb {

args = /etc/dovecot/dovecot-mysql.conf
driver = sql
}
protocol imap {
mail_plugins = quota imap_quota
}
protocol pop3 {
pop3_uidl_format = %08Xu%08Xv
}
protocol lda {

auth_socket_path = /var/run/dovecot/auth-master
mail_plugins = quota
postmaster_address = admin@domain
}


Edit: Its getting more confusing if I look at the table quota2 more in detail:



If I send a mail from the account where the quotas are enabled (using Thunderbird or Squirrelmail), I can actually see that the value bytes in the quota2 is increasing. I think this must be due to the copying of the message into the sent folder.




It seems like the quota is just not applied to incoming mail?


Answer



Okay, after some more research I found the solution: Problem was inside the postfix configuration, not dovecot!



Postfix had a wrong entry in the mydestination line - so it never used the virtual transport to deliver the messages to Dovecot, but delivered them directly to the local mailbox.



After removing the entry from mydestination in the postfix config, everything is working as expected. The log when mail is received now also looks different -it is now speaking explicitly about Dovecot:



Aug 21 20:32:39 zame postfix/pipe[26958]: 676243723C8: to=, relay=dovecot, delay=0.85, delays=0.5/0.03/0/0.33, dsn=2.0.0, status=sent (delivered via dovecot service)



Note the relay=dovecot.


No comments:

Post a Comment

linux - How to SSH to ec2 instance in VPC private subnet via NAT server

I have created a VPC in aws with a public subnet and a private subnet. The private subnet does not have direct access to external network. S...