Twig: Performance Testing / Enable twig cache by using the Drupal PHP Loading/Writing

+class TwigEnvironment extends \Twig_Environment {

this is so weird ^(
its like
green grin greeen grean

I didn't test it out, but the cache code looks good to me. It is so small, that I recommend incorporating it into #1696786: Integrate Twig into core: Implementation issue. Benchmarks with cache enabled would be nice.

Well, I think Fabian's hoping for a bit of dedicated discussion around this portion before incorporating it into the "mega" patch.

Btw, for those wanting to review the relevant changes, cmd+F for "2/2".

#4 patch 2/2 looks good
and I agree with #5

RTBC?

Er, no. :) #3 is a good point, and there is at least one glaring "@todo document me" thing remaining. ;)

latest HEAD w/o patch
drupal minimal profile install
apachebench second pass

root@pubuntu:/var/www/podarok/drupal# ab -c5 -n1000 http://127.0.0.1/podarok/drupal/index.php/node/1
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests


Server Software:        Apache/2.2.22
Server Hostname:        127.0.0.1
Server Port:            80

Document Path:          /podarok/drupal/index.php/node/1
Document Length:        4991 bytes

Concurrency Level:      5
Time taken for tests:   80.829 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      5595000 bytes
HTML transferred:       4991000 bytes
Requests per second:    12.37 [#/sec] (mean)
Time per request:       404.143 [ms] (mean)
Time per request:       80.829 [ms] (mean, across all concurrent requests)
Transfer rate:          67.60 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.4      0       7
Processing:   126  404  82.5    405     699
Waiting:      117  377  77.0    380     676
Total:        126  404  82.5    405     699

Percentage of the requests served within a certain time (ms)
  50%    405
  66%    438
  75%    460
  80%    470
  90%    506
  95%    541
  98%    576
  99%    630
 100%    699 (longest request)

the same with #4 patch

 ab -c5 -n1000 http://127.0.0.1/podarok/drupal/index.php/node/1
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests


Server Software:        Apache/2.2.22
Server Hostname:        127.0.0.1
Server Port:            80

Document Path:          /podarok/drupal/index.php/node/1
Document Length:        4991 bytes

Concurrency Level:      5
Time taken for tests:   53.281 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      5595000 bytes
HTML transferred:       4991000 bytes
Requests per second:    18.77 [#/sec] (mean)
Time per request:       266.407 [ms] (mean)
Time per request:       53.281 [ms] (mean, across all concurrent requests)
Transfer rate:          102.55 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.3      0       8
Processing:   129  266  46.0    286     423
Waiting:      119  249  43.4    268     396
Total:        129  266  46.0    286     427

Percentage of the requests served within a certain time (ms)
  50%    286
  66%    301
  75%    306
  80%    308
  90%    318
  95%    327
  98%    337
  99%    347
 100%    427 (longest request)

#12 shows speed-up +~51%
did I miss something?

#15
yup
logs displayed here second or third passes for better stability results
server with LoadAverage ~0 :)

cache cleared before testing

+++ b/core/lib/Drupal/Core/Template/TwigEnvironment.php
@@ -0,0 +1,56 @@
+        $storage = drupal_php_storage('twig');

Is this not injectable yet?

+++ b/core/lib/Drupal/Core/Template/TwigEnvironment.php
@@ -0,0 +1,56 @@
+        $obj = cache()->get($cid);

This probably isn't injectable until #1764474: Make Cache interface and backends use the DIC lands, but that's really close. When that happens, this should be injected. That would then enable unit testing of this class, I think.

I agree, though, that this is small enough to just bake into the Twig patch itself. Especially given the impressive numbers above (yowza!)

Are you sure about those benchmarks ? Trying to run the patch gives me fatal error here , unless I'm doing something completely stupid.

Considering that Drupal spends less than 50% of its time in the theme layer, I'm pretty sure the benchmark is wrong.

ab -c5 -n1000 http://127.0.0.1/podarok/drupal/index.php/node/1
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests


Server Software:        Apache/2.2.22
Server Hostname:        127.0.0.1
Server Port:            80

Document Path:          /podarok/drupal/index.php/node/1
Document Length:        10297 bytes

Concurrency Level:      5
Time taken for tests:   118.582 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      10901000 bytes
HTML transferred:       10297000 bytes
Requests per second:    8.43 [#/sec] (mean)
Time per request:       592.908 [ms] (mean)
Time per request:       118.582 [ms] (mean, across all concurrent requests)
Transfer rate:          89.77 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.1      0       2
Processing:   228  592  99.3    595     914
Waiting:      210  551  93.6    553     840
Total:        228  592  99.3    595     914

Percentage of the requests served within a certain time (ms)
  50%    595
  66%    632
  75%    654
  80%    667
  90%    707
  95%    748
  98%    794
  99%    837
 100%    914 (longest request)

with patch #26
template caching works

./sites/default/files/php/twig
./sites/default/files/php/twig/1#52#fd#c5e80be8e75f270e9d036fe7995b.php
./sites/default/files/php/twig/1#52#fd#c5e80be8e75f270e9d036fe7995b.php/82b09f53afd2c13ae4b17656e5b8ac1ca6dd1fde631e5aaf4eeb67076396e747.php

ab -c5 -n1000 http://127.0.0.1/podarok/drupal/index.php/node/1
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 100 requests
Completed 200 requests
Completed 300 requests
Completed 400 requests
Completed 500 requests
Completed 600 requests
Completed 700 requests
Completed 800 requests
Completed 900 requests
Completed 1000 requests
Finished 1000 requests


Server Software:        Apache/2.2.22
Server Hostname:        127.0.0.1
Server Port:            80

Document Path:          /podarok/drupal/index.php/node/1
Document Length:        10476 bytes

Concurrency Level:      5
Time taken for tests:   128.091 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      11080000 bytes
HTML transferred:       10476000 bytes
Requests per second:    7.81 [#/sec] (mean)
Time per request:       640.455 [ms] (mean)
Time per request:       128.091 [ms] (mean, across all concurrent requests)
Transfer rate:          84.47 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.2      0       3
Processing:   243  639 104.7    638     940
Waiting:      223  595  99.4    592     898
Total:        243  639 104.7    638     940

Percentage of the requests served within a certain time (ms)
  50%    638
  66%    675
  75%    699
  80%    719
  90%    768
  95%    810
  98%    870
  99%    890
 100%    940 (longest request)

Frontpage, memory and ab -c1 -n100 - done on bartik

- Before: age execution time was 111.33 ms. Memory used at: devel_boot()=1.19 MB, devel_shutdown()=5.07 MB, PHP peak=5.25 MB.
Requests per second: 10.07 [#/sec] (mean)
- After: Page execution time was 115.26 ms. Memory used at: devel_boot()=1.19 MB, devel_shutdown()=5.35 MB, PHP peak=5.5 MB.
Requests per second: 9.65 [#/sec] (mean)

Node 1, memory and ab -n5 c1000

- Before: Page execution time was 65.1 ms. Memory used at: devel_boot()=1.19 MB, devel_shutdown()=4.75 MB, PHP peak=5 MB.
Requests per second: 15.97 [#/sec] (mean)
- After: Page execution time was 65.89 ms. Memory used at: devel_boot()=1.19 MB, devel_shutdown()=5.02 MB, PHP peak=5.25 MB.
Requests per second: 15.38 [#/sec] (mean)

So with the compilation cache, the difference is *much* less then without, but it's still a tiny little bit slower, and eating a little more memory. I haven't done xhprof, but my guess this is because of the autoloading and two theme engines being enabled.

So I'd really prefer to enable cache by default for the first commit. I'd post this patch on #1696786: Integrate Twig into core: Implementation issue and mark this one duplicate.

Yes, I would think so. However I thought the cache() wrapper would remain? Could you clarify how you think this class should be using the DIC?

cache() is for legacy support in procedural code. Instead, the cache object for the appropriate bin should be passed into the object's constructor, and saved to an object propertly. Then instead of $obj = cache()->get($cid);, you call $this->cache->get($id);

That makes it possible to pass in a completely fake cache object, such a memory-backed cache object or a cache object that is hard coded to return values relevant for testing, without modifying the global environment.

+++ b/core/includes/theme.incundefined
@@ -468,6 +474,28 @@ function _theme_process_registry(&$cache, $name, $type, $theme, $path) {
+          $render_engines = array(
+            '.twig' => 'twig',
+            '.tpl.php' => 'phptemplate'

can we convert this into config?

+++ b/core/lib/Drupal/Core/Template/TwigFactory.phpundefined
@@ -0,0 +1,86 @@
+    $twig = new \Twig_Environment($loader, array(

possibly we have to move into ...files/ folder

+++ b/core/lib/Drupal/Core/Template/TwigFactory.phpundefined
@@ -0,0 +1,86 @@
+    $functions = array(
+      'hide' => 'twig_hide',
+      'render' => 'twig_render',
+      'show' => 'twig_show',
+      'unset' => 'unset'
+    );
+    $filters = array(
+      't' => 't'

possibly we have to move this to config()

+++ b/core/lib/Drupal/Core/Template/TwigTemplate.phpundefined
@@ -0,0 +1,58 @@
+   * @todo Document me!
+   */ ¶

trailing whitespace :*