Better instrument 067-preemptive-unpark
We're seeing mysterious failures. It would be nice to understand the
timing of various events. Print them on failure.
Bug: 22242462
Test: .../testrunner.py --host -b -t 067-premptive-unpark
Change-Id: I89e9efa9639e742cb7755f478909787dd7629e23
diff --git a/test/067-preemptive-unpark/src/Main.java b/test/067-preemptive-unpark/src/Main.java
index b674690..fa09462 100644
--- a/test/067-preemptive-unpark/src/Main.java
+++ b/test/067-preemptive-unpark/src/Main.java
@@ -52,6 +52,11 @@
System.out.println("Test succeeded!");
} else {
System.out.println("Test failed.");
+ test.printTimes();
+ System.out.println("Value of success = " + test.success);
+ Thread.sleep(3000);
+ System.out.println("Value of success after sleeping = " + test.success);
+ test.printTimes(); // In case they weren't ready the first time.
}
}
@@ -81,6 +86,7 @@
/**
* Scribbles on the stack to help ensure we don't have a fake
* pointer that would keep would-be garbage alive.
+ * TODO(hboehm): Remove this long useless cruft once we understand current failure.
*/
private static void clearStack(int depth) {
int a = 0;
@@ -102,6 +108,9 @@
private static class ParkTester extends Thread {
public volatile boolean parkNow = false;
public volatile boolean success = false;
+ public volatile long startTime = 0;
+ public volatile long elapsedTime = 0;
+ public volatile long finishTime = 0;
public void run() {
while (!parkNow) {
@@ -122,7 +131,15 @@
} else {
System.out.println("park() returned quickly");
success = true;
+ finishTime = System.currentTimeMillis();
+ startTime = start;
+ elapsedTime = elapsed;
}
}
+
+ public void printTimes() {
+ System.out.println("Started at " + startTime + "ms, took " + elapsedTime
+ + "ms, signalled at " + finishTime + "ms");
+ }
}
}