From 045bb2988a526696c13b0dcf7eb952b38aca54a5 Mon Sep 17 00:00:00 2001
From: Tony Sarajarvi <tony.sarajarvi@digia.com>
Date: Wed, 17 Apr 2013 11:51:09 +0300
Subject: [PATCH] Add timestamp and phase entry and exit prints to build log.
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

When testscript.pm now enters a new job or phase, it will print to
log a timestamped entry. This will also be printed with duration
at the point of exit.
example of entry and exit:
09:34:21 #=# Wed Apr 17 09:34:21 2013 #=# >cleaning existing target directories
09:34:36 #=# Wed Apr 17 09:34:36 2013 #=# <cleaning existing target directories #=# Elapsed 15 second(s).

Change-Id: I76a300244ea09193f877f57c3ed1f9e44a4b3d2b
Reviewed-by: Janne Anttila <janne.anttila@digia.com>
Reviewed-by: Simo Fält <simo.falt@digia.com>
---
 scripts/lib/perl5/QtQA/TestScript.pm | 8 ++++++++
 1 file changed, 8 insertions(+)

diff --git a/scripts/lib/perl5/QtQA/TestScript.pm b/scripts/lib/perl5/QtQA/TestScript.pm
index 609afd3c..fc66231d 100644
--- a/scripts/lib/perl5/QtQA/TestScript.pm
+++ b/scripts/lib/perl5/QtQA/TestScript.pm
@@ -526,6 +526,10 @@ sub _push_context
 
     push @{ $self->{ _context } }, $thing;
 
+    my $time = time();
+    push @{ $self->{ _context_start } }, $time;
+    print "#=# ". localtime($time) ." #=# >$thing\n";
+
     return;
 }
 
@@ -538,6 +542,10 @@ sub _pop_context
         $self->_warn( "scope mismatch: leaving context '$actual_thing', expecting to leave '$thing'" );
     }
 
+    my $time = time();
+    my $elapsed = $time - pop @{ $self->{ _context_start } || [] };
+    print "#=# ". localtime($time) ." #=# <$thing #=# Elapsed $elapsed second(s).\n";
+
     return;
 }
 
-- 
GitLab