/**
* 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) : '';
}
