[gnugo-devel] slowest moves statistic from regress.pike

[Arend Bayer]

When measuring performance improvements/losses, we effectivel only measure
average time spent per move. However, both for the "gnugo user
experience", and for reasonable time management in games with time
limits, the worst case behaviour is very important.

Thus the patch below to regress.pike. (I added a generic highscore list
class to make it easy to add other statistics.)
A run ./regress.pike --slow-moves=40 produced the output below.

Arend

P.S.: Yes, this is no longer on my K6-II 400 MHz, in case anyone
wonders...

Slowest moves:
lazarus:6: 14.764 seconds
nngs:290: 14.875 seconds
nngs:390: 15.022 seconds
strategy3:112: 15.065 seconds
nngs4:470: 15.166 seconds
nngs3:970: 16.010 seconds
strategy3:113: 16.125 seconds
nngs:250: 16.179 seconds
nngs3:220: 16.224 seconds
nngs4:160: 16.395 seconds
lazarus:16: 16.426 seconds
nngs3:380: 17.027 seconds
handtalk:20: 17.102 seconds
nngs3:400: 17.283 seconds
nngs4:1030: 17.328 seconds
nngs:500: 17.382 seconds
nngs2:20: 17.834 seconds
ninestones:640: 18.064 seconds
ninestones:650: 18.112 seconds
13x13:52: 18.282 seconds
nngs4:1040: 18.840 seconds
neurogo:13: 18.858 seconds
arend2:80: 18.957 seconds
strategy4:219: 19.124 seconds
nngs2:30: 19.391 seconds
nngs3:410: 20.173 seconds
lazarus:9: 21.389 seconds
nngs3:250: 22.000 seconds
lazarus:8: 22.001 seconds
nngs3:760: 23.110 seconds
strategy2:55: 23.606 seconds
13x13:63: 25.022 seconds
nngs4:650: 26.935 seconds
neurogo:14: 27.228 seconds
nngs3:240: 27.880 seconds
nngs3:260: 28.022 seconds
neurogo:11: 28.267 seconds
nngs4:150: 33.451 seconds
nngs3:270: 37.833 seconds
(ninestones:670: 44.118 seconds) <-- accounting error


Index: regression/regress.pike
===================================================================
RCS file: /cvsroot/gnugo/gnugo/regression/regress.pike,v
retrieving revision 1.7
diff -u -p -r1.7 regress.pike
--- regression/regress.pike     25 Jan 2004 21:35:38 -0000      1.7
+++ regression/regress.pike     29 Mar 2004 06:42:47 -0000
@@ -15,6 +15,49 @@ static int total_pass = 0;
 static int total_fail = 0;
 static int verbose = 0;

+/* General class to manage a high-score list (e.g. of slow tests, tests
+ * with many nodes, ..)
+ */
+class Highscorelist
+{
+  array(float) scores;
+  array(string) names;
+  int max;
+
+  void create(int m)
+  {
+    max = m;
+    scores = ({});
+    names = ({});
+  }
+
+  void add_score(float score, string name)
+  {
+    int num = sizeof(scores);
+    if (num != sizeof(names)) {
+      write("This should not happen!!");
+      return;
+    }
+    if (num < max) {
+      scores += ({score});
+      names += ({name});
+      sort(scores, names);
+    }
+    else if (scores[0] < score) {
+      scores[0] = score;
+      names[0] = name;
+      sort(scores, names);
+    }
+    return;
+  }
+
+  void report(string s)
+  {
+    for (int i = 0; i < sizeof(scores); i++)
+      write(s, names[i], scores[i]);
+  }
+}
+
 class Testsuite
 {
   string name;
@@ -46,6 +89,9 @@ class Testsuite
 array(Testsuite) testsuites = ({});
 Testsuite current_testsuite;

+Highscorelist slow_moves;
+int report_slow = 0;
+
 void send(string|void s)
 {
   if (!s) {
@@ -113,6 +159,9 @@ static void program_reader(object f)
        }
        current_testsuite[result] += ({test_number});
        current_testsuite->time += (current_time - last_time);
+       if (report_slow)
+         slow_moves->add_score(current_time - last_time,
+                               current_testsuite->name + ":" + test_number);

        if (result == "PASS" || result == "FAIL" || verbose)
          write("%-15s %s %s [%s]\n",
@@ -283,6 +332,10 @@ void final_report()
     write("%d PASS\n", number_unexpected_pass);
   if (number_unexpected_fail > 0)
     write("%d FAIL\n", number_unexpected_fail);
+  if (report_slow) {
+    write("Slowest moves:\n");
+    slow_moves->report("%s: %f seconds\n");
+  }
 }

 string parse_tests(mapping(string:array(int)) partial_testsuites,
@@ -333,6 +386,7 @@ int main(int argc, array(string) argv)
                   ({"valgrind", Getopt.NO_ARG, "--valgrind"}),
                   ({"check-unoccupied-answers", Getopt.NO_ARG,
                     "--check-unoccupied"}),
+                  ({"slow_moves", Getopt.HAS_ARG, ({"-s", "--slow-moves"})}),
                   ({"engine", Getopt.HAS_ARG, ({"-e", "--engine"})}),
                   ({"options", Getopt.HAS_ARG, ({"-o", "--options"})}),
                   ({"file", Getopt.HAS_ARG, ({"-f", "--file"})})});
@@ -368,6 +422,11 @@ int main(int argc, array(string) argv)
       case "options":
        engine_options += value / " ";
        break;
+
+      case "slow_moves":
+        report_slow = 1;
+        slow_moves = Highscorelist((int) value);
+        break;

       case "file":
        string testlist = Stdio.read_file(value);