[imp] session timeout at login

Tue Apr 27 06:32:33 PDT 2004

I have received reports from time to time of logins failing with a
"Your
mail session has expired" message. It seemed that most of these came
from Windows systems and running adaware or spybot "fixed" the problem.
But now I have a Sun Ultra 10 running Solaris 8 and Netscape 6 that
consistently gives the error.
Horde = 2.2.4
IMP = 3.2.2

I changed $conf['log']['priority'] to LOG_DEBUG and got these messages
from the Sun box:

Apr 26 14:33:06 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'76a17ec0459376c6a036d6e5db48bae3' AND session_lastmodified >
1082993586" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:33:06 HORDE [info] [imp] clean session [on line 882 of
"/usr/local/htdocs/horde-2.2.4/lib/Horde.php"]

Apr 26 14:33:06 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::destroy(): query = "DELETE FROM
horde_sessionhandler WHERE session_id =
'76a17ec0459376c6a036d6e5db48bae3'" [on line 169 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:33:06 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'661b90be3e23d6bd1f3ec586383a7120' AND session_lastmodified >
1082993586" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:33:06 HORDE [notice] [imp] Login success for
reitsmac at denison.edu [140.141.15.91] to {imap.denison.edu:143} [on line
92 of "/usr/local/htdocs/horde-2.2.4/imp-3.2.2/redirect.php"]

Apr 26 14:33:06 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'81b75c7ae4f5a9d9ba13dcd942c75f00' AND session_lastmodified >
1082993586" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:33:06 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8d8f5a7c97106a0510cc97a64c0b921d' AND session_lastmodified >
1082993586" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:33:06 HORDE [info] [imp] Session timeout for client
[140.141.15.91] [on line 80 of
"/usr/local/htdocs/horde-2.2.4/imp-3.2.2/login.php"]

Each of the last three "SQL Query..." lines came up with a different
session_id. Why?

Here's a login to the same server from a Windows box with IE 6
resulting
in a successful login:

Apr 26 14:40:14 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab' AND session_lastmodified >
1082994014" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:40:22 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab' AND session_lastmodified >
1082994022" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:40:22 HORDE [info] [imp] clean session [on line 882 of
"/usr/local/htdocs/horde-2.2.4/lib/Horde.php"]

Apr 26 14:40:22 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::destroy(): query = "DELETE FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab'" [on line 169 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:40:22 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab' AND session_lastmodified >
1082994022" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:40:23 HORDE [notice] [imp] Login success for
reitsmac at denison.edu [140.141.15.93] to {imap.denison.edu:143} [on line
92 of "/usr/local/htdocs/horde-2.2.4/imp-3.2.2/redirect.php"]

Apr 26 14:40:23 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab' AND session_lastmodified >
1082994023" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:40:33 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab' AND session_lastmodified >
1082994033" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:40:41 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab' AND session_lastmodified >
1082994041" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:40:45 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab' AND session_lastmodified >
1082994045" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Apr 26 14:40:56 HORDE [debug] [imp] SQL Query by
SessionHandler_mysql::read(): query = "SELECT session_data FROM
horde_sessionhandler WHERE session_id =
'8f4e6cb6d472053b2b5e90a57a606aab' AND session_lastmodified >
1082994056" [on line 114 of
"/usr/local/htdocs/horde-2.2.4/lib/SessionHandler/mysql.php"]

Here, the session_id stays the same for each operation after "Login
success."

No errors in the apache logs correspond to these events.

I see the latest stable horde/imp combo is 2.2.5/3.2.3 so I'm one
revision behind in both. It'll be a couple of weeks before I can make
that change.

I do not think Netscape 6 on Solaris 8 is the culprit, either. We have
a
portal that logs users into imp bypassing the login screens. This is
successful on the Sun box. After which I can logout and login again
without problems until I close the browser. Then it reverts back to
getting "Your Mail session has expired" messages.

Anyway, since I can repeat the problem if anyone has ideas they want me
to try just let me know.
I tried the dirty fix from
http://marc.theaimsgroup.com/?l=imp&m=108057628404027&w=2
first...it did not help (but then I could not replicate the problem it
purported to fix).

Charlie Reitsma
Systems Engineer