[Dovecot] 1.1beta14 cache bug ?

Raphael Bittencourt S. Costa raphaelbscosta at gmail.com
Tue Jan 22 18:20:04 EET 2008


Helo all,

After enable auth_cache_size = 20480 and auth_cache_ttl = 0, dovecot
stops working for users that are in cache. See the log bellow: 


1 - POP3 session OK
jan 22 14:02:59 mailserver--03 dovecot: auth(default): client in: AUTH
1       PLAIN   service=pop3    lip=10.0.149.3  rip=10.0.2.2
resp=<hidden>
Jan 22 14:02:59 mailserver--03 dovecot: auth(default):
cache(teste2 at xxxx.com.br,10.0.2.2): miss
Jan 22 14:02:59 mailserver--03 dovecot: auth(default):
ldap(teste2 at xxxx.com.br,10.0.2.2): bind search:
base=ou=xxxx.com.br,ou=accounts,o=comMail
filter=(&(objectClass=qmailUser)(mail=teste2 at xxxx.com.br)(!(accountStatus=disabled)))
Jan 22 14:02:59 mailserver--03 dovecot: auth(default):
ldap(teste2 at xxxx.com.br,10.0.2.2): result:
mailMessageStore(userdb_home)=/data/services/dominios/xxxx.com.br/t/te/teste2/ mailHostAddress(host)=10.0.149.3 mailQuotaSize(userdb_quota_rule=*:bytes)=2048576000 uid(user)=teste2 at xxxx.com.br qmailGID(userdb_gid)=1033 qmailUID(proxy_maybe)=1033
Jan 22 14:02:59 mailserver--03 dovecot: auth(default): client out: OK
1       user=teste2 at xxxx.com.br
Jan 22 14:02:59 mailserver--03 dovecot: auth(default): master in:
REQUEST  1       3085    1
Jan 22 14:02:59 mailserver--03 dovecot: auth(default):
prefetch(teste2 at xxxx.com.br,10.0.2.2): success
Jan 22 14:02:59 mailserver--03 dovecot: auth(default): master out: USER
1       teste2 at xxxx.com.br
home=/data/services/dominios/xxxx.com.br/t/te/teste2/
quota_rule=*:bytes=2048576000   gid=1033
Jan 22 14:02:59 mailserver--03 dovecot: pop3-login: Login:
user=<teste2 at xxxx.com.br>, method=PLAIN, rip=10.0.2.2, lip=10.0.149.3
Jan 22 14:02:59 mailserver--03 dovecot: auth(default): new auth
connection: pid=3085
Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br):
Loading modules from directory: /usr/local/lib/dovecot/pop3
Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br): Module
loaded: /usr/local/lib/dovecot/pop3/lib10_quota_plugin.so
Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br):
Effective uid=1033, gid=1033
Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br): Quota
root: name= backend=maildir args=
Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br): Quota
rule: root= mailbox= bytes=2048576000 messages=0
Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br):
Namespace: type=private, prefix=INBOX., sep=, inbox=yes, hidden=no,
list=yes, subscriptions=yes
Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br):
maildir: data=/data/services/dominios/xxxx.com.br/t/te/teste2//Maildir
Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br):
maildir++:
root=/data/services/dominios/xxxx.com.br/t/te/teste2//Maildir, index=,
control=, inbox=/data/services/dominios/xxxx.com.br/t/te/teste2//Maildir
Jan 22 14:03:02 mailserver--03 dovecot: POP3(teste2 at xxxx.com.br):
Disconnected: Logged out top=0/0, retr=0/0, del=0/3012, size=534868620

2 - POP3 session fail
Jan 22 14:03:08 mailserver--03 dovecot: auth(default): client in: AUTH
1       PLAIN   service=pop3    lip=10.0.149.3  rip=10.0.2.2
resp=<hidden>
Jan 22 14:03:08 mailserver--03 dovecot: auth(default):
cache(teste2 at xxxx.com.br,10.0.2.2): hit
Jan 22 14:03:08 mailserver--03 dovecot: auth(default): client out: OK
1       user=teste2 at xxxx.com.br host=10.0.149.3 proxy   pass=<hidden>
Jan 22 14:03:08 mailserver--03 dovecot: pop3-login: Login:
user=<teste2 at xxxx.com.br>, method=PLAIN, rip=10.0.2.2, lip=10.0.149.3
Jan 22 14:03:08 mailserver--03 dovecot: auth(default): new auth
connection: pid=3078

server01:~# telnet 10.0.145.3 110
Trying 10.0.145.3...
Connected to 10.0.145.3.
Escape character is '^]'.
+OK Dovecot ready.
user teste2 at xxxx.com.br
+OK
pass 123mudar
+OK Logged in.
Connection closed by foreign host.

Is it a bug on cache?

[]s,


Raphael Costa


More information about the dovecot mailing list