[Dovecot] Problems with quota dict in 1.1.alpha4
Hello,
there are problems with quota dict when multiple dovecot deliver processes are launched in parallel. It can be reproduced by sending a mail with multiple different recipients - the mail is delivered OK to all recipients, but the quota are not updated correctly in sql. I looked at the code and it seems that the problem is somewhere in dict cache. If I configure in Postfix max number of deliver processes to 1, dict quota is updated correctly.
postconf -n output: # 1.1.alpha4: /usr/local/dovecot/etc/dovecot.conf base_dir: /var/run/dovecot/ syslog_facility: local0 protocols: pop3 ssl_disable: yes disable_plaintext_auth: no login_dir: /var/run/dovecot/login login_executable: /usr/local/dovecot/libexec/dovecot/pop3-login login_greeting: Server. login_process_per_connection: no login_process_size: 64 verbose_proctitle: yes first_valid_uid: 95 first_valid_gid: 95 mail_uid: 95 mail_gid: 95 mail_location: maildir:~/Maildir mail_debug: yes fsync_disable: yes mail_executable: /usr/local/dovecot/libexec/dovecot/pop3 mail_plugins: quota mail_plugin_dir: /usr/local/dovecot/lib/dovecot/pop3 pop3_enable_last: yes pop3_client_workarounds: outlook-no-nuls oe-ns-eoh auth default: mechanisms: plain login digest-md5 cram-md5 apop cache_size: 2048 cache_ttl: 28800 cache_negative_ttl: 60 user: doveauth verbose: yes debug: yes debug_passwords: yes passdb: driver: sql args: /usr/local/dovecot/etc/dovecot-sql.conf userdb: driver: prefetch userdb: driver: sql args: /usr/local/dovecot/etc/dovecot-sql.conf socket: type: listen master: path: /var/run/dovecot/auth-master mode: 384 user: vmail group: vmail plugin: quota: dict:::proxy:/var/run/dovecot/dict-server:quotadict dict: quotadict: mysql:/usr/local/dovecot/etc/dovecot-sql-dict-quota.conf
Regards, Arvids
On Fri, 2007-09-14 at 22:30 +0300, arvids wrote:
Hello,
there are problems with quota dict when multiple dovecot deliver processes are launched in parallel. It can be reproduced by sending a mail with multiple different recipients - the mail is delivered OK to all recipients, but the quota are not updated correctly in sql. I looked at the code and it seems that the problem is somewhere in dict cache.
I couldn't reproduce this, but I did fix some other problems with quota. Try the latest nightly snapshot to see if they fixed this problem also?
On Saturday 22 September 2007 16:29:50 Timo Sirainen wrote:
I couldn't reproduce this, but I did fix some other problems with quota. Try the latest nightly snapshot to see if they fixed this problem also?
I have tried snapshot eab04861f2fc - it does not fix the problem. The problem is constantly reproducible on my system. I will try to describe problem in details. I have created 6 test users - test1..test6(the number of users is not important). Then I send one email with these 6 users as recipients. Postfix server launches 6 dovecot deliver processes in parallel. And the quota dictionary is updateted incorrectly. The incorrectness is random - sometimes quota dictionary is updated as if one of these 6 users received 6 messages, sometimes as if one user received 3 messages, one user - 2 messages, one user - 1 message etc. The total count of received messages always equals the total count of quota updates for these users - just the updates are for wrong users. I can not reproduce the problem if I launch deliver process with different recipients from command-line quickly one after another. Below is details for one such mail.
SQL dict before mail: mysql> select * from current where user like "test_"; Empty set (0.00 sec)
SQL dict after mail: mysql> select * from current where user like "test_"; +-------+----------------+---------+ | user | path | current | +-------+----------------+---------+ | test2 | quota/messages | 1 | | test2 | quota/storage | 940 | | test3 | quota/messages | 5 | | test3 | quota/storage | 4700 | +-------+----------------+---------+ 4 rows in set (0.00 sec)
delivery logs for this: Sep 22 17:52:42 server2 deliver(test2): Loading modules from directory: /usr/local/dovecot/lib/dovecot/lda Sep 22 17:52:42 server2 deliver(test2): Module loaded: /usr/local/dovecot/lib/dovecot/lda/lib10_quota_plugin.so Sep 22 17:52:42 server2 deliver(test2): auth input: test2 Sep 22 17:52:42 server2 deliver(test2): auth input: home=/vmail/00/test2 Sep 22 17:52:42 server2 deliver(test2): auth input: uid=95 Sep 22 17:52:42 server2 deliver(test2): auth input: gid=95 Sep 22 17:52:42 server2 deliver(test2): auth input: quota_rule=*:storage=2000 Sep 22 17:52:42 server2 deliver(test2): auth input: quota_rule2=*:messages=40 Sep 22 17:52:42 server2 deliver(test2): auth input: quota_warning=storage=950 /usr/local/bin/quota-storage-warning.sh 95 Sep 22 17:52:42 server2 deliver(test2): auth input: quota_warning2=messages=19 /usr/local/bin/quota-messages-warning.sh 95 Sep 22 17:52:42 server2 deliver(test2): Home dir not found: /vmail/00/test2 Sep 22 17:52:42 server2 deliver(test2): dict quota: user = test2, uri = proxy:/var/run/dovecot/dict-server:quotadict Sep 22 17:52:42 server2 deliver(test2): Quota rule: root= mailbox= storage=2000kB messages=0 Sep 22 17:52:42 server2 deliver(test2): Quota rule: root= mailbox= storage=2000kB messages=40 Sep 22 17:52:42 server2 deliver(test2): maildir: data=/vmail/00/test2/Maildir Sep 22 17:52:42 server2 deliver(test2): maildir++: root=/vmail/00/test2/Maildir, index=, control=, inbox=/vmail/00/test2/Maildir Sep 22 17:52:42 server2 deliver(test2): msgid=<200709221752.41292.arvids@arvids.net>: saved mail to INBOX Sep 22 17:52:42 server2 deliver(test3): Loading modules from directory: /usr/local/dovecot/lib/dovecot/lda Sep 22 17:52:42 server2 deliver(test3): Module loaded: /usr/local/dovecot/lib/dovecot/lda/lib10_quota_plugin.so Sep 22 17:52:42 server2 deliver(test3): auth input: test3 Sep 22 17:52:42 server2 deliver(test3): auth input: home=/vmail/00/test3 Sep 22 17:52:42 server2 deliver(test3): auth input: uid=95 Sep 22 17:52:42 server2 deliver(test3): auth input: gid=95 Sep 22 17:52:42 server2 deliver(test3): auth input: quota_rule=*:storage=2000 Sep 22 17:52:42 server2 deliver(test3): auth input: quota_rule2=*:messages=40 Sep 22 17:52:42 server2 deliver(test3): auth input: quota_warning=storage=950 /usr/local/bin/quota-storage-warning.sh 95 Sep 22 17:52:42 server2 deliver(test3): auth input: quota_warning2=messages=19 /usr/local/bin/quota-messages-warning.sh 95 Sep 22 17:52:42 server2 deliver(test3): Home dir not found: /vmail/00/test3 Sep 22 17:52:42 server2 deliver(test3): dict quota: user = test3, uri = proxy:/var/run/dovecot/dict-server:quotadict Sep 22 17:52:42 server2 deliver(test3): Quota rule: root= mailbox= storage=2000kB messages=0 Sep 22 17:52:42 server2 deliver(test3): Quota rule: root= mailbox= storage=2000kB messages=40 Sep 22 17:52:42 server2 deliver(test3): maildir: data=/vmail/00/test3/Maildir Sep 22 17:52:42 server2 deliver(test3): maildir++: root=/vmail/00/test3/Maildir, index=, control=, inbox=/vmail/00/test3/Maildir Sep 22 17:52:42 server2 deliver(test1): Loading modules from directory: /usr/local/dovecot/lib/dovecot/lda Sep 22 17:52:42 server2 deliver(test1): Module loaded: /usr/local/dovecot/lib/dovecot/lda/lib10_quota_plugin.so Sep 22 17:52:42 server2 deliver(test1): auth input: test1 Sep 22 17:52:42 server2 deliver(test1): auth input: home=/vmail/00/test1 Sep 22 17:52:42 server2 deliver(test1): auth input: uid=95 Sep 22 17:52:42 server2 deliver(test1): auth input: gid=95 Sep 22 17:52:42 server2 deliver(test1): auth input: quota_rule=*:storage=2000 Sep 22 17:52:42 server2 deliver(test1): auth input: quota_rule2=*:messages=40 Sep 22 17:52:42 server2 deliver(test1): auth input: quota_warning=storage=950 /usr/local/bin/quota-storage-warning.sh 95 Sep 22 17:52:42 server2 deliver(test1): auth input: quota_warning2=messages=19 /usr/local/bin/quota-messages-warning.sh 95 Sep 22 17:52:42 server2 deliver(test1): Home dir not found: /vmail/00/test1 Sep 22 17:52:42 server2 deliver(test1): dict quota: user = test1, uri = proxy:/var/run/dovecot/dict-server:quotadict Sep 22 17:52:42 server2 deliver(test1): Quota rule: root= mailbox= storage=2000kB messages=0 Sep 22 17:52:42 server2 deliver(test1): Quota rule: root= mailbox= storage=2000kB messages=40 Sep 22 17:52:42 server2 deliver(test1): maildir: data=/vmail/00/test1/Maildir Sep 22 17:52:42 server2 deliver(test1): maildir++: root=/vmail/00/test1/Maildir, index=, control=, inbox=/vmail/00/test1/Maildir Sep 22 17:52:42 server2 deliver(test6): Loading modules from directory: /usr/local/dovecot/lib/dovecot/lda Sep 22 17:52:42 server2 deliver(test6): Module loaded: /usr/local/dovecot/lib/dovecot/lda/lib10_quota_plugin.so Sep 22 17:52:42 server2 deliver(test6): auth input: test6 Sep 22 17:52:42 server2 deliver(test6): auth input: home=/vmail/00/test6 Sep 22 17:52:42 server2 deliver(test6): auth input: uid=95 Sep 22 17:52:42 server2 deliver(test6): auth input: gid=95 Sep 22 17:52:42 server2 deliver(test6): auth input: quota_rule=*:storage=2000 Sep 22 17:52:42 server2 deliver(test6): auth input: quota_rule2=*:messages=40 Sep 22 17:52:42 server2 deliver(test6): auth input: quota_warning=storage=950 /usr/local/bin/quota-storage-warning.sh 95 Sep 22 17:52:42 server2 deliver(test6): auth input: quota_warning2=messages=19 /usr/local/bin/quota-messages-warning.sh 95 Sep 22 17:52:42 server2 deliver(test6): Home dir not found: /vmail/00/test6 Sep 22 17:52:42 server2 deliver(test6): dict quota: user = test6, uri = proxy:/var/run/dovecot/dict-server:quotadict Sep 22 17:52:42 server2 deliver(test6): Quota rule: root= mailbox= storage=2000kB messages=0 Sep 22 17:52:42 server2 deliver(test6): Quota rule: root= mailbox= storage=2000kB messages=40 Sep 22 17:52:42 server2 deliver(test6): maildir: data=/vmail/00/test6/Maildir Sep 22 17:52:42 server2 deliver(test6): maildir++: root=/vmail/00/test6/Maildir, index=, control=, inbox=/vmail/00/test6/Maildir Sep 22 17:52:42 server2 deliver(test4): Loading modules from directory: /usr/local/dovecot/lib/dovecot/lda Sep 22 17:52:42 server2 deliver(test4): Module loaded: /usr/local/dovecot/lib/dovecot/lda/lib10_quota_plugin.so Sep 22 17:52:42 server2 deliver(test4): auth input: test4 Sep 22 17:52:42 server2 deliver(test4): auth input: home=/vmail/00/test4 Sep 22 17:52:42 server2 deliver(test4): auth input: uid=95 Sep 22 17:52:42 server2 deliver(test4): auth input: gid=95 Sep 22 17:52:42 server2 deliver(test4): auth input: quota_rule=*:storage=2000 Sep 22 17:52:42 server2 deliver(test4): auth input: quota_rule2=*:messages=40 Sep 22 17:52:42 server2 deliver(test4): auth input: quota_warning=storage=950 /usr/local/bin/quota-storage-warning.sh 95 Sep 22 17:52:42 server2 deliver(test4): auth input: quota_warning2=messages=19 /usr/local/bin/quota-messages-warning.sh 95 Sep 22 17:52:42 server2 deliver(test4): Home dir not found: /vmail/00/test4 Sep 22 17:52:42 server2 deliver(test4): dict quota: user = test4, uri = proxy:/var/run/dovecot/dict-server:quotadict Sep 22 17:52:42 server2 deliver(test4): Quota rule: root= mailbox= storage=2000kB messages=0 Sep 22 17:52:42 server2 deliver(test4): Quota rule: root= mailbox= storage=2000kB messages=40 Sep 22 17:52:42 server2 deliver(test4): maildir: data=/vmail/00/test4/Maildir Sep 22 17:52:42 server2 deliver(test4): maildir++: root=/vmail/00/test4/Maildir, index=, control=, inbox=/vmail/00/test4/Maildir Sep 22 17:52:42 server2 deliver(test5): Loading modules from directory: /usr/local/dovecot/lib/dovecot/lda Sep 22 17:52:42 server2 deliver(test5): Module loaded: /usr/local/dovecot/lib/dovecot/lda/lib10_quota_plugin.so Sep 22 17:52:42 server2 deliver(test5): auth input: test5 Sep 22 17:52:42 server2 deliver(test5): auth input: home=/vmail/00/test5 Sep 22 17:52:42 server2 deliver(test5): auth input: uid=95 Sep 22 17:52:42 server2 deliver(test5): auth input: gid=95 Sep 22 17:52:42 server2 deliver(test5): auth input: quota_rule=*:storage=2000 Sep 22 17:52:42 server2 deliver(test5): auth input: quota_rule2=*:messages=40 Sep 22 17:52:42 server2 deliver(test5): auth input: quota_warning=storage=950 /usr/local/bin/quota-storage-warning.sh 95 Sep 22 17:52:42 server2 deliver(test5): auth input: quota_warning2=messages=19 /usr/local/bin/quota-messages-warning.sh 95 Sep 22 17:52:42 server2 deliver(test5): Home dir not found: /vmail/00/test5 Sep 22 17:52:42 server2 deliver(test5): dict quota: user = test5, uri = proxy:/var/run/dovecot/dict-server:quotadict Sep 22 17:52:42 server2 deliver(test5): Quota rule: root= mailbox= storage=2000kB messages=0 Sep 22 17:52:42 server2 deliver(test5): Quota rule: root= mailbox= storage=2000kB messages=40 Sep 22 17:52:42 server2 deliver(test5): maildir: data=/vmail/00/test5/Maildir Sep 22 17:52:42 server2 deliver(test5): maildir++: root=/vmail/00/test5/Maildir, index=, control=, inbox=/vmail/00/test5/Maildir Sep 22 17:52:42 server2 deliver(test5): msgid=<200709221752.41292.arvids@arvids.net>: saved mail to INBOX Sep 22 17:52:42 server2 deliver(test3): msgid=<200709221752.41292.arvids@arvids.net>: saved mail to INBOX Sep 22 17:52:42 server2 deliver(test4): msgid=<200709221752.41292.arvids@arvids.net>: saved mail to INBOX Sep 22 17:52:42 server2 deliver(test6): msgid=<200709221752.41292.arvids@arvids.net>: saved mail to INBOX Sep 22 17:52:42 server2 deliver(test1): msgid=<200709221752.41292.arvids@arvids.net>: saved mail to INBOX
dovecot -n: # 1.1.alpha5: /usr/local/dovecot/etc/dovecot.conf base_dir: /var/run/dovecot/ syslog_facility: local0 protocols: pop3 ssl_disable: yes disable_plaintext_auth: no login_dir: /var/run/dovecot/login login_executable: /usr/local/dovecot/libexec/dovecot/pop3-login login_greeting: Server. login_process_per_connection: no login_process_size: 64 verbose_proctitle: yes first_valid_uid: 95 first_valid_gid: 95 mail_uid: 95 mail_gid: 95 mail_location: maildir:~/Maildir mail_debug: yes fsync_disable: yes mail_executable: /usr/local/dovecot/libexec/dovecot/pop3 mail_plugins: quota mail_plugin_dir: /usr/local/dovecot/lib/dovecot/pop3 pop3_enable_last: yes pop3_client_workarounds: outlook-no-nuls oe-ns-eoh auth default: mechanisms: plain login digest-md5 cram-md5 apop cache_size: 2048 cache_ttl: 28800 cache_negative_ttl: 60 user: doveauth verbose: yes debug: yes debug_passwords: yes passdb: driver: sql args: /usr/local/dovecot/etc/dovecot-sql.conf userdb: driver: prefetch userdb: driver: sql args: /usr/local/dovecot/etc/dovecot-sql.conf socket: type: listen master: path: /var/run/dovecot/auth-master mode: 384 user: vmail group: vmail plugin: quota: dict:::proxy:/var/run/dovecot/dict-server:quotadict dict: quotadict: mysql:/usr/local/dovecot/etc/dovecot-sql-dict-quota.conf
Regards, Arvids
On Sat, 2007-09-22 at 18:17 +0300, arvids wrote:
On Saturday 22 September 2007 16:29:50 Timo Sirainen wrote:
I couldn't reproduce this, but I did fix some other problems with quota. Try the latest nightly snapshot to see if they fixed this problem also?
I have tried snapshot eab04861f2fc - it does not fix the problem. The problem is constantly reproducible on my system. I will try to describe problem in details. I have created 6 test users
Oh, I didn't think about the different users case, since in my tests I was testing only one user.. Well, this is a quick fix for it:
http://hg.dovecot.org/dovecot/rev/bd886e12aaa0
But I think I'll have to move the cache elsewhere. The idea was to use a single SQL connection, but with this fix it'll create a separate connection for each user.
participants (2)
-
arvids
-
Timo Sirainen