From 369810a98e6394b6dd162f5349e38a1f597b3bc7 Mon Sep 17 00:00:00 2001 From: Andreas Gampe Date: Wed, 14 Jan 2015 19:53:31 -0800 Subject: [PATCH] ART: Allow scoped adjustments to log verbosity Add ScopedLogSeverity to adjust the logging level. Suppress warnings by default in gtests. Suppress errors in instances where errors are expected. Change-Id: If3ef865813e9505ab60bc90baed63ff11d90afbb --- compiler/jni/jni_compiler_test.cc | 9 +++ compiler/utils/x86_64/assembler_x86_64_test.cc | 1 - runtime/arch/stub_test.cc | 9 +++ runtime/base/logging.cc | 9 +++ runtime/base/logging.h | 10 ++++ runtime/common_runtime_test.cc | 6 ++ runtime/gc/space/space_test.h | 3 + runtime/indirect_reference_table_test.cc | 3 + runtime/jni_internal_test.cc | 81 +++++++++++++++++--------- runtime/monitor_test.cc | 6 ++ runtime/utils_test.cc | 3 + 11 files changed, 111 insertions(+), 29 deletions(-) diff --git a/compiler/jni/jni_compiler_test.cc b/compiler/jni/jni_compiler_test.cc index 281e3fe10..f513ea812 100644 --- a/compiler/jni/jni_compiler_test.cc +++ b/compiler/jni/jni_compiler_test.cc @@ -973,6 +973,9 @@ void Java_MyClassNatives_staticMethodThatShouldTakeClass(JNIEnv*, jclass, jclass } void JniCompilerTest::UpcallArgumentTypeChecking_InstanceImpl() { + // This will lead to error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + SetUpForTest(false, "instanceMethodThatShouldTakeClass", "(ILjava/lang/Class;)V", reinterpret_cast(&Java_MyClassNatives_instanceMethodThatShouldTakeClass)); @@ -985,6 +988,9 @@ void JniCompilerTest::UpcallArgumentTypeChecking_InstanceImpl() { JNI_TEST(UpcallArgumentTypeChecking_Instance) void JniCompilerTest::UpcallArgumentTypeChecking_StaticImpl() { + // This will lead to error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + SetUpForTest(true, "staticMethodThatShouldTakeClass", "(ILjava/lang/Class;)V", reinterpret_cast(&Java_MyClassNatives_staticMethodThatShouldTakeClass)); @@ -1475,6 +1481,9 @@ void JniCompilerTest::MaxParamNumberImpl() { JNI_TEST(MaxParamNumber) void JniCompilerTest::WithoutImplementationImpl() { + // This will lead to error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + SetUpForTest(false, "withoutImplementation", "()V", nullptr); env_->CallVoidMethod(jobj_, jmethod_); diff --git a/compiler/utils/x86_64/assembler_x86_64_test.cc b/compiler/utils/x86_64/assembler_x86_64_test.cc index b8d724d77..e93f45c0e 100644 --- a/compiler/utils/x86_64/assembler_x86_64_test.cc +++ b/compiler/utils/x86_64/assembler_x86_64_test.cc @@ -330,7 +330,6 @@ std::string shlq_fn(AssemblerX86_64Test::Base* assembler_test, x86_64::X86_64Ass assembler->shlq(*reg, shifter); str << "shlq %cl, %" << assembler_test->GetRegisterName(*reg) << "\n"; } - printf("%s\n", str.str().c_str()); return str.str(); } diff --git a/runtime/arch/stub_test.cc b/runtime/arch/stub_test.cc index 285007c48..986b7ecd5 100644 --- a/runtime/arch/stub_test.cc +++ b/runtime/arch/stub_test.cc @@ -799,6 +799,9 @@ static void TestUnlockObject(StubTest* test) NO_THREAD_SAFETY_ANALYSIS { } TEST_F(StubTest, UnlockObject) { + // This will lead to monitor error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + TestUnlockObject(this); } @@ -992,6 +995,9 @@ TEST_F(StubTest, AllocObject) { TEST_DISABLED_FOR_HEAP_REFERENCE_POISONING(); #if defined(__i386__) || defined(__arm__) || defined(__aarch64__) || (defined(__x86_64__) && !defined(__APPLE__)) + // This will lead to OOM error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + // TODO: Check the "Unresolved" allocation stubs Thread* self = Thread::Current(); @@ -1116,6 +1122,9 @@ TEST_F(StubTest, AllocObjectArray) { #if defined(__i386__) || defined(__arm__) || defined(__aarch64__) || (defined(__x86_64__) && !defined(__APPLE__)) // TODO: Check the "Unresolved" allocation stubs + // This will lead to OOM error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + Thread* self = Thread::Current(); // Create an object ScopedObjectAccess soa(self); diff --git a/runtime/base/logging.cc b/runtime/base/logging.cc index f3e0918d3..0764b877a 100644 --- a/runtime/base/logging.cc +++ b/runtime/base/logging.cc @@ -303,4 +303,13 @@ void LogMessage::LogLineLowStack(const char* file, unsigned int line, LogSeverit #endif } +ScopedLogSeverity::ScopedLogSeverity(LogSeverity level) { + old_ = gMinimumLogSeverity; + gMinimumLogSeverity = level; +} + +ScopedLogSeverity::~ScopedLogSeverity() { + gMinimumLogSeverity = old_; +} + } // namespace art diff --git a/runtime/base/logging.h b/runtime/base/logging.h index ae83e331f..cc1a4a1e6 100644 --- a/runtime/base/logging.h +++ b/runtime/base/logging.h @@ -254,6 +254,16 @@ class LogMessage { DISALLOW_COPY_AND_ASSIGN(LogMessage); }; +// Allows to temporarily change the minimum severity level for logging. +class ScopedLogSeverity { + public: + explicit ScopedLogSeverity(LogSeverity level); + ~ScopedLogSeverity(); + + private: + LogSeverity old_; +}; + } // namespace art #endif // ART_RUNTIME_BASE_LOGGING_H_ diff --git a/runtime/common_runtime_test.cc b/runtime/common_runtime_test.cc index e017699b0..d48ac9d6b 100644 --- a/runtime/common_runtime_test.cc +++ b/runtime/common_runtime_test.cc @@ -20,6 +20,7 @@ #include #include #include +#include #include "../../external/icu/icu4c/source/common/unicode/uvernum.h" #include "base/macros.h" @@ -43,6 +44,11 @@ #include "well_known_classes.h" int main(int argc, char **argv) { + // Gtests can be very noisy. For example, an executable with multiple tests will trigger native + // bridge warnings. The following line reduces the minimum log severity to ERROR and suppresses + // everything else. In case you want to see all messages, comment out the line. + setenv("ANDROID_LOG_TAGS", "*:e", 1); + art::InitLogging(argv); LOG(::art::INFO) << "Running main() from common_runtime_test.cc..."; testing::InitGoogleTest(&argc, argv); diff --git a/runtime/gc/space/space_test.h b/runtime/gc/space/space_test.h index 9f39b80c9..09d10dd94 100644 --- a/runtime/gc/space/space_test.h +++ b/runtime/gc/space/space_test.h @@ -127,6 +127,9 @@ static inline size_t test_rand(size_t* seed) { } void SpaceTest::InitTestBody(CreateSpaceFn create_space) { + // This will lead to error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + { // Init < max == growth std::unique_ptr space(create_space("test", 16 * MB, 32 * MB, 32 * MB, nullptr)); diff --git a/runtime/indirect_reference_table_test.cc b/runtime/indirect_reference_table_test.cc index 99ee597bb..1156cf599 100644 --- a/runtime/indirect_reference_table_test.cc +++ b/runtime/indirect_reference_table_test.cc @@ -43,6 +43,9 @@ static void CheckDump(IndirectReferenceTable* irt, size_t num_objects, size_t nu } TEST_F(IndirectReferenceTableTest, BasicTest) { + // This will lead to error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + ScopedObjectAccess soa(Thread::Current()); static const size_t kTableInitial = 10; static const size_t kTableMax = 20; diff --git a/runtime/jni_internal_test.cc b/runtime/jni_internal_test.cc index 8e329687c..906aa4c1b 100644 --- a/runtime/jni_internal_test.cc +++ b/runtime/jni_internal_test.cc @@ -634,6 +634,9 @@ TEST_F(JniInternalTest, GetVersion) { } TEST_F(JniInternalTest, FindClass) { + // This tests leads to warnings in the log. + ScopedLogSeverity sls(LogSeverity::ERROR); + FindClassTest(false); FindClassTest(true); } @@ -890,40 +893,44 @@ TEST_F(JniInternalTest, RegisterAndUnregisterNatives) { // Sanity check that no exceptions are pending. ASSERT_FALSE(env_->ExceptionCheck()); - // Check that registering method without name causes a NoSuchMethodError. + // The following can print errors to the log we'd like to ignore. { - JNINativeMethod methods[] = { { nullptr, "()V", native_function } }; - EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); - } - ExpectException(jlnsme); + ScopedLogSeverity sls(LogSeverity::FATAL); + // Check that registering method without name causes a NoSuchMethodError. + { + JNINativeMethod methods[] = { { nullptr, "()V", native_function } }; + EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); + } + ExpectException(jlnsme); - // Check that registering method without signature causes a NoSuchMethodError. - { - JNINativeMethod methods[] = { { "notify", nullptr, native_function } }; - EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); - } - ExpectException(jlnsme); + // Check that registering method without signature causes a NoSuchMethodError. + { + JNINativeMethod methods[] = { { "notify", nullptr, native_function } }; + EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); + } + ExpectException(jlnsme); - // Check that registering method without function causes a NoSuchMethodError. - { - JNINativeMethod methods[] = { { "notify", "()V", nullptr } }; - EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); - } - ExpectException(jlnsme); + // Check that registering method without function causes a NoSuchMethodError. + { + JNINativeMethod methods[] = { { "notify", "()V", nullptr } }; + EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); + } + ExpectException(jlnsme); - // Check that registering to a non-existent java.lang.Object.foo() causes a NoSuchMethodError. - { - JNINativeMethod methods[] = { { "foo", "()V", native_function } }; - EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); - } - ExpectException(jlnsme); + // Check that registering to a non-existent java.lang.Object.foo() causes a NoSuchMethodError. + { + JNINativeMethod methods[] = { { "foo", "()V", native_function } }; + EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); + } + ExpectException(jlnsme); - // Check that registering non-native methods causes a NoSuchMethodError. - { - JNINativeMethod methods[] = { { "equals", "(Ljava/lang/Object;)Z", native_function } }; - EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); + // Check that registering non-native methods causes a NoSuchMethodError. + { + JNINativeMethod methods[] = { { "equals", "(Ljava/lang/Object;)Z", native_function } }; + EXPECT_EQ(env_->RegisterNatives(jlobject, methods, 1), JNI_ERR); + } + ExpectException(jlnsme); } - ExpectException(jlnsme); // Check that registering native methods is successful. { @@ -1707,6 +1714,9 @@ TEST_F(JniInternalTest, DeleteLocalRef_nullptr) { } TEST_F(JniInternalTest, DeleteLocalRef) { + // This tests leads to warnings and errors in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + jstring s = env_->NewStringUTF(""); ASSERT_NE(s, nullptr); env_->DeleteLocalRef(s); @@ -1743,6 +1753,9 @@ TEST_F(JniInternalTest, PushLocalFrame_10395422) { ASSERT_EQ(JNI_OK, env_->PushLocalFrame(0)); env_->PopLocalFrame(nullptr); + // The following two tests will print errors to the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + // Negative capacities are not allowed. ASSERT_EQ(JNI_ERR, env_->PushLocalFrame(-1)); @@ -1751,6 +1764,9 @@ TEST_F(JniInternalTest, PushLocalFrame_10395422) { } TEST_F(JniInternalTest, PushLocalFrame_PopLocalFrame) { + // This tests leads to errors in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + jobject original = env_->NewStringUTF(""); ASSERT_NE(original, nullptr); @@ -1815,6 +1831,9 @@ TEST_F(JniInternalTest, DeleteGlobalRef_nullptr) { } TEST_F(JniInternalTest, DeleteGlobalRef) { + // This tests leads to warnings and errors in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + jstring s = env_->NewStringUTF(""); ASSERT_NE(s, nullptr); @@ -1865,6 +1884,9 @@ TEST_F(JniInternalTest, DeleteWeakGlobalRef_nullptr) { } TEST_F(JniInternalTest, DeleteWeakGlobalRef) { + // This tests leads to warnings and errors in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + jstring s = env_->NewStringUTF(""); ASSERT_NE(s, nullptr); @@ -1989,6 +2011,9 @@ TEST_F(JniInternalTest, NewDirectBuffer_GetDirectBufferAddress_GetDirectBufferCa } TEST_F(JniInternalTest, MonitorEnterExit) { + // This will print some error messages. Suppress. + ScopedLogSeverity sls(LogSeverity::FATAL); + // Create an object to torture. jclass object_class = env_->FindClass("java/lang/Object"); ASSERT_NE(object_class, nullptr); diff --git a/runtime/monitor_test.cc b/runtime/monitor_test.cc index adc7848ae..6d1e721bb 100644 --- a/runtime/monitor_test.cc +++ b/runtime/monitor_test.cc @@ -356,6 +356,8 @@ static void CommonWaitSetup(MonitorTest* test, ClassLinker* class_linker, uint64 TEST_F(MonitorTest, CheckExceptionsWait1) { // Make the CreateTask wait 10ms, the UseTask wait 10ms. // => The use task will get the lock first and get to self == owner check. + // This will lead to OOM and monitor error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); CommonWaitSetup(this, class_linker_, 10, 50, false, false, 2, 50, true, "Monitor test thread pool 1"); } @@ -364,6 +366,8 @@ TEST_F(MonitorTest, CheckExceptionsWait1) { TEST_F(MonitorTest, CheckExceptionsWait2) { // Make the CreateTask wait 0ms, the UseTask wait 10ms. // => The create task will get the lock first and get to ms >= 0 + // This will lead to OOM and monitor error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); CommonWaitSetup(this, class_linker_, 0, -1, true, false, 10, 50, true, "Monitor test thread pool 2"); } @@ -373,6 +377,8 @@ TEST_F(MonitorTest, CheckExceptionsWait3) { // Make the CreateTask wait 0ms, then Wait for a long time. Make the InterruptTask wait 10ms, // after which it will interrupt the create task and then wait another 10ms. // => The create task will get to the interrupted-exception throw. + // This will lead to OOM and monitor error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); CommonWaitSetup(this, class_linker_, 0, 500, true, true, 10, 50, true, "Monitor test thread pool 3"); } diff --git a/runtime/utils_test.cc b/runtime/utils_test.cc index a98bc909f..a3dd13c66 100644 --- a/runtime/utils_test.cc +++ b/runtime/utils_test.cc @@ -392,6 +392,9 @@ TEST_F(UtilsTest, ExecSuccess) { } TEST_F(UtilsTest, ExecError) { + // This will lead to error messages in the log. + ScopedLogSeverity sls(LogSeverity::FATAL); + std::vector command; command.push_back("bogus"); std::string error_msg; -- 2.11.0