[OSSTEST PATCH 00/11] Improve performance of sg-report-host-history

[OSSTEST PATCH 00/11] Improve performance of sg-report-host-history

[Ian Jackson]

This is reasonably straightforward.

In my tests it reduces the time for an incremental run, with a hot
cache, from several hundred seconds to a handful of seconds.

This series really wants to go after the flight report improvements,
although the schema updates could be combined.

Ian Jackson (11):
  schema: Add index for quick lookup by host
  sg-report-host-history: Find flight limit by flight start date
  sg-report-host-history: Drop per-job debug etc.
  Executive: Export opendb_tests
  sg-report-host-history: Add a debug print after sorting jobs
  sg-report-host-history: Do the main query per host
  sg-report-host-history: Rerganisation: Make mainquery per-host
  sg-report-host-history: Rerganisation: Read old logs later
  sg-report-host-history: Rerganisation: Change loops
  sg-report-host-history: Drop a redundznt AND clause
  sg-report-host-history: Fork

 Osstest/Executive.pm          |   2 +-
 schema/runvars-host-index.sql |   8 ++
 sg-report-host-history        | 152 +++++++++++++++++++---------------
 3 files changed, 94 insertions(+), 68 deletions(-)
 create mode 100644 schema/runvars-host-index.sql

-- 
2.20.1

[OSSTEST PATCH 01/11] schema: Add index for quick lookup by host

[Ian Jackson]

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 schema/runvars-host-index.sql | 8 ++++++++
 1 file changed, 8 insertions(+)
 create mode 100644 schema/runvars-host-index.sql

diff --git a/schema/runvars-host-index.sql b/schema/runvars-host-index.sql
new file mode 100644
index 00000000..fec0b960
--- /dev/null
+++ b/schema/runvars-host-index.sql
@@ -0,0 +1,8 @@
+-- ##OSSTEST## 009 Preparatory
+--
+-- This index helps sg-report-host-history find relevant flights.
+
+CREATE INDEX runvars_host_idx
+    ON runvars (val, flight)
+ WHERE name ='host'
+    OR name LIKE '%_host';
-- 
2.20.1

[OSSTEST PATCH 02/11] sg-report-host-history: Find flight limit by flight start date

[Ian Jackson]

By default we look for anything in (roughly) the last year.

This query is in fact quite fast because the flights table is small.

There is still the per-host limit of $limit (2000) recent runs.

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 sg-report-host-history | 56 ++++++++++++++++++++----------------------
 1 file changed, 27 insertions(+), 29 deletions(-)

diff --git a/sg-report-host-history b/sg-report-host-history
index 54738e68..5dd875c1 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -29,6 +29,7 @@ use POSIX;
 use Osstest::Executive qw(:DEFAULT :colours);
 
 our $limit= 2000;
+our $timelimit= 86400 * (366 + 14);
 our $flightlimit;
 our $htmlout = ".";
 our $read_existing=1;
@@ -45,6 +46,8 @@ while (@ARGV && $ARGV[0] =~ m/^-/) {
     last if m/^--?$/;
     if (m/^--(limit)\=([1-9]\d*)$/) {
         $$1= $2;
+    } elsif (m/^--time-limit\=([1-9]\d*)$/) {
+        $timelimit= $1;
     } elsif (m/^--flight-limit\=([1-9]\d*)$/) {
 	$flightlimit= $1;
     } elsif (restrictflight_arg($_)) {
@@ -108,38 +111,33 @@ sub read_existing_logs ($) {
 }
 
 sub computeflightsrange () {
-    if (!$flightlimit) {
-	my $flagscond =
-	    '('.join(' OR ', map { "f.hostflag = 'blessed-$_'" } @blessings).')';
-	my $nhostsq = db_prepare(<<END);
-	    SELECT count(*)
-	      FROM resources r
-	     WHERE restype='host'
-	       AND EXISTS (SELECT 1
-			     FROM hostflags f
-			    WHERE f.hostname=r.resname
-			      AND $flagscond)
+    if ($flightlimit) {
+	my $minflightsq = db_prepare(<<END);
+	    SELECT flight
+	      FROM (
+		SELECT flight
+		  FROM flights
+		 WHERE $restrictflight_cond
+		 ORDER BY flight DESC
+		 LIMIT $flightlimit
+	      ) f
+	      ORDER BY flight ASC
+	      LIMIT 1
 END
-        $nhostsq->execute();
-	my ($nhosts) = $nhostsq->fetchrow_array();
-	print DEBUG "COUNTED $nhosts hosts\n";
-	$flightlimit = $nhosts * $limit * 2;
-    }
-
-    my $minflightsq = db_prepare(<<END);
-	SELECT flight
-	  FROM (
+	$minflightsq->execute();
+	($minflight,) = $minflightsq->fetchrow_array();
+    } else {
+	my $minflightsq = db_prepare(<<END);
 	    SELECT flight
-	      FROM flights
-             WHERE $restrictflight_cond
-	     ORDER BY flight DESC
-	     LIMIT $flightlimit
-	  ) f
-	  ORDER BY flight ASC
-	  LIMIT 1
+              FROM flights
+             WHERE started >= ?
+          ORDER BY flight ASC
+             LIMIT 1
 END
-    $minflightsq->execute();
-    ($minflight,) = $minflightsq->fetchrow_array();
+	my $now = time // die $!;
+        $minflightsq->execute($now - $timelimit);
+	($minflight,) = $minflightsq->fetchrow_array();
+    }
     $minflight //= 0;
 
     $flightcond = "(flight > $minflight)";
-- 
2.20.1

[OSSTEST PATCH 03/11] sg-report-host-history: Drop per-job debug etc.

[Ian Jackson]

This printing has a significant effect on the performance of this
program, at least after we optimise various other things.

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 sg-report-host-history | 14 +++++++-------
 1 file changed, 7 insertions(+), 7 deletions(-)

diff --git a/sg-report-host-history b/sg-report-host-history
index 5dd875c1..8b409fc7 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -102,9 +102,9 @@ sub read_existing_logs ($) {
 	    my $k = $1;
 	    s{\%([0-9a-f]{2})}{ chr hex $1 }ge;
 	    $ch->{$k} = $_;
-	    print DEBUG "GOTCACHE $hostname $k\n";
+#	    print DEBUG "GOTCACHE $hostname $k\n";
 	}
-	print DEBUG "GOTCACHE $hostname \@ $jr->{flight} $jr->{job} $jr->{status},$jr->{name}\n";
+#	print DEBUG "GOTCACHE $hostname \@ $jr->{flight} $jr->{job} $jr->{status},$jr->{name}\n";
 	$tcache->{$jr->{flight},$jr->{job},$jr->{status},$jr->{name}} = $jr;
     }
     close H;
@@ -272,7 +272,7 @@ END
     my @rows;
     my $cachehits = 0;
     foreach my $jr (@$inrows) {
-	print DEBUG "JOB $jr->{flight}.$jr->{job} ";
+	#print DEBUG "JOB $jr->{flight}.$jr->{job} ";
 
 	my $cacherow =
 	    $tcache->{$jr->{flight},$jr->{job},$jr->{status},$jr->{name}};
@@ -283,11 +283,11 @@ END
 
 	my $endedrow = jobquery($endedq, $jr, 'e');
 	if (!$endedrow) {
-	    print DEBUG "no-finished\n";
+	    #print DEBUG "no-finished\n";
 	    next;
 	}
-	print DEBUG join " ", map { $endedrow->{$_} } sort keys %$endedrow;
-	print DEBUG ".\n";
+	#print DEBUG join " ", map { $endedrow->{$_} } sort keys %$endedrow;
+	#print DEBUG ".\n";
 
 	push @rows, { %$jr, %$endedrow };
     }
@@ -329,7 +329,7 @@ END
 	    next;
 	}
 
-        print DEBUG "JR $jr->{flight}.$jr->{job}\n";
+        #print DEBUG "JR $jr->{flight}.$jr->{job}\n";
 	my $ir = jobquery($infoq, $jr, 'i');
 	my $ar = jobquery($allocdq, $jr, 'a');
 	my $ident = $jr->{name};
-- 
2.20.1

[OSSTEST PATCH 04/11] Executive: Export opendb_tests

[Ian Jackson]

sg-report-host-history is going to want this in a moment

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 Osstest/Executive.pm | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/Osstest/Executive.pm b/Osstest/Executive.pm
index 33de3708..c1095bac 100644
--- a/Osstest/Executive.pm
+++ b/Osstest/Executive.pm
@@ -49,7 +49,7 @@ BEGIN {
                       task_spec_desc findtask findtask_spec @all_lock_tables
                       restrictflight_arg restrictflight_cond
                       report_run_getinfo report_altcolour
-                      report_altchangecolour
+                      report_altchangecolour opendb_tests
                       report_blessingscond report_find_push_age_info
                       tcpconnect_queuedaemon plan_search
                       manual_allocation_base_jobinfo
-- 
2.20.1

[OSSTEST PATCH 05/11] sg-report-host-history: Add a debug print after sorting jobs

[Ian Jackson]

This helps rule this sort out as a source of slowness.

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 sg-report-host-history | 2 ++
 1 file changed, 2 insertions(+)

diff --git a/sg-report-host-history b/sg-report-host-history
index 8b409fc7..25a0c847 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -318,6 +318,8 @@ END
 
     @rows = sort { $b->{finished} <=> $a->{finished} } @rows;
 
+    print DEBUG "SORTED\n";
+
     my $alternate = 0;
     my $wrote = 0;
     my $runvarq_hits = 0;
-- 
2.20.1

[OSSTEST PATCH 06/11] sg-report-host-history: Do the main query per host

[Ian Jackson]

In f6001d628c3b3fd42b10cd15351981a04bc02572 we combined these
queries into one:
  sg-report-host-history: Aggregate runvars query for all hosts

Now that we have an index, there is a faster way for the db to do this
query: via that index.  But it doesn't like to do that if be aggregate
the queries.  Experimentally, doing this query separately once per
host is significantly faster.

Also, later, it will allow us to parallelise this work.

So, we undo that.  (Not by reverting, though.)

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 schema/runvars-host-index.sql |  2 +-
 sg-report-host-history        | 27 +++++++++------------------
 2 files changed, 10 insertions(+), 19 deletions(-)

diff --git a/schema/runvars-host-index.sql b/schema/runvars-host-index.sql
index fec0b960..cd6a1f9e 100644
--- a/schema/runvars-host-index.sql
+++ b/schema/runvars-host-index.sql
@@ -1,4 +1,4 @@
--- ##OSSTEST## 009 Preparatory
+-- ##OSSTEST## 009 Needed
 --
 -- This index helps sg-report-host-history find relevant flights.
 
diff --git a/sg-report-host-history b/sg-report-host-history
index 25a0c847..ab88828e 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -165,34 +165,25 @@ sub jobquery ($$$) {
 our %hosts;
 
 sub mainquery () {
-    our $valcond = join " OR ", map { "val = ?" } keys %hosts;
-    our @params = keys %hosts;
-
     our $runvarq //= db_prepare(<<END);
-	SELECT flight, job, name, val, status
+	SELECT flight, job, name, status
 	  FROM runvars
           JOIN jobs USING (flight, job)
-	 WHERE $namecond
-	   AND ($valcond)
+	 WHERE (name = 'host' OR name LIKE '%_host')
+	   AND val = ?
 	   AND $flightcond
            AND $restrictflight_cond
            AND flight > ?
 	 ORDER BY flight DESC
-	 LIMIT ($limit * 3 + 100) * ?
+         LIMIT $limit * 2
 END
+    foreach my $host (sort keys %hosts) {
+	print DEBUG "MAINQUERY $host...\n";
+	$runvarq->execute($host, $minflight);
 
-    push @params, $minflight;
-    push @params, scalar keys %hosts;
-
-    print DEBUG "MAINQUERY...\n";
-    $runvarq->execute(@params);
-
-    print DEBUG "FIRST PASS\n";
-    while (my $jr= $runvarq->fetchrow_hashref()) {
-	print DEBUG " $jr->{flight}.$jr->{job} ";
-	push @{ $hosts{$jr->{val}} }, $jr;
+	$hosts{$host} = $runvarq->fetchall_arrayref({});
+	print DEBUG "MAINQUERY $host got ".(scalar @{ $hosts{$host} })."\n";
     }
-    print DEBUG "\n";
 }
 
 sub reporthost ($) {
-- 
2.20.1

[OSSTEST PATCH 07/11] sg-report-host-history: Rerganisation: Make mainquery per-host

[Ian Jackson]

This moves the loop over hosts into the main program.  We are working
our way to a new code structure.

No functional change.

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 sg-report-host-history | 19 +++++++++++--------
 1 file changed, 11 insertions(+), 8 deletions(-)

diff --git a/sg-report-host-history b/sg-report-host-history
index ab88828e..509d053d 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -164,7 +164,9 @@ sub jobquery ($$$) {
 
 our %hosts;
 
-sub mainquery () {
+sub mainquery ($) {
+    my ($host) = @_;
+
     our $runvarq //= db_prepare(<<END);
 	SELECT flight, job, name, status
 	  FROM runvars
@@ -177,13 +179,12 @@ sub mainquery () {
 	 ORDER BY flight DESC
          LIMIT $limit * 2
 END
-    foreach my $host (sort keys %hosts) {
-	print DEBUG "MAINQUERY $host...\n";
-	$runvarq->execute($host, $minflight);
 
-	$hosts{$host} = $runvarq->fetchall_arrayref({});
-	print DEBUG "MAINQUERY $host got ".(scalar @{ $hosts{$host} })."\n";
-    }
+    print DEBUG "MAINQUERY $host...\n";
+    $runvarq->execute($host, $minflight);
+
+    $hosts{$host} = $runvarq->fetchall_arrayref({});
+    print DEBUG "MAINQUERY $host got ".(scalar @{ $hosts{$host} })."\n";
 }
 
 sub reporthost ($) {
@@ -473,7 +474,9 @@ db_retry($dbh_tests, [], sub {
 });
 
 db_retry($dbh_tests, [], sub {
-    mainquery();
+    foreach my $host (sort keys %hosts) {
+	mainquery($host);
+    }
 });
 
 foreach my $host (sort keys %hosts) {
-- 
2.20.1

[OSSTEST PATCH 08/11] sg-report-host-history: Rerganisation: Read old logs later

[Ian Jackson]

Perhaps at one point something read from these logs influenced the db
query for thye flights range, but that is no longer the case and it
doesn't seem likely to need to come back.

We want to move the per-host stuff together.

No functional change.

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 sg-report-host-history | 8 ++++----
 1 file changed, 4 insertions(+), 4 deletions(-)

diff --git a/sg-report-host-history b/sg-report-host-history
index 509d053d..4b0b5b2d 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -465,14 +465,14 @@ END
 
 exit 0 unless %hosts;
 
-foreach (keys %hosts) {
-    read_existing_logs($_);
-}
-
 db_retry($dbh_tests, [], sub {
     computeflightsrange();
 });
 
+foreach (keys %hosts) {
+    read_existing_logs($_);
+}
+
 db_retry($dbh_tests, [], sub {
     foreach my $host (sort keys %hosts) {
 	mainquery($host);
-- 
2.20.1

[OSSTEST PATCH 09/11] sg-report-host-history: Rerganisation: Change loops

[Ian Jackson]

Move the per-host code all into the same per-host loop.  One effect is
to transpose the db_retry and host loops for mainquery.

No functional change.

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 sg-report-host-history | 12 ++----------
 1 file changed, 2 insertions(+), 10 deletions(-)

diff --git a/sg-report-host-history b/sg-report-host-history
index 4b0b5b2d..1f5c14e1 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -469,18 +469,10 @@ db_retry($dbh_tests, [], sub {
     computeflightsrange();
 });
 
-foreach (keys %hosts) {
-    read_existing_logs($_);
-}
-
-db_retry($dbh_tests, [], sub {
-    foreach my $host (sort keys %hosts) {
-	mainquery($host);
-    }
-});
-
 foreach my $host (sort keys %hosts) {
+    read_existing_logs($host);
     db_retry($dbh_tests, [], sub {
+        mainquery($host);
 	reporthost $host;
     });
 }
-- 
2.20.1

[OSSTEST PATCH 10/11] sg-report-host-history: Drop a redundznt AND clause

[Ian Jackson]

This condition is the same as $flightcond.  (This has no effect on the
db performance since the query planner figures it out, but it is
confusing.)

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 sg-report-host-history | 3 +--
 1 file changed, 1 insertion(+), 2 deletions(-)

diff --git a/sg-report-host-history b/sg-report-host-history
index 1f5c14e1..787f7c5b 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -175,13 +175,12 @@ sub mainquery ($) {
 	   AND val = ?
 	   AND $flightcond
            AND $restrictflight_cond
-           AND flight > ?
 	 ORDER BY flight DESC
          LIMIT $limit * 2
 END
 
     print DEBUG "MAINQUERY $host...\n";
-    $runvarq->execute($host, $minflight);
+    $runvarq->execute($host);
 
     $hosts{$host} = $runvarq->fetchall_arrayref({});
     print DEBUG "MAINQUERY $host got ".(scalar @{ $hosts{$host} })."\n";
-- 
2.20.1

[OSSTEST PATCH 11/11] sg-report-host-history: Fork

[Ian Jackson]

Run each host's report in a separate child.  This is considerably
faster.

Signed-off-by: Ian Jackson <ian.jackson@eu.citrix.com>
---
 sg-report-host-history | 47 +++++++++++++++++++++++++++++++++++-------
 1 file changed, 40 insertions(+), 7 deletions(-)

diff --git a/sg-report-host-history b/sg-report-host-history
index 787f7c5b..d8e19127 100755
--- a/sg-report-host-history
+++ b/sg-report-host-history
@@ -34,6 +34,7 @@ our $flightlimit;
 our $htmlout = ".";
 our $read_existing=1;
 our $doinstall=1;
+our $maxjobs=10;
 our @blessings;
 
 open DEBUG, ">/dev/null";
@@ -44,7 +45,7 @@ csreadconfig();
 while (@ARGV && $ARGV[0] =~ m/^-/) {
     $_= shift @ARGV;
     last if m/^--?$/;
-    if (m/^--(limit)\=([1-9]\d*)$/) {
+    if (m/^--(limit|maxjobs)\=([1-9]\d*)$/) {
         $$1= $2;
     } elsif (m/^--time-limit\=([1-9]\d*)$/) {
         $timelimit= $1;
@@ -468,12 +469,44 @@ db_retry($dbh_tests, [], sub {
     computeflightsrange();
 });
 
+undef $dbh_tests;
+
+our %children;
+our $worst = 0;
+
+sub wait_for_max_children ($) {
+    my ($lim) = @_;
+    while (keys(%children) > $lim) {
+	$!=0; $?=0; my $got = wait;
+	die "$! $got $?" unless exists $children{$got};
+	my $host = $children{$got};
+	delete $children{$got};
+	$worst = $? if $? > $worst;
+	if ($?) {
+	    print STDERR "sg-report-flight[: [$got] failed for $host: $?\n";
+	} else {
+	    print DEBUG "REAPED [$got] $host\n";
+	}
+    }
+}
+
 foreach my $host (sort keys %hosts) {
-    read_existing_logs($host);
-    db_retry($dbh_tests, [], sub {
-        mainquery($host);
-	reporthost $host;
-    });
+    wait_for_max_children($maxjobs);
+
+    my $pid = fork // die $!;
+    if (!$pid) {
+	opendb_tests();
+	read_existing_logs($host);
+	db_retry($dbh_tests, [], sub {
+            mainquery($host);
+	    reporthost $host;
+	});
+	print DEBUG "JQ CACHE ".($jqtotal-$jqcachemisses)." / $jqtotal\n";
+	exit(0);
+    }
+    print DEBUG "SPAWNED [$pid] $host\n";
+    $children{$pid} = $host;
 }
 
-print DEBUG "JQ CACHE ".($jqtotal-$jqcachemisses)." / $jqtotal\n";
+wait_for_max_children(0);
+exit $worst;
-- 
2.20.1