[Dovecot] 1.1beta14 cache bug ?
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@xxxx.com.br,10.0.2.2): miss Jan 22 14:02:59 mailserver--03 dovecot: auth(default): ldap(teste2@xxxx.com.br,10.0.2.2): bind search: base=ou=xxxx.com.br,ou=accounts,o=comMail filter=(&(objectClass=qmailUser)(mail=teste2@xxxx.com.br)(!(accountStatus=disabled))) Jan 22 14:02:59 mailserver--03 dovecot: auth(default): ldap(teste2@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@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@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@xxxx.com.br,10.0.2.2): success Jan 22 14:02:59 mailserver--03 dovecot: auth(default): master out: USER 1 teste2@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@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@xxxx.com.br): Loading modules from directory: /usr/local/lib/dovecot/pop3 Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2@xxxx.com.br): Module loaded: /usr/local/lib/dovecot/pop3/lib10_quota_plugin.so Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2@xxxx.com.br): Effective uid=1033, gid=1033 Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2@xxxx.com.br): Quota root: name= backend=maildir args= Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2@xxxx.com.br): Quota rule: root= mailbox= bytes=2048576000 messages=0 Jan 22 14:02:59 mailserver--03 dovecot: POP3(teste2@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@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@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@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@xxxx.com.br,10.0.2.2): hit Jan 22 14:03:08 mailserver--03 dovecot: auth(default): client out: OK 1 user=teste2@xxxx.com.br host=10.0.149.3 proxy pass=<hidden> Jan 22 14:03:08 mailserver--03 dovecot: pop3-login: Login: user=teste2@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@xxxx.com.br +OK pass 123mudar +OK Logged in. Connection closed by foreign host.
Is it a bug on cache?
[]s,
Raphael Costa
On Tue, 2008-01-22 at 14:20 -0200, Raphael Bittencourt S. Costa wrote:
After enable auth_cache_size = 20480 and auth_cache_ttl = 0, dovecot stops working for users that are in cache. See the log bellow:
Show your dovecot-ldap.conf? It seems cache key contains wrong information.
Timo,
Here is dovecot-ldap.conf:
uris = ldap://10.0.x.x:389/
dn = cn=xxxx, o=xxx dnpass = xxxx sasl_bind = no auth_bind = yes ldap_version = 2 base = ou=%d,ou=accounts,o=xxxx deref = never scope = onelevel
pass_attrs = uid=user,userPassword=password,mailMessageStore=userdb_home,qmailUID=userdb_uid,qmailGID=userdb_gid,mailQuotaSize=userdb_quota_rule=*:bytes,qmailUID=proxy_maybe,mailHostAddress=host pass_filter = (&(objectClass=qmailUser)(mail=% u)(!(accountStatus=disabled)))
user_attrs = mailMessageStore=home,qmailUID=uid,qmailGID=gid,mailQuotaSize=quota_rule=*:bytes user_filter = (&(objectClass=qmailUser)(mail=% u)(!(accountStatus=disabled)))
On Thu, 2008-01-31 at 17:15 +0200, Timo Sirainen wrote:
On Tue, 2008-01-22 at 14:20 -0200, Raphael Bittencourt S. Costa wrote:
After enable auth_cache_size = 20480 and auth_cache_ttl = 0, dovecot stops working for users that are in cache. See the log bellow:
Show your dovecot-ldap.conf? It seems cache key contains wrong information.
[]s,
Raphael Costa
On Thu, 2008-01-31 at 13:42 -0200, Raphael Bittencourt S. Costa wrote:
Here is dovecot-ldap.conf:
..
pass_attrs = uid=user,userPassword=password,mailMessageStore=userdb_home,qmailUID=userdb_uid,qmailGID=userdb_gid,mailQuotaSize=userdb_quota_rule=*:bytes,qmailUID=proxy_maybe,mailHostAddress=host
This doesn't have "proxy".
Jan 22 14:03:08 mailserver--03 dovecot: auth(default): cache(teste2@xxxx.com.br,10.0.2.2): hit Jan 22 14:03:08 mailserver--03 dovecot: auth(default): client out: OK 1 user=teste2@xxxx.com.br host=10.0.149.3 proxy pass=<hidden> Jan 22 14:03:08 mailserver--03 dovecot: pop3-login: Login:
This does. Are you using multiple passdbs? Show dovecot -n output?
On Thu, 2008-01-31 at 17:55 +0200, Timo Sirainen wrote:
On Thu, 2008-01-31 at 13:42 -0200, Raphael Bittencourt S. Costa wrote:
Here is dovecot-ldap.conf:
..
pass_attrs = uid=user,userPassword=password,mailMessageStore=userdb_home,qmailUID=userdb_uid,qmailGID=userdb_gid,mailQuotaSize=userdb_quota_rule=*:bytes,qmailUID=proxy_maybe,mailHostAddress=host
This doesn't have "proxy".
Whops, it does. I didn't notice it first because it wasn't visible in my window (would have had to scroll horizontally). I'll see if I can reproduce this.
Timo,
Follows dovecot -n:
protocols: imap pop3 ssl_disable: yes disable_plaintext_auth: no shutdown_clients: no login_dir: /usr/local/var/run/dovecot/login login_executable(default): /usr/local/libexec/dovecot/imap-login login_executable(imap): /usr/local/libexec/dovecot/imap-login login_executable(pop3): /usr/local/libexec/dovecot/pop3-login login_process_per_connection: no login_greeting_capability(default): yes login_greeting_capability(imap): yes login_greeting_capability(pop3): no login_process_size: 128 login_processes_count: 30 login_max_processes_count: 1024 login_max_connections: 512 max_mail_processes: 10240 mail_uid: 1033 mail_gid: 1033 mail_location: maildir:%h/Maildir mail_debug: yes mail_executable(default): /usr/local/libexec/dovecot/imap mail_executable(imap): /usr/local/libexec/dovecot/imap mail_executable(pop3): /usr/local/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/lib/dovecot/imap mail_plugin_dir(imap): /usr/local/lib/dovecot/imap mail_plugin_dir(pop3): /usr/local/lib/dovecot/pop3 pop3_uidl_format(default): %08Xu%08Xv pop3_uidl_format(imap): %08Xu%08Xv pop3_uidl_format(pop3): %f pop3_client_workarounds(default): pop3_client_workarounds(imap): pop3_client_workarounds(pop3): outlook-no-nuls namespace: type: private prefix: INBOX. inbox: yes list: yes subscriptions: yes auth default: mechanisms: plain login cache_ttl: 0 cache_negative_ttl: 0 verbose: yes debug: yes passdb: driver: ldap args: /etc/dovecot/dovecot-ldap.conf userdb: driver: prefetch userdb: driver: ldap args: /etc/dovecot/dovecot-ldap.conf socket: type: listen master: path: /var/run/dovecot/auth-master mode: 438 plugin: quota: maildir quota_rule: *:bytes=10240
On Thu, 2008-01-31 at 17:58 +0200, Timo Sirainen wrote:
On Thu, 2008-01-31 at 17:55 +0200, Timo Sirainen wrote:
On Thu, 2008-01-31 at 13:42 -0200, Raphael Bittencourt S. Costa wrote:
Here is dovecot-ldap.conf:
..
pass_attrs = uid=user,userPassword=password,mailMessageStore=userdb_home,qmailUID=userdb_uid,qmailGID=userdb_gid,mailQuotaSize=userdb_quota_rule=*:bytes,qmailUID=proxy_maybe,mailHostAddress=host
This doesn't have "proxy".
Whops, it does. I didn't notice it first because it wasn't visible in my window (would have had to scroll horizontally). I'll see if I can reproduce this.
[]s,
Raphael Costa
On Tue, 2008-01-22 at 14:20 -0200, Raphael Bittencourt S. Costa wrote:
After enable auth_cache_size = 20480 and auth_cache_ttl = 0, dovecot stops working for users that are in cache. See the log bellow:
This fixes some issues with proxy_maybe: http://hg.dovecot.org/dovecot-1.1/rev/27b7b6c34961
Does it help to this problem? I also added code to make cache hit lines show what they had cached:
http://hg.dovecot.org/dovecot-1.1/rev/6127a0501e72 http://hg.dovecot.org/dovecot-1.1/rev/e0debdcd2e10
It worked on 1.1rc1.
Thanks Timo,
Raphael Costa
On Thu, 2008-02-21 at 15:59 +0200, Timo Sirainen wrote:
On Tue, 2008-01-22 at 14:20 -0200, Raphael Bittencourt S. Costa wrote:
After enable auth_cache_size = 20480 and auth_cache_ttl = 0, dovecot stops working for users that are in cache. See the log bellow:
This fixes some issues with proxy_maybe: http://hg.dovecot.org/dovecot-1.1/rev/27b7b6c34961
Does it help to this problem? I also added code to make cache hit lines show what they had cached:
http://hg.dovecot.org/dovecot-1.1/rev/6127a0501e72 http://hg.dovecot.org/dovecot-1.1/rev/e0debdcd2e10
participants (2)
-
Raphael Bittencourt S. Costa
-
Timo Sirainen