Make system_list() return full module records

subscribing

I've been looking at this patch a bunch today (actually the first patch - I was trying to figure out how $list could every be empty also but I got nuthin) and everything looks good ... I'd give it a RTBC, but we should probably get another look or two

Are you going to do #3 (from the original post) in a followup?

I like this overall.

1. I think this patch changes the behavior of system_get_info('theme') from returning only enabled themes to returning all themes? Not sure what to do about that.
2. I am not a fan of adding the static cache here. As far as I can tell, the system_list() static cache is a bit of a mess and needs to be cleared lots of places, and this one would too...

   Any reason we can't just do the unserialize() inside system_list(), right when the data is loaded?

3. +        $list = (!empty($list) ? array_combine($list, $list) : array());
   

   Minor - don't think we should bother with the outer parentheses there.

4. + * @param $name
   + *   (optional) The name of a $type to return. If omitted, all records are
   + *   returned.
   

   I had to read this a couple times (and then confirm by looking at the code) before I got it :) How about something like "The name of a module or theme whose information will be returned. If omitted, all records for the provided $type will be returned."

1. -        if ($record->type == 'module' && $record->status) {
   -          // Build a list of all enabled modules.
   -          $lists['module_enabled'][$record->name] = $record->name;
   +        // Build a list of modules.
   +        if ($record->type == 'module') {
   +          $lists['module'][$record->name] = $record;
   

   This makes a lot of sense in terms of consistency, but the side effect is that we are now storing (in the cache) all data for all modules in the filesystem, including e.g. the 40-50 hidden modules used by Simpletest. Because it's cached, that's not too bad, but it's still nonzero work to cache_get() a very large record on each page request, plus store the resultant giant array in the static cache where it takes up memory. Is it definitely worth it?

2. The problem is that normal requests do not need to unserialize that data at all. Thus, the unserialize() would be needless for most requests. However, I'd also be happy to simply remove the static cache. Unserializing this data more than once might be needless, but then again, it's not the end of the world, performance-wise.

   If the unserialize() moved to system_list(), it would not happen on every request, only very rare ones - since system_list() uses a database cache. Whereas right now, for themes it is kind of silly that system_list() caches the info in a "still-serialized" state, but then http://api.drupal.org/api/function/list_themes/7 unserializes that on every request. Your patch adds more of the same to system_get_info(), so indeed not a performance disaster, just perpetuating some odd behavior in a new place, that would be lovely to fix instead :)

3. -function system_get_info($type) {
   +function system_get_info($type, $only_enabled = TRUE, $name = NULL) {
   

   Maybe the order of the last two parameters should be switched? (I would think getting info about a particular module would be a lot more common than wanting to set $only_enabled to FALSE.)

4.   * This function returns the information from the {system} table corresponding
     * to the cached contents of the .info file for each active module or theme.
   

   With this patch, the "active" in that docblock is no longer quite correct.

Subscribe.

Because it's cached, that's not too bad, but it's still nonzero work to cache_get() a very large record on each page request, plus store the resultant giant array in the static cache where it takes up memory.

See #812016-8: Themes cannot always participate in drupal_alter(). A very large cache_get() that includes an unserialize() can be on the order of ms: something to avoid, if happening on every page request and unnecessary.

Last time someone tried to make system_list() more generic, I won't name names but they're the author of this issue, page caching took a more than 50% performance hit. I can't find that issue but this is more or less exactly the same thing.

Here it is:

http://drupal.org/node/623992#comment-2248022

Also there is no way on earth that this is critical.

The $name parameter confused me. The name module_list() really suggests that we return more than one record.

Do we really need it? It feels like it is cramped into the API, unless I misunderstood what $name does.

Why wouldn't you return everything, and then use the big array to get the details for one record?

Sorry, cross-post. Didn't meant to put the status back to 'critical'.

Wouldn't it be easier to just add a simple cache_set/cache_get of the css/js declarations found in the module .info files right where this information is processed? The cache can be cleared in hook_module_enable. Then there's now penalty for cached page requests.

It might be useful but it shouldn't bog down poor, defenceless Drupal 7 which is already slow as molasses. This doesn't merit review until there are accompanying benchmarks. I'm tempted to mark it won't fix due to http://drupal.org/node/623992#comment-2248022 which just appears to have been completely forgotten.

I think I was guilty of using imprecise language in some of my reviews above. To clarify, this patch shouldn't have any effect whatsoever on cached (i.e., anonymous) page requests.

It may have an effect on uncached (i.e., authenticated) pages due to the size of the system_list() cache, as discussed by @effulgentsia and I above. To deal with that, we can limit this to enabled modules only (I think the use case for querying info about disabled modules is relatively small). Frankly, if we do that and then couple this with removing the silly unserialize() call from inside list_themes() we may wind up with a performance improvement: We'd effectively go from "double-unserializing" (once in the cache_get, once outside) all enabled+disabled theme data on every authenticated page view, which is just silly, to "single-unseralizing" both the (enabled) module and (enabled+disabled) theme data. Themes tend to have much bigger info files than modules anyway so who knows how it would all add up. It could be benchmarked.

Maybe something like the attached reroll?

Regarding $name, we don't strictly speaking need it (since as Dries points out you can just get the whole array and pick out what you need from that), but on the other hand it should lead to simpler, clearer calling code in cases where you're doing that. I don't have a strong opinion, but left it in the patch for now.

[updated: these benchmarks may not be accurate - see later comment]

ab shows the patch in #22 reduces performance by 90%.

Without patch: typical 30 req/sec
With patch: typical 3 req/sec

I re-ran these tests a number of times and saw similar results each time.

Without patch

ab -n100 -c25 -t3 http://d7.local/
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 d7.local (be patient)
Finished 89 requests


Server Software:        Apache/2.2.12
Server Hostname:        d7.local
Server Port:            80

Document Path:          /
Document Length:        1310 bytes

Concurrency Level:      25
Time taken for tests:   3.003 seconds
Complete requests:      89
Failed requests:        0
Write errors:           0
Total transferred:      151389 bytes
HTML transferred:       116590 bytes
Requests per second:    29.63 [#/sec] (mean)
Time per request:       843.635 [ms] (mean)
Time per request:       33.745 [ms] (mean, across all concurrent requests)
Transfer rate:          49.23 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    1   0.5      0       2
Processing:   392  716 144.4    722    1026
Waiting:      392  716 144.4    722    1025
Total:        393  717 144.3    723    1026
WARNING: The median and mean for the initial connection time are not within a normal deviation
        These results are probably not that reliable.

Percentage of the requests served within a certain time (ms)
  50%    722
  66%    756
  75%    806
  80%    822
  90%    890
  95%    978
  98%   1024
  99%   1026
 100%   1026 (longest request)

With patch

 ab -n100 -c25 -t3 http://d7.local/
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 d7.local (be patient)
Finished 12 requests


Server Software:        Apache/2.2.12
Server Hostname:        d7.local
Server Port:            80

Document Path:          /
Document Length:        4089 bytes

Concurrency Level:      25
Time taken for tests:   3.132 seconds
Complete requests:      12
Failed requests:        0
Write errors:           0
Total transferred:      54456 bytes
HTML transferred:       49068 bytes
Requests per second:    3.83 [#/sec] (mean)
Time per request:       6525.777 [ms] (mean)
Time per request:       261.031 [ms] (mean, across all concurrent requests)
Transfer rate:          16.98 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        1    1   0.1      1       1
Processing:  1525 1812 449.2   1653    3131
Waiting:     1524 1781 439.4   1653    3064
Total:       1525 1813 449.2   1654    3132

Percentage of the requests served within a certain time (ms)
  50%   1654
  66%   1657
  75%   1841
  80%   1841
  90%   2158
  95%   3132
  98%   3132
  99%   3132
 100%   3132 (longest request)

Closed #338002: Allow modules to cache module information as a duplicate. I had a module_info() function going on there, but system_get_info() is more appropriate.

+ $list = (!empty($list) ? array_combine($list, $list) : array());

use drupal_map_assoc().

@manarth - do you believe your own benchmark? For starters, there should be no change for anonymous cached pages. Are you passing a cookie in order to be logged in? If not, is page caching enabled?

IMO this is critical since it blocks the css/js preprocess issue but not getting fussy over that.

@sun pointed out above that we don't want to use drupal_map_assoc() because it makes module.inc require common.inc (on the other hand, if this part of the code path only happens during a full bootstrap, maybe it doesn't matter - not sure).

Yeah, geez, I hope those benchmarks are wrong :) Is there any chance that one was accidentally done with page caching enabled and the other with page caching disabled?

@moshe @David_Rothstein I'm having doubts on those benchmarks too (perils of running benchmarks on a VM instead of bare metal). Both were run with ab (as anon user, hitting the homepage, fresh build, no page-caching).

Xdebug profiler doesn't show a great deal of difference with the patch, and there doesn't seem to be anything performance-sucking in the patch, so I'd discount the benchmarks.

This issue is only major, but there is a critical issue (#328357: Allow module .info files to add CSS/JS) we're working on that allows modules to add css/js in their info files.

If we want that work do be done here instead, doesn't that make this issue critical?

guess not, I'll keep focusing on the other issue.

Still no valid benchmarks on this issue.

Attempting to Benchmark the patch at #22
Drush Devel generated content.
Without Patch

ubuntu@helpdesklive:~/projects/testlocal/drupal-7-git$ ab -n100 -c25 -t3 http://testlocal/drupal-7-git
This is ApacheBench, Version 2.0.40-dev <$Revision: 1.146 $> apache-2.0
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Copyright 2006 The Apache Software Foundation, http://www.apache.org/

Benchmarking testlocal (be patient)
Finished 1424 requests


Server Software:        Apache/2.2.8
Server Hostname:        testlocal
Server Port:            80

Document Path:          /drupal-7-git
Document Length:        353 bytes

Concurrency Level:      25
Time taken for tests:   3.21116 seconds
Complete requests:      1424
Failed requests:        0
Write errors:           0
Non-2xx responses:      1425
Total transferred:      1023150 bytes
HTML transferred:       503025 bytes
Requests per second:    471.35 [#/sec] (mean)
Time per request:       53.039 [ms] (mean)
Time per request:       2.122 [ms] (mean, across all concurrent requests)
Transfer rate:          330.67 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    9   6.3      9      32
Processing:    18   40   8.0     41      91
Waiting:        1   29   9.5     27      82
Total:         25   50   5.7     50      93

Percentage of the requests served within a certain time (ms)
  50%     50
  66%     51
  75%     53
  80%     53
  90%     56
  95%     60
  98%     65
  99%     67
 100%     93 (longest request)

Applied Patch.
Used Drush CC all to clear caches.
Interestingly, got this warning [multiple times] on first run of drush cc all.

Trying to get property of non-object in drupal_alter() (line 915 of                           [notice]
/home/ubuntu/projects/testlocal/drupal-7-git/includes/module.inc).

Ran drush cc all again, and it seems to run fine.

With Patch
Ran ab

 ab -n100 -c25 -t3 http://testlocal/drupal-7-git
This is ApacheBench, Version 2.0.40-dev <$Revision: 1.146 $> apache-2.0
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Copyright 2006 The Apache Software Foundation, http://www.apache.org/

Benchmarking testlocal (be patient)
Finished 1351 requests


Server Software:        Apache/2.2.8
Server Hostname:        testlocal
Server Port:            80

Document Path:          /drupal-7-git
Document Length:        353 bytes

Concurrency Level:      25
Time taken for tests:   3.16900 seconds
Complete requests:      1351
Failed requests:        0
Write errors:           0
Non-2xx responses:      1352
Total transferred:      970736 bytes
HTML transferred:       477256 bytes
Requests per second:    447.81 [#/sec] (mean)
Time per request:       55.827 [ms] (mean)
Time per request:       2.233 [ms] (mean, across all concurrent requests)
Transfer rate:          313.90 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0   11   7.4     10      54
Processing:    14   41  10.7     41     103
Waiting:        1   29  11.5     27      93
Total:         23   52  10.0     52     109

Percentage of the requests served within a certain time (ms)
  50%     52
  66%     55
  75%     57
  80%     58
  90%     62
  95%     67
  98%     77
  99%    101
 100%    109 (longest request)

This seems to return a performance improvement, so something somewhere might not be right [the patch, my system or my benchmarking].

@alanburke - the filesize looks awfully small - 353 bytes isn't enough for the doctype and HTML tag!

Document Path:          /drupal-7-git
Document Length:        353 bytes
...
Non-2xx responses:      1352

Looks like you're getting error responses.

• Core install with devel + devel-generate enabled
• devel-generate 50 nodes with comments.
• Benchmarked the homepage (which is showing /node)
• Using anonymous-user to benchmark
• No page-cacheing

Here are the results:

• n=250, c=10, t=5:
  • Unpatched: 6.49 req/sec
  • Patched: 8.76 req/sec
• n=1000, c=15, t=5:
  • Unpatched: 7.89 req/sec
  • Patched: 8.84 req/sec
• n=1000, c=12, t=5:
  • Unpatched: 8.78 req/sec
  • Patched: 9.35 req/sec
• Longer running - n=250, c=5, t=60:
  • Unpatched: 10.29 req/sec
  • Patched: 11.24 req/sec

I think it's reasonable to conclude that the patch improves performance.

250 requests, 10 concurrent users (timeout after 5secs)

Without patch

ab -n 250 -c 10 -t 5 http://benchmarks.d7core.local/
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 benchmarks.d7core.local (be patient)
Finished 33 requests


Server Software:        Apache/2.2.12
Server Hostname:        benchmarks.d7core.local
Server Port:            80

Document Path:          /
Document Length:        22284 bytes

Concurrency Level:      10
Time taken for tests:   5.082 seconds
Complete requests:      33
Failed requests:        0
Write errors:           0
Total transferred:      772174 bytes
HTML transferred:       757656 bytes
Requests per second:    6.49 [#/sec] (mean)
Time per request:       1540.140 [ms] (mean)
Time per request:       154.014 [ms] (mean, across all concurrent requests)
Transfer rate:          148.37 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.2      0       1
Processing:   836 1391 482.8   1141    2314
Waiting:      697 1273 445.4   1052    2203
Total:        836 1392 482.9   1141    2315

Percentage of the requests served within a certain time (ms)
  50%   1141
  66%   1344
  75%   1803
  80%   2049
  90%   2188
  95%   2275
  98%   2315
  99%   2315
 100%   2315 (longest request)

With patch

ab -n 250 -c 10 -t 5 http://benchmarks.d7corepatched.local/
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 benchmarks.d7corepatched.local (be patient)
Finished 44 requests


Server Software:        Apache/2.2.12
Server Hostname:        benchmarks.d7corepatched.local
Server Port:            80

Document Path:          /
Document Length:        22466 bytes

Concurrency Level:      10
Time taken for tests:   5.022 seconds
Complete requests:      44
Failed requests:        0
Write errors:           0
Total transferred:      1053078 bytes
HTML transferred:       1033436 bytes
Requests per second:    8.76 [#/sec] (mean)
Time per request:       1141.255 [ms] (mean)
Time per request:       114.125 [ms] (mean, across all concurrent requests)
Transfer rate:          204.80 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.4      0       2
Processing:   559  996 248.1   1000    1578
Waiting:      524  937 236.8    958    1523
Total:        560  996 248.0   1000    1579

Percentage of the requests served within a certain time (ms)
  50%   1000
  66%   1082
  75%   1107
  80%   1177
  90%   1328
  95%   1472
  98%   1579
  99%   1579
 100%   1579 (longest request)

1000 requests, 15 concurrent users (timeout after 5secs)

Without patch

ab -n 1000 -c 15 -t 5 http://benchmarks.d7core.local/
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 benchmarks.d7core.local (be patient)
Finished 40 requests


Server Software:        Apache/2.2.12
Server Hostname:        benchmarks.d7core.local
Server Port:            80

Document Path:          /
Document Length:        22284 bytes

Concurrency Level:      15
Time taken for tests:   5.069 seconds
Complete requests:      40
Failed requests:        0
Write errors:           0
Total transferred:      932599 bytes
HTML transferred:       914665 bytes
Requests per second:    7.89 [#/sec] (mean)
Time per request:       1901.062 [ms] (mean)
Time per request:       126.737 [ms] (mean, across all concurrent requests)
Transfer rate:          179.65 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    1   0.4      0       1
Processing:   948 1580 463.3   1455    2633
Waiting:      855 1458 446.3   1328    2470
Total:        949 1581 463.2   1455    2633
ERROR: The median and mean for the initial connection time are more than twice the standard
       deviation apart. These results are NOT reliable.

Percentage of the requests served within a certain time (ms)
  50%   1455
  66%   1589
  75%   2001
  80%   2023
  90%   2362
  95%   2587
  98%   2633
  99%   2633
 100%   2633 (longest request)

With patch

ab -n 1000 -c 15 -t 5 http://benchmarks.d7corepatched.local/
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 benchmarks.d7corepatched.local (be patient)
Finished 45 requests


Server Software:        Apache/2.2.12
Server Hostname:        benchmarks.d7corepatched.local
Server Port:            80

Document Path:          /
Document Length:        22466 bytes

Concurrency Level:      15
Time taken for tests:   5.091 seconds
Complete requests:      45
Failed requests:        0
Write errors:           0
Total transferred:      1087059 bytes
HTML transferred:       1066136 bytes
Requests per second:    8.84 [#/sec] (mean)
Time per request:       1696.958 [ms] (mean)
Time per request:       113.131 [ms] (mean, across all concurrent requests)
Transfer rate:          208.53 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    1   0.7      0       2
Processing:  1159 1450 244.4   1388    2120
Waiting:      991 1311 242.3   1248    1942
Total:       1159 1451 244.5   1389    2121
WARNING: The median and mean for the initial connection time are not within a normal deviation
        These results are probably not that reliable.

Percentage of the requests served within a certain time (ms)
  50%   1385
  66%   1434
  75%   1500
  80%   1711
  90%   1903
  95%   1953
  98%   2121
  99%   2121
 100%   2121 (longest request)

1000 requests, 12 concurrent users (timeout after 5secs)

I re-tested with fewer concurrent users, because ab reported unreliable tests for c=15:

WARNING: The median and mean for the initial connection time are not within a normal deviation
        These results are probably not that reliable.

Without patch

ab -n 1000 -c 12 -t 5 http://benchmarks.d7core.local/
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 benchmarks.d7core.local (be patient)
Finished 44 requests


Server Software:        Apache/2.2.12
Server Hostname:        benchmarks.d7core.local
Server Port:            80

Document Path:          /
Document Length:        22284 bytes

Concurrency Level:      12
Time taken for tests:   5.009 seconds
Complete requests:      44
Failed requests:        0
Write errors:           0
Total transferred:      999284 bytes
HTML transferred:       980496 bytes
Requests per second:    8.78 [#/sec] (mean)
Time per request:       1366.007 [ms] (mean)
Time per request:       113.834 [ms] (mean, across all concurrent requests)
Transfer rate:          194.83 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.8      0       5
Processing:   955 1280 286.9   1229    2428
Waiting:      944 1187 303.5   1099    2351
Total:        955 1280 286.8   1229    2429

Percentage of the requests served within a certain time (ms)
  50%   1229
  66%   1251
  75%   1257
  80%   1296
  90%   1548
  95%   2089
  98%   2429
  99%   2429
 100%   2429 (longest request)

With patch

ab -n 1000 -c 12 -t 5 http://benchmarks.d7corepatched.local/
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 benchmarks.d7corepatched.local (be patient)
Finished 47 requests


Server Software:        Apache/2.2.12
Server Hostname:        benchmarks.d7corepatched.local
Server Port:            80

Document Path:          /
Document Length:        22466 bytes

Concurrency Level:      12
Time taken for tests:   5.024 seconds
Complete requests:      47
Failed requests:        0
Write errors:           0
Total transferred:      1075971 bytes
HTML transferred:       1055902 bytes
Requests per second:    9.35 [#/sec] (mean)
Time per request:       1282.745 [ms] (mean)
Time per request:       106.895 [ms] (mean, across all concurrent requests)
Transfer rate:          209.14 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.7      0       5
Processing:   911 1140 240.8   1073    1954
Waiting:      823 1047 240.4    988    1825
Total:        912 1140 241.0   1073    1955

Percentage of the requests served within a certain time (ms)
  50%   1071
  66%   1119
  75%   1143
  80%   1154
  90%   1527
  95%   1782
  98%   1955
  99%   1955
 100%   1955 (longest request)

Longer running:

Without patch

ab -n 250 -c 5 -t 60 http://benchmarks.d7core.local/
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 benchmarks.d7core.local (be patient)
Finished 618 requests


Server Software:        Apache/2.2.12
Server Hostname:        benchmarks.d7core.local
Server Port:            80

Document Path:          /
Document Length:        22284 bytes

Concurrency Level:      5
Time taken for tests:   60.065 seconds
Complete requests:      618
Failed requests:        0
Write errors:           0
Total transferred:      14035398 bytes
HTML transferred:       13771512 bytes
Requests per second:    10.29 [#/sec] (mean)
Time per request:       485.959 [ms] (mean)
Time per request:       97.192 [ms] (mean, across all concurrent requests)
Transfer rate:          228.20 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.5      0       8
Processing:   415  484  20.0    484     644
Waiting:      368  439  20.1    440     601
Total:        416  485  20.0    484     644

Percentage of the requests served within a certain time (ms)
  50%    484
  66%    492
  75%    497
  80%    499
  90%    508
  95%    514
  98%    526
  99%    530
 100%    644 (longest request)

With patch

ab -n 250 -c 5 -t 60 http://benchmarks.d7corepatched.local/
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 benchmarks.d7corepatched.local (be patient)
Finished 675 requests


Server Software:        Apache/2.2.12
Server Hostname:        benchmarks.d7corepatched.local
Server Port:            80

Document Path:          /
Document Length:        22466 bytes

Concurrency Level:      5
Time taken for tests:   60.039 seconds
Complete requests:      675
Failed requests:        0
Write errors:           0
Total transferred:      15452775 bytes
HTML transferred:       15164550 bytes
Requests per second:    11.24 [#/sec] (mean)
Time per request:       444.734 [ms] (mean)
Time per request:       88.947 [ms] (mean, across all concurrent requests)
Transfer rate:          251.35 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.4      0       6
Processing:   367  443  25.4    441     614
Waiting:      322  402  24.9    401     585
Total:        367  443  25.5    441     615

Percentage of the requests served within a certain time (ms)
  50%    441
  66%    451
  75%    457
  80%    460
  90%    471
  95%    484
  98%    502
  99%    520
 100%    615 (longest request)

NB: the Document lengths is larger for the patched version than the unpatched version by 182 bytes, because the URLs are different on my setup (foo.core vs foo.corepatched). The difference is less than 1% of the total document length and can safely be ignored.

Did some micro-benchmarking, 100 iterations of system_list(); drupal_static_reset('system_list');

HEAD: 45.91s
Patch: 47.034038066864s

Note I have no idea why it's taking ~500ms to call system_list() in both HEAD and the patch, so these may well be invalid overall, I checked a single call to system_list() locally and also saw 500ms. About to get on a flight but will try to look again at this later, possibly on another machine.

Here's the test script:

<?php
error_reporting(E_ALL | E_STRICT);
define('ITERATIONS', 100);

define('DRUPAL_ROOT', getcwd());

require_once DRUPAL_ROOT . '/includes/bootstrap.inc';
drupal_bootstrap(DRUPAL_BOOTSTRAP_FULL);

$start = microtime(true);
for ($i=0; $i < ITERATIONS; ++$i) {
}
$stop = microtime(true);
echo "nothing: " . ($stop - $start) . " seconds". PHP_EOL;

for ($i=0; $i < ITERATIONS; ++$i) {
  drupal_static_reset('system_list');
  system_list();
}
$stop = microtime(true);
echo "system_list: " . ($stop - $start) . " seconds". PHP_EOL;

Correct function argument would've helped... system_list('module_enabled');

100k iterations this time.

HEAD: 22.606045007706 seconds

Patch: system_list: 22.733495950699 seconds

Looks like no measurable difference, which is great. Not sure how manarth got consistently faster results though. Did the same test with 'bootstrap' instead of 'module_enabled' and no change there either.

Well ... either Catch is correct and there is no measurable difference ... or manarth is correct and we get a bit of a win with this patch. Either way do we have enough to mark this back to RTBC?

XHprof is happy to report improvements with the patch:

I also just did a quick micro-benchmark of list_themes() - since this patch affected that too. I used @catch's code but with:

  drupal_static_reset('list_themes');
  list_themes();

With 1000 iterations I got this:

HEAD: 21.3 seconds
With patch: 0.126 seconds

I expected some performance improvement due to removing the unserialize(), but not sure I expected that much, so maybe I did something wrong...

In any case, it sounds like overall the conclusion from everyone is that this patch doesn't hurt performance and may actually help it :)

Actually, after looking at http://www.phpdevblog.net/2009/11/serialize-vs-var-export-vs-json-encode... maybe my results do make sense.

Basically, the unserializing that took place in list_themes() during the first call to it on every authenticated page request probably took around 20ms, and with this patch, that is gone, so we gain those 20ms. (Offset somewhat by a larger cache unserialization elsewhere, but apparently not as bad.)

Is this RTBC now?

it's pretty much impossible that list_themes() was taking 20ms, I'd run it once with a timer to compare before and after the patch to see what might be happening.

I'd be really happy if I could see the xhprof report just for system_list() instead of the whole request, but this seems fine to me, thanks to people for actually doing the benchmarks.

Code looks solid to me, and bot is happy.

We could move drupal_map_assoc() to bootstrap.inc and use it here. We've needed it early elsewhere. Lets only bother if we have to re-roll.

Committed to CVS HEAD. Hopefully we can make progress with that critical now. Thanks!