magento2: Magento 2 suddenly does not work with REDIS anymore after upgrade to (M2.1.6)
Preconditions
- M2.1.4 > M2.1.6 - NGINX - phpREDIS
Steps to reproduce
- Run $php bin/magento setup:static-content:deploy"
- Getting:
[Exception] Notice: unserialize(): Error at offset 0 of 1 bytes in /var/www/domain.com/vendor/magento/module-config/App/Config/Type/System.php on line 214
Expected result
- Able to deploy without errors
Actual result
- The newly updated System.php file (M2.1.6) “vendor/magento/module-config/App/Config/Type/System.php” was changed and breaking the connection with REDIS. It was however working fine with M2.1.4 and all earlier version of System.php
- Run $php bin/magento setup:static-content:deploy"
- Now getting:
[Exception] Notice: unserialize(): Error at offset 0 of 1 bytes in /var/www/domain.com/vendor/magento/module-config/App/Config/Type/System.php on line 214
About this issue
- Original URL
- State: closed
- Created 7 years ago
- Comments: 25 (14 by maintainers)
Apologies. I did rush through to find a solution and didn’t spend the time to explain clearly. I’ll try my best to detail everything I found.
I was randomly receiving the following error like others:
My investigation started by inserting old school I-Dont-Know-What-A-Debugger-Is style
error_loglines into this file around the cache loads:LOAD: [cache-entry]and then checking if the result is unserialisable or not before Magento attempts to do it, logging eitherLOAD SUCCESSFULorLOAD FAILURE: [the-value-that-we-couldn't-unserialize].From this I could see that
1was returned from a load forsystem_defaultweband Magento was expecting serialised data. Further from these logs I could see there were many othersystem_defaultwebloads happening that worked fine.From this I added further
error_logtoCm_Redis_Cache_Backendin theload()anddecodeData()functions. It would log the first 3 characters of the decoded data.The presence of multiple
CMCACHE LOADlogs in a row without an immediately followingCMCACHE DECODE(which the code dictates must happen) indicated an impossible code path explained only by parallelism. Investigatingstatic-content:deploywe can see that it performs parallelism. TheMagento\Deploy\Console\Command\DeployStaticContentCommand::executemethod uses a Model to manage deployment of each area, which can be found atMagento\Deploy\Model\DeployManager.In
Magento\Deploy\Model\DeployManager::deploythere is a check to see if parallelism is enabled and available (-jset to> 1andpctnl_forkfunction available.) If so, it callsrunInParallel. This function usesMagento\Deploy\Model\ProcessQueueManagerto queue a list of tasks to be run in parallel, and this in turn creates processes up to the amount specified by-j(default3) by creatingMagento\Deploy\Model\ProcessManagerobjects.Magento\Deploy\Model\ProcessManagerhas aforkmethod that callspctnl_fork. After forking, nothing is adjusted so all open descriptors, including MySQL connections, Redis connections, etc etc, are still held, and whilst held the process continues to run the requested processing, using the same connections.This triggers wild behaviours with a variety of errors such as the unserialise problem, lost connections to redis, corrupt data errors from redis where data could not be uncompressed (if you have enabled compression) and various other random exceptions. This is caused because of a race condition between
reads on the Redis connection from the different parallel processes. They essentially battle with each other to receive data, and will at times receive data that is a response to a request a completing different process made. In our case of the exception above, inApp/Config/Type/System.php, the process was expecting a response forsystem_defaultwebbut was actually receive a response forsystem_cache_existsthat was made by a different process, which of course returns a single integer1, and not serialised data as is expected. In fact, the process that wantedsystem_cache_existsreceivedsystem_defaultwebresponse, but this did not cause an exception there was it was simply evaluated for trueness.Best solution is to
pcntl_execto replace the current image for the child with a new PHP run starting from, say,magento static:deploy-content --child-process <info-it-can-run>, that then creates it’s own connections to MySQL / Redis as needed.Another method would be to ensure that these child processes never use Redis. There’s also the possibility of attempting to open another Redis connection too which might get through this. In either case though, it would be extremely important not to close the existing Redis connection as this is most likely going to trigger a
QUITto be sent across the connection. This is why sometimes when one child finishes before others have you seeConnection to Redis Lost, since one child will sendQUITwhen PHP exits, and the other children (and the parent) would be left with an open Redis connection where QUIT was sent, which would be an invalid state.Overall, workaround is to disable the
static-content:deployparallelism if you are using Redis, by passing-j 1to the arguments.Hope this is enough detail.
Workaround for now which is deterministically safe:
The
-j 1sets parallel processing to just a single process, which effectively undoes the parallelism change that must have been introduced in Magento 2.1.4 or thereabouts.Yes, that’s enough detail. Lemme get my popcorn, though. And thank you very much for your time explaining.
I am using Redis version 3.0.6 and Magento 2.1.5. It is working smooth for me. Could you share the server confifuration ?
Hi @commcad.
Have you followed this steps while upgrading?
Please, pay attention for 5th step - clear var/ directories as well as run FLUSHALL command in redis cli.