[WWcvs] webwork2: re-added timer for entire content generation process.

[Sam H. v. a. <we...@ma...>]

Log Message:
-----------
re-added timer for entire content generation process.

Modified Files:
--------------
    webwork2/lib:
        WeBWorK.pm

Revision Data
-------------
Index: WeBWorK.pm
===================================================================
RCS file: /webwork/cvs/system/webwork2/lib/WeBWorK.pm,v
retrieving revision 1.73
retrieving revision 1.74
diff -Llib/WeBWorK.pm -Llib/WeBWorK.pm -u -r1.73 -r1.74
--- lib/WeBWorK.pm
+++ lib/WeBWorK.pm
@@ -39,6 +39,7 @@
 use strict;
 use warnings;
 use Apache::Constants qw(:common REDIRECT DONE);
+use Time::HiRes qw/time/;
 
 # load WeBWorK::Constants before anything else
 # this sets package variables in several packages
@@ -53,8 +54,7 @@
 use WeBWorK::Request;
 use WeBWorK::Upload;
 use WeBWorK::URLPath;
-use WeBWorK::Utils qw(runtime_use);
-use Date::Format;
+use WeBWorK::Utils qw(runtime_use writeTimingLogEntry);
 
 use constant AUTHEN_MODULE => "WeBWorK::ContentGenerator::Login";
 use constant PROCTOR_AUTHEN_MODULE => "WeBWorK::ContentGenerator::LoginProctor";
@@ -285,6 +285,9 @@
 	#	die "An error occured while accessing '$displayArgs{courseID}': '", $ce->{'!'}, "'.\n";
 	#}
 	
+	# store the time before we invoke the content generator
+	my $cg_start = time; # this is Time::HiRes's time, which gives floating point values
+	
 	debug(("-" x 80) . "\n");
 	debug("Finally, we'll load the display module...\n");
 	
@@ -301,6 +304,10 @@
 	
 	debug("-------------------- call to ${displayModule}::go\n");
 	
+	my $cg_end = time;
+	my $cg_duration = $cg_end - $cg_start;
+	writeTimingLogEntry($ce, "[".$r->uri."]", sprintf("runTime = %.3f sec", $cg_duration)." ".$ce->{dbLayoutName}, "");
+	
 	debug("returning result: " . (defined $result ? $result : "UNDEF") . "\n");
 	
 	return $result;