When using Redis to store sessions, you may encounter the problem of sessions that start slowly and issues with reading these sessions. In this article we will look at the causes of these problems by examining the Cm_RedisSession module as an example.
Problem
Often when you monitor online stores on Magento that use Redis for session storage, you can see the following picture in New Relic:
In this screenshot you can see that it took almost 30 seconds to launch the session.
Another example:
In this example it took about 15 seconds to read session data.
Let's try to find out why this is happening.
Redis and Magento
Background:
Redis is an open source (BSD licensed), in-memory data structure store, used as database, cache and message broker. It supports data structures such as strings, hashes, lists, sets, sorted sets with range queries, bitmaps, hyperloglogs and geospatial indexes with radius queries.
Redis together with memcached can be used successfully to store sessions in Magento. In addition, Redis can be used as a cache storage.
You can find detailed information about how to configure and set up Redis in the instruction available at the bottom of the article (see the link 2).
Cm_RedisSession is the standard module in Magento for storing sessions (see the link 3). This module is already included in the official distribution of Magento, where it can be found in the app/code/community/Cm/RedisSession folder.
The Cm_RedisSession_Model_Session class is responsible for working with sessions.
In this class there are two basic methods for reading and writing session data, which are called "read" and "write". Both these functions work according to rather complex logic, but the following fragment of code in the "read" function is what we are most interested in:
public function read($sessionId)
{
...
while ($this->_useLocking) {
...
// Timeout
if ($tries >= $this->_breakAfter + $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');
}
}
...
}
As you can see from the code, the module uses a locking mechanism to avoid concurrent access to the session. This means that if a customer opens a slow page and tries to go to another page without waiting for it to completely load, then the second request to access the session will wait for the completion of the first request. It will pause inside the loop and wait for permission to read data. At the same time only one process can be the "owner" of the session. The ID of the process owner is stored in Redis and is generated as follows:
public function _getPid()
{
return gethostname().'|'.getmypid();
}
If the process is not granted permission to read data after a certain amount of time, the current process becomes the "owner" of the session.
The disable_locking parameter is responsible for disabling the locking mechanism. It is located in the app/etc/local.xml site settings file
<config>
<global>
...
<redis_session>
...
<disable_locking>0</disable_locking>
<break_after_frontend>5</break_after_frontend>
<break_after_adminhtml>30</break_after_adminhtml>
<max_concurrency>6</max_concurrency>
...
</redis_session>
...
</global>
</config>
Other parameters that affect the session locking mechanism include:
max_concurrency - maximum number of processes (requests) that can be expected to be locked for one session. If this number is exceeded, the user will be shown a screen with the error "Error 503: Service Unavailable";
break_after_frontend - the number of seconds that the process will wait for the lock to be released before the current process becomes the session owner;
break_after_adminhtml - setting has the same value as break_after_frontend, but it applies to the administrative area of the site.
The parameter disable_locking has a default setting of 0 (lock activated), which ensures data consistency and integrity when working with sessions. It is not recommended to turn off the lock on a "live" store.
The following are the recommended parameter values:
disable_locking = 0
break_after_frontend = 5
break_after_adminhtml = 30
max_concurrency = 6
Cm_RedisSession bug
At the time this article was written the Cm_RedisSession (v.0.2) module had a bug where the break_after_ * parameters were not read from the file app/etc/local.xml. At the same time the default value was used for 30 seconds, which may be too large a value for the client area of the site.
The bug is caused by the following line in the class Cm_RedisSession_Model_Session
$this->_breakAfter = ((float) $config->descend('break_after_'.session_name()) ?: self::DEFAULT_BREAK_AFTER);
At the time this code is executed, the session_name() value is equal to "PHPSESSID".
This problem can be solved in the following way:
$currentArea = Mage::app()->getStore()->isAdmin() ? 'adminhtml' : 'frontend';
$this->_breakAfter = ((float) $config->descend('break_after_'.$currentArea) ?: self::DEFAULT_BREAK_AFTER);
When you make a change to the file, remember to copy it to the local directory with preserving the full path!
Conclusion
Thus, it should now be clear what causes delays when certain website pages are loaded. You can disable the lock and perform load testing on the site for the purpose of debugging and eliminating bottlenecks in the code, during it the slow queries related to "waiting for competitive requests" will be excluded from the statistics.
Links:
1. REDIS site
2. Redis & Magento Settings
3. Cm_RedisSession Module
