Hello,
it seems that there is some bug in authentication cache code in dovecot
version 1.1.alpha4 - after login attempt with wrong password the correct
password also will fail.
I can reproduce it very easy:
$telnet 10.10.10.30 110
+OK Server. <[EMAIL PROTECTED]>
user testuser
+OK
pass pass
+OK Logged in.
quit
+OK Logging out.
Connection closed by foreign host.
$telnet 10.10.10.30 110
+OK Server. <[EMAIL PROTECTED]>
user testuser
+OK
pass wrongpass
-ERR Authentication failed.
quit
+OK Logging out
Connection closed by foreign host.
$telnet 10.10.10.30 110
+OK Server. <[EMAIL PROTECTED]>
user testuser
+OK
pass pass
-ERR [IN-USE] Internal login failure. Refer to server log for more information.
Connection closed by foreign host.
here is debug log:
Sep 11 19:46:39 server2 dovecot: Dovecot v1.1.alpha4 starting up
Sep 11 19:46:40 server2 dovecot: auth-worker(default): mysql: Connected to
/tmp/mysql.sock (mail)
Sep 11 19:47:03 server2 dovecot: auth(default): client in:
AUTH^I1^IPLAIN^Iservice=pop3^Ilip=10.10.10.30^Irip=10.10.10.20^Iresp=AHRlc3R1c2VyAHBhc3M=
Sep 11 19:47:03 server2 dovecot: auth(default): cache(testuser,10.10.10.20):
miss
Sep 11 19:47:03 server2 dovecot: auth-worker(default):
sql(testuser,10.10.10.20): query: SELECT user, password, home as userdb_home,
uid as userdb_uid, gid
as userdb_gid FROM users WHERE user = 'testuser'
Sep 11 19:47:03 server2 dovecot: auth(default): client out: OK^I1^Iuser=testuser
Sep 11 19:47:03 server2 dovecot: auth(default): master in: REQUEST^I1^I2148^I1
Sep 11 19:47:03 server2 dovecot: auth(default): prefetch(testuser,10.10.10.20):
success
Sep 11 19:47:03 server2 dovecot: auth(default): master out:
USER^I1^Itestuser^Itestuser=^Ihome=/vmail/00/testuser^Iuid=95^Igid=95
Sep 11 19:47:03 server2 dovecot: pop3-login: Login: user=<testuser>,
method=PLAIN, rip=10.10.10.20, lip=10.10.10.30
Sep 11 19:47:08 server2 dovecot: POP3(testuser): Disconnected: Logged out
top=0/0, retr=0/0, del=0/0, size=0
Sep 11 19:47:34 server2 dovecot: auth(default): client in:
AUTH^I2^IPLAIN^Iservice=pop3^Ilip=10.10.10.30^Irip=10.10.10.20^Iresp=AHRlc3R1c2VyAHdyb25ncGFzcw==
Sep 11 19:47:34 server2 dovecot: auth(default): cache(testuser,10.10.10.20): hit
Sep 11 19:47:34 server2 dovecot: auth(default): cache(testuser,10.10.10.20):
Password mismatch
Sep 11 19:47:34 server2 dovecot: auth(default): cache(testuser,10.10.10.20):
PLAIN(wrongpass) != 'pass'
Sep 11 19:47:34 server2 dovecot: auth-worker(default):
sql(testuser,10.10.10.20): query: SELECT user, password, home as userdb_home,
uid as userdb_uid, gid
as userdb_gid FROM users WHERE user = 'testuser'
Sep 11 19:47:34 server2 dovecot: auth-worker(default):
sql(testuser,10.10.10.20): Password mismatch
Sep 11 19:47:34 server2 dovecot: auth-worker(default):
sql(testuser,10.10.10.20): PLAIN(wrongpass) != 'pass'
Sep 11 19:47:35 server2 dovecot: auth(default): client out:
FAIL^I2^Iuser=testuser
Sep 11 19:47:37 server2 dovecot: pop3-login: Aborted login: user=<testuser>,
method=PLAIN, rip=10.10.10.20, lip=10.10.10.30
Sep 11 19:47:46 server2 dovecot: auth(default): client in:
AUTH^I3^IPLAIN^Iservice=pop3^Ilip=10.10.10.30^Irip=10.10.10.20^Iresp=AHRlc3R1c2VyAHBhc3M=
Sep 11 19:47:46 server2 dovecot: auth(default): cache(testuser,10.10.10.20): hit
Sep 11 19:47:46 server2 dovecot: auth(default): client out: OK^I3^Iuser=testuser
Sep 11 19:47:46 server2 dovecot: auth(default): master in: REQUEST^I2^I2148^I3
Sep 11 19:47:46 server2 dovecot: auth(default): prefetch(testuser,10.10.10.20):
passdb didn't return userdb entries
Sep 11 19:47:46 server2 dovecot: auth(default): userdb(testuser,10.10.10.20):
user not found from userdb
Sep 11 19:47:46 server2 dovecot: auth(default): master out: NOTFOUND^I2
Sep 11 19:47:46 server2 dovecot: pop3-login: Internal login failure:
user=<testuser>, method=PLAIN, rip=10.10.10.20, lip=10.10.10.30
dovecot -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
fsync_disable: yes
mail_executable: /usr/local/dovecot/libexec/dovecot/pop3
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
Regards, Arvids
