[Dovecot] cram-md5 problem re-post
I apparently did not post enough information the first time, so I am re-posting the original email with the requested configs.
I just updated to dovecot 1.1.10 from 1.1.2 and now anyone using cram-md5 can't get authenticated. I am using mysql for passwords (in plain text) and home directories.
Per some googling I tried to set (in /usr/local/etc/dovecot.conf):
# SQL database
userdb sql {
# Path for SQL configuration file, see doc/dovecot-sql.conf for example
args = /usr/local/etc/dovecot-sql.conf
}but that didn't help. And in any case people NOT using cram-md5 can authenticate just fine, both before and after I made that change.
This worked "out of the box" under 1.1.2, but is broken now.
Here's an example I pulled from the logs.
dovecot: Jan 29 16:35:03 Info: auth-worker(default): sql(jennshinjo,xx.xx.xx.xx): SELECT home, uid, gid FROM users WHERE username = 'jennshinjo' AND domain = '' dovecot: Jan 29 16:35:03 Info: auth(default): prefetch(jennshinjo,xx.xx.xx.xx): success dovecot: Jan 29 16:35:03 Info: auth(default): master out: USER 1490 jennshinjo home=j/e/jennshinjo/Maildir/ uid=5000 gid=5000 home=j/e/jennshinjo/Maildir/ uid=5000 gid=5000 dovecot: Jan 29 16:35:03 Info: pop3-login: Internal login failure (auth failed, 1 attempts): user=<jennshinjo>, method=CRAM-MD5, rip=xx.xx.xx.xx, lip=10.255.0.11
Here is the "dovecot-sql.conf":
:> more /usr/local/etc/dovecot-sql.conf driver = mysql connect = host=10.211.1.3 dbname=mail user=postfix password=p0stf1x9 default_pass_scheme = PLAIN password_query = SELECT password, home as userdb_home, 5000 as userdb_uid, 5000 as userdb_gid FROM mailbox where userid = '%n'
Here are the results of "dovecot -n":
:> dovecot -n # 1.1.10: /usr/local/etc/dovecot.conf # OS: Linux 2.6.18-128.el5 i686 Red Hat Enterprise Linux Server release 5.3 (Tikanga) ext3 base_dir: /var/run/dovecot/ log_path: /var/log/pop.log info_log_path: /var/log/dovecot-info.log protocols: imap imaps pop3 pop3s listen(default): *:143 listen(imap): *:143 listen(pop3): *:110 ssl_listen(default): *:993 ssl_listen(imap): *:993 ssl_listen(pop3): *:995 ssl_cert_file: /etc/ssl/certs/server.crt ssl_key_file: /etc/ssl/private/server.key ssl_cipher_list: ALL:!LOW:!SSLv2 disable_plaintext_auth: no verbose_ssl: yes login_dir: /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_greeting: Dovecot on mail-pop01.xxxxx.com ready. verbose_proctitle: yes mail_location: maildir:/mail/%h:INDEX=MEMORY mmap_disable: 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): mail_log mail_plugins(imap): mail_log mail_plugins(pop3): 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 mail_log_max_lines_per_sec: 0 auth default: mechanisms: plain cram-md5 debug_passwords: yes process_size: 1024 passdb: driver: sql args: /usr/local/etc/dovecot-sql.conf userdb: driver: sql args: /usr/local/etc/dovecot-sql.conf userdb: driver: prefetch
Any ideas appreciated. TIA.
- Richard
On Mon, 2009-02-02 at 09:51 -0800, Richard Stockton wrote:
dovecot: Jan 29 16:35:03 Info: auth(default): master out: USER 1490 jennshinjo home=j/e/jennshinjo/Maildir/ uid=5000 gid=5000 home=j/e/jennshinjo/Maildir/ uid=5000 gid=5000 dovecot: Jan 29 16:35:03 Info: pop3-login: Internal login failure (auth failed, 1 attempts): user=<jennshinjo>, method=CRAM-MD5, rip=xx.xx.xx.xx, lip=10.255.0.11
You're missing the actual error message from the middle, since it's written to a different log file:
log_path: /var/log/pop.log info_log_path: /var/log/dovecot-info.log
Why would you call Dovecot's error log pop.log?
Anyway this should fix your problem: http://hg.dovecot.org/dovecot-1.1/rev/7ef5e6c32443
I'll get v1.1.11 out today.
At 10:10 AM 2/2/2009, you wrote:
On Mon, 2009-02-02 at 09:51 -0800, Richard Stockton wrote:
dovecot: Jan 29 16:35:03 Info: auth(default): master out: USER 1490 jennshinjo home=j/e/jennshinjo/Maildir/ uid=5000 gid=5000 home=j/e/jennshinjo/Maildir/ uid=5000 gid=5000 dovecot: Jan 29 16:35:03 Info: pop3-login: Internal login failure (auth failed, 1 attempts): user=<jennshinjo>, method=CRAM-MD5, rip=xx.xx.xx.xx, lip=10.255.0.11
You're missing the actual error message from the middle, since it's written to a different log file:
Hmmm, the only errors I see there look like this:
dovecot: Jan 29 16:35:03 Error: uid specified multiple times for jennshinjo
and very occasionally I'll see an NFS error or a "Broken header", but neither seems to relate to the cram-MD5 problems.
log_path: /var/log/pop.log info_log_path: /var/log/dovecot-info.log
Why would you call Dovecot's error log pop.log?
Why not? Dovecot doesn't use it, and it's already set to logrotate, so I used it. I wanted it to be separate from the syslog. What would you suggest it be called?
Anyway this should fix your problem: http://hg.dovecot.org/dovecot-1.1/rev/7ef5e6c32443
Thank you, that seems to have fixed it.
I'll get v1.1.11 out today.
Thank you again, not only for this fix, but for dovecot itself. It is still far and away the best POP/IMAP server I have found.
- Richard
On Mon, 2009-02-02 at 11:16 -0800, Richard Stockton wrote:
At 10:10 AM 2/2/2009, you wrote:
On Mon, 2009-02-02 at 09:51 -0800, Richard Stockton wrote:
dovecot: Jan 29 16:35:03 Info: auth(default): master out: USER 1490 jennshinjo home=j/e/jennshinjo/Maildir/ uid=5000 gid=5000 home=j/e/jennshinjo/Maildir/ uid=5000 gid=5000 dovecot: Jan 29 16:35:03 Info: pop3-login: Internal login failure (auth failed, 1 attempts): user=<jennshinjo>, method=CRAM-MD5, rip=xx.xx.xx.xx, lip=10.255.0.11
You're missing the actual error message from the middle, since it's written to a different log file:
Hmmm, the only errors I see there look like this:
dovecot: Jan 29 16:35:03 Error: uid specified multiple times for jennshinjo
Right, that's the one.
and very occasionally I'll see an NFS error or a "Broken header", but neither seems to relate to the cram-MD5 problems.
These shouldn't happen either, could you show some of them?
log_path: /var/log/pop.log info_log_path: /var/log/dovecot-info.log
Why would you call Dovecot's error log pop.log?
Why not? Dovecot doesn't use it, and it's already set to logrotate, so I used it. I wanted it to be separate from the syslog. What would you suggest it be called?
I mean you call the info log so logically dovecot-info.log, why not error log dovecot-error.log? :) I'd think that you could easily forget to look at pop.log when errors happen.
At 11:20 AM 2/2/2009, Timo Sirainen wrote:
dovecot: Jan 29 16:35:03 Error: uid specified multiple times for jennshinjo
Right, that's the one.
and very occasionally I'll see an NFS error or a "Broken header", but neither seems to relate to the cram-MD5 problems.
These shouldn't happen either, could you show some of them?
dovecot: Jan 30 10:20:32 Error: IMAP(mx3ga04): lseek(/mail/m/x/mxxxx/Maildir/dovecot-uidlist) failed: Stale NFS file handle
dovecot: Jan 30 10:41:17 Error: IMAP(syxxx): mail/s/y/syxxx/Maildir/.Trash/dovecot-uidlist: Broken header (uidvalidity = 0, next_uid=67)
The "Broken header" messages are only happening on my webmail servers which are still running dovecot version 1.0.7. I will get those updated soon. The errors look like this:
dovecot: Jan 14 15:50:50 Error: IMAP(puxxxx): /mail/p/u/pxxxx/Maildir/.Sent/dovecot-uidlist: Broken header (uidvalidity = 0, next_uid=28)
dovecot: Jan 29 06:04:46 Error: IMAP(doxx): /mail/d/o/dxxx/Maildir/.Sent/dovecot-uidlist: Broken header (uidvalidity = 0, next_uid=14)
I mean you call the info log so logically dovecot-info.log, why not error log dovecot-error.log? :) I'd think that you could easily forget to look at pop.log when errors happen.
I called the main dovecot log "dovecot-info.log" because that was the default, but you are undoubtedly correct, I will change the error log to "dovecot-error.log".
Thanks again for all your help.
- Richard
On Mon, 2009-02-02 at 11:52 -0800, Richard Stockton wrote:
and very occasionally I'll see an NFS error or a "Broken header", but neither seems to relate to the cram-MD5 problems.
These shouldn't happen either, could you show some of them?
dovecot: Jan 30 10:20:32 Error: IMAP(mx3ga04): lseek(/mail/m/x/mxxxx/Maildir/dovecot-uidlist) failed: Stale NFS file handle
At 11:58 AM 2/2/2009, Timo Sirainen wrote:
On Mon, 2009-02-02 at 11:52 -0800, Richard Stockton wrote:
These shouldn't happen either, could you show some of them?
dovecot: Jan 30 10:20:32 Error: IMAP(mx3ga04): lseek(/mail/m/x/mxxxx/Maildir/dovecot-uidlist) failed: Stale NFS file handle
That doesn't appear to have worked for me...
dovecot: Feb 02 18:30:19 Error: IMAP(asxxxx): lseek(/mail/a/s/asxxxx/Maildir/dovecot-uidlist) failed: Stale NFS file handle
dovecot: Feb 02 19:05:59 Error: IMAP(loxxxxx): lseek(/mail/l/o/loxxxxx/Maildir/dovecot-uidlist) failed: Stale NFS file handle
Sorry.
- Richard
participants (2)
-
Richard Stockton
-
Timo Sirainen