dovecot - Feb 2009 - 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.
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 197 bytes
Desc: This is a digitally signed message part
URL:
<http://dovecot.org/pipermail/dovecot/attachments/20090202/1aa19f08/attachment-0002.bin>

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