Long Running Admin Page Requests Blocking Other Requests

Question

If I'm logged into Magento's backend and perform some task that takes a long time (global search on large catalogs, long running dataflow, etc), my web browser will refuse to load other admin pages in that browser only. Why does this happen, and is there any known science for workarounds?

That is, if I

1. Log into Magento's dashboard page

2. Open a second tab with any Magento admin page

3. Perform a long running global search (simulated with a call to sleep(30) at the start of globalSearchAction) in the first tab

4. Attempt to reload the second tab

Expected Behavior: Second tab loads with page contents immediately

Actual Behavior: Second tab only loads once the long running global search completes

Does anyone know, specifically, why this happens? (My guess is Magento admin console requests lock some resource Magento needs to bootstrap, but I don't know what that is)

Does anyone know of a fix/workaround?

Answer 1

The problem is caused by a lock placed by the PHP session handler. So it's not Magento explicitly locking something and trying to block admin requests, but almost a side-effect per-se of file-based session storage.

A write lock is being placed on the session data file when it is opened by the initial (long-running) request, causing the second request to block until the lock is released when it calls session_start in Mage_Core_Model_Session_Abstract_Varien::start

This is 100% reproducible. I used the same method you did, adding a sleep(30) to the top of Mage_Adminhtml_IndexController::globalSearchAction

Worth noting is that this cannot be reproduced if you are using db session storage. After I found the root cause, I set a sandbox to db session storage and could no longer reproduce the issue. So the db session handlers Magento has seemingly do not use row-level locking to lock session writes. I find this interesting, because it has the potential for session data loss since the application is obviously not accounting for multiple threads writing to the same session. Note for Readers: I would never use db session storage in production to try and solve this, it's only good for overloading your MySql database.

I didn't try reproducing the behavior using memory based session storage systems such as Redis, but my guess is that locking the records in the session store was probably overlooked in these as well.

There are techniques which could be employed to avoid this like using session_write_close to release the lock before you start on a long-running job. But this would also prevent you from writing to the session since you've just closed it. So it's not likely to be readily implemented across the board in Magento, but could potentially be implemented on specific routes/controllers.

My technique for pinning this as the root cause was to enable the Xdebug profiler and exam the "cachegrind" file. Once the second request completed, I loaded the output file (~25 MB log) into MacCallGrind and drilled down into the trace following the path of calls where the inclusive time was 28 seconds or greater. This ultimately led me to the session_start call which took ~28 seconds to run, giving me a great point to research from.

EDIT: For the interested, I've posted a screenshot of the "cachegrind" file viewed in MacCallGrind on Twitter.