session_start(): Failed to read session data: user (path: /var/lib/php/sessions)

[AykutCevik]

While viewing the orders page in the admin area and opening several orders I'm facing an error message.

Preconditions

1. PHP 7.1.17-1
2. Redis server v=3.0.6
3. set redis as the session handler in env.php
   3.1 see session config:

`'session' => [
        'save' => 'redis',
        'redis' => [
            'host' => '<IP>',
            'port' => '<PORT>',
            'password' => '',
            'timeout' => '2.5',
            'persistent_identifier' => '',
            'database' => '0',
            'compression_threshold' => '2048',
            'compression_library' => 'gzip',
            'log_level' => '1',
            'max_concurrency' => '6',
            'break_after_frontend' => '5',
            'break_after_adminhtml' => '30',
            'first_lifetime' => '600',
            'bot_first_lifetime' => '60',
            'bot_lifetime' => '7200',
            'disable_locking' => '0',
            'min_lifetime' => '60',
            'max_lifetime' => '2592000'
        ]
    ],`

2. have orders in your system

Steps to reproduce

1. Browse the order pages in the admin area
2. click on an order
3. go back to the order list
4. click on an other order again
5. retry several times
6. see error message in the admin area:
   

Expected result

1. Browsing pages in the admin area shouldn't throw an error

Actual result

Message in step 6 of reproduction appears, in the log I can find the following:

{"0":"Warning: session_start(): Failed to read session data: user (path: /var/lib/php/sessions) in /vendor/magento/framework/Session/SessionManager.php on line 193","1":"#0 [internal function]: Magento\Framework\App\ErrorHandler->handler(2, 'session_start()...', '/home/cloudpane...', 193, Array)\n#1 /vendor/magento/framework/Session/SessionManager.php(193): session_start()\n#2 /generated/code/Magento/Backend/Model/Session/Interceptor.php(63): Magento\Framework\Session\SessionManager->start()\n#3 /vendor/magento/framework/Session/SessionManager.php(130): Magento\Backend\Model\Session\Interceptor->start()\n#4 /generated/code/Magento/Backend/Model/Session/Interceptor.php(14): Magento\Framework\Session\SessionManager->__construct(Object(Magento\Framework\App\Request\Http), Object(Magento\Framework\Session\SidResolver\Proxy), Object(Magento\Backend\Model\Session\AdminConfig), Object(Magento\Framework\Session\SaveHandler), Object(Magento\Framework\Session\Validator), Object(Magento\Framework\Session\Storage), Object(Magento\Framework\Stdlib\Cookie\PhpCookieManager), Object(Magento\Framework\Stdlib\Cookie\CookieMetadataFactory), Object(Magento\Framework\App\State))\n#5 /vendor/magento/framework/ObjectManager/Factory/AbstractFactory.php(111): Magento\Backend\Model\Session\Interceptor->__construct(Object(Magento\Framework\App\Request\Http), Object(Magento\Framework\Session\SidResolver\Proxy), Object(Magento\Backend\Model\Session\AdminConfig), Object(Magento\Framework\Session\SaveHandler), Object(Magento\Framework\Session\Validator), Object(Magento\Framework\Session\Storage), Object(Magento\Framework\Stdlib\Cookie\PhpCookieManager), Object(Magento\Framework\Stdlib\Cookie\CookieMetadataFactory), Object(Magento\Framework\App\State))\n#6 /vendor/magento/framework/ObjectManager/Factory/Dynamic/Developer.php(66): Magento\Framework\ObjectManager\Factory\AbstractFactory->createObject('Magento\\Backend...', Array)\n#7 /vendor/magento/framework/ObjectManager/ObjectManager.php(70): Magento\Framework\ObjectManager\Factory\Dynamic\Developer->create('Magento\\Backend...')\n#8 /vendor/magento/framework/ObjectManager/Factory/AbstractFactory.php(144): Magento\Framework\ObjectManager\ObjectManager->get('Magento\\Backend...')\n#9 /vendor/magento/framework/ObjectManager/Factory/AbstractFactory.php(230): Magento\Framework\ObjectManager\Factory\AbstractFactory->resolveArgument(Array, 'Magento\\Framewo...', NULL, 'session', 'Magento\\Store\\A...')\n#10 /vendor/magento/framework/ObjectManager/Factory/Dynamic/Developer.php(34): Magento\Framework\ObjectManager\Factory\AbstractFactory->resolveArgumentsInRuntime('Magento\\Store\\A...', Array, Array)\n#11 /vendor/magento/framework/ObjectManager/Factory/Dynamic/Developer.php(59): Magento\Framework\ObjectManager\Factory\Dynamic\Developer->_resolveArguments('Magento\\Store\\A...', Array, Array)\n#12 /vendor/magento/framework/ObjectManager/ObjectManager.php(70): Magento\Framework\ObjectManager\Factory\Dynamic\Developer->create('Magento\\Store\\A...')\n#13 /vendor/magento/framework/ObjectManager/Factory/AbstractFactory.php(144): Magento\Framework\ObjectManager\ObjectManager->get('Magento\\Store\\A...')\n#14 /vendor/magento/framework/ObjectManager/Factory/AbstractFactory.php(230): Magento\Framework\ObjectManager\Factory\AbstractFactory->resolveArgument(Array, 'Magento\\Framewo...', NULL, 'redirect', 'Magento\\Backend...')\n#15 /vendor/magento/framework/ObjectManager/Factory/Dynamic/Developer.php(34): Magento\Framework\ObjectManager\Factory\AbstractFactory->resolveArgumentsInRuntime('Magento\\Backend...', Array, Array)\n#16 /vendor/magento/framework/ObjectManager/Factory/Dynamic/Developer.php(59): Magento\Framework\ObjectManager\Factory\Dynamic\Developer->_resolveArguments('Magento\\Backend...', Array, Array)\n#17 /vendor/magento/framework/ObjectManager/ObjectManager.php(70): Magento\Framework\ObjectManager\Factory\Dynamic\Developer->create('Magento\\Backend...')\n#18 /vendor/magento/framework/ObjectManager/Factory/AbstractFactory.php(144): Magento\Framework\ObjectManager\ObjectManager->get('Magento\\Backend...')\n#19 /vendor/magento/framework/ObjectManager/Factory/AbstractFactory.php(230): Magento\Framework\ObjectManager\Factory\AbstractFactory->resolveArgument(Array, 'Magento\\Backend...', NULL, 'context', 'Magento\\Ui\\Cont...')\n#20 /vendor/magento/framework/ObjectManager/Factory/Dynamic/Developer.php(34): Magento\Framework\ObjectManager\Factory\AbstractFactory->resolveArgumentsInRuntime('Magento\\Ui\\Cont...', Array, Array)\n#21 /vendor/magento/framework/ObjectManager/Factory/Dynamic/Developer.php(59): Magento\Framework\ObjectManager\Factory\Dynamic\Developer->_resolveArguments('Magento\\Ui\\Cont...', Array, Array)\n#22 /vendor/magento/framework/ObjectManager/ObjectManager.php(56): Magento\Framework\ObjectManager\Factory\Dynamic\Developer->create('Magento\\Ui\\Cont...', Array)\n#23 /vendor/magento/framework/App/ActionFactory.php(40): Magento\Framework\ObjectManager\ObjectManager->create('Magento\\Ui\\Cont...')\n#24 /vendor/magento/framework/App/Router/Base.php(297): Magento\Framework\App\ActionFactory->create('Magento\\Ui\\Cont...')\n#25 /vendor/magento/framework/App/Router/Base.php(158): Magento\Framework\App\Router\Base->matchAction(Object(Magento\Framework\App\Request\Http), Array)\n#26 /vendor/magento/framework/App/FrontController.php(50): Magento\Framework\App\Router\Base->match(Object(Magento\Framework\App\Request\Http))\n#27 /vendor/magento/framework/Interception/Interceptor.php(58): Magento\Framework\App\FrontController->dispatch(Object(Magento\Framework\App\Request\Http))\n#28 /vendor/magento/framework/Interception/Interceptor.php(138): Magento\Framework\App\FrontController\Interceptor->___callParent('dispatch', Array)\n#29 /vendor/magento/framework/Interception/Interceptor.php(153): Magento\Framework\App\FrontController\Interceptor->Magento\Framework\Interception\{closure}(Object(Magento\Framework\App\Request\Http))\n#30 /generated/code/Magento/Framework/App/FrontController/Interceptor.php(26): Magento\Framework\App\FrontController\Interceptor->___callPlugins('dispatch', Array, Array)\n#31 /vendor/magento/framework/App/Http.php(135): Magento\Framework\App\FrontController\Interceptor->dispatch(Object(Magento\Framework\App\Request\Http))\n#32 /generated/code/Magento/Framework/App/Http/Interceptor.php(24): Magento\Framework\App\Http->launch()\n#33 /vendor/magento/framework/App/Bootstrap.php(256): Magento\Framework\App\Http\Interceptor->launch()\n#34 /pub/index.php(37): Magento\Framework\App\Bootstrap->run(Object(Magento\Framework\App\Http\Interceptor))\n#35 {main}","url":"/admin/mui/index/render/key/[MASKED]/order_id/[MASKED]]?namespace=payone_sales_order_view_transactionstatus_grid&sorting%5Bfield%5D=sequencenumber&sorting%5Bdirection%5D=asc&isAjax=true","script_name":"/index.php"}

The path /var/lib/php/sessions was never set anywhere. I actually can't understand why Magento is trying to use the path when redis is configured. It may be related to SessionManager->registerSaveHandler()?

[magento-engcom-team]

Hi @AykutCevik. Thank you for your report.
To help us process this issue please make sure that you provided the following information:

• Summary of the issue
• Information on your environment
• Steps to reproduce
• Expected and actual results

Please make sure that the issue is reproducible on the vanilla Magento instance following Steps to reproduce. To deploy vanilla Magento instance on our environment, please, add a comment to the issue:

@magento-engcom-team give me {$VERSION} instance

where {$VERSION} is version tags (starting from 2.2.0+) or develop branches (2.2-develop +).
For more details, please, review the Magento Contributor Assistant documentation.

@AykutCevik do you confirm that you was able to reproduce the issue on vanilla Magento instance following steps to reproduce?

• yes
• no

[engcom-backlog-nickolas]

Hello @AykutCevik, thank you for your report. I'm not able to reproduce this issue on 2.2-develop branch. Could you please specify magento version you use?

[ananth-iyer]

@AykutCevik Can you tell us which link you followed to install Redis?

[AykutCevik]

@engcom-backlog-nickolas I'm using Magento CE 2.2.5.
@ananth-iyer what do you mean by link and following it to install Redis?

[ananth-iyer]

Yes, the website you followed to install Redis.

[josephmcdermott]

Agree with @AykutCevik we have this appearing in var/report every now and then, its very difficult to track down and/or replicate but is happening. We are also using Redis for session saves.

I was able to replicate using the view order > view order grid as @AykutCevik suggested, for a split second I saw the error on the Order view page, before being taken to the order grid.

Here is the stack trace generated:

{"0":"Warning: session_start(): Failed to read session data: user (path: /var/session/) in /vendor/magento/framework/Session/SessionManager.php on line 189","1":"
0 [internal function]: Magento\\Framework\\App\\ErrorHandler->handler(2, 'session_start()...', '/var/www/vhosts...', 189, Array)\n
1 /vendor/magento/framework/Session/SessionManager.php(189): session_start()\n
2 /generated/code/Magento/Backend/Model/Session/Interceptor.php(24): Magento\\Framework\\Session\\SessionManager->start()\n
3 /vendor/magento/framework/Session/SessionManager.php(130): Magento\\Backend\\Model\\Session\\Interceptor->start()\n
4 /generated/code/Magento/Backend/Model/Session/Interceptor.php(14): Magento\\Framework\\Session\\SessionManager->__construct(Object(Magento\\Framework\\App\\Request\\Http), Object(Magento\\Framework\\Session\\SidResolver\\Proxy), Object(Magento\\Backend\\Model\\Session\\AdminConfig), Object(Magento\\Framework\\Session\\SaveHandler), Object(Magento\\Framework\\Session\\Validator), Object(Magento\\Framework\\Session\\Storage), Object(Magento\\Framework\\Stdlib\\Cookie\\PhpCookieManager), Object(Magento\\Framework\\Stdlib\\Cookie\\CookieMetadataFactory), Object(Magento\\Framework\\App\\State))\n
5 /vendor/magento/framework/ObjectManager/Factory/AbstractFactory.php(111): Magento\\Backend\\Model\\Session\\Interceptor->__construct(Object(Magento\\Framework\\App\\Request\\Http), Object(Magento\\Framework\\Session\\SidResolver\\Proxy), Object(Magento\\Backend\\Model\\Session\\AdminConfig), Object(Magento\\Framework\\Session\\SaveHandler), Object(Magento\\Framework\\Session\\Validator), Object(Magento\\Framework\\Session\\Storage), Object(Magento\\Framework\\Stdlib\\Cookie\\PhpCookieManager), Object(Magento\\Framework\\Stdlib\\Cookie\\CookieMetadataFactory), Object(Magento\\Framework\\App\\State))\n
6 /vendor/magento/framework/ObjectManager/Factory/Compiled.php(108): Magento\\Framework\\ObjectManager\\Factory\\AbstractFactory->createObject('Magento\\\\Backend...', Array)\n
7 /vendor/magento/framework/ObjectManager/Factory/Compiled.php(150): Magento\\Framework\\ObjectManager\\Factory\\Compiled->create('Magento\\\\Backend...')\n
8 /vendor/magento/framework/ObjectManager/Factory/Compiled.php(79): Magento\\Framework\\ObjectManager\\Factory\\Compiled->get('Magento\\\\Backend...')\n
9 /vendor/magento/framework/ObjectManager/Factory/Compiled.php(150): Magento\\Framework\\ObjectManager\\Factory\\Compiled->create('Magento\\\\Store\\\\A...')\n
10 /vendor/magento/framework/ObjectManager/Factory/Compiled.php(79): Magento\\Framework\\ObjectManager\\Factory\\Compiled->get('Magento\\\\Store\\\\A...')\n
11 /vendor/magento/framework/ObjectManager/Factory/Compiled.php(150): Magento\\Framework\\ObjectManager\\Factory\\Compiled->create('Magento\\\\Backend...')\n
12 /vendor/magento/framework/ObjectManager/Factory/Compiled.php(79): Magento\\Framework\\ObjectManager\\Factory\\Compiled->get('Magento\\\\Backend...')\n
13 /vendor/magento/framework/ObjectManager/ObjectManager.php(56): Magento\\Framework\\ObjectManager\\Factory\\Compiled->create('Magento\\\\Ui\\\\Cont...', Array)\n
14 /vendor/magento/framework/App/ActionFactory.php(40): Magento\\Framework\\ObjectManager\\ObjectManager->create('Magento\\\\Ui\\\\Cont...')\n
15 /vendor/magento/framework/App/Router/Base.php(297): Magento\\Framework\\App\\ActionFactory->create('Magento\\\\Ui\\\\Cont...')\n
16 /vendor/magento/framework/App/Router/Base.php(158): Magento\\Framework\\App\\Router\\Base->matchAction(Object(Magento\\Framework\\App\\Request\\Http), Array)\n
17 /vendor/magento/framework/App/FrontController.php(50): Magento\\Framework\\App\\Router\\Base->match(Object(Magento\\Framework\\App\\Request\\Http))\n
18 /vendor/magento/framework/Interception/Interceptor.php(58): Magento\\Framework\\App\\FrontController->dispatch(Object(Magento\\Framework\\App\\Request\\Http))\n
19 /vendor/magento/framework/Interception/Interceptor.php(138): Magento\\Framework\\App\\FrontController\\Interceptor->___callParent('dispatch', Array)\n
20 /vendor/magento/framework/Interception/Interceptor.php(153): Magento\\Framework\\App\\FrontController\\Interceptor->Magento\\Framework\\Interception\\{closure}(Object(Magento\\Framework\\App\\Request\\Http))\n
21 /generated/code/Magento/Framework/App/FrontController/Interceptor.php(26): Magento\\Framework\\App\\FrontController\\Interceptor->___callPlugins('dispatch', Array, Array)\n
22 /vendor/magento/framework/App/Http.php(135): Magento\\Framework\\App\\FrontController\\Interceptor->dispatch(Object(Magento\\Framework\\App\\Request\\Http))\n
23 /vendor/magento/framework/App/Bootstrap.php(256): Magento\\Framework\\App\\Http->launch()\n
24 /pub/index.php(37): Magento\\Framework\\App\\Bootstrap->run(Object(Magento\\Framework\\App\\Http\\Interceptor))\n
25 {main}","url":"/admin/mui/bookmark/save/key/0194bbb75ffe47f654ca4e5343628982d1264a99d6a680a341326e9111d89296/?isAjax=true","script_name":"/index.php"}

From searching online, it appears to be either
a) a red herring message and some session read data is being returned as NULL or FALSE instead of '',
b) or Magento is falling back to the native session handler in \Magento\Framework\Session\SaveHandlerFactory::create
c) or something else :)

[AykutCevik]

May this be related to max_concurrency where the fallback is the default PHP session handling? 🤔
(https://devdocs.magento.com/guides/v2.2/config-guide/redis/redis-session.html)

[engcom-backlog-nickolas]

@AykutCevik, thanks for feedback, and @josephmcdermott for details. I've tested on 2.2.5 with order view and order grid. Also I've been trying other different manipulation and still couldn't get described error on screen nor in logs.
Looks like we still missing some important steps or details, to replicate and therefore to fix this issue.
I'm leaving this issue open and if you guys have any details, feel free to share in order to write specific steps to reproduce.

[chris-pook]

@AykutCevik I believe this is indeed due to the max_concurrency value in env.php under the session => redis section. Magento is failing to save/retrieve sessions from the redis back-end based on the value of this config. However the error that's being reported here is stating that having failed to access Redis, the session also couldn't be accessed from the native PHP session directory (it may not exist on the server in the php.ini specified location, have a check on your server).

@engcom-backlog-nickolas, to consistently replicate the issue please try the following steps:

Preconditions

• Redis enabled for sessions
• Sessions Redis env.php config as per defaults in M2 devdocs (Max_concurency => 6)

Steps to reproduce

• Using Google Chrome, login to the admin area
• Open 10 or more browser tabs with the orders grid page
• Click the left most tab
• Hold shift and click the right most tab (this selects all tabs)
• Right click the right most tab and select "reload"
• Check the tabs after they have all reloaded, only ~6 will successfully load, the rest will exhibit this error *
• Check the var/report folder for the start_session error report relating to the tabs that failed.
• Now modify the max_concurrency to a value greater than the number of tabs, reload them all again and none will fail.

* if you aren't seeing this error, check in your PHP sessions directory. It should be empty (as Redis is the session back-end of course), however if there are session files building up in the directory, you are seeing a symptom of the same problem here, although it hides the error because PHP handles the session as a fallback. @AykutCevik try a php -i | grep session and check your session save path is available and has the correct permissions. Once corrected you'll likely see PHP handling the sessions rather than your error.

This is all happening because of contention for accessing session data from single threaded Redis. The max_concurency config value defines the size of the queue that can form to access Redis and retrieve the session. In the event of lots of traffic hitting the server at once, some users will receive this behavior because the queue is full, so the request to access the Redis session back-end is denied. PHP session handling kicks in here and if configured correctly will start creating sessions (this is still an issue as Redis is meant to be doing this for a reason, PHP will be saving to local disk so sessions wont be available across multiple web servers etc).

This same error will happen also on the front-end of Magento2. Try it by opening 10 or more tabs of different pages; clear the FPC (or just disable full page cache to emulate hitting un-cached pages); reload all the tabs at once as above and again some will fail. This is particularly bad when you have items in your cart as the local storage is not synched, resulting in the "I have no items in my cart, but there are items in my mini-cart" scenario I'm sure you've come across.

I would suggest that "6" as a default for max_concurrency is no good for most sites and that a better explanation of how to derive the correct value for the config should be made available. The Devdocs state "at least 10% of the number of PHP processes" but not why. I would assume that with 10% covered, in the unlikely(ish) event all your users hit pages at the same time (think Flash sale, Black Friday etc), 90% would receive this behavior still. I'm guessing the 10% suggestion is a stab in the dark at the likely percentage of requests that might all hit at the same time. This value should probably be derived from the max_children / max_requests values of the server's PHP-FPM pools, looking to accommodate as many requests as might come in concurrently.

Would be great to get a view from Magento on this!

Thanks

[chris-pook]

Update on the above comment

Having looked further in to this, I think potentially my above comment may not be completely accurate. The key being the code implementation of the function below:

\Cm\RedisSession\Handler::read()

This function implements the locking mechanism and appears to hold the lock per $sessionId. So this issue is not a problem globally across multiple sessions after all. I.e on a flash sale day, it would not be the case that the first 6 concurrent requests globally would get through and the rest bounce. Instead you would see all requests served but for each individual user's session only 6 concurrent requests allowed through.

To test this, I have repeated the front-end mass concurrent reload steps from before (with max_concurrency set to 6 still) only this time using ab:

ab -c 100 -n 100 <M2-instance-domain>

Concurrency Level:      100
Time taken for tests:   6.037 seconds
Complete requests:      100
Failed requests:        0

Here 100 concurrent requests are served no problem with no failures despite sessions being started.

Having discovered this I am happy that the 10% of PHP processes (php-fpm max_children) suggestion is probably quite sound. You don't want a single user session hogging the Redis instance making everyone else wait, so better to serve them 503 errors beyond their first X concurrent requests.

The likelihood is that this limit will only ever be exceeded by admin users trying to do too much at once, or abuse of the front-end.

It would still be great to get a line from Magento here to confirm. Apologies if this is going back over old ground that may have been covered elsewhere.

Thanks

[engcom-backlog-nickolas]

@AykutCevik, we are closing this issue due to inactivity. If you'd like to update it, please reopen the issue.