dovecot - Feb 2013 - Dict quota timeout error: Has anything changed in the latest versions?

Hi,

I'm using dict quota with mysql for track them via SQL query instead of 
read maildirsize file. Primary quota and enforcing is provided via 
userdb and is "maildir" type.

Since dovecot 2.1.10-13 (but perhaps even before) when a new user log in 
via POP/IMAP or receive an email for the first time dovecot created the 
entry for the users in the table "quota" of dovecot database with
quota
usage and number of messages (before of this login/delivery the user has 
no entry in the quota table of dovecot DB).

After the update to 2.1.14 when a new user login or receive an email for 
the first time dovecot was unable to create (immediately) the entry in 
quota table and in the log print these errors:

Feb 12 11:03:49 master: Info: Dovecot v2.1.15 starting up (core dumps 
disabled)
Feb 12 11:04:02 auth-worker(31421): Info: mysql(localhost): Connected to 
database vpopmail
Feb 12 11:04:02 pop3-login: Info: Login: user=<alessio at domain.com>, 
method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=31422, secured, 
session=<eK4gJYTV1QB/AAAB>
Feb 12 11:04:08 pop3(alessio at domain.com): Info: Disconnected: Logged out 
top=0/0, retr=0/0, del=0/9, size=18618
Feb 12 11:04:41 pop3-login: Info: Login: user=<alessio at domain.com>, 
method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, mpid=31424, secured, 
session=<D7F0J4TV1gB/AAAB>
Feb 12 11:05:11 pop3(alessio at domain.com): Info: Disconnected: Logged out 
top=0/0, retr=0/0, del=1/9, size=18618
Feb 12 11:05:11 dict: Info: mysql(10.10.3.19): Connected to database dovecot


[ here is when I "quit" from telnet session]

Feb 12 11:05:41 pop3(alessio at domain.com): Error: 
read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout after 
30 seconds
Feb 12 11:06:11 pop3(alessio at domain.com): Error: 
read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout after 
30 seconds
Feb 12 11:06:41 pop3(alessio at domain.com): Error: 
read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout after 
30 seconds
Feb 12 11:07:11 pop3(alessio at domain.com): Error: 
read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout after 
30 seconds
Feb 12 11:07:41 pop3(alessio at domain.com): Error: 
read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout after 
30 seconds
Feb 12 11:08:11 pop3(alessio at domain.com): Error: 
read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout after 
30 seconds
Feb 12 11:08:41 pop3(alessio at domain.com): Error: 
read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout after 
30 seconds

[ only now telnet close the session ]

This is the telnet session:

# telnet 0 110
Trying 0.0.0.0...
Connected to 0.
Escape character is '^]'.
+OK Dovecot ready.
user alessio at domain.com
+OK
pass ciao
+OK Logged in.
list
+OK 8 messages:
1 1594
2 1594
3 1594
4 1594
5 1594
6 1594
7 3755
8 3714
.
dele 8
+OK Marked to be deleted.
quit

[ here dovecot wait about 3 minuts before close the connecctions ]

+OK Logging out, messages deleted.
Connection closed by foreign host.

After 3 minutes of wait in the mysql database dovecot insert the entry 
for the new users:

mysql> use dovecot
Database changed
mysql> select * from quota where username='alessio at domain.com';
+--------------------------+---------+----------+
| username                 | bytes   | messages |
+--------------------------+---------+----------+
| alessio at domain.com       | 2144030 |       15 |
+--------------------------+---------+----------+

Errors like

Error: read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout 
after 30 seconds

were present also before the upgrade but they were occasional, now I had 
to disable "dict quota".

Can this be fixed?

My dovecot configuration:

# cat /usr/local/dovecot-2.1/etc/dovecot/dovecot-dict-sql.conf.ext
connect = host=10.10.3.19 dbname=dovecot user=dovecot password=XXX
map {
   pattern = priv/quota/storage
   table = quota
   username_field = username
   value_field = bytes
}
map {
   pattern = priv/quota/messages
   table = quota
   username_field = username
   value_field = messages
}
map {
   pattern = shared/expire/$user/$mailbox
   table = expires
   value_field = expire_stamp

   fields {
     username = $user
     mailbox = $mailbox
   }
}


# dovecot -n
# 2.1.15: /usr/local/dovecot-2.1/etc/dovecot/dovecot.conf
# OS: Linux 2.6.32-5-xen-amd64 x86_64 Debian 6.0.6
auth_cache_size = 512 k
auth_worker_max_count = 60
default_login_user = nobody
dict {
   acl = mysql:/usr/local/dovecot-2.1/etc/dovecot/dovecot-share-folder.conf
   sqlquota = 
mysql:/usr/local/dovecot-2.1/etc/dovecot/dovecot-dict-sql.conf.ext
}
disable_plaintext_auth = no
dotlock_use_excl = no
first_valid_gid = 89
first_valid_uid = 89
last_valid_gid = 89
last_valid_uid = 89
lda_mailbox_autocreate = yes
lda_mailbox_autosubscribe = yes
log_path = /var/log/dovecot/dovecot.log
mail_fsync = always
mail_location = maildir:~/Maildir
mail_nfs_index = yes
mail_nfs_storage = yes
mail_plugins = quota acl zlib
maildir_very_dirty_syncs = yes
managesieve_notify_capability = mailto
managesieve_sieve_capability = fileinto reject envelope 
encoded-character vacation subaddress comparator-i;ascii-numeric 
relational regex imap4flags copy include variables body enotify 
environment mailbox date ihave
mmap_disable = yes
namespace {
   list = children
   location = maildir:%%h/Maildir:INDEX=~/Maildir/shared/%%u
   prefix = shared/%%n/
   separator = /
   subscriptions = no
   type = shared
}
namespace inbox {
   inbox = yes
   location    mailbox Drafts {
     auto = subscribe
     special_use = \Drafts
   }
   mailbox Sent {
     auto = subscribe
     special_use = \Sent
   }
   mailbox Spam {
     auto = subscribe
     special_use = \Junk
   }
   mailbox Trash {
     auto = subscribe
     special_use = \Trash
   }
   prefix    separator = /
}
passdb {
   args = /usr/local/dovecot-2.1/etc/dovecot/dovecot-sql.conf.ext
   driver = sql
}
plugin {
   acl = vfile:/usr/local/dovecot-2.1/etc/dovecot/global-acls:cache_secs=300
   acl_shared_dict = proxy::acl
   quota = maildir:UserQuota
   quota2 = dict:User usage::proxy::sqlquota
   quota_rule2 = Trash:storage=+100M
   quota_warning = storage=95%% quota-warning 95 %u
   quota_warning2 = storage=80%% quota-warning 80 %u
   sieve = ~/.dovecot.sieve
   sieve_default = /usr/local/dovecot-2.1/etc/dovecot/sieve/default.sieve
   sieve_dir = ~/sieve
}
protocols = imap pop3 sieve
sendmail_path = /var/qmail/bin/sendmail
service auth {
   unix_listener auth-userdb {
     group = vchkpw
     mode = 0660
     user = vpopmail
   }
}
service dict {
   unix_listener dict {
     group = vchkpw
     mode = 0660
     user = vpopmail
   }
}
service imap-login {
   service_count = 0
}
service managesieve-login {
   inet_listener sieve {
     port = 4190
   }
}
service pop3-login {
   service_count = 0
}
service quota-warning {
   executable = script 
/usr/local/dovecot-2.1/etc/dovecot/scripts/quota-warning.sh
   unix_listener quota-warning {
     user = vpopmail
   }
   user = vpopmail
}
ssl_cert = </etc/ssl/certs/wildcard.net.pem
ssl_key = </etc/ssl/private/wildcard.net.key
userdb {
   args = /usr/local/dovecot-2.1/etc/dovecot/dovecot-sql.conf.ext
   driver = sql
}
protocol lda {
   log_path = /var/log/dovecot/lda.log
   mail_plugins = quota acl zlib sieve
}
protocol imap {
   imap_client_workarounds = delay-newmail tb-extra-mailbox-sep 
tb-lsub-flags
   mail_max_userip_connections = 20
   mail_plugins = quota acl zlib imap_quota imap_acl
}
protocol sieve {
   mail_max_userip_connections = 10
}
protocol pop3 {
   mail_max_userip_connections = 5
   pop3_client_workarounds = outlook-no-nuls oe-ns-eoh
}

-- 
Alessio Cecchi is:
@ ILS -> http://www.linux.it/~alessice/
on LinkedIn -> http://www.linkedin.com/in/alessice
Assistenza Sistemi GNU/Linux -> http://www.cecchi.biz/
@ PLUG -> ex-Presidente, adesso senatore a vita, http://www.prato.linux.it

Il 12/02/2013 11:34, Alessio Cecchi ha scritto:
> Hi,
>
> I'm using dict quota with mysql for track them via SQL query instead of
> read maildirsize file. Primary quota and enforcing is provided via
> userdb and is "maildir" type.
>
> Since dovecot 2.1.10-13 (but perhaps even before) when a new user log in
> via POP/IMAP or receive an email for the first time dovecot created the
> entry for the users in the table "quota" of dovecot database with
quota
> usage and number of messages (before of this login/delivery the user has
> no entry in the quota table of dovecot DB).
>
> After the update to 2.1.14 when a new user login or receive an email for
> the first time dovecot was unable to create (immediately) the entry in
> quota table and in the log print these errors:
Anyone have this problem?

Timo, can be fixed by creating the entry in the Dict database 
immediately (when is not already present) instead of wait the timeout 
seven time?

Thanks
-- 
Alessio Cecchi is:
@ ILS -> http://www.linux.it/~alessice/
on LinkedIn -> http://www.linkedin.com/in/alessice
Assistenza Sistemi GNU/Linux -> http://www.cecchi.biz/
@ PLUG -> ex-Presidente, adesso senatore a vita, http://www.prato.linux.it

On 12.2.2013, at 12.34, Alessio Cecchi <alessio at skye.it> wrote:
> Since dovecot 2.1.10-13 (but perhaps even before) when a new user log in
via POP/IMAP or receive an email for the first time dovecot created the entry
for the users in the table "quota" of dovecot database with quota
usage and number of messages (before of this login/delivery the user has no
entry in the quota table of dovecot DB).
> 
> After the update to 2.1.14 when a new user login or receive an email for
the first time dovecot was unable to create (immediately) the entry in quota
table and in the log print these errors:
> 
> Feb 12 11:05:41 pop3(alessio at domain.com): Error:
read(/usr/local/dovecot-2.1/var/run/dovecot/dict) failed: Timeout after 30
seconds
I don't see any recent changes in this code, so I think it has been broken
for a long time. Anyway, this fixes it:
http://hg.dovecot.org/dovecot-2.1/rev/225c64ed0439