From 8e93cd01c7d2ffafb3a9282a453d8bed222b0e49 Mon Sep 17 00:00:00 2001
From: Chip Morningstar <chip@fudco.com>
Date: Thu, 10 Sep 2020 11:51:53 -0700
Subject: [PATCH] feat: further minor perf instrumentation tweaks

---
 .../demo/megaPong/vat-alice.js                | 16 ++++++-------
 .../swingset-runner/demo/megaPong/vat-bob.js  | 16 ++++++-------
 packages/swingset-runner/polywhacker          | 16 +++++++++++++
 packages/swingset-runner/src/main.js          | 24 +++++++------------
 packages/swingset-runner/trun                 |  4 ++--
 packages/swingset-runner/whacker              | 12 ++++++++++
 6 files changed, 55 insertions(+), 33 deletions(-)
 create mode 100755 packages/swingset-runner/polywhacker
 create mode 100755 packages/swingset-runner/whacker

diff --git a/packages/swingset-runner/demo/megaPong/vat-alice.js b/packages/swingset-runner/demo/megaPong/vat-alice.js
index 30370c2c865..c8696a4387b 100644
--- a/packages/swingset-runner/demo/megaPong/vat-alice.js
+++ b/packages/swingset-runner/demo/megaPong/vat-alice.js
@@ -4,14 +4,14 @@ const log = console.log;
 
 // Ping Print Predicate, a hack to reduce log spam
 function ppp(count) {
-  if (count > 10000) {
-    return count % 10000 === 0;
-  } else if (count > 1000) {
-    return count % 1000 === 0;
-  } else if (count > 100) {
-    return count % 100 === 0;
-  } else if (count > 10) {
-    return count % 10 === 0;
+  if (count > 9999) {
+    return count % 9999 === 0;
+  } else if (count > 999) {
+    return count % 999 === 0;
+  } else if (count > 99) {
+    return count % 99 === 0;
+  } else if (count > 9) {
+    return count % 9 === 0;
   } else {
     return true;
   }
diff --git a/packages/swingset-runner/demo/megaPong/vat-bob.js b/packages/swingset-runner/demo/megaPong/vat-bob.js
index 6872bbb6c85..763b907c857 100644
--- a/packages/swingset-runner/demo/megaPong/vat-bob.js
+++ b/packages/swingset-runner/demo/megaPong/vat-bob.js
@@ -4,14 +4,14 @@ const log = console.log;
 
 // Ping Print Predicate, a hack to reduce log spam
 function ppp(count) {
-  if (count > 10000) {
-    return count % 10000 === 0;
-  } else if (count > 1000) {
-    return count % 1000 === 0;
-  } else if (count > 100) {
-    return count % 100 === 0;
-  } else if (count > 10) {
-    return count % 10 === 0;
+  if (count > 9999) {
+    return count % 9999 === 0;
+  } else if (count > 999) {
+    return count % 999 === 0;
+  } else if (count > 99) {
+    return count % 99 === 0;
+  } else if (count > 9) {
+    return count % 9 === 0;
   } else {
     return true;
   }
diff --git a/packages/swingset-runner/polywhacker b/packages/swingset-runner/polywhacker
new file mode 100755
index 00000000000..617fd365847
--- /dev/null
+++ b/packages/swingset-runner/polywhacker
@@ -0,0 +1,16 @@
+#!/bin/bash
+
+reference='=> alice contact for bob receives ping: 1 hey!'
+success=0
+failure=0
+
+while [ 1 ]; do
+  result=`./whacker`
+  if [ "$result" == "$reference" ]; then
+    ((success=success+1))
+    echo "ok (success: $success failure: $failure)"
+  else
+    ((failure=failure+1))
+    echo "bad (success: $success failure: $failure)"
+  fi
+done
diff --git a/packages/swingset-runner/src/main.js b/packages/swingset-runner/src/main.js
index 58832f3ed07..b00621ccffd 100644
--- a/packages/swingset-runner/src/main.js
+++ b/packages/swingset-runner/src/main.js
@@ -360,7 +360,7 @@ export async function main() {
   if (logTimes || logMem || logDisk) {
     let headers = ['block', 'steps'];
     if (logTimes) {
-      headers.push('btime');
+      headers.push('btime', 'ctime');
     }
     if (logMem) {
       headers = headers.concat(['rss', 'heapTotal', 'heapUsed', 'external']);
@@ -529,6 +529,7 @@ export async function main() {
         log(`===> end of crank ${crankNumber}`);
       }
     }
+    const commitStartTime = readClock();
     if (doCommit) {
       store.commit();
     }
@@ -541,6 +542,7 @@ export async function main() {
       let data = [blockNumber, actualSteps];
       if (logTimes) {
         data.push(blockEndTime - blockStartTime);
+        data.push(blockEndTime - commitStartTime);
       }
       if (logMem) {
         const mem = process.memoryUsage();
@@ -609,21 +611,13 @@ export async function main() {
         bootstrapResult = null;
       }
     }
-    if (logTimes) {
-      if (totalSteps) {
-        const per = deltaT / BigInt(totalSteps);
-        log(
-          `runner finished ${totalSteps} cranks in ${deltaT} ns (${per}/crank)`,
-        );
-      } else {
-        log(`runner finished replay in ${deltaT} ns`);
-      }
+    if (totalSteps) {
+      const per = deltaT / BigInt(totalSteps);
+      log(
+        `runner finished ${totalSteps} cranks in ${deltaT} ns (${per}/crank)`,
+      );
     } else {
-      if (totalSteps) {
-        log(`runner finished ${totalSteps} cranks`);
-      } else {
-        log(`runner finished replay`);
-      }
+      log(`runner finished replay in ${deltaT} ns`);
     }
   }
 }
diff --git a/packages/swingset-runner/trun b/packages/swingset-runner/trun
index 8e0aa954b20..c2db0a7640f 100755
--- a/packages/swingset-runner/trun
+++ b/packages/swingset-runner/trun
@@ -47,9 +47,9 @@ function runone {
     cmdargs="$cmdargs --dump --dumptag t${runct}-"
   fi
   cmdline="$cmd $cmdargs $@"
-  echo "$cmdline"
+  echo "$cmdline > rlog-${runct}"
   if [ $dotime ]; then
-    time $cmdline > rlog-${runct}
+    (time $cmdline) >& rlog-${runct}
   else
     $cmdline > rlog-${runct}
   fi
diff --git a/packages/swingset-runner/whacker b/packages/swingset-runner/whacker
new file mode 100755
index 00000000000..492595c7cf5
--- /dev/null
+++ b/packages/swingset-runner/whacker
@@ -0,0 +1,12 @@
+#!/bin/bash
+
+t=`jot -p 3 -r 1 3 15`
+#echo killing after ${t} secs
+bin/runner --init --blockmode run demo/megapong 10000 > /dev/null &
+pid=$!
+sleep ${t}
+kill -9 ${pid} >& /dev/null
+wait ${pid} >& /dev/null
+sleep 1
+#echo @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
+bin/runner --blockmode run demo/megapong 10000 | grep 'alice contact' | tail -1