Add FinalizerTimeoutMs argument, and respect it

Add -XX:FinalizerTimeoutMs commandline argument, and make it
available for libcore.

Add 1336-short-finalizer-timeout to test it. Blacklist it for
the cases in which 030-bad-finalizers was known not to work,
since it's largely a clone. Disable it for gcstress, since timeout
margins are tight.

Increase timeout in 030-bad-finalizers due to gcstress issues.

Use the result in 004-NativeAllocations and 030-bad-finalizers
to avoid timeouts. Make 004-NativeAllocations more proactive in
avoiding timeout.

This is intended as a replacement for aosp/836642 .

Bug: 129350738
Bug: 68792448
Test: Boot AOSP, TreeHugger
Change-Id: I9aef9c9bacb7e8d851bd2c879ed9fb5b596abc60
diff --git a/cmdline/cmdline_types.h b/cmdline/cmdline_types.h
index 1f63d7d..dd9221d 100644
--- a/cmdline/cmdline_types.h
+++ b/cmdline/cmdline_types.h
@@ -237,7 +237,7 @@
     return ParseNumeric<int>(str);
   }
 
-  static const char* Name() { return "unsigned integer"; }
+  static const char* Name() { return "integer"; }
 };
 
 // Lightweight nanosecond value type. Allows parser to convert user-input from milliseconds
diff --git a/runtime/native/dalvik_system_VMRuntime.cc b/runtime/native/dalvik_system_VMRuntime.cc
index 7fb3c40..c233171 100644
--- a/runtime/native/dalvik_system_VMRuntime.cc
+++ b/runtime/native/dalvik_system_VMRuntime.cc
@@ -308,6 +308,10 @@
   Runtime::Current()->GetHeap()->NotifyNativeAllocations(env);
 }
 
+static jlong VMRuntime_getFinalizerTimeoutMs(JNIEnv*, jobject) {
+  return Runtime::Current()->GetFinalizerTimeoutMs();
+}
+
 static void VMRuntime_registerSensitiveThread(JNIEnv*, jobject) {
   Runtime::Current()->RegisterSensitiveThread();
 }
@@ -737,6 +741,7 @@
   NATIVE_METHOD(VMRuntime, registerNativeAllocation, "(J)V"),
   NATIVE_METHOD(VMRuntime, registerNativeFree, "(J)V"),
   NATIVE_METHOD(VMRuntime, getNotifyNativeInterval, "()I"),
+  NATIVE_METHOD(VMRuntime, getFinalizerTimeoutMs, "()J"),
   NATIVE_METHOD(VMRuntime, notifyNativeAllocationsInternal, "()V"),
   NATIVE_METHOD(VMRuntime, notifyStartupCompleted, "()V"),
   NATIVE_METHOD(VMRuntime, registerSensitiveThread, "()V"),
diff --git a/runtime/parsed_options.cc b/runtime/parsed_options.cc
index cf0d478..8172e1d 100644
--- a/runtime/parsed_options.cc
+++ b/runtime/parsed_options.cc
@@ -141,6 +141,9 @@
       .Define("-XX:ConcGCThreads=_")
           .WithType<unsigned int>()
           .IntoKey(M::ConcGCThreads)
+      .Define("-XX:FinalizerTimeoutMs=_")
+          .WithType<unsigned int>()
+          .IntoKey(M::FinalizerTimeoutMs)
       .Define("-Xss_")
           .WithType<Memory<1>>()
           .IntoKey(M::StackSize)
@@ -710,6 +713,7 @@
   UsageMessage(stream, "  -XX:+DisableExplicitGC\n");
   UsageMessage(stream, "  -XX:ParallelGCThreads=integervalue\n");
   UsageMessage(stream, "  -XX:ConcGCThreads=integervalue\n");
+  UsageMessage(stream, "  -XX:FinalizerTimeoutMs=integervalue\n");
   UsageMessage(stream, "  -XX:MaxSpinsBeforeThinLockInflation=integervalue\n");
   UsageMessage(stream, "  -XX:LongPauseLogThreshold=integervalue\n");
   UsageMessage(stream, "  -XX:LongGCLogThreshold=integervalue\n");
diff --git a/runtime/runtime.cc b/runtime/runtime.cc
index c649221..c978b83 100644
--- a/runtime/runtime.cc
+++ b/runtime/runtime.cc
@@ -1211,6 +1211,7 @@
   }
   image_compiler_options_ = runtime_options.ReleaseOrDefault(Opt::ImageCompilerOptions);
 
+  finalizer_timeout_ms_ = runtime_options.GetOrDefault(Opt::FinalizerTimeoutMs);
   max_spins_before_thin_lock_inflation_ =
       runtime_options.GetOrDefault(Opt::MaxSpinsBeforeThinLockInflation);
 
diff --git a/runtime/runtime.h b/runtime/runtime.h
index 449a5a4..e811230 100644
--- a/runtime/runtime.h
+++ b/runtime/runtime.h
@@ -272,6 +272,10 @@
     return default_stack_size_;
   }
 
+  unsigned int GetFinalizerTimeoutMs() const {
+    return finalizer_timeout_ms_;
+  }
+
   gc::Heap* GetHeap() const {
     return heap_;
   }
@@ -944,6 +948,9 @@
   // The default stack size for managed threads created by the runtime.
   size_t default_stack_size_;
 
+  // Finalizers running for longer than this many milliseconds abort the runtime.
+  unsigned int finalizer_timeout_ms_;
+
   gc::Heap* heap_;
 
   std::unique_ptr<ArenaPool> jit_arena_pool_;
diff --git a/runtime/runtime_options.def b/runtime/runtime_options.def
index 41f0634..95a3f4c 100644
--- a/runtime/runtime_options.def
+++ b/runtime/runtime_options.def
@@ -55,6 +55,7 @@
 RUNTIME_OPTIONS_KEY (double,              ForegroundHeapGrowthMultiplier, gc::Heap::kDefaultHeapGrowthMultiplier)
 RUNTIME_OPTIONS_KEY (unsigned int,        ParallelGCThreads,              0u)
 RUNTIME_OPTIONS_KEY (unsigned int,        ConcGCThreads)
+RUNTIME_OPTIONS_KEY (unsigned int,        FinalizerTimeoutMs,             10000u)
 RUNTIME_OPTIONS_KEY (Memory<1>,           StackSize)  // -Xss
 RUNTIME_OPTIONS_KEY (unsigned int,        MaxSpinsBeforeThinLockInflation,Monitor::kDefaultMaxSpinsBeforeThinLockInflation)
 RUNTIME_OPTIONS_KEY (MillisecondsToNanoseconds, \
diff --git a/test/004-NativeAllocations/src-art/Main.java b/test/004-NativeAllocations/src-art/Main.java
index 6b1c48d..7bd064c 100644
--- a/test/004-NativeAllocations/src-art/Main.java
+++ b/test/004-NativeAllocations/src-art/Main.java
@@ -23,6 +23,7 @@
     static Object deadlockLock = new Object();
     static VMRuntime runtime = VMRuntime.getRuntime();
     static volatile boolean aboutToDeadlock = false;
+    static final long MAX_EXPECTED_GC_DURATION_MS = 2000;
 
     // Save ref as a static field to ensure it doesn't get GC'd before the
     // referent is enqueued.
@@ -49,7 +50,6 @@
         long maxMem = Runtime.getRuntime().maxMemory();
         int size = (int)(maxMem / 32);
         int allocationCount = 256;
-        int maxExpectedGcDurationMs = 2000;
 
         ReferenceQueue<Object> queue = new ReferenceQueue<Object>();
         ref = allocPhantom(queue);
@@ -61,14 +61,14 @@
             // Sleep a little bit to ensure not all of the calls to
             // registerNativeAllocation complete while GC is in the process of
             // running.
-            Thread.sleep(maxExpectedGcDurationMs / allocationCount);
+            Thread.sleep(MAX_EXPECTED_GC_DURATION_MS / allocationCount);
         }
 
-        // Wait up to maxExpectedGcDurationMs to give GC a chance to finish
+        // Wait up to MAX_EXPECTED_GC_DURATION_MS to give GC a chance to finish
         // running. If the reference isn't enqueued after that, then it is
         // pretty unlikely (though technically still possible) that GC was
         // triggered as intended.
-        if (queue.remove(maxExpectedGcDurationMs) == null) {
+        if (queue.remove(MAX_EXPECTED_GC_DURATION_MS) == null) {
             throw new RuntimeException("GC failed to complete");
         }
 
@@ -78,15 +78,18 @@
         }
     }
 
-    // Call registerNativeAllocation repeatedly at a high rate to trigger the
-    // case of blocking registerNativeAllocation.
+    // Call registerNativeAllocation repeatedly at a high rate to trigger the case of blocking
+    // registerNativeAllocation. Stop before we risk exhausting the finalizer timeout.
     private static void triggerBlockingRegisterNativeAllocation() throws Exception {
+        final long startTime = System.currentTimeMillis();
+        final long finalizerTimeoutMs = VMRuntime.getRuntime().getFinalizerTimeoutMs();
+        final long quittingTime = startTime + finalizerTimeoutMs - MAX_EXPECTED_GC_DURATION_MS;
         long maxMem = Runtime.getRuntime().maxMemory();
         int size = (int)(maxMem / 5);
         int allocationCount = 10;
 
         long total = 0;
-        for (int i = 0; i < allocationCount; ++i) {
+        for (int i = 0; i < allocationCount && System.currentTimeMillis() < quittingTime; ++i) {
             runtime.registerNativeAllocation(size);
             total += size;
         }
diff --git a/test/030-bad-finalizer/src/Main.java b/test/030-bad-finalizer/src/Main.java
index 71167c1..a912f7d 100644
--- a/test/030-bad-finalizer/src/Main.java
+++ b/test/030-bad-finalizer/src/Main.java
@@ -14,6 +14,7 @@
  * limitations under the License.
  */
 
+import dalvik.system.VMRuntime;
 import java.util.concurrent.CountDownLatch;
 import static java.util.concurrent.TimeUnit.MINUTES;
 
@@ -41,9 +42,11 @@
 
         // Now fall asleep with a timeout. The timeout is large enough that we expect the
         // finalizer daemon to have killed the process before the deadline elapses.
+        // The timeout is also large enough to cover the extra 5 seconds we wait
+        // to dump threads, plus potentially substantial gcstress overhead.
         // Note: the timeout is here (instead of an infinite sleep) to protect the test
         //       environment (e.g., in case this is run without a timeout wrapper).
-        final long timeout = 60 * 1000;  // 1 minute.
+        final long timeout = 100 * 1000 + VMRuntime.getRuntime().getFinalizerTimeoutMs();
         long remainingWait = timeout;
         final long waitStart = System.currentTimeMillis();
         while (remainingWait > 0) {
diff --git a/test/1336-short-finalizer-timeout/check b/test/1336-short-finalizer-timeout/check
new file mode 100755
index 0000000..e5d5c4e
--- /dev/null
+++ b/test/1336-short-finalizer-timeout/check
@@ -0,0 +1,20 @@
+#!/bin/bash
+#
+# Copyright (C) 2014 The Android Open Source Project
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#     http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+# Strip timeout logging. These are "E/System" messages.
+sed -e '/^E\/System/d' "$2" > "$2.tmp"
+
+diff --strip-trailing-cr -q "$1" "$2.tmp" >/dev/null
diff --git a/test/1336-short-finalizer-timeout/expected.txt b/test/1336-short-finalizer-timeout/expected.txt
new file mode 100644
index 0000000..8f5f91c
--- /dev/null
+++ b/test/1336-short-finalizer-timeout/expected.txt
@@ -0,0 +1,7 @@
+Finalizer timeout = 500 msecs.
+About to null reference.
+Finalizer started and snoozing...
+Starting main snooze.
+Finalizer done snoozing.
+Finalizer sleeping forever now.
+exit status: 2
diff --git a/test/1336-short-finalizer-timeout/info.txt b/test/1336-short-finalizer-timeout/info.txt
new file mode 100644
index 0000000..60dea68
--- /dev/null
+++ b/test/1336-short-finalizer-timeout/info.txt
@@ -0,0 +1 @@
+Check that FinalizerTimeoutMs option works. Similar to 030-bad-finalizer.
diff --git a/test/1336-short-finalizer-timeout/run b/test/1336-short-finalizer-timeout/run
new file mode 100755
index 0000000..3e33524
--- /dev/null
+++ b/test/1336-short-finalizer-timeout/run
@@ -0,0 +1,19 @@
+#!/bin/bash
+#
+# Copyright 2017 The Android Open Source Project
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+# Squash the exit status and put it in expected
+./default-run "$@" --runtime-option -XX:FinalizerTimeoutMs=500
+echo "exit status:" $?
diff --git a/test/1336-short-finalizer-timeout/src/Main.java b/test/1336-short-finalizer-timeout/src/Main.java
new file mode 100644
index 0000000..e5a4aad
--- /dev/null
+++ b/test/1336-short-finalizer-timeout/src/Main.java
@@ -0,0 +1,96 @@
+/*
+ * Copyright (C) 2007 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+import dalvik.system.VMRuntime;
+import java.util.concurrent.CountDownLatch;
+import static java.util.concurrent.TimeUnit.MINUTES;
+
+/**
+ * Test a class with a bad finalizer in an environment with a short finalizer timeout.
+ *
+ * This test is inherently flaky. It assumes that the system will schedule the finalizer daemon
+ * and finalizer watchdog daemon enough to reach the timeout and throwing the fatal exception.
+ * Largely cloned from 030-bad-finalizer.
+ */
+public class Main {
+    public static void main(String[] args) throws Exception {
+        CountDownLatch finalizerWait = new CountDownLatch(1);
+
+        System.out.println("Finalizer timeout = "
+                + VMRuntime.getRuntime().getFinalizerTimeoutMs() + " msecs.");
+        // A separate method to ensure no dex register keeps the object alive.
+        createBadFinalizer(finalizerWait);
+
+        for (int i = 0; i < 2; i++) {
+            Runtime.getRuntime().gc();
+        }
+
+        // Now wait for the finalizer to start running.
+        if (!finalizerWait.await(1, MINUTES)) {
+            System.out.println("finalizerWait timed out.");
+        }
+
+        System.out.println("Starting main snooze.");
+        // Sleep for less time than the default finalizer timeout, but significantly more than
+        // the new timeout plus the 5 seconds we wait to dump thread stacks before actually
+        // exiting.
+        snooze(9800);
+
+        // We should not get here, since it should only take 5.5 seconds for the timed out
+        // fiinalizer to kill the process.
+        System.out.println("UNREACHABLE");
+        System.exit(0);
+    }
+
+    private static void createBadFinalizer(CountDownLatch finalizerWait) {
+        BadFinalizer bf = new BadFinalizer(finalizerWait);
+
+        System.out.println("About to null reference.");
+        bf = null;  // Not that this would make a difference, could be eliminated earlier.
+    }
+
+    public static void snooze(int ms) {
+        try {
+            Thread.sleep(ms);
+        } catch (InterruptedException ie) {
+            System.out.println("Snooze(" + ms + ") interrupted");
+        }
+    }
+
+    /**
+     * Class with a bad finalizer.
+     */
+    public static class BadFinalizer {
+        private CountDownLatch finalizerWait;
+        private volatile int j = 0;  // Volatile in an effort to curb loop optimization.
+
+        public BadFinalizer(CountDownLatch finalizerWait) {
+            this.finalizerWait = finalizerWait;
+        }
+
+        protected void finalize() {
+            System.out.println("Finalizer started and snoozing...");
+            finalizerWait.countDown();
+            snooze(200);
+            System.out.println("Finalizer done snoozing.");
+
+            System.out.println("Finalizer sleeping forever now.");
+            while (true) {
+                snooze(10000);
+            }
+        }
+    }
+}
diff --git a/test/knownfailures.json b/test/knownfailures.json
index c5e4221..e78e002 100644
--- a/test/knownfailures.json
+++ b/test/knownfailures.json
@@ -375,7 +375,8 @@
         "tests": ["530-checker-lse",
                   "530-checker-lse2",
                   "030-bad-finalizer",
-                  "080-oom-throw"],
+                  "080-oom-throw",
+                  "1336-short-finalizer-timeout"],
         "bug": "http://b/36377828",
         "variant": "interp-ac"
     },
@@ -1064,6 +1065,7 @@
           "993-breakpoints",
           "1002-notify-startup",
           "1003-metadata-section-strings",
+          "1336-short-finalizer-timeout",
           "1900-track-alloc",
           "1906-suspend-list-me-first",
           "1914-get-local-instance",
@@ -1149,6 +1151,12 @@
         "description": ["Test timing out under gcstress possibly due to slower unwinding by libbacktrace"]
     },
     {
+        "tests": ["1336-short-finalizer-timeout"],
+        "variant": "gcstress",
+        "bug": "b/68792448",
+        "description": ["Timing margins are too tight for gcstress"]
+    },
+    {
         "tests": ["021-string2"],
         "variant": "jit & debuggable",
         "bug": "b/109791792",