frequent read error on connection in backend only

[jonathanvaughn]

We are having repeated problems with the admin backend in Magento, but not any frequent problems on the front end. The front end is handled on two separate nodes, and a third runs the backend, all sharing common Redis caches (separate instances for Sessions, Magento Cache, and Full Page Cache). The Redis instances are on a 4th server.

a:5:{i:0;s:71:"read error on connection";i:1;s:2311:"#0 /var/www/vhosts/www.example.com/.modman/Cm_RedisSession/code/Model/Session.php(380): Credis_Client->__call('exec', Array)
#1 /var/www/vhosts/www.example.com/.modman/Cm_RedisSession/code/Model/Session.php(380): Credis_Client->exec()
#2 [internal function]: Cm_RedisSession_Model_Session->read('cm0uenj0pdj4im6...')
#3 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Model/Session/Abstract/Varien.php(125): session_start()
#4 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Model/Session/Abstract/Varien.php(168): Mage_Core_Model_Session_Abstract_Varien->start('adminhtml')
#5 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Model/Session/Abstract.php(84): Mage_Core_Model_Session_Abstract_Varien->init('core', 'adminhtml')
#6 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Model/Session.php(42): Mage_Core_Model_Session_Abstract->init('core', 'adminhtml')
#7 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Model/Config.php(1348): Mage_Core_Model_Session->__construct(Array)
#8 /var/www/vhosts/www.example.com/app/Mage.php(463): Mage_Core_Model_Config->getModelInstance('core/session', Array)
#9 /var/www/vhosts/www.example.com/app/Mage.php(477): Mage::getModel('core/session', Array)
#10 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Controller/Varien/Action.php(493): Mage::getSingleton('core/session', Array)
#11 /var/www/vhosts/www.example.com/app/code/core/Mage/Adminhtml/Controller/Action.php(160): Mage_Core_Controller_Varien_Action->preDispatch()
#12 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Controller/Varien/Action.php(407): Mage_Adminhtml_Controller_Action->preDispatch()
#13 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Controller/Varien/Router/Standard.php(250): Mage_Core_Controller_Varien_Action->dispatch('start')
#14 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Controller/Varien/Front.php(172): Mage_Core_Controller_Varien_Router_Standard->match(Object(Mage_Core_Controller_Request_Http))
#15 /var/www/vhosts/www.example.com/app/code/core/Mage/Core/Model/App.php(354): Mage_Core_Controller_Varien_Front->dispatch()
#16 /var/www/vhosts/www.example.com/app/Mage.php(684): Mage_Core_Model_App->run(Array)
#17 /var/www/vhosts/www.example.com/index.php(98): Mage::run('', 'store')
#18 {main}";s:3:"url";s:99:"/index.php/admin/sales_order_create/start/customer_id/3115/key/99f5680349b18f208dc386bcceaec7a6/";s:11:"script_name";s:10:"/index.php";s:4:"skin";s:5:"admin";}

There isn't a large number of admin requests occurring (typically only one or two people using it) and the other nodes appear to communicate to Redis just fine. They're all Rackspace cloud performance 8GB servers in the same DC.

Since this only happens in the backend, I'm not sure if it's just a backend triggered issue, or if it's the server, but I've tried monitoring connectivity to redis from that server and it never fails (and the cache / full page cache never error, just sessions).

Any suggestions on what to look for / instrument to investigate this? I tried adding a call to a shell command to get the number of active / time_wait / etc Redis connections when the error occurs, but there's never more than a couple in total on that server, so I'm pretty sure its not any kind of socket/descriptor starvation.

edit: replaced stacktrace with correct one

[jonathanvaughn]

One thought I'd had was to possibly try forcing Cm_RedisSession to not use phpredis (since some similar-ish Cm_Cache_Backend_Redis issues are apparently solved by forcing it to not use phpredis), but there's not an option I can find for it.

[danslo]

@jonathanvaughn The option is called force_standalone.

[jonathanvaughn]

I didn't see it anywhere in Cm_RedisSession though - if we set that will it be passed through to CRedis?

[danslo]

Oops, my bad, that doesn't seem to be an option for sessions. Just for the cache backend.

[jonathanvaughn]

Yeah, though it's exactly the first thing I looked for when first trying to debug this :D

[parhamr]

I believe I have previously seen @colinmollenhour mention this is a common side effect of AJAX in the media manager. (Which means it is annoying and pollutes the logs but isn’t outright a sign of problems.)

[jonathanvaughn]

We're getting "an error processing your request" Magento error page with stack trace though, so... it breaks stuff. -_-

Honestly not sure whether the client is seeing this entirely randomly or randomly on a specific page though, now that you mention it. I'll find out ...

[danslo]

On second thought, that stacktrace indicates an issue with the cache backend. Is there a particular reason you suspect sessions to be the problem?

[jonathanvaughn]

Oops, I think I posted an old / wrong stack. Let me find and update the OP.

edit: done.

[danslo]

After reading some of @colinmollenhour's answers at the phpredis repository, you may want to try to add $this->_redis->forceStandalone(); just after this line and see if that solves it.

[jonathanvaughn]

Thanks, we may try that.

The obvious just occurred to me: I could just disable phpredis module and graceful Apache, that would also force standalone, surely? This particular site is only using Redis via Credis and it's Cm_* friends, so assuming Cm_RedisSession properly falls back to standalone on it's own this should be testable without code changes.

[colinmollenhour]

Yes, disabling the extension and reloading Apache should have the desired effect safely. phpredis does offer significantly better performance though.

As to the read errors I really don't know.. I see these myself sometimes but they are very far and few between (like once or twice a week with a very busy server). So, I don't really know what to make of it..

If you're really determined to get to the bottom of it a couple things you could try:

• Monitor traffic with redis-cli monitor to see what the last command logged in Redis is.
• Monitor traffic with tcpdump to see if there is anything weird going on with requests/responses.

I can't reproduce the issue anywhere near enough to do the above... Sorry I don't have any better ideas..

It seems like in general Redis is just not 100% reliable when it comes to requests/responses.. You just don't ever see this issue with MySQL, MongoDb, etc.. At least not without some explanation and an error in the log files to accompany it..

[seansan]

I can confirm this issue. We see this also.

Continuous error: Read error on connection and logged out backend (after upgrade)

Since upgrade (22-1-2-15) we see many logging

** Next exception 'CredisException' with message 'read error on connection'

** and users complaining about being logged out in backend

Logging below

Next exception 'CredisException' with message 'read error on connection' in /home/shirts350/domains/webstore.com/public_html/.modman/Cm_RedisSession/lib/Credis/Client.php:919
Stack trace:
#0 /home/shirts350/domains/webstore.com/public_html/.modman/Cm_RedisSession/lib/Credis/Client.php(586): Credis_Client->__call('select', Array)
#1 /home/shirts350/domains/webstore.com/public_html/.modman/Cm_RedisSession/code/Model/Session.php(415): Credis_Client->select(2)
#2 [internal function]: Cm_RedisSession_Model_Session->write('ec31cf667c0b8f1...', '')
#3 /home/shirts350/domains/webstore.com/public_html/app/code/core/Mage/Core/Model/Resource/Session.php(97): session_write_close()
#4 [internal function]: Mage_Core_Model_Resource_Session->__destruct()
#5 {main}
2015-01-14T11:05:51+00:00 ERR (3):
exception 'RedisException' with message 'read error on connection' in /home/shirts350/domains/webstore.com/public_html/.modman/Cm_RedisSession/lib/Credis/Client.php:901
Stack trace:
#0 [internal function]: Redis->select(2)
#1 /home/shirts350/domains/webstore.com/public_html/.modman/Cm_RedisSession/lib/Credis/Client.php(901): call_user_func_array(Array, Array)
#2 /home/shirts350/domains/webstore.com/public_html/.modman/Cm_RedisSession/lib/Credis/Client.php(586): Credis_Client->__call('select', Array)
#3 /home/shirts350/domains/webstore.com/public_html/.modman/Cm_RedisSession/code/Model/Session.php(415): Credis_Client->select(2)
#4 [internal function]: Cm_RedisSession_Model_Session->write('3c0ca6f2d3d4c56...', '')
#5 /home/shirts350/domains/webstore.com/public_html/app/code/core/Mage/Core/Model/Resource/Session.php(97): session_write_close()
#6 [internal function]: Mage_Core_Model_Resource_Session->__destruct()
#7 {main}

[seansan]

@colinmollenhour is there maybe a way to debug all calls and replies from REDIS? Maybe this way I can help to debug this issue /// see what is going on

[colinmollenhour]

Yes, use:

redis-cli monitor

Also set the log_level to 7 in your config and you will get a lot of logging in redis_session.log

[seansan]

Hi, our update

** we upgraded REDIS and PHPREDIS ....

** turned on logging, but don't see any errors

** the problem however persists, users are kicked out of backend frequently .... and as I understand also sometimes in frontend cart-> checkout

** Turning off redis session seems to fix the issue

[colinmollenhour]

Perhaps check that the session data is not growing to be unusually large due to some bug or unruly extension. Enable compression if not already to reduce data transfer. Otherwise, I don't know what the issue would be attributed to and I'd consider trying another backend that has more reliable connections than Redis such as MySQL (it can be configured to use a separate database/connection).

[seansan]

I hope this is solved for us now. Still waiting.... to see it again

We had persistent connection turned on @ same server, different database (now off)
and realized that session.gc_maxlifetime was set to 30 mins (and apparently Magento takes this is a max too).

http://stackoverflow.com/questions/4022952/set-session-time-out-limit-for-magento-frontend

Hope our issue is solved now