Re: [Dovecot] Unexplainable problem with POP3 quotas

Hello there

I did some more research in the last two days, unfortunately without any result.

First thing, I looked up all the relevant documentation and reviewed our configuration, in particular the directives regarding the quota configuration for POP3. Unless I overlooked something, it looked substantially correct to me.

I also verified that the maildirsize file is updated the way I expected, and it is.

I then focused on our quota-warning.sh script. I wanted to check if something was going wrong during the execution, so I added two logger commands in it. Now the script logs any execution attempt. Moreover, if it fails to inject a message into the mailbox, it logs the failure. After some debugging, I had it logging into /var/log/debug via syslog (see attachment).

The script is in place since hours. Despite the fact that I deliberately triggered a warning condition on an account[*], nothing was logged, so it seems that the quota warning is never issued. And I can't make sense of it, because quota warnings seem to work regualrly via IMAP...

Any clues? Pointers? Whatever? Are we missing something?

Please don't let the Warnock Dilemma eat me! ;-)

Ciao --bronto

root@mgo2-popimap-v01:/usr/local/dovecot/etc# ../sbin/dovecot -n # 1.1.7: /usr/local/dovecot_1.1.7/etc/dovecot.conf Warning: fd limit 1024 is lower than what Dovecot can use under full load (more than 16384). Either grow the limit or change login_max_processes_count and max_mail_processes settings # OS: Linux 2.6.24.5-smp i686 Slackware 11.0.0 base_dir: /var/run/dovecot/ protocols: imap pop3 listen(default): mgo2-popimap-v01:143 listen(imap): mgo2-popimap-v01:143 listen(pop3): mgo2-popimap-v01:110 ssl_disable: yes disable_plaintext_auth: no shutdown_clients: no login_dir: /var/run/dovecot/login login_executable(default): /usr/local/dovecot/libexec/dovecot/imap-login login_executable(imap): /usr/local/dovecot/libexec/dovecot/imap-login login_executable(pop3): /usr/local/dovecot/libexec/dovecot/pop3-login login_greeting: POP/IMAP Server! login_max_processes_count: 4096 max_mail_processes: 8192 first_valid_uid: 4000 first_valid_gid: 4000 mail_location: maildir:%h/Maildir mail_debug: yes mmap_disable: yes mail_nfs_storage: yes mail_nfs_index: yes mail_executable(default): /usr/local/dovecot/libexec/dovecot/imap mail_executable(imap): /usr/local/dovecot/libexec/dovecot/imap mail_executable(pop3): /usr/local/dovecot/libexec/dovecot/pop3 mail_plugins(default): quota imap_quota mail_plugins(imap): quota imap_quota mail_plugins(pop3): quota mail_plugin_dir(default): /usr/local/dovecot/lib/dovecot/imap mail_plugin_dir(imap): /usr/local/dovecot/lib/dovecot/imap mail_plugin_dir(pop3): /usr/local/dovecot/lib/dovecot/pop3 imap_client_workarounds(default): outlook-idle imap_client_workarounds(imap): outlook-idle imap_client_workarounds(pop3): pop3_uidl_format(default): %08Xu%08Xv pop3_uidl_format(imap): %08Xu%08Xv pop3_uidl_format(pop3): %v-%u pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls oe-ns-eoh auth default: passdb: driver: sql args: /usr/local/dovecot/etc/dovecot-sql.conf userdb: driver: sql args: /usr/local/dovecot/etc/dovecot-sql.conf plugin: quota: maildir:User quota quota_rule: ?:storage=100M quota_warning: storage=95%% /usr/local/dovecot/bin/quota-warning.sh 95 %h %n %d quota_warning2: storage=80%% /usr/local/dovecot/bin/quota-warning.sh 80 %h %n %d

root@mgo2-popimap-v01:/usr/local/dovecot/etc# grep -v '^ *\(#.*\)\?$' dovecot-sql.conf driver = pgsql connect = host=172.30.213.10 dbname=postfix user=postfix password=_HIDDEN_PASSWORD_ default_pass_scheme = SHA1 password_query = SELECT username, password FROM postfix.accounts WHERE (username = '%u' OR username = '%u@_HIDDEN_DOMAIN_') AND ( user_status_id = 0 or user_status_id = 2 ); user_query = SELECT maildir AS home, uid, gid, '*:storage=' || max_quota || 'B' AS quota_rule FROM postfix.accounts WHERE (username = '%u' OR username = '%u@_HIDDEN_DOMAIN_') AND ( user_status_id = 2 OR user_status_id = 0 )

The log says:

Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): Loading modules from directory: /usr/local/dovecot/lib/dovecot/pop3 Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): Module loaded: /usr/local/dovecot/lib/dovecot/pop3/lib10_quota_plugin.so Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): Effective uid=10812, gid=5008 Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): Quota root: name=User quota backend=maildir args= Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): Quota rule: root=User quota mailbox=* bytes=104857600 (0%) messages=0 (0%) Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): Quota warning: bytes=99614720 (95%) messages=0 (0%) command=/usr/local/dovecot/bin/quota-warning.sh 95 /mnt/maildir/_HIDDEN_DOMAIN_/USER/r/ra/rasrcbldg@_HIDDEN_DOMAIN_ rasrcbldg _HIDDEN_DOMAIN_ Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): Quota warning: bytes=83886080 (80%) messages=0 (0%) command=/usr/local/dovecot/bin/quota-warning.sh 80 /mnt/maildir/_HIDDEN_DOMAIN_/USER/r/ra/rasrcbldg@_HIDDEN_DOMAIN_ rasrcbldg _HIDDEN_DOMAIN_ Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): maildir: data=/mnt/maildir/_HIDDEN_DOMAIN_/USER/r/ra/rasrcbldg@_HIDDEN_DOMAIN_/Maildir Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: POP3(rasrcbldg@_HIDDEN_DOMAIN_): maildir++: root=/mnt/maildir/_HIDDEN_DOMAIN_/USER/r/ra/rasrcbldg@_HIDDEN_DOMAIN_/Maildir, index=, control=, inbox=/mnt/maildir/_HIDDEN_DOMAIN_/USER/r/ra/rasrcbldg@_HIDDEN_DOMAIN_/Maildir Apr 28 10:32:13 mgo2-popimap-v01._HIDDEN_DOMAIN_ dovecot: pop3-login: Login: user=_HIDDEN_DOMAIN_>, method=PLAIN, rip=_HIDDEN_ADDRESS_, lip=192.168.207.16

Note that having this user's quota the same as the default quota is just an incident, if a user has a quota different from the default, the actual quota it is reported correctly in the logs.