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",