[Dovecot] cannot login with plain authentication - missing UID

[Marc Donovan]

Mar 29 09:39:22 vertuso dovecot: dovecot v1.1.13 starting up (core dumps
disabled)
Mar 29 09:39:22 vertuso dovecot: auth(default): args = 512
Mar 29 09:39:22 vertuso dovecot: auth(default): passwd-file
/etc/dovecot/userdb: Read 1 users
Mar 29 09:39:23 vertuso dovecot: auth(default): new auth connection:
pid=31142
Mar 29 09:39:23 vertuso dovecot: auth(default): new auth connection:
pid=31143
Mar 29 09:39:23 vertuso dovecot: auth(default): new auth connection:
pid=31144
Mar 29 09:39:26 vertuso dovecot: auth(default): new auth connection:
pid=31145
Mar 29 09:39:33 vertuso dovecot: auth(default): client in: AUTH 1
PLAIN   service=imap    lip=207.210.243.5       rip=71.99.73.252
lport=143       rport=34016     resp=AHRlc3RAcmVkbW91bnRhaW5vcmdhbmljcy5j
b20AZjBydzRyZA==
Mar 29 09:39:33 vertuso dovecot: auth(default): passwd-file(
test at redmountainorganics.com,71.99.73.252): lookup: user=
test at redmountainorganics.com file=/etc/dovecot/userdb
Mar 29 09:39:33 vertuso dovecot: auth(default): client out: OK  1
user=test at redmountainorganics.com
Mar 29 09:39:33 vertuso dovecot: auth(default): master in: REQUEST
1       31144   1
Mar 29 09:39:33 vertuso dovecot: auth(default): master out: USER
1       test at redmountainorganics.com
Mar 29 09:39:33 vertuso dovecot: User test at redmountainorganics.com is
missing UID (see mail_uid setting)
Mar 29 09:39:33 vertuso dovecot: imap-login: Internal login failure (auth
failed, 1 attempts): user=<test at redmountainorganics.com>, method=PLAIN,
rip=71.99.73.252, lip=207.210.243.5

# cat /etc/dovecot/userdb
test at redmountainorganics.com:
$1$382-munged-qPfVf687aBiH0.rBgQ80:512:512::/var/mail/vhosts/
redmountainorganics.com/::


$ telnet redmountainorganics.com 143
Trying 207.210.243.5...
Connected to redmountainorganics.com.
Escape character is '^]'.
* OK Dovecot ready.
a login test at redmountainorganics.com XXXXXXX
* BYE Internal login failure. Refer to server log for more information.
Connection closed by foreign host.



# dovecot -n
# 1.1.13: /usr/local/etc/dovecot.conf
# OS: Linux 2.6.16.38-xenU i686 Red Hat Enterprise Linux WS release 4
(Nahant) ext3
ssl_disable: yes
disable_plaintext_auth: no
login_dir: /usr/local/var/run/dovecot/login
login_executable: /usr/local/libexec/dovecot/imap-login
mail_location: maildir:/var/mail/vhosts/%d/%n
mail_debug: yes
auth default:
  user: vmail
  verbose: yes
  debug: yes
  debug_passwords: yes
  passdb:
    driver: passwd-file
    args: /etc/dovecot/userdb

compiled from the latest source.

I have spent two days with gdb and can't figure out what is going on. Here
is a bt

# gdb -p 31140
GNU gdb Red Hat Linux (6.3.0.0-1.132.EL4rh)
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain
conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for details.
This GDB was configured as "i386-redhat-linux-gnu".
Attaching to process 31140

warning: The current VSYSCALL page code requires an existing execuitable.
Use "add-symbol-file-from-memory" to load the VSYSCALL page by hand
Reading symbols from /usr/local/sbin/dovecot...done.
Using host libthread_db library "/lib/libthread_db.so.1".
Reading symbols from /lib/libc.so.6...done.
Loaded symbols for /lib/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /lib/libnss_files.so.2...done.
Loaded symbols for /lib/libnss_files.so.2
0xb7f39079 in epoll_wait () from /lib/libc.so.6
(gdb) break auth_process_input_user
Function "auth_process_input_user" not defined.
Make breakpoint pending on future shared library load? (y or [n]) n
(gdb) break master_login_process
Function "master_login_process" not defined.
Make breakpoint pending on future shared library load? (y or [n]) n
(gdb) break create_mail_process
Breakpoint 1 at 0x804fc64: file mail-process.c, line 542.
(gdb) cont
Continuing.
Detaching after fork from child process 31212.

Breakpoint 1, create_mail_process (process_type=PROCESS_TYPE_IMAP,
set=0x8070330, socket_fd=21, local_ip=0x8077468,
    remote_ip=0x807747c, user=0x806c322 "test at redmountainorganics.com",
args=0x806c370, dump_capability=false)
    at mail-process.c:542
542    {
(gdb) p *args
$1 = 0x0
(gdb) bt
#0  create_mail_process (process_type=PROCESS_TYPE_IMAP, set=0x8070330,
socket_fd=21, local_ip=0x8077468, remote_ip=0x807747c,
    user=0x806c322 "test at redmountainorganics.com", args=0x806c370,
dump_capability=false) at mail-process.c:542
#1  0x0804ddb5 in auth_master_callback (user=0x806c322 "
test at redmountainorganics.com", args=0x806c370, request=0x8077458)
    at login-process.c:105
#2  0x0804ab94 in auth_process_input (process=0x80741b0) at
auth-process.c:142
#3  0x0805a400 in io_loop_handler_run (ioloop=0x8072ea8) at
ioloop-epoll.c:203
#4  0x080598bd in io_loop_run (ioloop=0x8072ea8) at ioloop.c:336
#5  0x08051853 in main (argc=1, argv=0xbfca79d4) at main.c:604

*args is NULL, so it cant get the UID. I've been trying to figure out how
this works and why mine does not.

Its got to be something simple.


Thanks, Marc D.