Index: /trunk/lib/Auth_SQL.inc.php
===================================================================
--- /trunk/lib/Auth_SQL.inc.php	(revision 371)
+++ /trunk/lib/Auth_SQL.inc.php	(revision 372)
@@ -382,8 +382,8 @@
             // Don't return password value.
             unset($user_data['userpass']);
-            $app->logMsg(sprintf('Authentication successful for user %s (%s)', $user_data['user_id'], $username), LOG_INFO, __FILE__, __LINE__);
+            $app->logMsg(sprintf('Authentication successful for user_id %s (%s)', $user_data['user_id'], $username), LOG_INFO, __FILE__, __LINE__);
             return $user_data;
         } else {
-            $app->logMsg(sprintf('Authentication failed for user %s (encrypted attempted password: %s)', $username, $this->encryptPassword($password)), LOG_NOTICE, __FILE__, __LINE__);
+            $app->logMsg(sprintf('Authentication failed for username %s (encrypted attempted password: %s)', $username, $this->encryptPassword($password)), LOG_NOTICE, __FILE__, __LINE__);
             return false;
         }
@@ -436,5 +436,5 @@
             if (!empty($user_data['blocked'])) {
 
-                $app->logMsg(sprintf('User %s (%s) login failed due to blocked account: %s', $this->get('user_id'), $this->get('username'), $this->get('blocked_reason')), LOG_NOTICE, __FILE__, __LINE__);
+                $app->logMsg(sprintf('User_id %s (%s) login failed due to blocked account: %s', $this->get('user_id'), $this->get('username'), $this->get('blocked_reason')), LOG_NOTICE, __FILE__, __LINE__);
 
                 switch ($user_data['blocked_reason']) {
@@ -471,10 +471,10 @@
                     $this->resetPassword(null, _("This is a security precaution. We have detected this account has been accessed from multiple computers simultaneously. It is against policy to share login information with others. If further account abuse is detected this account will be blocked."));
                     $app->raiseMsg(_("Your password has been reset as a security precaution. Please check your email for more information."), MSG_NOTICE, __FILE__, __LINE__);
-                    $app->logMsg(sprintf('Account abuse detected for user %s (%s) from IP %s', $this->get('user_id'), $this->get('username'), $this->get('remote_ip')), LOG_WARNING, __FILE__, __LINE__);
+                    $app->logMsg(sprintf('Account abuse detected for user_id %s (%s) from IP %s', $this->get('user_id'), $this->get('username'), $this->get('remote_ip')), LOG_WARNING, __FILE__, __LINE__);
                 } else {
                     // Block the account with the reason of account abuse.
                     $this->blockAccount(null, 'account abuse');
                     $app->raiseMsg(_("Your account has been blocked as a security precaution. Please contact us for more information."), MSG_NOTICE, __FILE__, __LINE__);
-                    $app->logMsg(sprintf('Account blocked for user %s (%s) from IP %s', $this->get('user_id'), $this->get('username'), $this->get('remote_ip')), LOG_ALERT, __FILE__, __LINE__);
+                    $app->logMsg(sprintf('Account blocked for user_id %s (%s) from IP %s', $this->get('user_id'), $this->get('username'), $this->get('remote_ip')), LOG_ALERT, __FILE__, __LINE__);
                 }
                 // Increment user's warning level.
@@ -529,5 +529,5 @@
 		$app =& App::getInstance();
     	$db =& DB::getInstance();
-	
+
         $this->initDB();
 
@@ -540,9 +540,12 @@
                 AND DATE_ADD(last_access_datetime, INTERVAL '" . $this->_params['idle_timeout'] . "' SECOND) > NOW()
             ");
-            return (mysql_num_rows($qid) > 0);
+            $login_status = (mysql_num_rows($qid) > 0);
+            $app->logMsg(sprintf('Returning %s login status for user_id %s', ($login_status ? 'true' : 'false'), $user_id), LOG_DEBUG, __FILE__, __LINE__);
+            return $login_status;
         }
 
         // User login test need only be run once per script execution. We cache the result in the session.
         if ($this->_authentication_tested && isset($_SESSION['_auth_sql'][$this->_ns]['authenticated'])) {
+            $app->logMsg(sprintf('Returning cached authentication status: %s', ($_SESSION['_auth_sql'][$this->_ns]['authenticated'] ? 'true' : 'false')), LOG_DEBUG, __FILE__, __LINE__);
             return $_SESSION['_auth_sql'][$this->_ns]['authenticated'];
         }
@@ -555,12 +558,12 @@
         if ($trusted_net = ipInRange(getRemoteAddr(), $this->_params['trusted_networks'])) {
             $user_in_trusted_network = true;
-            $app->logMsg(sprintf('User %s accessing from trusted network %s',
-                ($this->get('user_id') ? ' ' . $this->get('user_id') . ' (' .  $this->get('username') . ')' : ''),
+            $app->logMsg(sprintf('User_id %s accessing from trusted network %s',
+                ($this->get('user_id') ? $this->get('user_id') . ' (' .  $this->get('username') . ')' : 'unknown'),
                 $trusted_net
             ), LOG_DEBUG, __FILE__, __LINE__);
         } else if (preg_match('/proxy.aol.com$/i', getRemoteAddr(true))) {
             $user_in_trusted_network = true;
-            $app->logMsg(sprintf('User %s accessing from trusted network proxy.aol.com',
-                ($this->get('user_id') ? ' ' . $this->get('user_id') . ' (' .  $this->get('username') . ')' : '')
+            $app->logMsg(sprintf('User_id %s accessing from trusted network proxy.aol.com',
+                ($this->get('user_id') ? $this->get('user_id') . ' (' .  $this->get('username') . ')' : 'unknown')
             ), LOG_DEBUG, __FILE__, __LINE__);
         } else {
@@ -572,6 +575,6 @@
             $remote_ip_is_matched = (isset($_SESSION['_auth_sql'][$this->_ns]['remote_ip']) && $_SESSION['_auth_sql'][$this->_ns]['remote_ip'] == getRemoteAddr()) || $user_in_trusted_network;
         } else {
-            $app->logMsg(sprintf('User %s exempt from remote_ip match (comparing %s == %s)', 
-                ($this->get('user_id') ? ' ' . $this->get('user_id') . ' (' .  $this->get('username') . ')' : ''),
+            $app->logMsg(sprintf('User_id %s exempt from remote_ip match (comparing %s == %s)', 
+                ($this->get('user_id') ? $this->get('user_id') . ' (' .  $this->get('username') . ')' : 'unknown'),
                 $_SESSION['_auth_sql'][$this->_ns]['remote_ip'],
                 getRemoteAddr()
@@ -583,6 +586,9 @@
         if (isset($_SESSION['_auth_sql'][$this->_ns]['authenticated']) 
             && true === $_SESSION['_auth_sql'][$this->_ns]['authenticated']
+            && isset($_SESSION['_auth_sql'][$this->_ns]['username'])
             && !empty($_SESSION['_auth_sql'][$this->_ns]['username'])
+            && isset($_SESSION['_auth_sql'][$this->_ns]['login_datetime'])
             && strtotime($_SESSION['_auth_sql'][$this->_ns]['login_datetime']) > time() - $this->_params['login_timeout']
+            && isset($_SESSION['_auth_sql'][$this->_ns]['last_access_datetime'])
             && strtotime($_SESSION['_auth_sql'][$this->_ns]['last_access_datetime']) > time() - $this->_params['idle_timeout']
             && $remote_ip_is_matched
@@ -602,5 +608,5 @@
                 return true;
             } else {
-                $app->logMsg(sprintf('User update failed. Record not found for user %s (%s).', $this->get('user_id'), $this->get('username')), LOG_NOTICE, __FILE__, __LINE__);
+                $app->logMsg(sprintf('Session update failed; record not found for user_id %s (%s).', $this->get('user_id'), $this->get('username')), LOG_NOTICE, __FILE__, __LINE__);
             }
         } else if (isset($_SESSION['_auth_sql'][$this->_ns]['authenticated']) && true === $_SESSION['_auth_sql'][$this->_ns]['authenticated']) {
@@ -617,8 +623,8 @@
             }
             if (strtotime($_SESSION['_auth_sql'][$this->_ns]['login_datetime']) <= time() - $this->_params['login_timeout']) {
-                $expire_reasons[] = 'login_timeout expired';
+                $expire_reasons[] = sprintf('login_timeout expired (%s older than %s seconds ago)', $_SESSION['_auth_sql'][$this->_ns]['login_datetime'], $this->_params['login_timeout']);
             }
             if (strtotime($_SESSION['_auth_sql'][$this->_ns]['last_access_datetime']) <= time() - $this->_params['idle_timeout']) {
-                $expire_reasons[] = 'idle_timeout expired';
+                $expire_reasons[] = sprintf('idle_timeout expired (%s older than %s seconds ago)', $_SESSION['_auth_sql'][$this->_ns]['last_access_datetime'], $this->_params['idle_timeout']);
             }
             if ($_SESSION['_auth_sql'][$this->_ns]['remote_ip'] != getRemoteAddr()) {
@@ -633,5 +639,7 @@
                 }
             }
-            $app->logMsg(sprintf('User %s (%s) session expired: %s', $this->get('user_id'), $this->get('username'), join(', ', $expire_reasons)), LOG_INFO, __FILE__, __LINE__);
+            $app->logMsg(sprintf('User_id %s (%s) session expired: %s', $this->get('user_id'), $this->get('username'), join(', ', $expire_reasons)), LOG_INFO, __FILE__, __LINE__);
+        } else {
+            $app->logMsg(sprintf('Session not authenticated: %s', getDump($_SESSION['_auth_sql'][$this->_ns])), LOG_DEBUG, __FILE__, __LINE__);
         }
 
@@ -917,5 +925,5 @@
         
         if (mysql_affected_rows($db->getDBH()) != 1) {
-            $app->logMsg(sprintf('Failed to update password for user %s', $user_id), LOG_WARNING, __FILE__, __LINE__);
+            $app->logMsg(sprintf('Failed to update password for user_id %s', $user_id), LOG_WARNING, __FILE__, __LINE__);
             return false;
         }
@@ -947,5 +955,5 @@
         ");
         if (!$user_data = mysql_fetch_assoc($qid)) {
-            $app->logMsg(sprintf('Reset password failed. User %s not found.', $user_id), LOG_NOTICE, __FILE__, __LINE__);
+            $app->logMsg(sprintf('Reset password failed. User_id %s not found.', $user_id), LOG_NOTICE, __FILE__, __LINE__);
             return false;
         }
@@ -959,5 +967,5 @@
         // Make sure user has an email on record before continuing.
         if (!isset($user_data['email']) || '' == trim($user_data['email'])) {
-            $app->logMsg(sprintf('Password reset but notification failed, no email address for user %s (%s).', $user_data[$this->_params['db_primary_key']], $user_data[$this->_params['db_username_column']]), LOG_NOTICE, __FILE__, __LINE__);
+            $app->logMsg(sprintf('Password reset but notification failed, no email address for user_id %s (%s).', $user_data[$this->_params['db_primary_key']], $user_data[$this->_params['db_username_column']]), LOG_NOTICE, __FILE__, __LINE__);
         } else {
             // Send the new password in an email.
