Mainly due to ob_start().

Noticed this when profiling 300 nodes in D6 vs. 300 in D7. Since we execute both node.tpl.php and field.tpl.php in D7 (one field added via CCK UI) - it doubles the calls to ob_start() per-node.

Not sure there's anything we can actually do about this (and it's an extreme example, although might not be if rendering say 10 nodes with 10 fields each), but opening this anyway.

webgrind screenshots attached.

Support from Acquia helps fund testing for Drupal Acquia logo

Comments

moshe weitzman’s picture

The only fix I can think of is to stop using print statements in the templates and instead use {$VARIABLE}. Essentially, the template would become one big heredoc. Found an interesting discussion about using PHp inside a heredoc - http://stackoverflow.com/questions/104516/calling-php-functions-within-h.... Ultimately, I think heredoc will be worse than the current phptemplate approach. More ideas needed.

mfb’s picture

I looked at this with kcachegrind and for me it looks like most of the time is spent on include::/d7/modules/field/theme/field.tpl.php, not ob_start(). Enabling APC extension improved performance for this function from over 4% of time spent to under 3%.

catch’s picture

mfb - how many times was field.tpl.php called on the page?

mfb’s picture

In my test node.tpl.php and field.tpl.php were each included 171 times and theme_render_template() was called 343 times (the 1 left over was for the page I guess). field.tpl.php took more time than node.tpl.php due to the t() call.

casey’s picture

Issue tags: +Performance

This one is worth looking at, performance-wise.

casey’s picture

FileSize
937 bytes

Patch at least saves a function call + some memory per template.

casey’s picture

Status: Active » Needs review
moshe weitzman’s picture

Status: Needs review » Reviewed & tested by the community

sure ... lets keep this open even after commit as the patch doesn't yet tackle the main issue. i am not optimistic we can solve it cleanly, but it should stay open nonetheless.

webchick’s picture

Status: Reviewed & tested by the community » Needs review

Could we get some before/after numbers with this patch? Output of memory usage from devel or similar?

moshe weitzman’s picture

Status: Needs review » Reviewed & tested by the community

i'm not expecting any difference that would show up in benchmarks. this just consolidates some overly verbose code into one line.

webchick’s picture

Status: Reviewed & tested by the community » Active

Ah, ok. I got confused by the performance tag.

Committed to HEAD and now marking back to active.

casey’s picture

The difference between d6 and d7 is probably caused by render().

catch’s picture

I don't think we had render() in May when those cachegrinds were done though though.

casey’s picture

Oww I actually only had a look at the code, not your cachegrinds. You're right.

This is probably related to #374388: node drupal_rendered twice on node page

total cost in d7 seems to be lower than d6, even with double the amount of invocations

casey’s picture

Nah after all I don't think we can optimize this function very much. I even tried code generation to circumvent multiple includes and buffer, but can't get much improvement (attached a patch of what I tried).

I think we can close this issue.

catch’s picture

Status: Active » Closed (won't fix)

Can't win 'em all. Thanks for looking though!