While profiling D7, I noticed that _menu_check_access() is called many many times with paths that have no relevance to the current page. This function is in the top 5 time sucks right now.

To reproduce the problem:

  1. Ideally, start with clean HEAD install
  2. Create a standard user and login as that user
  3. Add this line to top of _menu_check_access(): print ($item['href']) . "\n";
  4. View homepage and note all the strange paths that get checked like taxonomy/autocomplete and user field/js_add_more system/ahah
Support from Acquia helps fund testing for Drupal Acquia logo

Comments

pwolanin’s picture

discussed in IRc - sounds like a bug

moshe weitzman’s picture

Issue tags: +Performance

Silly placeholder because I have to say something when adding a tag.

catch’s picture

subscribing.

Nick Lewis’s picture

That's very odd. The ones that have me really puzzled are:
My user can't create that content type, much less delete it.
admin/structure/node-type/article/delete
admin/structure/node-type/page/delete

catch’s picture

It's checking access to see if that page is accessible to the user or not, to decide whether to render the menu link for 'structure', which should only show up if there's at least one item that user has access to underneath it.

And yes, this is really stupid and wasteful to be doing that on every page request.

catch’s picture

Component: menu system » toolbar.module
Status: Active » Needs review
FileSize
343.32 KB
380.62 KB
3.55 KB
413.8 KB
380.37 KB

This is caused by having toolbar.module (or anything which tries to get the entire admin menu tree on non-admin pages) enabled.

Attached patch doesn't fix the root cause, since I can't think of a good way to do that, but it fixes the performance issue and has the side-effect of speeding up /admin too.

I added a cache for system_admin_menu_block() based on $item['path'] (while it's not guaranteed to be unique, people who put two links to the same path at the top of /admin and expect it to work I have no interest in making their lives easier), and implode('|', array_keys($user->roles)); - so we get a cache entry per block, per combination of roles.

This makes system_admin_menu_block_access() require a cache_get() instead of two direct queries and a bunch of access checking of large arrays, not perfect, but better.

Additionally, I added a similar cache for the result of toolbar_get_menu_tree() - since that also triggers access checks on the entire admin menu structure as well, which was taking up 25% of page execution time by itself, and without both, we end up with no real gains here.

webgrind looks happier, attached screenshots ordered by both self and incl.

@TODO, clearing the new cache. It needs to be cleared on at least:

# saving the permissions page
# saving a new menu link and/or menu_rebuild() - might be covered by existing cache clears?

but marking as needs review for the bot/concept.

catch’s picture

FileSize
3.4 KB

Putting back a useful if check.

Status: Needs review » Needs work

The last submitted patch failed testing.

pwolanin’s picture

@catch - so this is basically due to some badly coded new core code?

catch’s picture

Title: too many calls to _menu_check_access() » Too many calls to _menu_check_access()

@pwolanin, well, yes.

#296693: Restrict access to empty top level administration pages was committed months ago, which was supposed to hide menu links for empty admin categories, but obviously didn't take into account that this check would be done on every page which might ever possibly want to display one of those links. Since the toolbar does the equivalent of setting 'admin' to expanded, we're now effectively rendering the entirety of /admin on every page request just to hide a couple of links. This isn't the fault of toolbar.module and it affects admin_menu.module as well in contrib (except admin_menu does client-side caching in D7 so mitigates the worst of this), or the management menu if you set admin to expanded in the menu UI, so needs to be fixed in system.module.

#520364: system_admin_menu_block_access() makes no sense exists to fix this stupidity properly, but I don't want to clutter that one with this workaround, since it's possible someone will come up with a proper fix there - after which this would be easy to revert if we don't think it's worth it for a slightly faster /admin. However that requires an API change, this patch doesn't, and there's four weeks to code freeze without even a suggested fix there.

Additionally, toolbar.module populates the top level links with it's own toolbar_get_menu_tree() function which pulls out the top level items under /admin then lops off their children. This could probably be improved by doing something like adding a $depth parameter to http://api.drupal.org/api/function/menu_tree_all_data/7 - which would allow it to only check access for the top level items before returning $tree instead of all of them. However, without the caching to system_admin_menu_block() this'd be a waste of time, since the top level has to check access to all children due to the _access() function anyway. I opened #509584: APi fixes for menu_tree_data() including depth param a while back to clean that up, but that was before I noticed how much damage it was causing (rather than just being a bit messy).

catch’s picture

Status: Needs work » Needs review
FileSize
3.4 KB

Fixed syntax error.

catch’s picture

FileSize
4.9 KB

Added hook_cache_clear_all() to avoid system and/or toolbar.module having to register a submit handler on the permissons page just to flush it's own cache, that whole thing really needs a cleanup having module_exists('block') in cache.inc, but I don't want to add a dependency here on #496248: Refactor cache API which should hopefully clean it up a lot better.

toolbar.module also piggybacks on the system.module provided cid prefix to avoid having to duplicate a lot of code in both places.

Gábor Hojtsy’s picture

@catch: good summary in #10. #296693: Restrict access to empty top level administration pages did indeed bring on some interesting side effects.

catch’s picture

FileSize
8.03 KB

Not keen on the cache.inc change, so adding the glaringly missing hooks for user role insert/update/delete instead. Yes, this is scope creep, that's what happens when patches get committed that introduce loads of critical bugs instead of being dealt with properly before they're in, see http://drupal.org/node/484820#comment-1772926

Status: Needs review » Needs work

The last submitted patch failed testing.

moshe weitzman’s picture

The toolbar patch introduced a critical performance bug that is non trivial to fix. I seriously recommend rolling back the toolbar patch (if possible). One precedent for this is #310467: Slimmer hook_theme() which was rolled back because it broke the installer.

catch’s picture

Status: Needs work » Needs review
FileSize
8.03 KB

minus very strange typo.

Status: Needs review » Needs work

The last submitted patch failed testing.

catch’s picture

Status: Needs work » Needs review
FileSize
8.03 KB

grr.

pwolanin’s picture

I see the approach, but I'm not sure I agree that just caching is the right approach vs. some simple API cleanups.

pwolanin’s picture

This function is written really badly: http://api.drupal.org/api/function/toolbar_get_menu_tree/7

I think the fairly simple change in this patch will already make for a dramatic reduction in access calls, by loading only the subtree we care about rather than the entire menu. There is a critical bug anyhow, since we could (based only current code) load any number of 'admin' links since ther is no check on the module attribute. I'll go visit #509584: APi fixes for menu_tree_data() including depth param too, since that should be fixed too.

I'm not sure the caching is correct or even doable (hence why we don't have it in the rest of the menu system), since there is no reason that access callbacks have to be strictly role based.

catch’s picture

Status: Needs review » Reviewed & tested by the community
FileSize
350.61 KB
347.23 KB

This cuts out half the extraneous calls to _menu_check_access() - after it's in we'll still need to fix system_admin_menu_block_access() for the rest.

webchick’s picture

Status: Reviewed & tested by the community » Needs review

Could we quickly get some benchmark data to prove that performing an extra query here we weren't doing before is a smaller performance hit than calling the function that many times? From what I understand, leaving PHP and going to the DB is monumentally slower than calling PHP functions.

Otherwise, this patch seems fine.

pwolanin’s picture

@webchick - since access callbacks may, e.g., load Views or cached data in a real-world scenario, I think this is a reasonable trade-off. However, we could probably hone this further if we care, e.g. by saving as a variable the menu link of interest so that we don't have to go to the DB on most page loads.

catch’s picture

Status: Needs review » Reviewed & tested by the community

@webchick, I was going to do benchmarks, but then I ran into #529314: Toolbar throws errors for anonymous users which is sufficiently broken that benchmarks won't be great (i.e. we have to log to watchdog every request which will completely mess up trying to measure the impact of a couple of SELECTs).

However, looking at devel query log, this patch actually causes four less queries on the default front page

HEAD:
Executed 46 queries

Patch:
Executed 42 queries

Looks like we're doing one call to menu_load() instead of six (-5) plus the extra query here (+1) = -4.

Also see this webgrind screenshots I posted in #3 for the current performance impact of the toolbar - menu_tree_check_access taking up 70%, compared to 10% when the whole toolbar was cached, the reason the total adds up to more than 100% is because various function calls can be included within the count for other functions (theme() for example), so not an ideal measure, but rendering the entirety of /admin on every page and checking access for all the links twice isn't cheap.

catch’s picture

FileSize
591.08 KB
352 KB
368.58 KB

Forgot screenshots:

devel query log output before/after patch.

Also a dpm(debug_backtrace()) inside menu_load() which shows it called by toolbar_get_menu_tree() vi menu access checks after about 12 levels of depth - because presumably one admin access callback is calling menu_load() for every menu.

pwolanin’s picture

if we finish #509584: APi fixes for menu_tree_data() including depth param, this will be radically improved, but in general access check can be pretty expensive, since each can load an object from the DB, so the patch here is almost always going to be a win despite the initial extra query.

webchick’s picture

Status: Reviewed & tested by the community » Fixed

Committed to HEAD.

pwolanin’s picture

Status: Fixed » Needs work

Hmm, actually I confused the behavior of function menu_tree_all_data() - this would make the code more correct, but should just wait anyhow for #509584: APi fixes for menu_tree_data() including depth param.

pwolanin’s picture

FileSize
1.04 KB
moshe weitzman’s picture

anything left to do here? bot is not testing this patch since it is 'needs work'.

pwolanin’s picture

@moshe - I was waiting for this commit: #509584: APi fixes for menu_tree_data() including depth param, so we can now proceed. We need to think about whether we want the toolbar to be empty if the 'admin' link is moved to another menu, or whether we shoudl get the menu name from that link.

pwolanin’s picture

It would be nice to make function book_menu_subtree_data() a general menu API function - but the trick there is that we have to be able to define an extra table to join on mlid. I wanted to do this for all menu link functions also like menu_tree_page_data(), but time got away from me unless we can call it API cleanup.

pwolanin’s picture

FileSize
1.01 KB

Here's a patch using the depth - for some reason the other part of the code from the prior patch doesn't work.

sun’s picture

Status: Needs work » Needs review
FileSize
1.18 KB

I didn't test this patch, but I wanted to make sure that there are no colons after @todo :P

moshe weitzman’s picture

Status: Needs review » Reviewed & tested by the community

Yup, now using $depth param.

catch’s picture

Title: Too many calls to _menu_check_access() » Clean up toolbar menu code
Priority: Critical » Normal
Issue tags: -Performance +Quick fix

Changing status since this is no longer a performance patch (calls to _menu_check_access() are unchanged by the patch). However still RTBC and very straightforward.

sun’s picture

Created the follow-up #618530: System module's "listing" pages (and blocks) should use menu_build_tree() that is required to eliminate the nightmare-ish workarounds that are hacked into Toolbar module here.

This patch should still go in before that.

Additionally, #296693: Restrict access to empty top level administration pages solves the "grouping item" access issue.

Dries’s picture

Status: Reviewed & tested by the community » Fixed

Committed to CVS HEAD. Thanks!

Status: Fixed » Closed (fixed)
Issue tags: -Quick fix

Automatically closed -- issue fixed for 2 weeks with no activity.