Field formatters as render arrays

See #538164-127: Comment body as field: at least for comment body as field, it's not promising yet, but let's keep exploring.

devel_generate is failing to add node body, so i manually created 10 article nodes (title = "Article #", body = "Body").

HEAD: 99.5ms
Patch 5: 98.2ms

Subscribing.

And for anyone else wanting to help with benchmarks, here's the fix to devel_generate: #652898: Small fix so nodes can be generated with field data

Status change was unintentional.

@yched: Not the exact sequence you outlined, but #9 has my system's benchmarks for home page with 10 article nodes.

Looks pretty cool.

However, I don't really understand why it's called 'formatter'. A hook_field_format(), or better yet, hook_field_view() would make much more sense to me. I guess that back then when this was introduced, CCK wanted to be extra cool and figured that, hey, all the other shit is old shit and we have quite a lot new shit, so let's call it "formatter", because "viewing" stuff is lame and in general associated with old-school shit, and we are absolutely new-school shit, so we don't view, no, we implement auto-formatting robots that are totally different than viewing a field, errr, are they? Anyway, who cares, this is cool.

Probably a separate issue. ;) If you fill out the @todos, then we're probably set. :)

errrrr. Now I even have to realize that it would have to be hook_field_build() and hook_field_build_multiple() in D7, because that's the common name for such functions. Ah well, it all takes some time to get used to. ;)

Generated content with devel, each just has a body field, hit the front page with ten of them.

I could only measure around a 2% improvement. However if that equates to a ten percent improvement with 5 fields per-node instead of one, then that's really good to have. 5 fields isn't many at all.

HEAD:

Concurrency Level:      1
Time taken for tests:   103.634 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      22663000 bytes
HTML transferred:       22198000 bytes
Requests per second:    9.65 [#/sec] (mean)
Time per request:       103.634 [ms] (mean)
Time per request:       103.634 [ms] (mean, across all concurrent requests)
Transfer rate:          213.56 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:    95  104   7.6    101     160
Waiting:       88   96   7.2     94     153
Total:         95  104   7.6    101     160

Time taken for tests:   104.010 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      22663000 bytes
HTML transferred:       22198000 bytes
Requests per second:    9.61 [#/sec] (mean)
Time per request:       104.010 [ms] (mean)
Time per request:       104.010 [ms] (mean, across all concurrent requests)
Transfer rate:          212.79 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:    95  104   7.8    101     169
Waiting:       87   96   7.0     94     149
Total:         95  104   7.8    101     169

Patch:

Concurrency Level:      1
Time taken for tests:   102.453 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      22663000 bytes
HTML transferred:       22198000 bytes
Requests per second:    9.76 [#/sec] (mean)
Time per request:       102.453 [ms] (mean)
Time per request:       102.453 [ms] (mean, across all concurrent requests)
Transfer rate:          216.02 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       1
Processing:    95  102   6.1    101     160
Waiting:       88   95   5.8     94     153
Total:         95  102   6.1    101     160

Concurrency Level:      1
Time taken for tests:   102.319 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      22663000 bytes
HTML transferred:       22198000 bytes
Requests per second:    9.77 [#/sec] (mean)
Time per request:       102.319 [ms] (mean)
Time per request:       102.319 [ms] (mean, across all concurrent requests)
Transfer rate:          216.30 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:    96  102   5.7    100     148
Waiting:       89   95   5.3     93     123
Total:         96  102   5.7    100     148

Tried a single node and manually added a bunch of different fields for it, then stuck some dummy content in. Two term fields, two images, 4 text fields etc.

In this case it actually comes out slower though... There are ten less calls to theme, and one less call to drupal_render() in the patched version according to cachegrind.

HEAD

Server Software:        Apache/2.2.11
Server Hostname:        d7.7
Server Port:            80

Document Path:          /node/204
Document Length:        9241 bytes

Concurrency Level:      1
Time taken for tests:   81.189 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      9771000 bytes
HTML transferred:       9241000 bytes
Requests per second:    12.32 [#/sec] (mean)
Time per request:       81.189 [ms] (mean)
Time per request:       81.189 [ms] (mean, across all concurrent requests)
Transfer rate:          117.53 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:    70   81  12.5     76     125
Waiting:       63   74  11.7     69     117
Total:         70   81  12.5     76     125

Patch:

Concurrency Level:      1
Time taken for tests:   92.960 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      9771000 bytes
HTML transferred:       9241000 bytes
Requests per second:    10.76 [#/sec] (mean)
Time per request:       92.960 [ms] (mean)
Time per request:       92.960 [ms] (mean, across all concurrent requests)
Transfer rate:          102.65 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.0      0       0
Processing:    83   93   9.4     90     151
Waiting:       77   86   8.9     83     142
Total:         83   93   9.4     90     151

@catch - there are fewer calls to theme() with the patch and still it came out slower? can you tell why patched is slower? this is a bit disheartening.

@sun - formatter deserves a new word, IMO. It refers to a function that transforms raw database values for viewing, and can be shared across different fields. modules can declare the availability of these functions and admins choose which they want to use on the Display fields tab or whatever it is called.

@moshe, no I didn't get very far working out why it's slower. I just repeated the benchmarks with ten nodes on front page and it came out slightly slower consistently. effulgentsia also got degradation testing an earlier version of the patch at http://drupal.org/node/538164#comment-2346970 - however it'd be great to get benchmarks by a third person to verify this.

Not encouraging. Here's benchmarks with overlay and rdf modules disabled. I added 2 text fields to the page type, made each multi-valued, and put 30 items into each, so the patch saves on 60 formatter theme() calls.

HEAD: 66.7ms
Patch: 68.8ms

Unfortunately, I don't have time today to help investigate this. But, I'd like to point out that a theme() call isn't as expensive as one might think. I don't have up to date microbenchmarks, but from previous testing, it's about 10us on my computer (including the calling of a theme implementation function that's fast, such as theme('links', array('links' => array())). Replacing each of these items that has a #theme of a formatter with an item that has a #markup, means saving a theme() call, but still invoking drupal_pre_render_markup() as a variable function name from within drupal_render(), so it's probably a net savings of roughly 5us per item, or for 60 items, 0.3ms. However, this patch is large and does a lot of other stuff, so it clearly includes something that's causing a degradation that's much larger than this savings.

On the other hand, drupal_render() is slow (roughly 20us even for a non-item such as the 'items' array that's in HEAD, and that this patch removes by placing the numeric items directly inside the field without the extra 'items' layer), so I like that part of what this patch does, and that might be what accounts for a chunk of the savings in the 10 teaser nodes scenario.

By far the biggest slowdown in field rendering, however, is theme('field'). Just removing that from the comment body conversion to a field (#538164-133: Comment body as field) resulted in the patch moving from having a net 6% - 10% impact (depending on system used to benchmark) to having a net -1% - 0.5% impact. theme('field') is slow because field.tpl.php is a template, and because there's quite a bit of preprocessing logic. Seems like we need to focus our time on that, but I can't help with that in time for tomorrow's deadline. On the other hand, improvements to that might not be as sweeping an API change, and could maybe happen after that deadline.

To be honest, I just don't think removing formatter theme functions is gonna result in much savings, but if someone can figure out what in this patch is causing degradation larger than those savings and fix that, then it still might be a good architectural thing to do. But I do think when we put some effort into optimizing theme('field'), then we'll see some nice rendering speed improvements.

Are we sure the field cache was pre-populated with a preliminary page view when benching both HEAD and the patch?

Yes. For each test, I empty cache, then view the page in Firefox as the root user, and in Safari as an anonymous user, then run "ab" for 100 iterations, and then run "ab" for 500 iterations (that's the one attached in #36). The first 100 iteration run helps any other caches (like APC) get well primed.

It does seem odd that there's an improvement for 10 teasers, but a degradation for a single node with many fields or many field items. Seems worth exploring. However, since there is improvement for 10 teasers, maybe it makes sense to have this land, and then we can find the mysterious trouble spot and optimize that after the deadline.

Sorry I can't be of any more help on this today. Best of luck to you, yched, and anyone else who keeps working on it up until the deadline. I think the basic approach makes sense and is sound, and that remaining performance anomalies are findable and fixable.

This is a re-roll of #25, plus the following changes:

1. In template_preprocess_field(), NOT changing HEAD's use of strtr() with drupal_html_class(), as #25 does. We probably should make this change, but in a separate issue. Doing it here affects benchmarks.

2. In field_default_view(), calling the formatter function directly instead of with module_invoke(), because module_invoke() is slow.

Will follow up with benchmarks, but wanted to get this into bot's queue.

superscribe

Benchmarks with rdf and overlay modules disabled:

A: Home page with 10 article teasers, each article node has a body field:
HEAD: 94.2ms
Patch: 91.9ms

B: Home page with 10 article teasers, each article node has a body field plus 3 single-valued plain-text single-line textfields:
HEAD: 113.5ms
Patch: 111.7ms

C: Single page node with a multi-valued plain-text single-line text field with 40 items populated:
HEAD: 65.5ms
Patch: 65.7ms

Conclusion: This patch doesn't do performance harm. It gives a nice boost to home page with 10 articles, which is a nice scenario to get a boost on. The boost doesn't seem to scale as more fields get added. There seems to be a no-op with just the formatter change alone (page node with 40 items). The no-op in case C makes sense to me. See my comment on #36. We're still invoking the formatter function for as many times as there are items, and as a variable function name. Just instead of doing it from theme(), we're doing it from field_default_view(). I don't see how we gain anything performance-wise from that. There must be something else that's giving us the nice benefit in case A.

So, I think the decision in front of us is whether we think the change to formatters returning render arrays instead of being theme implementations is a good change conceptually. Or does it open the door to further optimization in a way that having it as a theme implementation doesn't? If we think either of those is true, let's do it.

Otherwise, if it's a no-op performance wise, and has no other benefit, let's not do it, and instead try to find what the real cause for case A improvement is, and create a patch that has that, but without changing the formatter architecture.

Unless Dries changed his mind from what he wrote on #438570-62: Field API conversion leads to lots of expensive function calls, the deadline for making this decision is today. I have no strong preference either way (I just haven't thought deeply enough on the architectural implications of formatters as theme functions vs. not). But for anyone with insight on this, today's the day to share it.

Setting to RTBC because sun approved it (except for needing more comments) in #28, and to get it in front of Dries (seems like this is a big and deep enough issue / patch, that he'll need to do his own review and analysis of it).

Re: #47: +1 from me. Also, please re-read #29 and #32. If we simplify formatters in the way you're suggesting, it really starts looking pretty indistinguishable from other *_build() functions.

+1 from me as well. Removing the distinction between single value formatters and multiple value formatters would be awesome for DX. I recall how I got stuck understanding that bit in CCK when it got introduced.

Has anything changed since #41 which requires new benchmarks?

Great. Let's do this -- it is a nice win for the main page. Committed to CVS HEAD.

#47 sounds good but let's do a new issue for that.

In response to sun's #28/#29 comments: #658364: Does build/view/formatter terminology make sense?