Magento Update 1.9.3.7, Amasty Full Page Cache and Redis Session can kill your store

Akitogo Team, 16 Feb 2018

While the last updates of Magento 1.9 have been flawless the latest update to 1.9.3.7 caused an error. Backend worked, correct version of Magento appeared in the footer, but shop frontend showed 404 Page not found!
What happened? Error trace was also strange. Default Shop cannot be loaded or is not configured. Did Magento forget how to load the default store? Very unlikely. The further trace looked normal. Amasty Cache, RedisSession, some logs, everything as expected, but no default store anymore. Our Configuration has not been changed, every store and website looked configured correctly.
After some investigation we found that this bug happens if you have installed and configured in a certain way:

• Magento 1.9.3.7
• Amasty FPC (1.8)
• RedisSession

RedisSesson has not changed for the last two years.

So what has been changed in Magento 1.9.3.7?

The Mage::log function has been changed.

static $loggers = array();
$level  = is_null($level) ? Zend_Log::DEBUG : $level;
$file = empty($file) ? 'system.log' : basename($file);
// Validate file extension before save. Allowed file extensions: log, txt, html, csv
if (!self::helper('log')->isLogFileExtensionValid($file)) {
    return;
}
try {
    if (!isset($loggers[$file])) {
        $logDir  = self::getBaseDir('var') . DS . 'log';
        $logFile = $logDir . DS . $file;

On line app/Mage.php:811 a new line was added, just to validate the extension of the log file. According to the comment, just "log, txt, html, csv" is allowed. This function is implemented in log helper. Nothing showy there.
Back to our configuration and issue. Check app/code/core/Model/App:351: If a cache is registered, this one tries to process the request. In our case we use a cache! Amsty FPC! This cache wants to start a session. The extension checks if you are using Cm_RedisSession. The shop runs on AWS, so we use it. The RedisSession will be initialized. Now we've made a mistake here, Redis was not configured.

public function __construct()
{
    $this->_config = $config = Mage::getConfig()->getNode('global/redis_session');
    if (!$config) {
        $this->_useRedis = FALSE;
        Mage::log('Redis configuration does not exist, falling back to MySQL handler.', Zend_Log::EMERG);
        parent::__construct();
        return;
    }
    $this->_logLevel =  ((int) $config->descend('log_level') ?: self::DEFAULT_LOG_LEVEL);
    if ($this->_logLevel >= Zend_Log::DEBUG) {
        $timeStart = microtime(true);
    }

We've to change the source file to app/code/community/Cm/RedisSession/Model/Session.php:100. The function __construct checks the current configuration. But we've not configured Redis, but in this case, Redis uses as a fallback the mysql handler. So everything has worked fine until this new Magento Update. The error happens at the Mage::log. This was also done in the past, but now the extension of the logfile will be checked. The log helper is called, this one checks some configuration in the constructor with Mage::getStoreConfig, and this one tries to load the default store. In our case this is not configured, the error starts here. To reveal the secret we've to jump back to app/code/core/Model/App. Remember?

public function run($params)
{
    $options = isset($params['options']) ? $params['options'] : array();
    $this->baseInit($options);
    Mage::register('application_params', $params);
    if ($this->_cache->processRequest()) {
        $this->getResponse()->sendResponse();
    } else {
        $this->_initModules();
        $this->loadAreaPart(Mage_Core_Model_App_Area::AREA_GLOBAL, Mage_Core_Model_App_Area::PART_EVENTS);
        if ($this->_config->isLocalConfigLoaded()) {
            $scopeCode = isset($params['scope_code']) ? $params['scope_code'] : '';
            $scopeType = isset($params['scope_type']) ? $params['scope_type'] : 'store';
            $this->_initCurrentStore($scopeCode, $scopeType);
            $this->_initRequest();
            Mage_Core_Model_Resource_Setup::applyAllDataUpdates();
        }
        $this->getFrontController()->dispatch();
    }
    return $this;
}

On line 351 our cache is requested, but if you look on line 360, the default store is first initialized there. We try to use this earlier. the result is a 404 - Default Store not found!

Long story short. How to quick fix this?

public function __construct()
{
    $this->_config = $config = Mage::getConfig()->getNode('global/redis_session');
    if (!$config) {
        $this->_useRedis = FALSE;
     // QUICK FIX, just comment line below   
//Mage::log('Redis configuration does not exist, falling back to MySQL handler.', Zend_Log::EMERG);
        parent::__construct();
        return;
    }
    $this->_logLevel =  ((int) $config->descend('log_level') ?: self::DEFAULT_LOG_LEVEL);
    if ($this->_logLevel >= Zend_Log::DEBUG) {
        $timeStart = microtime(true);
    }

We have filed a bug requests with Amasty and Magento.

Magento development - Made in Frankfurt, Germany

If you are looking for a Magento development team in Frankfurt, please get in touch with us.