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

11 files changed, 111 insertions, 29 deletions

diff --git a/compiler/jni/jni_compiler_test.cc b/compiler/jni/jni_compiler_test.cc
index 281e3fe..f513ea8 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<void*>(&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<void*>(&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 b8d724d..e93f45c 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 285007c..986b7ec 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 f3e0918..0764b87 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 ae83e33..cc1a4a1 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 e017699..d48ac9d 100644
--- a/runtime/common_runtime_test.cc
+++ b/runtime/common_runtime_test.cc
@@ -20,6 +20,7 @@
 #include <dlfcn.h>
 #include <fcntl.h>
 #include <ScopedLocalRef.h>
+#include <stdlib.h>
 
 #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 9f39b80..09d10dd 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> 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 99ee597..1156cf5 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 8e32968..906aa4c 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 adc7848..6d1e721 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 a98bc90..a3dd13c 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<std::string> command;
   command.push_back("bogus");
   std::string error_msg;