Convert theme_views_view_fields() to 100% Twig: remove the theme function

This patch builds upon patch #4 but it moves all the HTML generation from preprocess function to twig file, thus avoiding HTML sanitation.

I like the way stuff is moving to template. That way we can get rid of double autoescaping issues. Perfect!! Maybe we should fix some documentation to the twig file to make it easire to understand.

Patch #11 replaced deprecated drupal_clean_css_identified() function call with Html::cleanCssIdentifier() in views_view_field preprocess function and updated documentation in views-view-fields.html.twig file.

Please review.

Patch #11 replaced deprecated drupal_clean_css_identified() function call with Html::cleanCssIdentifier() in views_view_field preprocess function and updated documentation in views-view-fields.html.twig file.

Please review.

@Manuel Garcia: I believe my patch (#9 and #11) avoided the need for |raw filters. If you agree, let's close the #2366167: views-view-fields.html.twig prints out escaped html tags and continue polishing in this thread.

Let's see if this fixes the tests :)

Now this template is used, the HTML apparently has more spaces between the >/span< for the label and the >span< for the value. (See screenshot.)

So $this->assertText(t('Updated date') . ': ' . date('Y-m-d', REQUEST_TIME)); would need to change to $this->assertText(t('Updated date') . ': ' PLUS NEWLINE PLUS CERTAIN AMOUNT OF SPACES . date('Y-m-d', REQUEST_TIME));

I think this patch is the way to do it. Disclaimer: I have no opinion on whether this is the right solution, or the rest of this issue.

Thanks @roderik for debugging this! I hope we could tackle this on the template by {% spaceless %}

Lets see if this works out

Looking at the list of remaining theme functions this would be a great one to get rid of if we can.

+++ b/core/modules/views/templates/views-view-fields.html.twig
@@ -25,17 +27,26 @@
+      <{{ field.wrapper_element }} {{ field.wrapper_attributes }}>
...
+          <{{ field.label_element }} {{ field.label_attributes }}>{{ field.label }}{{ field.label_suffix }}</{{ field.label_element }}>
...
+        <{{ field.element_type }} {{ field.element_attributes }}>{{ field.content }}</{{ field.element_type }}>

I think there shouldn't be a space before printing the attributes in all of these cases. https://www.drupal.org/node/1823416#attributes

Curious what you guys think of this for template formatting?

{% for field in fields %}
  {{ field.separator }}
  {{ field.wrapper_element ? '<' ~ field.wrapper_element ~ field.wrapper_attributes ~ '>' }}
  {{ field.label_element ? '<' ~ field.label_element ~ field.label_attributes ~ '>' }}
  {{ field.label }}{{ field.label_suffix }}
  {{ field.label_element ? '</' ~ field.label_element ~ '>' }}
  {{ field.element_type ? '<' ~ field.element_type ~ field.element_attributes ~ '>' }}
  {{ field.content }}
  {{ field.element_type ? '</' ~ field.element_type ~ '>' }}
  {{ field.wrapper_element ? '</' ~ field.wrapper_element ~ '>' }}
{% endfor %}

+++ b/core/modules/views/views.theme.inc
@@ -111,16 +111,7 @@ function template_preprocess_views_view_fields(&$variables) {
-      // Protect ourself somewhat for backward compatibility. This will prevent
-      // old templates from producing invalid HTML when no element type is selected.
-      if (empty($object->element_type)) {
-        $object->element_type = 'span';
+        $object->element_attributes = $attributes;

I think this got lost in translation?

Re #31 It was ignored and not used. Not sure it needs to stick around.

Hopefully you like the syntax I chose on this, that verbose if was getting to me. Also dropped the spaceless because it has some performance issues, but if it hurts the inline elements in anyway we can add it back.

Ignore that:P it looks prettier than functional;)

spaceless doesn't work inside other controls (the if statements). So these whitespace modifiers work at collapsing the space (especially before and after span elements and the separator.

For proof: http://twigfiddle.com/twrci4

This is what I'm seeing. :(

Run 54dec09b09eb9 uploaded successfully for drupal-perf-davidhernandez.
Run 54dec1ab3dfb1 uploaded successfully for drupal-perf-davidhernandez.

=== 8.0.x..8.0.x compared (54dec09b09eb9..54dec1ab3dfb1):

ct  : 412,752|412,752|0|0.0%
wt  : 1,252,353|1,254,472|2,119|0.2%
mu  : 28,417,184|28,417,184|0|0.0%
pmu : 28,736,984|28,736,984|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54dec09b09eb9&...

Run 54dec09b09eb9 uploaded successfully for drupal-perf-davidhernandez.
Run 54dec21b63f84 uploaded successfully for drupal-perf-davidhernandez.

=== 8.0.x..convertviewviewsfield compared (54dec09b09eb9..54dec21b63f84):

ct  : 412,752|471,884|59,132|14.3%
wt  : 1,252,353|1,356,116|103,763|8.3%
mu  : 28,417,184|28,682,128|264,944|0.9%
pmu : 28,736,984|29,139,712|402,728|1.4%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54dec09b09eb9&...

What scenario are you working with there for some context?

Oh sorry. That would help wouldn't it. :P

I made a view displaying 100 nodes, 4 fields each. 2 with labels, two without. I wasn't sure exactly what setup to profile with, so if you have something specific in mind, let me know.

Thanks a bunch for doing the profiling @davidhernandez! From first glance it looks like ~1ms per row is being added. That scenario sounds like a good one. And a big hunk of that time is SafeMarkup related (security), and getAttribute (twig C version would make this faster). I'm assuming you don't have the twig C extension installed?

I'll try to mimic the results and see if I can't shave a few microseconds off each row.

Also to confirm, twig_debug and XDebug off? Thanks @davidhernandez :)

Nooope! It's been a while since I last profiled, and forgot to adjust my settings. Apparently, I enabled "Give Joel a heart attack".

=== 8.0.x..8.0.x compared (54df8d322535a..54df8ec49b0ec):

ct  : 407,275|407,275|0|0.0%
wt  : 1,567,985|1,564,836|-3,149|-0.2%
mu  : 53,512,512|53,512,512|0|0.0%
pmu : 53,602,952|53,602,952|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54df8d322535a&...

=== 8.0.x..convertviewviewsfield compared (54df8d322535a..54df8f50b2e01):

ct  : 407,275|465,341|58,066|14.3%
wt  : 1,567,985|1,574,546|6,561|0.4%
mu  : 53,512,512|46,351,384|-7,161,128|-13.4%
pmu : 53,602,952|46,472,232|-7,130,720|-13.3%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54df8d322535a&...

Does such a large decrease in memory usage make sense?

Oh sweet! I was thinking up preprocess trickery but now I don't need to:) I'll do some of that in another issue;)

I shouldn't RTBC this but @Manuel Garcia or @davidhernandez, you can if you are cool with things. Or maybe @lauriii wants to give it another quick check?

• Profiling completed in #42 answer to the universe.
• Markup Tested in #36

After manual testing and reading the change going to RTBC this. I also added the beta evaluation.

Documentation looks good, performance looks good, and we are not changing markup. I reviewed the patch and manually tested, putting my stamp of approval on this one! Thanks all :)

+1

I tried this along with the patch I had to copy all the Views templates to Classy. Test that were failing before are now passing. I didn't check all the tests, but all the ones I did check are green.

FYI, all those tests were failing because this code was building up HTML tags but not marking it as safe markup in one fasion or another:

+++ b/core/modules/views/views.theme.inc
@@ -102,17 +102,8 @@ function template_preprocess_views_view_fields(&$variables) {
-        $pre = '<' . $object->element_type;
-        $pre .= $attributes;
-        $field_output = $pre . '>' . $field_output . '</' . $object->element_type . '>';

Incase you run into similar failing tests, it's likely concatenated markup in a preprocess or earlier which is not being marked as such. #markup renderable array or #inline_template would have solved that, but it hadn't been done yet.

Thanks everyone!

Oh and this kills both birds with one stone. Safemarkup in the template issues + removes theme function!

UsefulTemplates++

So we benchmarked that before, right? Can you explain why the performance is less bad this time?

@dawehner twig debug was turned on and it was printing debug information and xdebug was turned on.

Yeah I forgot to adjust my environment in the first test, so ignore #37. No code was changed when I made the second one.

Asked dawehner about this in IRC. He was referring to the benchmarks in a related Views patch at #1843748-50: Convert views/templates/views-view-fields.tpl.php to twig, and wants to make sure we don't introduce a similar regression here, by using the same performance scenario. Marking back to needs review for benchmarks.

Well I got two fairly similar profiling results by trying to match the scenario from #1843748-45: Convert views/templates/views-view-fields.tpl.php to twig
Here's my script for generating nodes:

https://gist.github.com/joelpittet/9fc3d6c224b8dfe73213
drush scr test-create-nodes.php

Here's my frontpage views export:
https://gist.github.com/joelpittet/2cc1a4f86f30d679aed8

I was getting high results at first then it seemed to settle down once I stopped using my computer while it was running...

• MBP 2010 mid, Apache 2.2, PHP 5.5 + Zend OpCode Cache
• Twig Debug is turned off
• XDebug is disabled
• Twig C extension is disabled(to play fair)
• Render Cache is disabled(because the fastest result will be the second run in both cases) and xhprof chooses the fastest run.

First Set of Results

=== 8.0.x..8.0.x compared (54e141c217b7e..54e143f66b907):

ct  : 553,963|553,963|0|0.0%
wt  : 1,206,117|1,206,947|830|0.1%
mu  : 29,001,176|29,001,176|0|0.0%
pmu : 29,596,952|29,596,952|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54e141c217b7e&...

=== 8.0.x..2348747-46-views-view-fields compared (54e141c217b7e..54e146d617a96):

ct  : 553,963|525,763|-28,200|-5.1%
wt  : 1,206,117|1,131,671|-74,446|-6.2%
mu  : 29,001,176|27,754,568|-1,246,608|-4.3%
pmu : 29,596,952|27,904,808|-1,692,144|-5.7%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54e141c217b7e&...

Second Set of Results

=== 8.0.x..8.0.x compared (54e1529b7f3e4..54e1550a08dd9):

ct  : 553,963|553,963|0|0.0%
wt  : 1,216,105|1,199,892|-16,213|-1.3%
mu  : 29,001,176|29,001,176|0|0.0%
pmu : 29,596,952|29,596,952|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54e1529b7f3e4&...

=== 8.0.x..2348747-46-views-view-fields compared (54e1529b7f3e4..54e157d33da83):

ct  : 553,963|525,763|-28,200|-5.1%
wt  : 1,216,105|1,131,162|-84,943|-7.0%
mu  : 29,001,176|27,754,568|-1,246,608|-4.3%
pmu : 29,596,952|27,904,808|-1,692,144|-5.7%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54e1529b7f3e4&...

Try to avoid comparing my results with @davidhernandez because we have difference scenarios as I'm trying to get something closer to the scenario from Portland 2013 drupalcon sprints. (Less rows more fields)

They were comparing PHP Template to Twig Template(which I think should have been faster because the Twig Template is compiled and run from a method, but I guess there are more function calls).

I'm not quite sure why my results are doing so well, though if someone wants to double check go ahead I'd be curious to see the results.

Disregard #55 (except for the scenario) the numbers are toooo nice:) My opcode cache revalidate settings were set to production 60 sec refresh, this they set they are set to 0 for development.

=== 8.0.x..8.0.x compared (54e17147d69ca..54e17418dee8e):

ct  : 553,963|553,963|0|0.0%
wt  : 1,220,538|1,214,997|-5,541|-0.5%
mu  : 29,000,976|29,000,976|0|0.0%
pmu : 29,597,520|29,597,520|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54e17147d69ca&...

=== 8.0.x..2348747-46-views-view-fields compared (54e17147d69ca..54e177a08308d):

ct  : 553,963|667,586|113,623|20.5%
wt  : 1,220,538|1,334,366|113,828|9.3%
mu  : 29,000,976|29,023,648|22,672|0.1%
pmu : 29,597,520|29,622,024|24,504|0.1%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54e17147d69ca&...

Cottser was getting similar results ~11% walltime increase.

Out of that 113ms the biggest time sucks are:

Twig_Template::getAttribute

ct 12,000 	10.6% 	
incl wt: 70,257 	61.7% 	
excl wt:70,230 	61.7% 

__TwigTemplate_80fb64e3a166b4b555bfcf9b2057993f1e4339e4b1a0b907cef30b63e6177970::doDisplay

ct 50 	0.0% 	
incl wt: 173,654 	152.6% 	
excl wt:33,596 	29.5% 

twig_drupal_escape_filter@2

ct: 8,600 	7.6% 	
incl wt: 69,569 	61.1% 	
excl wt: 29,730 	26.1%

1. The first one is hard to shake but does get way faster with the Twig C extension.
2. The second one is hard to shake too, because that is the main twig function after compiled to PHP (theme function equivalent method)
3. The third is the cost of properly escaping variables, as of right now those tags aren't escaped really and the whole theme function output is just Marked Safe in the renderer::render().

We could shave some time off in the preprocessor, I think Cottser has a few ideas in mind so I'll let him at it first.

Just to see what happens with Twig C Extension turned on:

=== 8.0.x..8.0.x compared (54e199664caef..54e1a1589bdae):

ct  : 552,857|552,857|0|0.0%
wt  : 1,227,936|1,226,162|-1,774|-0.1%
mu  : 28,986,648|28,986,648|0|0.0%
pmu : 29,584,392|29,584,392|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54e199664caef&...

=== 8.0.x..2348747-46-views-view-fields compared (54e199664caef..54e1a23013a4f):

ct  : 552,857|603,627|50,770|9.2%
wt  : 1,227,936|1,294,539|66,603|5.4%
mu  : 28,986,648|29,408,504|421,856|1.5%
pmu : 29,584,392|30,008,816|424,424|1.4%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54e199664caef&...

Note: views already escapes values, see FieldPluginBase::render().

@dawehner Thanks for the note, something to ponder, does views need to escape the values if Twig is doing that automatically?

I may still poke at this in preprocess, but would love to know the answer to #61, it seems like that would potentially allow for much more savings if we're avoiding doing work twice.

Thanks @Manuel Garcia, that sounds good. I put up a couple patches on #2426563: Ignore: Patch testing issue to see what testbot thinks.

Name your interdiff files .txt or something other than .patch and that will keep them from getting sent to testbot.

I'm going to try to test this today.

I ran some tests again. I tried to keep a similar scenario to previous, and created a View displaying 100 nodes with 5 fields.

This is using #46.

=== 8.0.x..8.0.x compared (54f283c5bb5f3..54f28857de4f6):

ct  : 396,159|396,159|0|0.0%
wt  : 1,817,000|1,813,866|-3,134|-0.2%
mu  : 27,024,408|27,024,408|0|0.0%
pmu : 27,292,656|27,292,656|0|0.0%

=== 8.0.x..2348747-46 compared (54f283c5bb5f3..54f2895fb8d0d):

ct  : 396,159|453,516|57,357|14.5%
wt  : 1,817,000|1,970,664|153,664|8.5%
mu  : 27,024,408|27,079,584|55,176|0.2%
pmu : 27,292,656|27,349,080|56,424|0.2%

This is using #65 with the Views sanitization removed.

=== 8.0.x..8.0.x compared (54f283c5bb5f3..54f28ca8966ab):

ct  : 396,159|396,159|0|0.0%
wt  : 1,817,000|1,812,304|-4,696|-0.3%
mu  : 27,024,408|26,797,584|-226,824|-0.8%
pmu : 27,292,656|27,070,376|-222,280|-0.8%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54f283c5bb5f3&...

=== 8.0.x..2348747-65 compared (54f283c5bb5f3..54f28d53cc42b):

ct  : 396,159|453,516|57,357|14.5%
wt  : 1,817,000|1,806,204|-10,796|-0.6%
mu  : 27,024,408|26,853,656|-170,752|-0.6%
pmu : 27,292,656|27,127,408|-165,248|-0.6%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54f283c5bb5f3&...

Let the skepticism begin. I'll see at some point if I can replicate Joel's scenario and test that instead, or maybe he'll beat me to it. ;)

I realized I didn't have render cache disabled. Maybe that was the issue I was having previously as well. Dunno.

46

=== 8.0.x..8.0.x compared (54f295e72ec52..54f2965f30be5):

ct  : 403,782|403,782|0|0.0%
wt  : 1,122,317|1,122,955|638|0.1%
mu  : 27,656,016|27,656,016|0|0.0%
pmu : 27,896,688|27,896,688|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54f295e72ec52&...

=== 8.0.x..2348747-46 compared (54f295e72ec52..54f29712d4f96):

ct  : 403,782|461,139|57,357|14.2%
wt  : 1,122,317|1,217,217|94,900|8.5%
mu  : 27,656,016|27,715,168|59,152|0.2%
pmu : 27,896,688|27,955,144|58,456|0.2%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54f295e72ec52&...

65

=== 8.0.x..8.0.x compared (54f29a0893b1f..54f29a910bf1c):

ct  : 403,782|403,782|0|0.0%
wt  : 1,121,912|1,122,152|240|0.0%
mu  : 27,656,016|27,656,016|0|0.0%
pmu : 27,896,688|27,896,688|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54f29a0893b1f&...

=== 8.0.x..2348747-65 compared (54f29a0893b1f..54f29b385ace9):

ct  : 403,782|461,139|57,357|14.2%
wt  : 1,121,912|1,218,523|96,611|8.6%
mu  : 27,656,016|27,759,888|103,872|0.4%
pmu : 27,896,688|28,003,672|106,984|0.4%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=54f29a0893b1f&...

Thanks @davidhernandez!

Somehow we're not losing any function calls :/

=== 8.0.x..2348747-46 compared (54f295e72ec52..54f29712d4f96):
ct  : 403,782|461,139|57,357|14.2%

=== 8.0.x..2348747-65 compared (54f29a0893b1f..54f29b385ace9):
ct  : 403,782|461,139|57,357|14.2%

Yeah, I noticed that too. I have no answer why. I checked the code in both branches and the sanitizeValue is there in 46 and removed in 65. It doesn't make sense, unless the change was irrelevant.

Relevant related issue from around the time of DrupalCon Portland.

I think the double escaping is still an issue, was doing some triaging of old issues and found #2363423: views-view-fields.html.twig gets escaped, should we fix the double escaping there in case this gets stuck?

Not saying we should postpone this but maybe some of the changes could be split out to make this smaller :)

We're not saying it's impossible, but so far nobody has been able to make it fast enough to be committable. 1% or less would be good but 8% or more is just not acceptable.

Sorry @Manuel Garcia if you feel you've wasted time here but the reality is not everything will make it in. Thank you for all your contributions and please continue!

+++ b/core/modules/views/views.theme.inc
@@ -101,18 +101,7 @@ function template_preprocess_views_view_fields(&$variables) {
-        $pre = '<' . $object->element_type;
-        $pre .= $attributes;
-        $field_output = $pre . '>' . $field_output . '</' . $object->element_type . '>';

@@ -130,16 +119,14 @@ function template_preprocess_views_view_fields(&$variables) {
-        $object->inline_html = $object->inline ? 'span' : 'div';

@@ -179,13 +164,7 @@ function template_preprocess_views_view_fields(&$variables) {
-          $pre = '<' . $object->elementLabelType;
-          $pre .= $attributes;
-          $pre .= '>';

Regardless of whether we remove the twig template theme function or not the markup build up and classes should be moved to the theme function.

So I think we can salvage a lot of this work in the preprocess to slim that down. Also template in core is broken without those changes so I'm tempted to mark this as a major bug instead of a task and get that bit done at least.

What do you think @Cottser?

I'm not sure right now about the major bug part, but definitely +1 to moving that ugly stuff to the theme function :)

Separate issue?

Postponing so we can focus on #2363423: views-view-fields.html.twig gets escaped. The performance improvements around SafeMarkup might improve performance here, will need another profiling after those get in, #2295823: Ensure that we don't store excessive lists of safe strings.

After a recent conference call on the SafeMarkup issues, we might be able to get this in. It seems there have been a number of caching related improvements in the last couple of months that might pave the way. Since the likelihood of non-cached content been delivered from Views has been reduced, the performance regression we're seeing may be more tolerable.

It was discussed during the conference call, because using the template would help with the SafeMarkup issues as well DX/TX.

We would still need to get #2363423: views-view-fields.html.twig gets escaped done first, but if that happens, we can move towards getting this one in.

The escaping issue was just committed, so we can move on this one. I'm sure the patch will need some redoing/rerolling, and we should agree on some profiling scenarios.

Reroll of #76.

1. +++ b/core/modules/views/views.theme.inc
   @@ -162,6 +163,7 @@ function template_preprocess_views_view_fields(&$variables) {
   +      // Set up field label.
              $element_label_class = $object->handler->elementLabelClasses($row->index);
   

   wrong indent

2. +++ b/core/modules/views/views.theme.inc
   @@ -177,61 +179,6 @@ function template_preprocess_views_view_fields(&$variables) {
   -function theme_views_view_fields($variables) {
   

   Still one usage in comments:

   $ git grep theme_views_view_fields
   core/modules/views/templates/views-view-fields.html.twig:33:See http://api.drupal.org/api/function/theme_views_view_fields/8 for details.

Fixed #91.1 and #91.2

looks good to go, would be great to profile that again

Config: drush si standard -y --account-pass=admin followed by drush generate-users 5 && drush generate-terms tags 10 && drush generate-content 50

Scenario one: default Frontpage view:

=== baseline-8.0.x..8.0.x compared (55f1bcc8df074..55f1bdb20788b):

ct  : 30,028|30,028|0|0.0%
wt  : 144,384|143,375|-1,009|-0.7%
mu  : 13,909,000|13,909,000|0|0.0%
pmu : 14,020,432|14,020,432|0|0.0%

=== baseline-8.0.x..2348747-92 compared (55f1bcc8df074..55f1bdce1d77e):

ct  : 30,028|30,028|0|0.0%
wt  : 144,384|143,042|-1,342|-0.9%
mu  : 13,909,000|13,908,976|-24|-0.0%
pmu : 14,020,432|14,019,776|-656|-0.0%

=== SUM: 2348747-92-summary..8_0_x-summary compared (55f1bdd46f942..55f1bdd77789a):

ct  : 3,005,505|3,005,505|0|0.0%
wt  : 15,877,681|16,332,912|455,231|2.9%
mu  : 1,392,231,856|1,392,015,312|-216,544|-0.0%
pmu : 1,403,330,600|1,403,173,152|-157,448|-0.0%

Scenario two: more complicated Frontpage view based on Joel's export:

=== baseline-8.0.x..8.0.x compared (55f1c29967343..55f1c2cd864ec):

ct  : 21,329|21,329|0|0.0%
wt  : 101,321|100,335|-986|-1.0%
mu  : 11,203,216|11,203,216|0|0.0%
pmu : 11,316,704|11,316,704|0|0.0%

=== baseline-8.0.x..2348747-92 compared (55f1c29967343..55f1c2f1548f3):

ct  : 21,329|21,329|0|0.0%
wt  : 101,321|101,248|-73|-0.1%
mu  : 11,203,216|11,203,440|224|0.0%
pmu : 11,316,704|11,317,072|368|0.0%

=== SUM: 2348747-92-summary..8_0_x-summary compared (55f1c2f46d4e4..55f1c2f73ec43):

ct  : 2,134,666|2,134,666|0|0.0%
wt  : 11,116,991|11,307,438|190,447|1.7%
mu  : 1,121,561,800|1,121,891,912|330,112|0.0%
pmu : 1,132,946,696|1,133,269,704|323,008|0.0%

so there's regression 1.7 and 2.9 % - is there a way to optimize that?

I think we'd be totally ok with a 2.9% regression, but those numbers are suspiciously low and the function calls are all exactly the same before and after. @mikeker did you have the render cache and everything disabled?

What is summary comparing? The commit ids are different from the others. It has been a while since I profiled, but I don't remember there being a third comparison.

On the plus side, this is a big, big improvement from the previous 11% wall time increase.

@davidhernandez, this is Ubuntu 14.04 running in a VM, XDebug disabled, using the stock settings.local.php and services.yml files (rendering caching off, Twig debugging off). Anything else I should be checking?

I'm not familiar with this issue so I can't answer the function call count question.

The summary is from Fabian's XHProf-Kit tools output. Honestly, I'm not really sure what it's comparing... Sorry, still learning profiling.

@mdrummond temper your excitement, need to see if we have render caching on or off. Otherwise we are just testing whether one cached result is any better/worse than another.

Also make sure xdebug is turned off because it buggers results, and to play fair turn off the twig php C extension off.

The tip off is usually the will be a function call change is 0 in the above results(usually twig calling escaping related calls on each printed value). @see the ct value is 0 on each branch.

@mikeker it sounds like you got all the things right on the first go. It could be ct 0. I'll do one and try to compare.

Maybe the actual drupal cache is still on? It's on by default.

I'm not sure how to turn off/on the Twig C extension... But I would like to know so I can speed up my non-profiled D8 sites! :P

I have the following in my settings.php

if (file_exists(__DIR__ . '/settings.local.php')) {
  include __DIR__ . '/settings.local.php';
}

And the following in my settings.local.php (should be a copy/paste of what's in example.settings.local.php):

$settings['container_yamls'][] = DRUPAL_ROOT . '/sites/development.services.yml';
$config['system.performance']['css']['preprocess'] = FALSE;
$config['system.performance']['js']['preprocess'] = FALSE;
$settings['cache']['bins']['render'] = 'cache.backend.null';

From the CLI:

php -m | grep -i xdebug returns NULL.

php -i | grep -i xhprof returns:

xhprof
xhprof => 0.9.2
XHPROF_KIT_DOCROOT => vagrant-clean.core.d8
_SERVER["XHPROF_KIT_DOCROOT"] => vagrant-clean.core.d8

php -i | grep -i enable_cli returns:

apc.enable_cli => Off => Off
opcache.enable_cli => Off => Off

Man, there's a lot places we can cache things! Anywhere else I should be checking?

Turning on twig c extension on OSX is simply brew install php55-twig

Profiling is slow to begin with you don't need to turn off CSS/JS aggregation;) And I'd put opcache on, but that is just me:)

The internet is basically a bunch of caches. router cache, browser cache, render cache, static cache, apache cache, mysql cache... you get the point:)

The only thing I can think of is turn off the internal page cache module (but nulling the bin should stop page caching,) or maybe the branch you made doesn't actually have the patch committed? Hrmm. :/

Option three is Joel will figure it out. Option four is everything is awesome, RTBC! but the function count definitely doesn't make sense.

@mikeker one problem with "default Frontpage view" is that it doesn't use fields, it's rendered content.

To find out I just turn on twig debug temporarily to confirm the template is being used (search source code for views-view-fields)

Using @mikeker's setup in #95 but only doing 2 because of what I said in #106

With Twig C extension

=== 8.0.x..8.0.x compared (55f235cac18ad..55f2363dd42e9):

ct  : 24,440|24,440|0|0.0%
wt  : 238,201|237,626|-575|-0.2%
mu  : 28,708,136|28,708,136|0|0.0%
pmu : 28,754,712|28,754,712|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=55f235cac18ad&...

=== 8.0.x..views-view-fields-2348747-92 compared (55f235cac18ad..55f2365d0c6b8):

ct  : 24,440|24,440|0|0.0%
wt  : 238,201|236,731|-1,470|-0.6%
mu  : 28,708,136|28,708,480|344|0.0%
pmu : 28,754,712|28,754,160|-552|-0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=55f235cac18ad&...

~1ms faster even but confirmed the functions calls didn't change.

Without Twig C Extension

=== 8.0.x..8.0.x compared (55f237e5dec64..55f23808ec628):

ct  : 24,496|24,496|0|0.0%
wt  : 84,218|85,104|886|1.1%
mu  : 11,124,936|11,124,968|32|0.0%
pmu : 11,181,672|11,181,712|40|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=55f237e5dec64&...

=== 8.0.x..views-view-fields-2348747-92 compared (55f237e5dec64..55f238230dd98):

ct  : 24,496|24,496|0|0.0%
wt  : 84,218|86,394|2,176|2.6%
mu  : 11,124,936|11,125,040|104|0.0%
pmu : 11,181,672|11,181,032|-640|-0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=55f237e5dec64&...

Still no function call change still only 1.5% regression or 1.3ms

I don't trust my results, I need a way to test that render cache is truely disabled. Also without twig extension I'm getting faster results:S

Is there something else going on that we don't understand? Something maybe that changed in core recently with all the caching/performance changes. Do we need Wim or effulgentsia to make sense of this? I remember on the SafeMarkup hangout Alex saying he'd expect this to be much faster, but I don't remember why.

I think I found out what is wrong. I put a breakpoint on RenderCache::get() and watched the bin's go by. Most are 'render', but one caught my eye. 'dynamic_page_cache'.

This is very new! also previously named 'smart cache' if people were following. #2429617: Make D8 2x as fast: Dynamic Page Cache: context-dependent page caching (for *all* users!).
Was wondering why we were getting 80-110ms render times, that would be cool if it's true:)

Getting 625ms render times. Redoing the tests above in #107

Edit: Solution is to add this to your settings.local.php $settings['cache']['bins']['dynamic_page_cache'] = 'cache.backend.null';

@davidhernandez they were saying it was faster because views rows or fields were cached individually. But killing render cache should negate that but still worth a test.

Dynamic Page Cache off (FYI it's in the latest example.settings.local.php under the other null cache bin). No need for Wim or effulgentsia.

The thing to note as I mentioned before now the Function calls (ct) are different, which means it's testing different things!

With Twig C extension

=== 8.0.x..8.0.x compared (55f2450b58930..55f2457c13d41):

ct  : 209,138|209,138|0|0.0%
wt  : 574,058|576,180|2,122|0.4%
mu  : 26,593,912|26,593,912|0|0.0%
pmu : 26,654,144|26,654,144|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=55f2450b58930&...

=== 8.0.x..views-view-fields-2348747-92 compared (55f2450b58930..55f2459f810af):

ct  : 209,138|220,537|11,399|5.5%
wt  : 574,058|583,640|9,582|1.7%
mu  : 26,593,912|26,696,048|102,136|0.4%
pmu : 26,654,144|26,755,136|100,992|0.4%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=55f2450b58930&...

1.3-1.7% or ~7.5-9ms wall time difference.

Without Twig C extension

^@=== 8.0.x..8.0.x compared (55f2501d384a2..55f250764a275):

ct  : 209,620|209,620|0|0.0%
wt  : 565,054|573,669|8,615|1.5%
mu  : 26,604,360|26,604,360|0|0.0%
pmu : 26,663,664|26,663,664|0|0.0%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=55f2501d384a2&...

=== 8.0.x..views-view-fields-2348747-92 compared (55f2501d384a2..55f250cd3eb64):

ct  : 209,620|233,622|24,002|11.5%
wt  : 565,054|598,790|33,736|6.0%
mu  : 26,604,360|26,626,640|22,280|0.1%
pmu : 26,663,664|26,686,352|22,688|0.1%

http://www.lionsad.de/xhprof-kit/xhprof/xhprof_html/?run1=55f2501d384a2&...

4.5-6% or ~25-33ms wall time difference.

Edit: FYI I was having variances of up to 3.5% depending on the run (did about 4-6 runs)

Wow! Nice sleuthing, @joelpittet! I'll give that a try in the morning...

I think this is ready to be reviewed by a commiter. I looked at the profiling and they looked somehow sane. There is slight regression in the performance but Views is doing quite well on caching. Also this has huge improvement to the TX which makes me think its a good trade off.

I try to play the devil's advocate ... we optimize DX for core for performance on most sites?
You can already override it without any problems, so we could also just expand the documentation on theme_views_view_fields() to say: never ever override it,
use that template instead.

+1 to RTBC, I think it is worth the performance tradeoff to have 100% consistency on Twig. Also I can confirm that getAttribute() with twig extension is way faster and hence for sites that can't do any of our numerous caching ways (edge case / seldom), I think it is fine to:

- either install the twig extension
- or re-instantiate theme_views_view_fields in some form (if really really really needed)

Thanks,

Fabian

Option 3 it is! joel++

Yeah, a 5% regression seems tame compared to where we started, and many hoops had to be jumped through, including disabling the smart cache, just to see it.

I reran my second scenario (as @joelpittet points out the first one doesn't really test the patch) and got somewhat similar results to #112 without the C extension though my wall time increase was greater.

=== baseline-8.0.x..8.0.x compared (55f311e084346..55f312aa64d5c):

ct  : 139,888|139,896|8|0.0%
wt  : 561,234|559,006|-2,228|-0.4%
mu  : 25,875,888|25,874,192|-1,696|-0.0%
pmu : 26,002,472|26,000,968|-1,504|-0.0%

=== baseline-8.0.x..2348747-92 compared (55f311e084346..55f313aa37c5d):

ct  : 139,888|154,318|14,430|10.3%
wt  : 561,234|603,301|42,067|7.5%
mu  : 25,875,888|25,896,336|20,448|0.1%
pmu : 26,002,472|25,979,072|-23,400|-0.1%

To sum up: @joelpittet saw an 11.5% increase in function calls resulting in a 4.5 - 6% increase in wall time. I'm seeing a 10.3% increase in function calls resulting in a 7.5 - 7.9% increase in wall time. This ran with n == 250 (rather than the default 100) in hopes of smoothing out any random spikes and decreasing the variation.

To recap the scenario I used so folks don't have to go searching through comments if they want to double-check these results:

Standard settings.php and services.yml
Uncomment the settings.local.php part in settings.php
Uncomment these lines in settings.local.php:
  # $settings['cache']['bins']['render'] = 'cache.backend.null';
  # $settings['cache']['bins']['dynamic_page_cache'] = 'cache.backend.null';
drush si standard -y --account-pass=admin
drush en -y devel_generate
drush generate-users 5 && drush generate-terms tags 10 && drush generate-content 50
drush pmu -y devel_generate
Disable the default frontpage view
Import https://gist.github.com/mikeker/f7e0128dcd327fde3aea

Thanks for posting your results @mikeker!

Random fail

We've committed to getting rid of theme functions, so will need to take the regression in raw rendering here.

Not committing yet just because I only skimmed the patch, although looked fine in principle.

I messed up the attribution a bit, but committed/pushed to 8.0.x, thanks!

Thanks, Catch!

I feel like this unblocks something but I can't remember what.

It might be the last non-admin theme function?