[svn:p5ee] r10425 - p5ee/trunk/App-Context/lib/App

[spadkins]

Author: spadkins
Date: Thu Dec 13 10:34:16 2007
New Revision: 10425

Modified:
   p5ee/trunk/App-Context/lib/App/Context.pm

Log:
logging changes, introduced log_hi_res and log_elapsed into the options, and 
based on them we now include hi res timestamps and elapsed time since the last 
log message when the options are enabled

Modified: p5ee/trunk/App-Context/lib/App/Context.pm
==============================================================================
--- p5ee/trunk/App-Context/lib/App/Context.pm   (original)
+++ p5ee/trunk/App-Context/lib/App/Context.pm   Thu Dec 13 10:34:16 2007
@@ -1577,12 +1577,34 @@
 sub _log {
     &App::sub_entry if ($App::trace);
     my $self = shift;
+    my $hi_res = $self->{options}{log_hi_res};
+    my $elapsed = $self->{options}{log_elapsed};
+    my $timestamp;
+    if ($hi_res) {
+        App->use("Time::HiRes");
+        my @timestuff = Time::HiRes::gettimeofday();
+        $timestamp = time2str("%Y-%m-%d %H:%M:%S.", $timestuff[0]) . 
$timestuff[1]; 
+        if ($elapsed) {
+            my $elapsed = 
Time::HiRes::tv_interval($self->{_last_log_elapsed_time}, [EMAIL PROTECTED]);
+            $timestamp .= " " . sprintf("%.6f", $elapsed);
+            $self->{_last_log_elapsed_time} = [EMAIL PROTECTED];
+        }
+    }
+    else {
+        my $time = time();
+        $timestamp = time2str("%Y-%m-%d %H:%M:%S", $time); 
+        if ($elapsed) {
+            my $elapsed = $time - $self->{_last_log_elapsed_time};
+            $timestamp .= " " . $elapsed;
+            $self->{_last_log_elapsed_time} = $time;
+        }
+    }
     if ($#_ > 0) {
-        my $fmt =  "[$$] " . time2str("%Y-%m-%d %H:%M:%S", time()) . " " . 
shift;
+        my $fmt =  "[$$] $timestamp " . shift;
         printf STDERR $fmt, @_;
     }
     elsif ($#_ == 0) {
-        print STDERR "[$$] ", time2str("%Y-%m-%d %H:%M:%S", time()), " ", @_;
+        print STDERR "[$$] $timestamp ", @_;
     }
     &App::sub_exit() if ($App::trace);
 }