Permalink
Browse files

adding more timers

  • Loading branch information...
tmaiaroto committed Jan 5, 2012
1 parent 229a360 commit 6117b154f51b618e448c1035203ed66c8bec6e62
Showing with 46 additions and 8 deletions.
  1. +32 −0 config/bootstrap/dispatcher.php
  2. +14 −8 views/elements/timers.html.php
@@ -3,6 +3,36 @@
use lithium\template\View;
use li3_perf\extensions\util\Data;
use lithium\core\Libraries;
+use lithium\net\http\Router;
+
+Dispatcher::applyFilter('_callable', function($self, $params, $chain) {
+ // At this point, the routing has completed. In order to call _callable, it's routed.
+ // So this is ever so slightly off actually.
+ Data::append('timers', array('li3_perf_has_route' => microtime(true)));
+
+ $result = $chain->next($self, $params, $chain);
+
+ // Now that we know whether or not the request is callable, it's going to be called.
+ // This is esentially right before the code in the controller action is executed.
+ // So mark the time.
+ Data::append('timers', array('li3_perf_start_call' => microtime(true)));
+
+ return $result;
+});
+
+Dispatcher::applyFilter('_call', function($self, $params, $chain) {
+
+ $result = $chain->next($self, $params, $chain);
+
+ // At this point the controller action has been called and now a response will be returned.
+ // $result here contains the response and we've been setting timers all along the way...
+ // The next time we'll be working with the same response is under the next filter below on
+ // run() AFTER $result = $chain->next() is called... That's the end of the dispatch cycle.
+ // The $result = part below is actually before this filter and the filter on _callable() above.
+ Data::append('timers', array('li3_perf_end_call' => microtime(true)));
+
+ return $result;
+});
// Apply a filter that will render the toolbar and mark some timers.
Dispatcher::applyFilter('run', function($self, $params, $chain) {
@@ -30,6 +60,8 @@
array(
'timers' => $timers += array(
'dispatch_cycle' => $timers['li3_perf_end'] - $timers['li3_perf_start_dispatch'],
+ 'routing' => $timers['li3_perf_has_route'] - $timers['li3_perf_start_dispatch'],
+ 'call' => $timers['li3_perf_end_call'] - $timers['li3_perf_start_call'],
'complete_load_with_li3_perf' => microtime(true) - $timers['li3_perf_start'],
'complete_load' => ($timers['li3_perf_end'] - $timers['li3_perf_start']) - $timers['_filter_for_variables'] - $timers['_filter_for_queries']
),
@@ -3,14 +3,16 @@
$total = $timers['complete_load_with_li3_perf'];
$percentages['complete_load'] = ($timers['complete_load'] / $total) * 100;
$percentages['dispatch_cycle'] = ($timers['dispatch_cycle'] / $total) * 100;
-var_dump($percentages);
-
+$percentages['routing'] = ($timers['routing'] / $total) * 100;
+$percentages['call'] = ($timers['call'] / $total) * 100;
?>
<h2>Time to Load</h2>
<?=$this->li3perf->printVars($timers); ?>
-<div id="holder" style="height: 900px;"></div>
-
+<p></p>
+<div id="holder" style="height: 205px;"></div>
+<p>Note: The time to route and call the code for the request should just about equal the complete dispatch cycle. If not, something is wrong.</p>
+
<script type="text/javascript" charset="utf-8">
window.onload = function () {
var hover_function = function () {
@@ -60,19 +62,23 @@
//r.g.barchart(330, 10, 300, 220, data2, {stacked: true});
var timer_labels = [
- ["Dispatch Cycle - <?=number_format($timers['dispatch_cycle'], 2); ?>s"],
+ ["Routing - <?=number_format($timers['routing'], 2); ?>s"],
+ ["Call (controller, action, etc.) - <?=number_format($timers['call'], 2); ?>s"],
+ ["Complete Dispatch Cycle - <?=number_format($timers['dispatch_cycle'], 2); ?>s"],
["Complete Load - <?=number_format($timers['complete_load'], 2); ?>s"],
["Complete Load (with li3_perf toolbar) - <?=number_format($timers['complete_load_with_li3_perf'], 2); ?>s"]
];
var timer_colors = [
"#4ddb49",
- "#00A5F5",
+ "#00A5F5",
+ "#00A5F5",
+ "#00A5F5",
"#444444"
];
- r.g.text(225, 25, "Time to Load").attr({"font-size": 20});
+ //r.g.text(225, 25, "Time to Load").attr({"font-size": 20});
- r.g.hbarchart(20, 55, 400, 110, [[<?=$percentages['dispatch_cycle']; ?>],[<?=$percentages['complete_load']; ?>],[100]], {stacked: false, colors: timer_colors}).label(timer_labels);
+ r.g.hbarchart(5, 5, 400, 200, [[<?=$percentages['routing']; ?>],[<?=$percentages['call']; ?>],[<?=$percentages['dispatch_cycle']; ?>],[<?=$percentages['complete_load']; ?>],[100]], {stacked: false, colors: timer_colors}).label(timer_labels);
//
//r.g.hbarchart(10, 25, 300, 25, [[100], [200], [300]], {stacked: true}).hover(fin, fout);

0 comments on commit 6117b15

Please sign in to comment.