[imp] imp login failure despite correct username and password

[Babita]

horde 3.1.5
imp 4.1.5
php 4
openbsd 4.1 i386

hi, we are seeing occasional login failures despite entering the correct 
username and password. once that info is entered and the user clicks the 
'log in' button the user is immediately taken back to the login page, 
without any error messages. normally if an incorrect username/password is 
entered webmail will process for a few moments before returning a 'login 
failed' response. a second login attempt usually succeeds, but sometimes 
it can take several tries.

the webmail logs show the initial login attempt as 'failed', but not much 
else so we added some custom debugging code which points to the 
openIMAPStream function in horde/imp/lib/IMAP.php. it appears as though 
the imap stream is not being opened successfully. below are log snippets 
for a failed and successful login attempt.

i'm wondering if this is a webmail/imp bug, a php bug or something else 
entirely?

failed attempt, despite correct username & password:

--
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** webmail2 is attempting a 
login. [on line 120 of "/var/www/horde/imp/redirect.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** about to create new 
session for webmail2. [on line 158 of "/var/www/horde/imp/redirect.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** about to enter the 
authentication process. [on line 218 of 
"/var/www/horde/imp/lib/Session.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** attempting to 
authenticate webmail2 at ualberta.ca. [on line 157 of 
"/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** about to open imap stream 
to mailbox='  ' for webmail2 at ualberta.ca. [on line 242 of 
"/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** creating imap instance... 
[on line 248 of "/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** done. now about to access 
mailbox via changeMbox(). [on line 254 of 
"/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** in changeMbox(), $mbox=' 
'. [on line 136 of "/var/www/horde/imp/lib/IMAP.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** no existing imap stream, 
opening one now via openIMAPStream(). [on line 143 of 
"/var/www/horde/imp/lib/IMAP.php"]
Dec  9 15:50:17 src at twc1 HORDE[11991]: [imp] *** in openIMAPStream(), 
$mbox='  '. [on line 102 of "/var/www/horde/imp/lib/IMAP.php"]
Dec  9 15:50:35 src at twc1 HORDE[11991]: [imp] *** back in changeMbox(). 
FAILURE! couldnt open imap stream. [on line 167 of 
"/var/www/horde/imp/lib/IMAP.php"]
Dec  9 15:50:35 src at twc1 HORDE[11991]: [imp] *** OH NO! why wasnt the imap 
stream a success?! [on line 262 of "/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:35 src at twc1 HORDE[11991]: [imp] FAILED LOGIN 68.148.141.153 
to 142.244.12.147:143[imap] as webmail2 [on line 284 of 
"/var/www/horde/imp/lib/Auth/imp.php"]
--

a successful login:

--
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** webmail2 is attempting a 
login. [on line 120 of "/var/www/horde/imp/redirect.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** about to create new 
session for webmail2. [on line 158 of "/var/www/horde/imp/redirect.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** about to enter the 
authentication process. [on line 218 of 
"/var/www/horde/imp/lib/Session.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** attempting to 
authenticate webmail2 at ualberta.ca. [on line 157 of 
"/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** about to open imap stream 
to mailbox='  ' for webmail2 at ualberta.ca. [on line 242 of 
"/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** creating imap instance... 
[on line 248 of "/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** done. now about to access 
mailbox via changeMbox(). [on line 254 of 
"/var/www/horde/imp/lib/Auth/imp.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** in changeMbox(), $mbox=' 
'. [on line 136 of "/var/www/horde/imp/lib/IMAP.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** no existing imap stream, 
opening one now via openIMAPStream(). [on line 143 of 
"/var/www/horde/imp/lib/IMAP.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** in openIMAPStream(), 
$mbox='  '. [on line 102 of "/var/www/horde/imp/lib/IMAP.php"]
Dec  9 15:50:58 src at twc1 HORDE[32462]: [imp] *** back in changeMbox(). 
stream opened successfully. [on line 149 of 
"/var/www/horde/imp/lib/IMAP.php"]
Dec  9 15:50:59 src at twc1 HORDE[32462]: [imp] SQL Query by 
Prefs_sql::retrieve(): SELECT pref_scope, pref_name, pref_value FROM 
horde_prefs WHERE pref_uid = ? AND (pref_scope = ? OR pref_scope = 
'horde') ORDER BY pref_scope [on line 137 of 
"/var/www/horde/lib/Horde/Prefs/sql.php"]
Dec  9 15:50:59 src at twc1 HORDE[32462]: [imp] *** authentication process 
complete. [on line 229 of "/var/www/horde/imp/lib/Session.php"]
Dec  9 15:51:00 src at twc1 HORDE[32462]: [imp] *** new session created 
successfully for webmail2! [on line 166 of 
"/var/www/horde/imp/redirect.php"]
Dec  9 15:51:00 src at twc1 HORDE[32462]: [imp] Login success for 
webmail2 at ualberta.ca [68.148.141.153] to {142.244.12.147:143} [on line 169 
of "/var/www/horde/imp/redirect.php"]
--


--
Babita Rana
AICT
University of Alberta