[Dovecot] Outlook 2000/2003 frequent disconnect issue

[Jeff Ramsey]

On Aug 1, 2007, at 9:47 AM, Timo Sirainen wrote:

> On 1.8.2007, at 18.43, Jeff Ramsey wrote:
>> Since my initial post, I have noticed this in my log file as well:
>>
>> Aug  1 08:13:42 imap dovecot: auth(default): userdb 
>> (johnfowler,::ffff:65.174.242.248): user not found from userdb
>> Aug  1 08:13:42 imap dovecot: imap-login: Internal login failure:  
>> user=<johnfowler>, method=PLAIN, rip=::ffff:65.174.242.248,  
>> lip=::ffff:65.174.242.66
>
> I suppose this is the problem then. Outlook stupidly keeps  
> reconnecting to server all the time, so if one reconnection fails I  
> guess this problem happens.
>
> So this "johnfowler" really should exist in your userdb? You could  
> set auth_debug=yes and then see what is logged before that error.  
> Also could you post your dovecot -n output?


Output of dovecot -n:

# 1.0.2: /etc/dovecot.conf
login_dir: /var/run/dovecot/login
login_executable(default): /usr/libexec/dovecot/imap-login
login_executable(imap): /usr/libexec/dovecot/imap-login
login_executable(pop3): /usr/libexec/dovecot/pop3-login
mail_executable(default): /usr/libexec/dovecot/imap
mail_executable(imap): /usr/libexec/dovecot/imap
mail_executable(pop3): /usr/libexec/dovecot/pop3
mail_plugin_dir(default): /usr/lib/dovecot/imap
mail_plugin_dir(imap): /usr/lib/dovecot/imap
mail_plugin_dir(pop3): /usr/lib/dovecot/pop3
auth default:
   passdb:
     driver: pam
   userdb:
     driver: passwd


And yes, issuing a 'getent passwd' command shows all of my users from  
the /etc/passwd file, and then all of the Active Directory users,  
including johnfowler.

I set auth_debug = yes. Here is an example to compare to the previous  
one with johnfowler, this one with QUINAULT-ileneyoung as the  
username; (QUINAULT is a trusted Active Directory domain, so I have  
to prefix the username with the DOMAIN for this user.)

Aug  1 11:58:47 imap dovecot: auth(default): pam(QUINAULT- 
ileneyoung,::ffff:10.200.254.110): lookup service=dovecot
Aug  1 11:58:47 imap dovecot: auth(default): client out: OK      
1       user=QUINAULT-ileneyoung
Aug  1 11:58:47 imap dovecot: auth(default): master in: REQUEST  
3       12173   1
Aug  1 11:58:47 imap dovecot: auth(default): passwd(QUINAULT- 
ileneyoung,::ffff:10.200.254.110): lookup
Aug  1 11:58:47 imap dovecot: auth(default): master out: USER    
3       QUINAULT-ileneyoung     system_user=QUINAULT-ileneyoung  
uid=16777352    gid=16777248    home=/home/QUINAULT/ileneyoung
Aug  1 11:58:47 imap dovecot: imap-login: Login: user=<QUINAULT- 
ileneyoung>, method=PLAIN, rip=::ffff:10.200.254.110, lip=::ffff: 
65.174.242.66
Aug  1 11:58:51 imap dovecot: auth(default): client in: AUTH     
1       PLAIN   service=IMAP    lip=::ffff:65.174.242.66         
rip=::ffff:10.200.254.110       resp=<hidden>
Aug  1 11:58:51 imap dovecot: auth(default): pam(QUINAULT- 
ileneyoung,::ffff:10.200.254.110): lookup service=dovecot
Aug  1 11:58:51 imap dovecot: auth(default): client out: OK      
1       user=QUINAULT-ileneyoung
Aug  1 11:58:51 imap dovecot: auth(default): master in: REQUEST  
4       12186   1
Aug  1 11:58:51 imap dovecot: auth(default): passwd(QUINAULT- 
ileneyoung,::ffff:10.200.254.110): lookup
Aug  1 11:58:51 imap dovecot: auth(default): passwd(QUINAULT- 
ileneyoung,::ffff:10.200.254.110): unknown user
Aug  1 11:58:51 imap dovecot: auth(default): userdb(QUINAULT- 
ileneyoung,::ffff:10.200.254.110): user not found from userdb
Aug  1 11:58:51 imap dovecot: auth(default): master out:  
NOTFOUND       4
Aug  1 11:58:51 imap dovecot: imap-login: Internal login failure:  
user=<QUINAULT-ileneyoung>, method=PLAIN, rip=::ffff:10.200.254.110,  
lip=::ffff:65.174.242.66
Aug  1 11:59:06 imap dovecot: auth(default): client in: AUTH     
1       PLAIN   service=IMAP    lip=::ffff:65.174.242.66         
rip=::ffff:65.174.242.239       resp=<hidden>

Perhaps this sheds some light on the matter? Why is it trying to  
authenticate the user again at 11:58:51 when there was no disconnect  
after 11:58:47? And why is it failing? My guess on why it is failing  
is because the Active Directory Server cannot respond fast enough to  
handle the second request, after already handling the first, but I am  
just guessing.

Thanks,


Jeff Ramsey
MIS Administrator
TMI Forest Products, Inc.
jefframsey at tubafor.com
360.477.0738





-- 
This message has been scanned for viruses and
dangerous content by MailScanner, and is
believed to be clean.