On profiling admin/config/people/accounts I noticed that theme_token_tree() can take up to 800ms and 3mb of memory. It is called with exactly the same arguments 8 times on that page.

Attached patch just adds a static cache. It reduces the CPU usage from theme_token_tree() on admin/config/people/accounts by around 90%, and reduces memory usage by 1/3rd.

It's very tempting to add cache_set() / cache_get() around this as well, although that would mean refactoring a bit - either to use render caching / #pre_render in the alters along with #attached for the css/js, or within the function to move the drupal_add_*() out of the cached bits. token_get_info() is cached, so that's feasible, but needs some thought/discussion.

xhprof summary, attaching screenshots of the theme_token_tree() detail as well. theme_token_tree() goes down from 60% of the request to 15%.

HEAD:
Total Incl. Wall Time (microsec): 602,142 microsecs
Total Incl. CPU (microsecs): 530,000 microsecs
Total Incl. MemUse (bytes): 9,125,744 bytes
Total Incl. PeakMemUse (bytes): 11,140,304 bytes
Number of Function Calls: 74,005

Patch:
Total Incl. Wall Time (microsec): 343,649 microsecs
Total Incl. CPU (microsecs): 250,000 microsecs
Total Incl. MemUse (bytes): 9,090,512 bytes
Total Incl. PeakMemUse (bytes): 10,717,968 bytes
Number of Function Calls: 22,319

Attaching xhprof screenshots that show the difference as well.

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

catch’s picture

FileSize
135.75 KB
127.73 KB
greggles’s picture

Looks solid to me.

Dave Reid’s picture

Status: Needs review » Needs work

Looks like we're caching the tree regardless of possible different $options which creates different output. With the patch it will cause different trees to be output the same.

Dave Reid’s picture

token_build_tree() already is cached in the db, so it's a little unclear why this is so bad aside from it can contain a metric ton of data.

catch’s picture

Status: Needs work » Needs review
FileSize
3.86 KB

Hmm good point.

Updated patch that moves the setting of the $options array up then serializes + hashes the $token_types and $options arrays. The cid could be done without that hash and serialize, but it'll be a fair bit more code to pick the different bits out.

catch’s picture

FileSize
3.86 KB

hash() sadly not a mind reader.

Dave Reid’s picture

Should I also consider calling theme_tree_table() directly rather than invoking a theme function from another theme function?

catch’s picture

That'd be worth looking at, I've re-opened #1068650: theme_token_tree uses lots of memory to look at generally optimizing the function. Hoping I'll have some time tomorrow to look at this.

Dave Reid’s picture

Also, since the token tree is the same one on the user account page, we should consider outputting only one token tree below the e-mail vertical tabs rather than repeating it every time in each vertical tab pane. Still doesn't change the fact that this function is still expensive by nature.

greggles’s picture

Title: theme_token_tree() is expensive » Cache theme_token_tree() to help performance when its called multiple times in the same page

Better title for the focus of this issue.

catch’s picture

Just the one token tree would mean a smaller page in terms of HTML and less javascript to execute (although didn't look whether the js is particularly expensive and that's not exactly my strength either), so that sounds like a good idea in itself.

catch’s picture

Issue tags: +memory
FileSize
4.26 KB

Alright I don't really like cache_get() cache_set() in a theme function, but here's a patch for comparison.

xhprof summary (APC enabled).

HEAD:

Total Incl. Wall Time (microsec):	255,208 microsecs
Total Incl. CPU (microsecs):	250,000 microsecs
Total Incl. MemUse (bytes):	12,902,888 bytes
Total Incl. PeakMemUse (bytes):	15,343,144 bytes
Number of Function Calls:	65,832

Patch:

Total Incl. Wall Time (microsec):	93,375 microsecs
Total Incl. CPU (microsecs):	90,000 microsecs
Total Incl. MemUse (bytes):	10,186,448 bytes
Total Incl. PeakMemUse (bytes):	10,977,648 bytes
Number of Function Calls:	10,380

So just under 3mb of memory, and 2/3rds of the page execution time. This is profiling admin/help/token

catch’s picture

FileSize
7.52 KB

I think we need to go for both here - make it as fast as possible on cache misses, and cache the whole thing as well.

Closed #1068650: theme_token_tree uses lots of memory as a duplicate, and attaching a combined (but untested) patch here.

catch’s picture

Title: Cache theme_token_tree() to help performance when its called multiple times in the same page » Optimize and add caching for theme_token_tree()

Re-titling.

Agence Web CoherActio’s picture

subscribing

johnv’s picture

subscribe. I get Fatal error: Allowed memory size ... exhausted in ...\database\database.inc on line 2039 as I described in #1115324: Slow pageload/Fatal error when editing Content Type. because of a call for tokens of type 'node':
$form['auto_nodetitle']['token_help'] = array( '#theme' => 'token_tree', '#token_types' => array('node'));
I'll try the patch.

johnv’s picture

Nope, the patch does not resolve my problem. I do see that each tree of a certain type is built only once. In that respect the patch is OK.
I can generate a working page (without a node-tree) when I add the following in the file token.pages.inc:

+if ($type  != 'node') {
       $tree = token_build_tree($type, $options);
+}

How can I help to analyze further?
- How can I know how many tokens 'node' has? Is it possible for a module to generate too many/indefinite tokens?
- I cannot find function token_build_tree(). It should be in the file, according to http://drupalcontrib.org/api/drupal/contributions--token--token.pages.in... [Edit: OK, it is in token.module itself.]
- The memory exhaust also appears on the generic page admin/modules. Why would you build a tree there? It slows down the page a lot.

johnv’s picture

Status: Needs review » Needs work
johnv’s picture

In my system, 'node' has 68 tokens, which doesn't seem too many. I tried the following in token.module file :
- In function token_build_tree(), I set 'depth' from 4, to 1, to 0: got a white screen instead of a fatal error-message.
- I've set define('TOKEN_MAX_DEPTH', 9) to 2; this works, although it should be the same as the previous attempt.
- I removed the recursive line $tree[$raw_token]['children'] = _token_build_tree($token_info['type'], $child_options);
The latter helped: although token trees are only 1 level deep, pages are showing correctly.

Can this occur because my node-reference fields generate an infinite loop? TypeA->TypeB->TypeA->etc. I'll have to check that.
Please tell me if I need to open a new issue.

johnv’s picture

And for the last time this morning: Does the recursive tree picks up too many fields, due to References.module?
As written before, 'node' has 68 tokens. Every user/node reference opens up with again 68 tokens.
This can't be correct. The following References issues deal with it:
#1058912: Prevent recursive tokens
#1005364: support hook_entity_property_info()
So, the initial patch seems OK to me. Sorry for any inconvenience..

catch’s picture

Status: Needs work » Needs review

Moving back to CNR.

If that references patch fixes things for you, it'd be great if you could still post before/after memory usage with the patch from here.

johnv’s picture

I'd be glad to give some figures, but don't know how to do that with only Notepad and Devel as my tools..

catch’s picture

So in devel, you should be able to see memory usage if you enable that in settings.

Then you can visit the page you had this problem (refresh a couple of times to ensure caches are warm), and make a note of how much memory it took.

After that, apply the patch, and do the same again. Then just post the results back here.

johnv’s picture

Here are the results. I ran each page 3 times, 2nd and 3rd time the results were identical, as you said.
Times & memory have dropped. I have killed auto_node title in the 3rd cycle. Strangely enough, this increases loading time, but drops memory usage from 14.14 to 12.76 to 10.86, meaning a 50%!

page admin/modules (why would you build the token tree here?):
-patch: Page exec time 43761.61 ms. Memory used at: devel_boot()=0.65 MB, devel_shutdown()=16.07 MB, PHP peak=21.25 MB.
+patch: Page exec time 41619.68 ms. Memory used at: devel_boot()=0.65 MB, devel_shutdown()=13.15 MB, PHP peak=15 MB.

page admin/structure/types/manage/{content type} with auto_nodetitles:
-patch: Page exec time 8806.76 ms. Memory used at: devel_boot()=0.65 MB, devel_shutdown()=14.17 MB, PHP peak=23 MB.
+patch: Page exec time 8363.05 ms. Memory used at: devel_boot()=0.65 MB, devel_shutdown()=12.76 MB, PHP peak=18.5 MB.

page admin/structure/types/manage/{content type} without auto_nodetitles:
-patch: Page exec time 13929.73 ms. Memory used at: devel_boot()=0.65 MB, devel_shutdown()=10.86 MB, PHP peak=13.25 MB.
+patch: Page exec time 14105.58 ms. Memory used at: devel_boot()=0.65 MB, devel_shutdown()=10.86 MB, PHP peak=13 MB.

catch’s picture

Could you put this in theme_token_tree() and hit admin/build/modules, then paste the results here?

print_r(debug_backtrace()); exit;

I think I've seen this before, and it was token_help(), but not 100% sure.

johnv’s picture

admin/modules says:
Array ( [0] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\includes\theme.inc [line] => 881 [function] => theme_token_tree [args] => Array ( [0] => Array ( [token_types] => all [click_insert] => [show_restricted] => 1 [global_types] => 1 [recursion_limit] => 4 ) ) ) [1] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\sites\all\modules\token\token.module [line] => 15 [function] => theme [args] => Array ( [0] => token_tree [1] => Array ( [token_types] => all [click_insert] => [show_restricted] => 1 ) ) ) [2] => Array ( [function] => token_help [args] => Array ( [0] => admin/help#token [1] => Array ( [0] => [1] => [2] => [3] => [4] => [5] => [6] => [7] => [8] => [9] => [10] => [11] => ) ) ) [3] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\includes\module.inc [line] => 793 [function] => call_user_func_array [args] => Array ( [0] => token_help [1] => Array ( [2] => admin/help#token [3] => Array ( [0] => [1] => [2] => [3] => [4] => [5] => [6] => [7] => [8] => [9] => [10] => [11] => ) ) ) ) [4] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\modules\system\system.admin.inc [line] => 824 [function] => module_invoke [args] => Array ( [0] => token [1] => help [2] => admin/help#token [3] => Array ( [0] => [1] => [2] => [3] => [4] => [5] => [6] => [7] => [8] => [9] => [10] => [11] => ) ) ) [5] => Array ( [function] => system_modules [args] => Array ( [0] => Array ( ) [1] => Array ( [build_info] => Array ( [args] => Array ( ) [files] => Array ( [menu] => modules/system/system.admin.inc ) ) [rebuild] => [rebuild_info] => Array ( ) [redirect] => [temporary] => Array ( ) [submitted] => [executed] => [programmed] => [cache] => [method] => post [groups] => Array ( ) [buttons] => Array ( ) [input] => Array ( ) ) ) ) [6] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\includes\form.inc [line] => 771 [function] => call_user_func_array [args] => Array ( [0] => system_modules [1] => Array ( [0] => Array ( ) [1] => Array ( [build_info] => Array ( [args] => Array ( ) [files] => Array ( [menu] => modules/system/system.admin.inc ) ) [rebuild] => [rebuild_info] => Array ( ) [redirect] => [temporary] => Array ( ) [submitted] => [executed] => [programmed] => [cache] => [method] => post [groups] => Array ( ) [buttons] => Array ( ) [input] => Array ( ) ) ) ) ) [7] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\includes\form.inc [line] => 315 [function] => drupal_retrieve_form [args] => Array ( [0] => system_modules [1] => Array ( [build_info] => Array ( [args] => Array ( ) [files] => Array ( [menu] => modules/system/system.admin.inc ) ) [rebuild] => [rebuild_info] => Array ( ) [redirect] => [temporary] => Array ( ) [submitted] => [executed] => [programmed] => [cache] => [method] => post [groups] => Array ( ) [buttons] => Array ( ) [input] => Array ( ) ) ) ) [8] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\includes\form.inc [line] => 188 [function] => drupal_build_form [args] => Array ( [0] => system_modules [1] => Array ( [build_info] => Array ( [args] => Array ( ) [files] => Array ( [menu] => modules/system/system.admin.inc ) ) [rebuild] => [rebuild_info] => Array ( ) [redirect] => [temporary] => Array ( ) [submitted] => [executed] => [programmed] => [cache] => [method] => post [groups] => Array ( ) [buttons] => Array ( ) [input] => Array ( ) ) ) ) [9] => Array ( [function] => drupal_get_form [args] => Array ( [0] => system_modules ) ) [10] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\includes\menu.inc [line] => 501 [function] => call_user_func_array [args] => Array ( [0] => drupal_get_form [1] => Array ( [0] => system_modules ) ) ) [11] => Array ( [file] => C:\Damp\Sites\hunkemoller.nl_v2\index.php [line] => 22 [function] => menu_execute_active_handler [args] => Array ( ) ) )
Page execution time was 21034.04 ms. Memory used at: devel_boot()=0.65 MB, devel_shutdown()=6.31 MB, PHP peak=6.75 MB.

catch’s picture

Right, that's token_help() - which lists all tokens on the site on its main page, and admin/build/modules executes token_help() even though it doesn't show it. So effectively, all tokens across the whole site are being generation, just because we want to show a help link.

This is partly due to the crapness of help module, but I don't see that getting fixed at all in D7, so it'd be good if token could work around it (i.e., by not showing all the tokens).

Dave Reid’s picture

Yeah, I've now fixed token_help() calling the token tree on the modules page. It will only execute if current_path() == 'admin/help/token'. Stupid help system.

johnv’s picture

Dave, I guess this is fixed then?

Dave Reid’s picture

Well we still could probably use token caching as well.

derhasi’s picture

FileSize
178.75 KB

This is still a big problem on one of my sites. Wehen using auto node titles (so token tree is display on the node add/edit page) it wants more than 300MB memory limit for just building the token tree.

I have got 10 node types, 10 node reference fields, 3 user reference fields, 4 taxonomies.

Temporary I could avoid this error bei setting the recursion_limit down to 3 (Defaults to 4).

I guess the bottle neck is somewhere in the _token_build_tree(), as cachin in token_build_tree() should solve at least at that level, but in _token_build_tree() there seems to be a lot of uncached recursion. Currently I have no time to dig deeper, but hope this information can help (error message attached as png)

13rac1’s picture

Site was hitting 256M PHP memory limit with entity_token.module enabled. Applying patch in #13 fixed the problem.

Xdebug cachegrind file went from 395MB to 1.5MB! Original comment in Entity queue: http://drupal.org/node/1203018#comment-4825362

Patch in #13 doesn't apply cleanly to 2011-Jul-29 7.x-1.x-dev from git. I applied the rejected hunks manually, and created the attached git patch.

johnv’s picture

@derhasi, eosrei, have you enabled References in your system? then your problem has another origin. See #1058912: Prevent recursive tokens and use any of the supplied patches over there for a solution.

13rac1’s picture

@johnv This patch fixes my issue with Token memory usage on admin/config/people/accounts, same issue catch has in the original post.

References is enabled, but this was still a problem. I wrote the most recent patch in #1058912: Prevent recursive tokens. It isn't IMO the overall best method to fix the problem, but it is a good workaround: http://drupal.org/node/1058912#comment-4830326

c4rl’s picture

[subscribe]

manu.zueger’s picture

subscribe

Michelle’s picture

I arrived here from #1115324: Slow pageload/Fatal error when editing Content Type. since Auto Nodetitles is making the node type edit pages unusably slow for me. I applied the patch in #32 and it has _not_ fixed the problem. I don't know enough about this to know if that means the issue isn't with Token or that the patch doesn't fix the issue.

Michelle

13rac1’s picture

@Michelle Try my patch in: http://drupal.org/node/1058912#comment-4830326 Change the token recursion limit to two. Note: The patch is a useful workaround, the "correct" (New UI) fix is TBD.

Michelle’s picture

That definitely helped, thanks. I don't like having a patched module but that at least lets me keep building the site while waiting on a better way. :)

Michelle

13rac1’s picture

Status: Needs review » Reviewed & tested by the community

Since my patch in #32 is just a clean up of the patch in #13, I am setting this to RTBC.

Dave Reid’s picture

Assigned: Unassigned » Dave Reid
Status: Reviewed & tested by the community » Needs review

There have been updates in the code since then so this does not apply. I am actively working on this today.

Dave Reid’s picture

Note that #1256524: Only output token tree on user account settings page once should help a little bit. Working on token tree render caching now.

Dave Reid’s picture

Here's what I'm using locally. Could someone see how this compares before and after?

Dave Reid’s picture

I excluded a static cache for theme_token_tree() as it increased the memory usage by over a MB on the Pathauto page.

Dave Reid’s picture

Status: Needs review » Needs work

I have pushed #43 to Git to at least get us somewhere.
http://drupalcode.org/project/token.git/commit/f04e818

SNaKeMe’s picture

I tested your new token code. But i also get some memory errors. I can't use my admin --> patterns site to config the pathauto. I get these errors:

Fatal error: Allowed memory size of 52428800 bytes exhausted (tried to allocate 41 bytes) in /.../sites/all/modules/token/token.pages.inc on line 14

Fatal error: Allowed memory size of 52428800 bytes exhausted (tried to allocate 41 bytes) in /.../sites/all/modules/token/token.pages.inc on line 15

Fatal error: Allowed memory size of 52428800 bytes exhausted (tried to allocate 41 bytes) in /.../sites/all/modules/token/token.pages.inc on line 17

SNaKeMe’s picture

When i deactivated the module rules and entity token i can use admin/config/search/path/patterns without memory problems.

erikhopp’s picture

Subscribe

daniela basualdo’s picture

Subscribe

dazz’s picture

subscribe

apmsooner’s picture

Entity tokens module is the culprit for me as well. Once i disabled that, no more memory errors.

Michelle’s picture

Oh, I have that enabled, too. Is there any way to know which tokens it's providing? I'm afraid of disabling it only to find I was using one of the tokens and mess something up. :(

Michelle

Dave Reid’s picture

Assigned: Dave Reid » Unassigned
apmsooner’s picture

Its a requirement for rules which is the only reason why i had it enabled in the first place. Thats the only place i know of it being used. There are other modules like VBO that requires the entity api module but not entity tokens. Unfortunate for rules since i use that also... but too much else is broken with entity tokens enabled: e.g. pathauto, automatic nodetitles, custom breadcrumbs. All of the php errors i got on those modules are now gone. I have 512 meg of ram on the site i'm running on dedicated server too so that's quite a load apparently caused by entity tokens.

greggles’s picture

For those commenting recently, it would be interesting to know if you are using the code from after August 22nd - i.e. are you using 7.x-1.0-beta5 or a 7.x-1.x-dev from after that date?

apmsooner’s picture

Hey Greg, i had beta-5 originally which was giving me the php errors, i then upgraded to the latest dev dated 9-6 from the module page and still had the php errors. Once i disabled entity tokens however, everything is fine.

Michelle’s picture

I've been keeping up with the dev snapshots hoping the problem would go away but it hasn't. I still have Entity Token enabled because I haven't yet determined if it's safe to disable it.

Michelle

dazz’s picture

I now have Entity tokens 7.x-1.0-beta10 and Tokens 7.x-1.0-beta5 running and the problems have disappeared.

apmsooner’s picture

I had entity tokens 7.x-1.0-beta 10, problems very much visible for me so maybe you have different problems. Custom breadcrumbs, automatic nodetitles, and pathauto were all unable to be administered fully with entity tokens enabled. I'm keeping it disabled till i see a new version in either module that takes another stab at fixing it.

dazz’s picture

I didn't check custom breadcrumbs but i did have the other problems. Maybe i did something else to fix it but except upgrading to the latest versions of both the modules i can't really recall anything major.

Michelle’s picture

I'm on beta 10 of Entity and the current dev of Token and it's still super duper slow any time I make changes to a file field and possibly other places as well but I haven't checked lately.

Michelle

Dave Reid’s picture

I've already added what caching I can to the token tree without rewriting it completely. At this point Entity Tokens completely overwhelms the token tree by the sheer number of tokens it creates and the tree was not designed to handle that amount, so I cannot provide support for Entity Tokens.

apmsooner’s picture

Well, i guess i won't be using rules in D7 then unfortunately.

SNaKeMe’s picture

Entity tokens know the problem ... but they say its a token problem ...

http://drupal.org/node/1203018#comment-4952900

greggles’s picture

If 4 levels is a problem would rendering 3 levels be a problem?

Maybe we should make it a variable that people can set? Maybe we should periodically count the number of tokens that are being rendered in the tree and if its too many (or too few) set it to render more or fewer levels of the tree?

Michelle’s picture

Dave Reid’s picture

Status: Needs work » Fixed

These are good follow-up issues but the issue here about adding caching and optimization has been completed to the best of my ability.

Dave Reid’s picture

daniela basualdo’s picture

I could fix the problem with the token tweaks module.
Now I got following modules enabled: token, token entity, rules and token tweaks. Works!
Site is running very fast, even when I edit content types and url alias patterns.
great stuff!

Status: Fixed » Closed (fixed)

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

basvredeling’s picture

I have pushed #43 to Git to at least get us somewhere.
http://drupalcode.org/project/token.git/commit/f04e818

Does this mean that it has been added to a dev version of token?

Dave Reid’s picture

Yes, hence the "closed (fixed)" status on this issue.