Log Message:
-----------
Use the Timing::HiRes module to calculate timing data for each
request. This gives more accurate timing data (using the unix
time gives only to the nearest second). I am printing the elapsed
time to 3 decimal places, it could be to 6 if that is desirable.
This will help us evaluate whether changes are increasing or decreasing
the speed with which requests are serviced.
Modified Files:
--------------
webwork-modperl/lib:
WeBWorK.pm
Revision Data
-------------
Index: WeBWorK.pm
===================================================================
RCS file: /webwork/cvs/system/webwork-modperl/lib/WeBWorK.pm,v
retrieving revision 1.70
retrieving revision 1.71
diff -Llib/WeBWorK.pm -Llib/WeBWorK.pm -u -r1.70 -r1.71
--- lib/WeBWorK.pm
+++ lib/WeBWorK.pm
@@ -268,8 +268,11 @@
debug(("-" x 80) . "\n");
debug("Finally, we'll load the display module...\n");
- my $localStartTime = time;
-
+ # The "production timer" uses a finer grained HiRes timing module
+ # rather than the standard unix "time".
+ #my $localStartTime = time;
+ my $productionTimer = WeBWorK::Timing->new($label);
+ $productionTimer->start();
runtime_use($displayModule);
debug("...instantiate it...\n");
@@ -288,9 +291,11 @@
#$WeBWorK::timer->stop();
#$WeBWorK::timer->save();
- my $localStopTime = time;
- my $timeDiff = $localStopTime - $localStartTime;
- writeTimingLogEntry($ce,"[".$r->uri."]", sprintf("runTime = %.1f sec", $timeDiff)." ".$ce->{dbLayoutName},"" );
+ #my $localStopTime = time;
+ $productionTimer->stop();
+ #my $timeDiff = $localStopTime - $localStartTime;
+ my $productionTimeDiff = $productionTimer->{stop} - $productionTimer->{start};
+ writeTimingLogEntry($ce,"[".$r->uri."]", sprintf("runTime = %.3f sec", $productionTimeDiff)." ".$ce->{dbLayoutName},"" );
return $result;
}
|
