The render_time metric is set after all Views hooks have been executed for a single View. Is there anyway to access this timing using a standard API function?

Files: 
CommentFileSizeAuthor
#6 views-render_time_metric-1809510-6.patch663 byteserikwebb
PASSED: [[SimpleTest]]: [MySQL] 1,603 pass(es).
[ View ]

Comments

dawehner’s picture

Status:Active» Fixed

You can look it up on the view object: $view->render_time.

erikwebb’s picture

Status:Fixed» Needs work

The problem is that $view->render_time is not available during hook_views_post_(build|execute|render). I even looked for it in template_process_views_view(), but it still was not set there either. The only way I was able to retrieve this metric was by overriding the theme function, which doesn't seem like the right solution.

dawehner’s picture

Mh good point.

I'm wondering whether hook_views_post_render should maybe fired after measuring the render_time, do you have an oppinion about that?

One thing you could do, but pssst you could alter the $view object and maybe replace it
with a decorator version/ a which which extends the normal view class.

If you do this you could fire some hook or something similar later.

erikwebb’s picture

I guess it depends on if we consider "render time" to include only the time required for Views to render the output or if we want to include any work done by modules in hook_views_post_render() implementations. I'm comfortable with this switch, but I'm not sure if there are any implications that I may not be familiar with.

dawehner’s picture

At least at the moment probably not may people are using the render time on actual live installations, but just in the admin interface
, so it seems to be safe for me to move this property up. With this hook_views_pre_view and hook_views_post_render you could
even build your own measurement, just throwing out some ideas.
We have considered to remove this property totally for live-views in d8, but that's not decided/done yet, but it's good
to know an actual usecase.

Regarding the decorator idea, here is a short codesnippet. I'm not sure about the performance implications, but they simply can't be positive :) Once you have this decorator in place, you can change the way for example the render method works.

class foo {
  var $test;
}

class fooDecorator {
  var $foo;
  public function __construct(foo $foo) {
    $this->foo = $foo;
  }
   public function __get($key) {
     return $this->foo->{$key};
   }
   public function __set($key, $value) {
     $this->foo->{$key} = $value;
   }
  public function __call($method, $args) {
    return call_user_func_array(array($this->foo, $method), $args);
  }
}

$foo = new foo();
$foo->test = 123;

replace($foo);

dsm($foo->test);

function replace(&$foo) {
  $foo = new fooDecorator($foo);
}

erikwebb’s picture

Title:Accessing render time performance metric» Make render time performance metric accessible in hook_views_post_render()
Category:support» feature
Status:Needs work» Needs review
StatusFileSize
new663 bytes
PASSED: [[SimpleTest]]: [MySQL] 1,603 pass(es).
[ View ]

Searching drupalcontrib.org for implementations of hook_views_post_render(), I actually don't see any. I think we can go ahead and move where this value is set.

erikwebb’s picture

Long-term I'd like to use this metric to analyze the performance of individual Views on a site. Currently it's difficult to do that using something like New Relic or XHProf, because the function calls are all mostly the same.

For the sake of completeness, here is an example as I see it being used -

<?php
function mymodule_views_post_render(&$view) {
 
// This could easily be replaced with a function to record the stat for analysis later.
 
drupal_set_message(t('View %view render time: @time ms.', array('%view' => $view->name, '@time' => intval($view->render_time * 100000) / 100)));
}
?>
dawehner’s picture

Version:7.x-3.x-dev» 8.x-3.x-dev
Status:Needs review» Patch (to be ported)

Committed this patch to 7.x-3.x

In drupal8 we actually try to remove this completly because we nether thought that this will be used on the actual live site, see #1811982: Remove ui preview logic viewExecuteable::render() and move it to viewUI. Your oppinion. is greatly appreciated.

erikwebb’s picture

I use it frequently for performance tuning. I'm actually working on a benchmarking module (sandbox) that can be used to log the individual performance of Views - http://drupal.org/sandbox/erikwebb/1812092

Using something like XHProf or XDebug Profiler, it is often difficult to figure out exactly which View is the culprit. We need these metrics to make sure that we can differentiate the performance of specific Views.

dawehner’s picture

I see the point totally, but in theory your module could use the views hooks to start/end some timing on the view object.
It seems to be that you vote against removing this part out of the actual executing of a view, maybe we should make it optional?

erikwebb’s picture

I would argue that it should be optional (and disabled by default, like now), but I wouldn't want to remove those statistics from the core Views module.

I agree that my implementation can be done in a different way, so I'm fine with this approach being outdated in the next release.

xjm’s picture

Project:Views» Drupal core
Version:8.x-3.x-dev» 8.x-dev
Component:Code» views.module
kim.pepper’s picture

Issue summary:View changes

This appears to already be before hook_views_post_build() in D8.

\Drupal\views\ViewExecutable line #1195:

<?php
    $this
->built = TRUE;
   
$this->build_time = microtime(TRUE) - $start;

   
// Attach displays
   
$this->attachDisplays();

   
// Let modules modify the view just after building it.
   
$module_handler->invokeAll('views_post_build', array($this));

    return
TRUE;
?>
dawehner’s picture

I guess the "render time" is now pretty much fucked up on Drupal 8, given that the actual rendering happens late via render API, so its kinda hard to measure it, especially once
we move more and more into post_render_callbacks and what not.