It would be good to get a notion of where we stand performance-wise with our current approach before we hit the core queue - especially since formatters will be based on the same approach.

Proposed test scenario :
- a node type with 10 text fields (& simple textfield widget)
- 10 nodes prepopulated with devel-generate
- a custom page callback showing edit forms for the 10 nodes

Then on 8.x
- drush cc all
- "ab -n 10" on that page to warm caches, ditch the results
- "ab -n 300" on that page
- I guess an XHProf run could be nice too :-)

And repeat on field-plugins-widgets-1742734

Sandbox Drush commands at http://drupal.org/sandbox/swentel/1781486 (more commands and options coming later today and this week)

Tests by swentel
node/add c 1:
- before : Reqs/sec (ab) : 11.85 [#/sec], Inc. wall time : 162,562 ms, Incl CPU: 158,952 ms, InclMemUse: 6,902,688 bytes
- after : Reqs/sec (ab) : 11.57 [#/sec], Inc. wall time : 176,185 ms, Incl CPU: 171,421 ms, InclMemUse: 7,128,280 byes
node/1/edit c 1:
- before : Reqs/sec (ab) : 11.55 [#/sec], Inc. wall time : 161,266 ms, Incl CPU: 155,564 ms, InclMemUse: 7,096,168 bytes
- after : Reqs/sec (ab) : 11.42 [#/sec], Inc. wall time : 185,186 ms, Incl CPU: 180,378 ms, InclMemUse: 7,286,480
node/add c 5:
- before : Reqs/sec (ab) : 22.15 [#/sec]
- after : Reqs/sec (ab) : 21.74 [#/sec]
node/1/edit c 5:
- before : Reqs/sec (ab) : 21.14 [#/sec]
- after : Reqs/sec (ab) : 20.89 [#/sec]

CommentFileSizeAuthor
#3 Screen Shot 2012-09-15 at 17.30.08.png24.16 KBswentel
#3 Screen Shot 2012-09-15 at 17.30.15.png24 KBswentel
#3 Screen Shot 2012-09-15 at 17.30.21.png23.07 KBswentel
#3 Screen Shot 2012-09-15 at 17.30.29.png23.78 KBswentel

Comments

swentel’s picture

swentel commented
Assigned: Unassigned » swentel

I'll take this.

I'll create some drush scripts which can easily can setup node types with fields etc and use devel generate - if that works on D8, that's sometimes tricky :)

swentel’s picture

swentel commented

First benchmarks - no xhprof runs at this point, but devel memory tracking.

Vanilla Drupal, standard install wo overlay and update, devel enabled, content type with 10 textfield, body field, 30 nodes, authenticated ab - node/add

Memory used at: devel_boot()=1.2 MB, devel_shutdown()=4.93 MB, PHP peak=5.5 MB.

ab -C sid=value -n 300 http://drupal8/node/add/fowdimq9

Concurrency Level:      1
Time taken for tests:   25.316 seconds
Complete requests:      300
Failed requests:        0
Write errors:           0
Total transferred:      8976900 bytes
HTML transferred:       8826300 bytes
Requests per second:    11.85 [#/sec] (mean)
Time per request:       84.388 [ms] (mean)
Time per request:       84.388 [ms] (mean, across all concurrent requests)
Transfer rate:          346.28 [Kbytes/sec] received

ab -C sid=value -n 300 -c 5 http://drupal8/node/add/fowdimq9

Concurrency Level:      5
Time taken for tests:   13.543 seconds
Complete requests:      300
Failed requests:        0
Write errors:           0
Total transferred:      8976900 bytes
HTML transferred:       8826300 bytes
Requests per second:    22.15 [#/sec] (mean)
Time per request:       225.722 [ms] (mean)
Time per request:       45.144 [ms] (mean, across all concurrent requests)
Transfer rate:          647.29 [Kbytes/sec] received

Vanilla Drupal, standard install wo overlay and update, devel enabled, content type with 10 textfield, body field, 30 nodes, authenticated ab - node/x/edit

Memory used at: devel_boot()=1.2 MB, devel_shutdown()=5.03 MB, PHP peak=6 MB.

ab -C sid=value -n 300 http://drupal8/node/1/edit

Concurrency Level:      1
Time taken for tests:   25.978 seconds
Complete requests:      300
Failed requests:        0
Write errors:           0
Total transferred:      10359300 bytes
HTML transferred:       10208700 bytes
Requests per second:    11.55 [#/sec] (mean)
Time per request:       86.594 [ms] (mean)
Time per request:       86.594 [ms] (mean, across all concurrent requests)
Transfer rate:          389.42 [Kbytes/sec] received

ab -C sid=value -n 300 -c 5 http://drupal8/node/1/edit

Concurrency Level:      5
Time taken for tests:   14.190 seconds
Complete requests:      300
Failed requests:        0
Write errors:           0
Total transferred:      10359300 bytes
HTML transferred:       10208700 bytes
Requests per second:    21.14 [#/sec] (mean)
Time per request:       236.506 [ms] (mean)
Time per request:       47.301 [ms] (mean, across all concurrent requests)
Transfer rate:          712.91 [Kbytes/sec] received

Patch with plugins patch, standard install wo overlay and update, devel enabled, content type with 10 textfield, body field, 30 nodes, authenticated ab - node/add

Memory used at: devel_boot()=1.2 MB, devel_shutdown()=5.04 MB, PHP peak=6 MB.

ab -C sid=value -n 300  http://drupal8/node/add/bctpekop

Concurrency Level:      1
Time taken for tests:   25.939 seconds
Complete requests:      300
Failed requests:        0
Write errors:           0
Total transferred:      8976900 bytes
HTML transferred:       8826300 bytes
Requests per second:    11.57 [#/sec] (mean)
Time per request:       86.464 [ms] (mean)
Time per request:       86.464 [ms] (mean, across all concurrent requests)
Transfer rate:          337.96 [Kbytes/sec] received

ab -C sid=value -n 300 -c 5 http://drupal8/node/add/bctpekop

Concurrency Level:      5
Time taken for tests:   13.801 seconds
Complete requests:      300
Failed requests:        0
Write errors:           0
Total transferred:      8976900 bytes
HTML transferred:       8826300 bytes
Requests per second:    21.74 [#/sec] (mean)
Time per request:       230.011 [ms] (mean)
Time per request:       46.002 [ms] (mean, across all concurrent requests)
Transfer rate:          635.22 [Kbytes/sec] received

Patch with plugins patch, standard install wo overlay and update, devel enabled, content type with 10 textfield, body field, 30 nodes, authenticated ab - node/x/edit

Memory used at: devel_boot()=1.2 MB, devel_shutdown()=5.14 MB, PHP peak=6 MB.

ab -C sid=value -n 300  http://drupal8/node/1/edit

Concurrency Level:      1
Time taken for tests:   26.280 seconds
Complete requests:      300
Failed requests:        0
Write errors:           0
Total transferred:      10016400 bytes
HTML transferred:       9865800 bytes
Requests per second:    11.42 [#/sec] (mean)
Time per request:       87.600 [ms] (mean)
Time per request:       87.600 [ms] (mean, across all concurrent requests)
Transfer rate:          372.21 [Kbytes/sec] received

ab -C sid=value -n 300 -c 5 http://drupal8/node/1/edit

Concurrency Level:      5
Time taken for tests:   14.358 seconds
Complete requests:      300
Failed requests:        0
Write errors:           0
Total transferred:      10016400 bytes
HTML transferred:       9865800 bytes
Requests per second:    20.89 [#/sec] (mean)
Time per request:       239.297 [ms] (mean)
Time per request:       47.859 [ms] (mean, across all concurrent requests)
Transfer rate:          681.28 [Kbytes/sec] received

We're loosing a little, but it's not that dramatic at all imo. This is also on a macbook. I asume the difference on a real production server would be even smaller.

I'll try to run xhprof later this day or tomorrow.

swentel’s picture

swentel commented
StatusFileSize
new Screen Shot 2012-09-15 at 17.30.29.png23.78 KB
new Screen Shot 2012-09-15 at 17.30.21.png23.07 KB
new Screen Shot 2012-09-15 at 17.30.15.png24 KB
new Screen Shot 2012-09-15 at 17.30.08.png24.16 KB

Attached the xhprof summaries, they're in the same order as in #2

Screen Shot 2012-09-15 at 17.30.08.png

Screen Shot 2012-09-15 at 17.30.15.png

Screen Shot 2012-09-15 at 17.30.21.png

Screen Shot 2012-09-15 at 17.30.29.png

sun’s picture

sun
Primary language German
Location Karlsruhe
commented

yeah... note that ArrayAccess definitely adds to the minor slowdown, and of course, there's the Legacy plugin stuff, which most likely adds some overhead, too.

swentel’s picture

swentel commented

Yeah, I'll rerun everything once everything has been converted. I'm kind of convinced the difference will be even smaller then.

yched’s picture

yched commented

The XHprof CPU numbers tend to indicate a 10% slowdown ? That's a bit much...

The Legacy stuff should play no part here. The tested nodes only use textfields, which are converted to the new systems.
Legacy then only impacts at plugin discovery time, which should not be affected with warm caches.

But ArrayAccess definitely plays a part. I guess we would need to evaluate that separately by just applying the "as ArrayAccess" change...
#1764278: Run PluginManagerBase::processDefinition() in a ProcessDecorator probably drags us down a bit too. processing plugin definitions is not cached, and is re-run each time we access the definition.

yched’s picture

yched commented
Issue summary: View changes

Updated to add sandbox

yched’s picture

yched commented

So, I ran my own benchmarks on node/N/edit between :
- 8.x
- only transforming $instance to ArrayAccess, no other code change
- widgets as plugins

With ab:
8.x - Time per request: 149.320 ms
ArrayAccess - Time per request: 151.462 ms, + 1.4 %
Widgets as plugins - Time per request: 156.840 ms, + 3.5 %

Wen turning to xhprof to check CPU diffs between 'ArrayAccess only' and 'widgets as plugins':
- field_attach_form takes 5.010ms longer to run (inclusive wall time)
This matches the difference above, which makes sense since all the changes happen below field_attach_form()
- ClassLoader::loadClass takes 5.711ms longer to run, with 7 more calls

So it seems:
- The ArrayAccess BC trick adds some overhead, but we know we want to get rif of it at some point
- After that, the overhead is mostly incurred by the autoloader.
Loading more classes is inherent to an "X as plugins" patch, and we know we have a slow autoloader already.

yched’s picture

yched commented
Status: Active » Fixed

As far as widgets are concerned, I think we can close that one.

Status: Fixed » Closed (fixed)

Automatically closed -- issue fixed for 2 weeks with no activity.

Anonymous’s picture

(not verified) commented
Issue summary: View changes

Update summary with first benchmark tests