Beispiel #1
0
 /**
  * Fetch session data
  *
  * @param string $sessionId
  * @return string
  */
 public function read($sessionId)
 {
     if (!$this->_useRedis) {
         return parent::read($sessionId);
     }
     Varien_Profiler::start(__METHOD__);
     // Get lock on session. Increment the "lock" field and if the new value is 1, we have the lock.
     $sessionId = self::SESSION_PREFIX . $sessionId;
     $tries = $waiting = $lock = 0;
     $lockPid = $oldLockPid = NULL;
     // Restart waiting for lock when current lock holder changes
     $detectZombies = FALSE;
     if ($this->_logLevel >= Zend_Log::WARN) {
         $timeStart = microtime(true);
     }
     if ($this->_logLevel >= Zend_Log::DEBUG) {
         $this->_log(sprintf("Attempting to take lock on ID %s", $sessionId));
     }
     $this->_redis->select($this->_dbNum);
     while ($this->_useLocking) {
         // Increment lock value for this session and retrieve the new value
         $oldLock = $lock;
         $lock = $this->_redis->hIncrBy($sessionId, 'lock', 1);
         // Get the pid of the process that has the lock
         if ($lock != 1 && $tries + 1 >= $this->_getBreakAfter()) {
             $lockPid = $this->_redis->hGet($sessionId, 'pid');
         }
         // If we got the lock, update with our pid and reset lock and expiration
         if ($lock == 1 || $tries >= $this->_getBreakAfter() && $oldLockPid == $lockPid) {
             $this->_hasLock = TRUE;
             break;
         } else {
             if (!$waiting) {
                 $i = 0;
                 do {
                     $waiting = $this->_redis->hIncrBy($sessionId, 'wait', 1);
                 } while (++$i < $this->_maxConcurrency && $waiting < 1);
             } else {
                 // Detect broken sessions (e.g. caused by fatal errors)
                 if ($detectZombies) {
                     $detectZombies = FALSE;
                     if ($lock > $oldLock && $lock + 1 < $oldLock + $waiting) {
                         // Reset session to fresh state
                         if ($this->_logLevel >= Zend_Log::INFO) {
                             $this->_log(sprintf("Detected zombie waiter after %.5f seconds for ID %s (%d waiting)\n  %s (%s - %s)", microtime(true) - $timeStart, $sessionId, $waiting, Mage::app()->getRequest()->getRequestUri(), Mage::app()->getRequest()->getClientIp(), Mage::app()->getRequest()->getHeader('User-Agent')), Zend_Log::INFO);
                         }
                         $waiting = $this->_redis->hIncrBy($sessionId, 'wait', -1);
                         continue;
                     }
                 }
                 // Limit concurrent lock waiters to prevent server resource hogging
                 if ($waiting >= $this->_maxConcurrency) {
                     // Overloaded sessions get 503 errors
                     $this->_redis->hIncrBy($sessionId, 'wait', -1);
                     $this->_sessionWritten = TRUE;
                     // Prevent session from getting written
                     $writes = $this->_redis->hGet($sessionId, 'writes');
                     if ($this->_logLevel >= Zend_Log::WARN) {
                         $this->_log(sprintf("Session concurrency exceeded for ID %s; displaying HTTP 503 (%s waiting, %s total requests)\n  %s (%s - %s)", $sessionId, $waiting, $writes, Mage::app()->getRequest()->getRequestUri(), Mage::app()->getRequest()->getClientIp(), Mage::app()->getRequest()->getHeader('User-Agent')), Zend_Log::WARN);
                     }
                     $this->_logLevel = -1;
                     // Disable further logging
                     require_once Mage::getBaseDir() . DS . 'errors' . DS . '503.php';
                     exit;
                 }
             }
         }
         $tries++;
         $oldLockPid = $lockPid;
         $sleepTime = self::SLEEP_TIME;
         // Detect dead lock waiters
         if ($tries % self::DETECT_ZOMBIES == 1) {
             $detectZombies = TRUE;
             $sleepTime += 10000;
             // sleep + 0.01 seconds
         }
         // Detect dead lock holder every 10 seconds (only works on same node as lock holder)
         if ($tries % self::DETECT_ZOMBIES == 0) {
             Varien_Profiler::start(__METHOD__ . '-detect-zombies');
             if ($this->_logLevel >= Zend_Log::DEBUG) {
                 $this->_log(sprintf("Checking for zombies after %.5f seconds of waiting...", microtime(true) - $timeStart));
             }
             $pid = $this->_redis->hGet($sessionId, 'pid');
             if ($pid && !$this->_pidExists($pid)) {
                 // Allow a live process to get the lock
                 $this->_redis->hSet($sessionId, 'lock', 0);
                 if ($this->_logLevel >= Zend_Log::INFO) {
                     $this->_log(sprintf("Detected zombie process (%s) for %s (%s waiting)\n  %s (%s - %s)", $pid, $sessionId, $waiting, Mage::app()->getRequest()->getRequestUri(), Mage::app()->getRequest()->getClientIp(), Mage::app()->getRequest()->getHeader('User-Agent')), Zend_Log::INFO);
                 }
                 Varien_Profiler::stop(__METHOD__ . '-detect-zombies');
                 continue;
             }
             Varien_Profiler::stop(__METHOD__ . '-detect-zombies');
         }
         // Timeout
         if ($tries >= $this->_getBreakAfter() + $this->_failAfter) {
             $this->_hasLock = FALSE;
             if ($this->_logLevel >= Zend_Log::NOTICE) {
                 $this->_log(sprintf("Giving up on read lock for ID %s after %.5f seconds (%d attempts)", $sessionId, microtime(true) - $timeStart, $tries), Zend_Log::NOTICE);
             }
             break;
         } else {
             if ($this->_logLevel >= Zend_Log::DEBUG) {
                 $this->_log(sprintf("Waiting %.2f seconds for lock on ID %s (%d tries, lock pid is %s, %.5f seconds elapsed)", $sleepTime / 1000000, $sessionId, $tries, $lockPid, microtime(true) - $timeStart));
             }
             Varien_Profiler::start(__METHOD__ . '-wait');
             usleep($sleepTime);
             Varien_Profiler::stop(__METHOD__ . '-wait');
         }
     }
     self::$failedLockAttempts = $tries;
     // Session can be read even if it was not locked by this pid!
     if ($this->_logLevel >= Zend_Log::DEBUG) {
         $timeStart = microtime(true);
     }
     list($sessionData, $sessionWrites) = $this->_redis->hMGet($sessionId, array('data', 'writes'));
     Varien_Profiler::stop(__METHOD__);
     if ($this->_logLevel >= Zend_Log::DEBUG) {
         $this->_log(sprintf("Data read for ID %s in %.5f seconds", $sessionId, microtime(true) - $timeStart));
     }
     $this->_sessionWrites = (int) $sessionWrites;
     // This process is no longer waiting for a lock
     if ($tries > 0) {
         $this->_redis->hIncrBy($sessionId, 'wait', -1);
     }
     // This process has the lock, save the pid
     if ($this->_hasLock) {
         $setData = array('pid' => $this->_getPid(), 'lock' => 1);
         // Save request data in session so if a lock is broken we can know which page it was for debugging
         if ($this->_logLevel >= Zend_Log::INFO) {
             if (empty($_SERVER['REQUEST_METHOD'])) {
                 $setData['req'] = $_SERVER['SCRIPT_NAME'];
             } else {
                 $setData['req'] = "{$_SERVER['REQUEST_METHOD']} {$_SERVER['SERVER_NAME']}{$_SERVER['REQUEST_URI']}";
             }
             if ($lock != 1) {
                 $this->_log(sprintf("Successfully broke lock for ID %s after %.5f seconds (%d attempts). Lock: %d\nLast request of broken lock: %s", $sessionId, microtime(true) - $timeStart, $tries, $lock, $this->_redis->hGet($sessionId, 'req')), Zend_Log::INFO);
             }
         }
     }
     // Set session data and expiration
     $this->_redis->pipeline();
     if (!empty($setData)) {
         $this->_redis->hMSet($sessionId, $setData);
     }
     $this->_redis->expire($sessionId, min($this->getLifeTime(), $this->_maxLifetime));
     $this->_redis->exec();
     // Reset flag in case of multiple session read/write operations
     $this->_sessionWritten = FALSE;
     return $sessionData ? $this->_decodeData($sessionData) : '';
 }
 /**
  * Fetch session data
  *
  * @param string $sessionId
  * @return string
  */
 public function read($sessionId)
 {
     if (!$this->_useRedis) {
         return parent::read($sessionId);
     }
     // Get lock on session. Increment the "lock" field and if the new value is 1, we have the lock.
     // If the new value is a multiple of BREAK_MODULO then we are breaking the lock.
     $sessionId = self::SESSION_PREFIX . $sessionId;
     $tries = $waiting = $lock = 0;
     $detectZombies = FALSE;
     if ($this->_logLevel >= 7) {
         Mage::log(sprintf("%s: Attempting read lock on ID %s", $this->_getPid(), $sessionId), Zend_Log::DEBUG, self::LOG_FILE);
         // reset timer
         $this->_timeStart = microtime(true);
     }
     if ($this->_dbNum) {
         $this->_redis->select($this->_dbNum);
     }
     while (1) {
         // Increment lock value for this session and retrieve the new value
         $oldLock = $lock;
         $lock = $this->_redis->hIncrBy($sessionId, 'lock', 1);
         // If we got the lock, update with our pid and reset lock and expiration
         if ($lock == 1 || $tries >= $this->_breakAfter && $lock % self::BREAK_MODULO == 0) {
             $setData = array('pid' => $this->_getPid(), 'lock' => 1);
             // Save request data in session so if a lock is broken we can know which page it was for debugging
             if ($this->_logLevel >= 6) {
                 $additionalDetails = sprintf("(%s attempts)", $tries);
                 if ($this->_logLevel >= 7) {
                     $additionalDetails = sprintf("after %.5f seconds ", microtime(true) - $this->_timeStart, $tries) . $additionalDetails;
                 }
                 if (empty($_SERVER['REQUEST_METHOD'])) {
                     $setData['req'] = $_SERVER['SCRIPT_NAME'];
                 } else {
                     $setData['req'] = "{$_SERVER['REQUEST_METHOD']} {$_SERVER['SERVER_NAME']}{$_SERVER['REQUEST_URI']}";
                 }
                 if ($lock != 1) {
                     Mage::log(sprintf("%s: Successfully broke lock for ID %s %s. Lock: %s, BREAK_MODULO: %s\nLast request of broken lock: %s", $this->_getPid(), $sessionId, $additionalDetails, $lock, self::BREAK_MODULO, $this->_redis->hGet($sessionId, 'req')), Zend_Log::INFO, self::LOG_FILE);
                 }
             }
             $this->_redis->pipeline()->hMSet($sessionId, $setData)->expire($sessionId, min($this->getLifeTime(), self::MAX_LIFETIME))->exec();
             $this->_hasLock = TRUE;
             break;
         } else {
             if (!$waiting) {
                 $i = 0;
                 do {
                     $waiting = $this->_redis->hIncrBy($sessionId, 'wait', 1);
                     if ($this->_logLevel >= 7) {
                         Mage::log(sprintf("%s: Waiting for lock on ID %s (%s tries, %s waiting, %.5f seconds elapsed)", $this->_getPid(), $sessionId, $tries, $waiting, microtime(true) - $this->_timeStart), Zend_Log::DEBUG, self::LOG_FILE);
                     }
                 } while (++$i < $this->_maxConcurrency && $waiting < 1);
             } else {
                 // Detect broken sessions (e.g. caused by fatal errors)
                 if ($detectZombies) {
                     $detectZombies = FALSE;
                     if ($lock > $oldLock && $lock + 1 < $oldLock + $waiting) {
                         // Reset session to fresh state
                         if ($this->_logLevel >= 6) {
                             Mage::log(sprintf("%s: Detected zombie waiter after %.5f seconds for ID %s (%s waiting)\n  %s (%s - %s)", $this->_getPid(), microtime(true) - $this->_timeStart, $sessionId, $waiting, Mage::app()->getRequest()->getRequestUri(), Mage::app()->getRequest()->getClientIp(), Mage::app()->getRequest()->getHeader('User-Agent')), Zend_Log::INFO, self::LOG_FILE);
                         }
                         $waiting = $this->_redis->hIncrBy($sessionId, 'wait', -1);
                         continue;
                     }
                 }
                 // Limit concurrent lock waiters to prevent server resource hogging
                 if ($waiting >= $this->_maxConcurrency) {
                     // Overloaded sessions get 503 errors
                     $this->_redis->hIncrBy($sessionId, 'wait', -1);
                     $this->_sessionWritten = TRUE;
                     // Prevent session from getting written
                     $writes = $this->_redis->hGet($sessionId, 'writes');
                     if ($this->_logLevel >= 4) {
                         Mage::log(sprintf("%s: Session concurrency exceeded for ID %s; displaying HTTP 503 (%s waiting, %s total requests)\n  %s (%s - %s)", $this->_getPid(), $sessionId, $waiting, $writes, Mage::app()->getRequest()->getRequestUri(), Mage::app()->getRequest()->getClientIp(), Mage::app()->getRequest()->getHeader('User-Agent')), Zend_Log::WARN, self::LOG_FILE);
                     }
                     require_once Mage::getBaseDir() . DS . 'errors' . DS . '503.php';
                     exit;
                 }
             }
         }
         $tries++;
         // Detect dead waiters
         if ($tries == 1) {
             $detectZombies = TRUE;
             // TODO: allow configuration of sleep period?
             usleep(1500000);
             // 1.5 seconds
         }
         // Detect dead processes every 10 seconds
         if ($tries % self::DETECT_ZOMBIES == 0) {
             if ($this->_logLevel >= 7) {
                 Mage::log(sprintf("%s: Checking for zombies after %.5f seconds of waiting...", $this->_getPid(), microtime(true) - $this->_timeStart), Zend_Log::DEBUG, self::LOG_FILE);
             }
             $pid = $this->_redis->hGet($sessionId, 'pid');
             if ($pid && !$this->_pidExists($pid)) {
                 // Allow a live process to get the lock
                 $this->_redis->hSet($sessionId, 'lock', 0);
                 if ($this->_logLevel >= 6) {
                     Mage::log(sprintf("%s: Detected zombie process (%s) for %s (%s waiting)\n  %s (%s - %s)", $this->_getPid(), $pid, $sessionId, $waiting, Mage::app()->getRequest()->getRequestUri(), Mage::app()->getRequest()->getClientIp(), Mage::app()->getRequest()->getHeader('User-Agent')), Zend_Log::INFO, self::LOG_FILE);
                 }
                 continue;
             }
         }
         // Timeout
         if ($tries >= $this->_breakAfter + self::FAIL_AFTER) {
             $this->_hasLock = FALSE;
             if ($this->_logLevel >= 5) {
                 $additionalDetails = sprintf("(%s attempts)", $tries);
                 if ($this->_logLevel >= 7) {
                     $additionalDetails = sprintf("after %.5f seconds ", microtime(true) - $this->_timeStart, $tries) . $additionalDetails;
                 }
                 Mage::log(sprintf("%s: Giving up on read lock for ID %s %s", $this->_getPid(), $sessionId, $additionalDetails), Zend_Log::NOTICE, self::LOG_FILE);
             }
             break;
         } else {
             // TODO: configurable wait period?
             sleep(1);
         }
     }
     self::$failedLockAttempts = $tries;
     // This process is no longer waiting for a lock
     if ($tries > 0) {
         $this->_redis->hIncrBy($sessionId, 'wait', -1);
     }
     // Session can be read even if it was not locked by this pid!
     $sessionData = $this->_redis->hGet($sessionId, 'data');
     if ($this->_logLevel >= 7) {
         Mage::log(sprintf("%s: Data read for ID %s after %.5f seconds", $this->_getPid(), $sessionId, microtime(true) - $this->_timeStart), Zend_Log::DEBUG, self::LOG_FILE);
     }
     return $sessionData ? $this->_decodeData($sessionData) : '';
 }