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.
Comment | File | Size | Author |
---|---|---|---|
#43 | 1068990-token-render-trees-performance.patch | 8.32 KB | Dave Reid |
#32 | token-cache-1068990-31.patch | 7.54 KB | 13rac1 |
#31 | admin_structure_types_add.png | 178.75 KB | derhasi |
#13 | token.patch | 7.52 KB | catch |
#12 | token_caching.patch | 4.26 KB | catch |
Comments
Comment #1
catchComment #2
gregglesLooks solid to me.
Comment #3
Dave ReidLooks 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.
Comment #4
Dave Reidtoken_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.
Comment #5
catchHmm 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.
Comment #6
catchhash() sadly not a mind reader.
Comment #7
Dave ReidShould I also consider calling theme_tree_table() directly rather than invoking a theme function from another theme function?
Comment #8
catchThat'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.
Comment #9
Dave ReidAlso, 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.
Comment #10
gregglesBetter title for the focus of this issue.
Comment #11
catchJust 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.
Comment #12
catchAlright 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:
Patch:
So just under 3mb of memory, and 2/3rds of the page execution time. This is profiling admin/help/token
Comment #13
catchI 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.
Comment #14
catchRe-titling.
Comment #15
Agence Web CoherActio CreditAttribution: Agence Web CoherActio commentedsubscribing
Comment #16
johnvsubscribe. 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.
Comment #17
johnvNope, 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:
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.
Comment #18
johnvComment #19
johnvIn 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.
Comment #20
johnvAnd 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..
Comment #21
catchMoving 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.
Comment #22
johnvI'd be glad to give some figures, but don't know how to do that with only Notepad and Devel as my tools..
Comment #23
catchSo 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.
Comment #24
johnvHere 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.
Comment #25
catchCould 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.
Comment #26
johnvadmin/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.
Comment #27
catchRight, 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).
Comment #28
Dave ReidYeah, 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.
Comment #29
johnvDave, I guess this is fixed then?
Comment #30
Dave ReidWell we still could probably use token caching as well.
Comment #31
derhasi CreditAttribution: derhasi commentedThis 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)
Comment #32
13rac1 CreditAttribution: 13rac1 commentedSite 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.
Comment #33
johnv@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.
Comment #34
13rac1 CreditAttribution: 13rac1 commented@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
Comment #35
c4rl CreditAttribution: c4rl commented[subscribe]
Comment #36
manu.zueger CreditAttribution: manu.zueger commentedsubscribe
Comment #37
MichelleI 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
Comment #38
13rac1 CreditAttribution: 13rac1 commented@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.
Comment #39
MichelleThat 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
Comment #40
13rac1 CreditAttribution: 13rac1 commentedSince my patch in #32 is just a clean up of the patch in #13, I am setting this to RTBC.
Comment #41
Dave ReidThere have been updates in the code since then so this does not apply. I am actively working on this today.
Comment #42
Dave ReidNote that #1256524: Only output token tree on user account settings page once should help a little bit. Working on token tree render caching now.
Comment #43
Dave ReidHere's what I'm using locally. Could someone see how this compares before and after?
Comment #44
Dave ReidI excluded a static cache for theme_token_tree() as it increased the memory usage by over a MB on the Pathauto page.
Comment #45
Dave ReidI have pushed #43 to Git to at least get us somewhere.
http://drupalcode.org/project/token.git/commit/f04e818
Comment #46
SNaKeMe CreditAttribution: SNaKeMe commentedI 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
Comment #47
SNaKeMe CreditAttribution: SNaKeMe commentedWhen i deactivated the module rules and entity token i can use admin/config/search/path/patterns without memory problems.
Comment #48
erikhopp CreditAttribution: erikhopp commentedSubscribe
Comment #49
daniela basualdo CreditAttribution: daniela basualdo commentedSubscribe
Comment #50
dazz CreditAttribution: dazz commentedsubscribe
Comment #51
apmsooner CreditAttribution: apmsooner commentedEntity tokens module is the culprit for me as well. Once i disabled that, no more memory errors.
Comment #52
MichelleOh, 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
Comment #53
Dave ReidComment #54
apmsooner CreditAttribution: apmsooner commentedIts 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.
Comment #55
gregglesFor 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?
Comment #56
apmsooner CreditAttribution: apmsooner commentedHey 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.
Comment #57
MichelleI'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
Comment #58
dazz CreditAttribution: dazz commentedI now have Entity tokens 7.x-1.0-beta10 and Tokens 7.x-1.0-beta5 running and the problems have disappeared.
Comment #59
apmsooner CreditAttribution: apmsooner commentedI 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.
Comment #60
dazz CreditAttribution: dazz commentedI 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.
Comment #61
MichelleI'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
Comment #62
Dave ReidI'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.
Comment #63
apmsooner CreditAttribution: apmsooner commentedWell, i guess i won't be using rules in D7 then unfortunately.
Comment #64
SNaKeMe CreditAttribution: SNaKeMe commentedEntity tokens know the problem ... but they say its a token problem ...
http://drupal.org/node/1203018#comment-4952900
Comment #65
gregglesIf 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?
Comment #66
MichelleSpin-off issue: #1271958: Allow admins to choose set of tokens available
Michelle
Comment #67
Dave ReidThese are good follow-up issues but the issue here about adding caching and optimization has been completed to the best of my ability.
Comment #68
Dave ReidSee also #1271966: Consider decreasing the default tree depth from 4 to 3.
Comment #69
daniela basualdo CreditAttribution: daniela basualdo commentedI 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!
Comment #71
basvredelingDoes this mean that it has been added to a dev version of token?
Comment #72
Dave ReidYes, hence the "closed (fixed)" status on this issue.