1. Patchew
  2. QEMU
  3. View series

[RFC PATCH] scripts/tap-driver: report "slow" tests (HACK)

Alex Bennée posted 1 patch 4 years, 5 months ago
Test asan passed
Test checkpatch passed
Test FreeBSD passed
Test docker-mingw@fedora passed
Test docker-clang@ubuntu passed
Test docker-quick@centos7 passed
Patches applied successfully (tree, apply log)
git fetch https://github.com/patchew-project/qemu tags/patchew/20191113142101.30280-1-alex.bennee@linaro.org
scripts/tap-driver.pl | 18 +++++++++++++++---
1 file changed, 15 insertions(+), 3 deletions(-)
[RFC PATCH] scripts/tap-driver: report "slow" tests (HACK)
Posted by Alex Bennée 4 years, 5 months ago 
Some tests seem to run slower on CI systems but we don't really get
visibility of which it is unless we happen to hang the test at the end
of a run. This hacky change exposes "slow" tests in the tap output.

[AJB: my perl is rusty, I'm sure this could be more idiomatic]

Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
---
 scripts/tap-driver.pl | 18 +++++++++++++++---
 1 file changed, 15 insertions(+), 3 deletions(-)

diff --git a/scripts/tap-driver.pl b/scripts/tap-driver.pl
index 6621a5cd671..0fe748d5de6 100755
--- a/scripts/tap-driver.pl
+++ b/scripts/tap-driver.pl
@@ -29,6 +29,7 @@ use strict;
 use Getopt::Long ();
 use TAP::Parser;
 use Term::ANSIColor qw(:constants);
+use Time::HiRes qw( time );
 
 my $ME = "tap-driver.pl";
 my $VERSION = "2018-11-30";
@@ -111,7 +112,7 @@ sub decorate_result ($);
 sub extract_tap_comment ($);
 sub handle_tap_bailout ($);
 sub handle_tap_plan ($);
-sub handle_tap_result ($);
+sub handle_tap_result ($$);
 sub is_null_string ($);
 sub main ();
 sub report ($;$);
@@ -220,12 +221,18 @@ sub testsuite_error ($)
   report "ERROR", "- $_[0]";
 }
 
-sub handle_tap_result ($)
+sub handle_tap_result ($$)
 {
   $testno++;
   my $result_obj = shift;
+  my $time = shift;
 
   my $test_result = stringify_result_obj $result_obj;
+
+  if ($time > 1.0) {
+    $test_result = $test_result . sprintf(" (%0.1fs)", $time);
+  }
+
   my $string = $result_obj->number;
 
   my $description = $result_obj->description;
@@ -312,6 +319,9 @@ sub main ()
 {
   my $iterator = TAP::Parser::Iterator::Stream->new(\*STDIN);
   my $parser = TAP::Parser->new ({iterator => $iterator });
+  my ($start, $end);
+
+  $start = time();
 
   STDOUT->autoflush(1);
   while (defined (my $cur = $parser->next))
@@ -325,7 +335,9 @@ sub main ()
         }
       elsif ($cur->is_test)
         {
-          handle_tap_result ($cur);
+          $end = time();
+          handle_tap_result ($cur, $end - $start);
+          $start = time();
         }
       elsif ($cur->is_bailout)
         {
-- 
2.20.1
Re: [RFC PATCH] scripts/tap-driver: report "slow" tests (HACK)
Posted by Alex Bennée 4 years, 5 months ago 
Alex Bennée <alex.bennee@linaro.org> writes:

> Some tests seem to run slower on CI systems but we don't really get
> visibility of which it is unless we happen to hang the test at the end
> of a run. This hacky change exposes "slow" tests in the tap output.
>
> [AJB: my perl is rusty, I'm sure this could be more idiomatic]
>
> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>

ping? It would be nice to get this or something similar in 4.2

> ---
>  scripts/tap-driver.pl | 18 +++++++++++++++---
>  1 file changed, 15 insertions(+), 3 deletions(-)
>
> diff --git a/scripts/tap-driver.pl b/scripts/tap-driver.pl
> index 6621a5cd671..0fe748d5de6 100755
> --- a/scripts/tap-driver.pl
> +++ b/scripts/tap-driver.pl
> @@ -29,6 +29,7 @@ use strict;
>  use Getopt::Long ();
>  use TAP::Parser;
>  use Term::ANSIColor qw(:constants);
> +use Time::HiRes qw( time );
>
>  my $ME = "tap-driver.pl";
>  my $VERSION = "2018-11-30";
> @@ -111,7 +112,7 @@ sub decorate_result ($);
>  sub extract_tap_comment ($);
>  sub handle_tap_bailout ($);
>  sub handle_tap_plan ($);
> -sub handle_tap_result ($);
> +sub handle_tap_result ($$);
>  sub is_null_string ($);
>  sub main ();
>  sub report ($;$);
> @@ -220,12 +221,18 @@ sub testsuite_error ($)
>    report "ERROR", "- $_[0]";
>  }
>
> -sub handle_tap_result ($)
> +sub handle_tap_result ($$)
>  {
>    $testno++;
>    my $result_obj = shift;
> +  my $time = shift;
>
>    my $test_result = stringify_result_obj $result_obj;
> +
> +  if ($time > 1.0) {
> +    $test_result = $test_result . sprintf(" (%0.1fs)", $time);
> +  }
> +
>    my $string = $result_obj->number;
>
>    my $description = $result_obj->description;
> @@ -312,6 +319,9 @@ sub main ()
>  {
>    my $iterator = TAP::Parser::Iterator::Stream->new(\*STDIN);
>    my $parser = TAP::Parser->new ({iterator => $iterator });
> +  my ($start, $end);
> +
> +  $start = time();
>
>    STDOUT->autoflush(1);
>    while (defined (my $cur = $parser->next))
> @@ -325,7 +335,9 @@ sub main ()
>          }
>        elsif ($cur->is_test)
>          {
> -          handle_tap_result ($cur);
> +          $end = time();
> +          handle_tap_result ($cur, $end - $start);
> +          $start = time();
>          }
>        elsif ($cur->is_bailout)
>          {


--
Alex Bennée
Re: [RFC PATCH] scripts/tap-driver: report "slow" tests (HACK)
Posted by Wainer dos Santos Moschetta 4 years, 4 months ago 
On 11/19/19 5:54 AM, Alex Bennée wrote:
> Alex Bennée <alex.bennee@linaro.org> writes:
>
>> Some tests seem to run slower on CI systems but we don't really get
>> visibility of which it is unless we happen to hang the test at the end
>> of a run. This hacky change exposes "slow" tests in the tap output.
>>
>> [AJB: my perl is rusty, I'm sure this could be more idiomatic]
>>
>> Signed-off-by: Alex Bennée <alex.bennee@linaro.org>
> ping? It would be nice to get this or something similar in 4.2

I tested `make check` with this patch but I could not notice any 
different on output. Likely none of the tests ran beyond the time 
threshold. At least make check did not crash miserably, so:

Tested-by: Wainer dos Santos Moschetta <wainersm@redhat.com>

>
>> ---
>>   scripts/tap-driver.pl | 18 +++++++++++++++---
>>   1 file changed, 15 insertions(+), 3 deletions(-)
>>
>> diff --git a/scripts/tap-driver.pl b/scripts/tap-driver.pl
>> index 6621a5cd671..0fe748d5de6 100755
>> --- a/scripts/tap-driver.pl
>> +++ b/scripts/tap-driver.pl
>> @@ -29,6 +29,7 @@ use strict;
>>   use Getopt::Long ();
>>   use TAP::Parser;
>>   use Term::ANSIColor qw(:constants);
>> +use Time::HiRes qw( time );
>>
>>   my $ME = "tap-driver.pl";
>>   my $VERSION = "2018-11-30";
>> @@ -111,7 +112,7 @@ sub decorate_result ($);
>>   sub extract_tap_comment ($);
>>   sub handle_tap_bailout ($);
>>   sub handle_tap_plan ($);
>> -sub handle_tap_result ($);
>> +sub handle_tap_result ($$);
>>   sub is_null_string ($);
>>   sub main ();
>>   sub report ($;$);
>> @@ -220,12 +221,18 @@ sub testsuite_error ($)
>>     report "ERROR", "- $_[0]";
>>   }
>>
>> -sub handle_tap_result ($)
>> +sub handle_tap_result ($$)
>>   {
>>     $testno++;
>>     my $result_obj = shift;
>> +  my $time = shift;
>>
>>     my $test_result = stringify_result_obj $result_obj;
>> +
>> +  if ($time > 1.0) {
>> +    $test_result = $test_result . sprintf(" (%0.1fs)", $time);
>> +  }
>> +
>>     my $string = $result_obj->number;
>>
>>     my $description = $result_obj->description;
>> @@ -312,6 +319,9 @@ sub main ()
>>   {
>>     my $iterator = TAP::Parser::Iterator::Stream->new(\*STDIN);
>>     my $parser = TAP::Parser->new ({iterator => $iterator });
>> +  my ($start, $end);
>> +
>> +  $start = time();
>>
>>     STDOUT->autoflush(1);
>>     while (defined (my $cur = $parser->next))
>> @@ -325,7 +335,9 @@ sub main ()
>>           }
>>         elsif ($cur->is_test)
>>           {
>> -          handle_tap_result ($cur);
>> +          $end = time();
>> +          handle_tap_result ($cur, $end - $start);
>> +          $start = time();
>>           }
>>         elsif ($cur->is_bailout)
>>           {
>
> --
> Alex Bennée
>

Patchew 2.1-devel-0870f84

© 2016 - 2024 Red Hat, Inc.