diff options
author | 2016-09-13 10:47:28 -0700 | |
---|---|---|
committer | 2016-09-26 10:59:22 -0700 | |
commit | 3fec9ac0d5af1358d216eb2fdc2000ec0205f3f0 (patch) | |
tree | f38d8d8aae51f53e7ee6b474f47597b784fc2316 | |
parent | 0cfe19af3b7395658210ea6044a65c9811962a7a (diff) |
ART: Use libbase logging
Move most of our logging infrastructure over to system/core/base.
Retain VLOG.
Using unified Android infrastructure has two main advantages. First,
it reduces the complexity/maintenance burden in ART. Second, it
allows to detach logging for the cases where we do not want or need
a runtime, e.g., dexdump, the disassembler, etc. As a part of the
latter, libbase is also supported for all hosts (including Windows).
From a developer viewpoint, there are minor behavior changes for the
LOG statements (see above), but otherwise usage is the same. Explicit
severity enum items are in the android::base namespace now.
Bug: 31338270
Test: m test-art-host
Change-Id: I5abcb2f45f5b03d49951874c48544f72a283a91b
63 files changed, 297 insertions, 513 deletions
diff --git a/compiler/Android.bp b/compiler/Android.bp index 09c53b6889..e56d8b2e0a 100644 --- a/compiler/Android.bp +++ b/compiler/Android.bp @@ -288,6 +288,7 @@ art_cc_library { shared_libs: [ "libartd-compiler", "libart-runtime-gtest", + "libbase", ], } diff --git a/compiler/oat_writer.cc b/compiler/oat_writer.cc index 9045817832..c840a9e64a 100644 --- a/compiler/oat_writer.cc +++ b/compiler/oat_writer.cc @@ -966,7 +966,7 @@ class OatWriter::InitImageMethodVisitor : public OatDexMethodVisitor { nullptr, invoke_type); if (method == nullptr) { - LOG(INTERNAL_FATAL) << "Unexpected failure to resolve a method: " + LOG(FATAL_WITHOUT_ABORT) << "Unexpected failure to resolve a method: " << PrettyMethod(it.GetMemberIndex(), *dex_file_, true); soa.Self()->AssertPendingException(); mirror::Throwable* exc = soa.Self()->GetException(); diff --git a/dex2oat/Android.bp b/dex2oat/Android.bp index 11c18b0924..931bbd368b 100644 --- a/dex2oat/Android.bp +++ b/dex2oat/Android.bp @@ -49,6 +49,7 @@ art_cc_binary { shared_libs: [ "libart", "libart-compiler", + "libbase", "libsigchain", ], } @@ -62,6 +63,7 @@ art_cc_binary { shared_libs: [ "libartd", "libartd-compiler", + "libbase", "libsigchain", ], } diff --git a/dex2oat/dex2oat.cc b/dex2oat/dex2oat.cc index c422163182..3b2715d56b 100644 --- a/dex2oat/dex2oat.cc +++ b/dex2oat/dex2oat.cc @@ -450,7 +450,11 @@ class WatchDog { // it's rather easy to hang in unwinding. // LogLine also avoids ART logging lock issues, as it's really only a wrapper around // logcat logging or stderr output. - LogMessage::LogLine(__FILE__, __LINE__, LogSeverity::FATAL, message.c_str()); + android::base::LogMessage::LogLine(__FILE__, + __LINE__, + android::base::LogId::DEFAULT, + LogSeverity::FATAL, + message.c_str()); exit(1); } diff --git a/dexdump/Android.bp b/dexdump/Android.bp index 64f2299fa5..3e589f7c5e 100644 --- a/dexdump/Android.bp +++ b/dexdump/Android.bp @@ -22,7 +22,10 @@ art_cc_binary { "dexdump.cc", ], cflags: ["-Wall"], - shared_libs: ["libart"], + shared_libs: [ + "libart", + "libbase", + ], } art_cc_test { diff --git a/dexlayout/Android.bp b/dexlayout/Android.bp index c411572237..296cdb6140 100644 --- a/dexlayout/Android.bp +++ b/dexlayout/Android.bp @@ -22,7 +22,10 @@ art_cc_binary { "dex_ir_builder.cc", ], cflags: ["-Wall"], - shared_libs: ["libart"], + shared_libs: [ + "libart", + "libbase", + ], } art_cc_test { diff --git a/imgdiag/Android.bp b/imgdiag/Android.bp index 7837d66913..eaeb78efa4 100644 --- a/imgdiag/Android.bp +++ b/imgdiag/Android.bp @@ -26,7 +26,10 @@ cc_defaults { // that the image it's analyzing be the same ISA as the runtime ISA. compile_multilib: "both", - shared_libs: ["libbacktrace"], + shared_libs: [ + "libbacktrace", + "libbase", + ], target: { android: { shared_libs: ["libcutils"], diff --git a/oatdump/Android.bp b/oatdump/Android.bp index dd6331c24b..bbe6cc1ac0 100644 --- a/oatdump/Android.bp +++ b/oatdump/Android.bp @@ -34,6 +34,7 @@ art_cc_binary { "libart", "libart-compiler", "libart-disassembler", + "libbase", ], } @@ -47,6 +48,7 @@ art_cc_binary { "libartd", "libartd-compiler", "libartd-disassembler", + "libbase", ], } diff --git a/patchoat/Android.bp b/patchoat/Android.bp index 8d8d6d1977..a78f97d54c 100644 --- a/patchoat/Android.bp +++ b/patchoat/Android.bp @@ -24,6 +24,9 @@ cc_defaults { compile_multilib: "prefer32", }, }, + shared_libs: [ + "libbase", + ], } art_cc_binary { diff --git a/profman/Android.bp b/profman/Android.bp index 322dda2211..2dcbaee456 100644 --- a/profman/Android.bp +++ b/profman/Android.bp @@ -32,6 +32,10 @@ cc_defaults { include_dirs: [ "art/cmdline", ], + + shared_libs: [ + "libbase", + ], } art_cc_binary { diff --git a/runtime/Android.bp b/runtime/Android.bp index ad953eaab4..fd9b5b9d94 100644 --- a/runtime/Android.bp +++ b/runtime/Android.bp @@ -470,6 +470,7 @@ art_cc_library { srcs: ["common_runtime_test.cc"], shared_libs: [ "libartd", + "libbase", ], } diff --git a/runtime/base/logging.cc b/runtime/base/logging.cc index e00e62d368..17873b541c 100644 --- a/runtime/base/logging.cc +++ b/runtime/base/logging.cc @@ -28,6 +28,7 @@ // Headers for LogMessage::LogLine. #ifdef ART_TARGET_ANDROID #include "cutils/log.h" +#include <android/set_abort_message.h> #else #include <sys/types.h> #include <unistd.h> @@ -39,24 +40,10 @@ LogVerbosity gLogVerbosity; unsigned int gAborting = 0; -static LogSeverity gMinimumLogSeverity = INFO; static std::unique_ptr<std::string> gCmdLine; static std::unique_ptr<std::string> gProgramInvocationName; static std::unique_ptr<std::string> gProgramInvocationShortName; -// Print INTERNAL_FATAL messages directly instead of at destruction time. This only works on the -// host right now: for the device, a stream buf collating output into lines and calling LogLine or -// lower-level logging is necessary. -#ifdef ART_TARGET_ANDROID -static constexpr bool kPrintInternalFatalDirectly = false; -#else -static constexpr bool kPrintInternalFatalDirectly = !kIsTargetBuild; -#endif - -static bool PrintDirectly(LogSeverity severity) { - return kPrintInternalFatalDirectly && severity == INTERNAL_FATAL; -} - const char* GetCmdLine() { return (gCmdLine.get() != nullptr) ? gCmdLine->c_str() : nullptr; } @@ -70,6 +57,16 @@ const char* ProgramInvocationShortName() { : "art"; } +NO_RETURN +static void RuntimeAborter(const char* abort_message) { +#ifdef __ANDROID__ + android_set_abort_message(abort_message); +#else + UNUSED(abort_message); +#endif + Runtime::Abort(); +} + void InitLogging(char* argv[]) { if (gCmdLine.get() != nullptr) { return; @@ -94,150 +91,14 @@ void InitLogging(char* argv[]) { // TODO: fall back to /proc/self/cmdline when argv is null on Linux. gCmdLine.reset(new std::string("<unset>")); } - const char* tags = getenv("ANDROID_LOG_TAGS"); - if (tags == nullptr) { - return; - } - - std::vector<std::string> specs; - Split(tags, ' ', &specs); - for (size_t i = 0; i < specs.size(); ++i) { - // "tag-pattern:[vdiwefs]" - std::string spec(specs[i]); - if (spec.size() == 3 && StartsWith(spec, "*:")) { - switch (spec[2]) { - case 'v': - gMinimumLogSeverity = VERBOSE; - continue; - case 'd': - gMinimumLogSeverity = DEBUG; - continue; - case 'i': - gMinimumLogSeverity = INFO; - continue; - case 'w': - gMinimumLogSeverity = WARNING; - continue; - case 'e': - gMinimumLogSeverity = ERROR; - continue; - case 'f': - gMinimumLogSeverity = FATAL; - continue; - // liblog will even suppress FATAL if you say 's' for silent, but that's crazy! - case 's': - gMinimumLogSeverity = FATAL; - continue; - } - } - LOG(FATAL) << "unsupported '" << spec << "' in ANDROID_LOG_TAGS (" << tags << ")"; - } -} - -// This indirection greatly reduces the stack impact of having -// lots of checks/logging in a function. -class LogMessageData { - public: - LogMessageData(const char* file, unsigned int line, LogSeverity severity, int error) - : file_(GetFilenameBase(file)), - line_number_(line), - severity_(severity), - error_(error) {} - const char * GetFile() const { - return file_; - } - - unsigned int GetLineNumber() const { - return line_number_; - } - - LogSeverity GetSeverity() const { - return severity_; - } - - int GetError() const { - return error_; - } - - std::ostream& GetBuffer() { - return buffer_; - } - - std::string ToString() const { - return buffer_.str(); - } - - private: - std::ostringstream buffer_; - const char* const file_; - const unsigned int line_number_; - const LogSeverity severity_; - const int error_; - - static const char* GetFilenameBase(const char* file) { - const char* last_slash = strrchr(file, '/'); - return (last_slash == nullptr) ? file : last_slash + 1; - } - - DISALLOW_COPY_AND_ASSIGN(LogMessageData); -}; - - -LogMessage::LogMessage(const char* file, unsigned int line, LogSeverity severity, int error) - : data_(new LogMessageData(file, line, severity, error)) { - if (PrintDirectly(severity)) { - static constexpr char kLogCharacters[] = { 'V', 'D', 'I', 'W', 'E', 'F', 'F' }; - static_assert(arraysize(kLogCharacters) == static_cast<size_t>(INTERNAL_FATAL) + 1, - "Wrong character array size"); - stream() << ProgramInvocationShortName() << " " << kLogCharacters[static_cast<size_t>(severity)] - << " " << getpid() << " " << ::art::GetTid() << " " << file << ":" << line << "]"; - } -} -LogMessage::~LogMessage() { - if (PrintDirectly(data_->GetSeverity())) { - // Add newline at the end to match the not printing directly behavior. - std::cerr << '\n'; - } else { - if (data_->GetSeverity() < gMinimumLogSeverity) { - return; // No need to format something we're not going to output. - } - - // Finish constructing the message. - if (data_->GetError() != -1) { - data_->GetBuffer() << ": " << strerror(data_->GetError()); - } - std::string msg(data_->ToString()); - - // Do the actual logging with the lock held. - { - MutexLock mu(Thread::Current(), *Locks::logging_lock_); - if (msg.find('\n') == std::string::npos) { - LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetSeverity(), msg.c_str()); - } else { - msg += '\n'; - size_t i = 0; - while (i < msg.size()) { - size_t nl = msg.find('\n', i); - msg[nl] = '\0'; - LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetSeverity(), &msg[i]); - i = nl + 1; - } - } - } - } - - // Abort if necessary. - if (data_->GetSeverity() == FATAL) { - Runtime::Abort(); - } -} - -std::ostream& LogMessage::stream() { - if (PrintDirectly(data_->GetSeverity())) { - return std::cerr; - } - return data_->GetBuffer(); +#ifdef __ANDROID__ +#define INIT_LOGGING_DEFAULT_LOGGER android::base::LogdLogger() +#else +#define INIT_LOGGING_DEFAULT_LOGGER android::base::StderrLogger +#endif + android::base::InitLogging(argv, INIT_LOGGING_DEFAULT_LOGGER, RuntimeAborter); +#undef INIT_LOGGING_DEFAULT_LOGGER } #ifdef ART_TARGET_ANDROID @@ -245,31 +106,14 @@ static const android_LogPriority kLogSeverityToAndroidLogPriority[] = { ANDROID_LOG_VERBOSE, ANDROID_LOG_DEBUG, ANDROID_LOG_INFO, ANDROID_LOG_WARN, ANDROID_LOG_ERROR, ANDROID_LOG_FATAL, ANDROID_LOG_FATAL }; -static_assert(arraysize(kLogSeverityToAndroidLogPriority) == INTERNAL_FATAL + 1, +static_assert(arraysize(kLogSeverityToAndroidLogPriority) == ::android::base::FATAL + 1, "Mismatch in size of kLogSeverityToAndroidLogPriority and values in LogSeverity"); #endif -void LogMessage::LogLine(const char* file, unsigned int line, LogSeverity log_severity, - const char* message) { -#ifdef ART_TARGET_ANDROID - const char* tag = ProgramInvocationShortName(); - int priority = kLogSeverityToAndroidLogPriority[static_cast<size_t>(log_severity)]; - if (priority == ANDROID_LOG_FATAL) { - LOG_PRI(priority, tag, "%s:%u] %s", file, line, message); - } else { - LOG_PRI(priority, tag, "%s", message); - } -#else - static const char* log_characters = "VDIWEFF"; - CHECK_EQ(strlen(log_characters), INTERNAL_FATAL + 1U); - char severity = log_characters[log_severity]; - fprintf(stderr, "%s %c %5d %5d %s:%u] %s\n", - ProgramInvocationShortName(), severity, getpid(), ::art::GetTid(), file, line, message); -#endif -} - -void LogMessage::LogLineLowStack(const char* file, unsigned int line, LogSeverity log_severity, - const char* message) { +void LogHelper::LogLineLowStack(const char* file, + unsigned int line, + LogSeverity log_severity, + const char* message) { #ifdef ART_TARGET_ANDROID // Use android_writeLog() to avoid stack-based buffers used by android_printLog(). const char* tag = ProgramInvocationShortName(); @@ -292,8 +136,9 @@ void LogMessage::LogLineLowStack(const char* file, unsigned int line, LogSeverit } #else static constexpr char kLogCharacters[] = { 'V', 'D', 'I', 'W', 'E', 'F', 'F' }; - static_assert(arraysize(kLogCharacters) == static_cast<size_t>(INTERNAL_FATAL) + 1, - "Wrong character array size"); + static_assert( + arraysize(kLogCharacters) == static_cast<size_t>(::android::base::FATAL) + 1, + "Wrong character array size"); const char* program_name = ProgramInvocationShortName(); TEMP_FAILURE_RETRY(write(STDERR_FILENO, program_name, strlen(program_name))); @@ -310,13 +155,4 @@ void LogMessage::LogLineLowStack(const char* file, unsigned int line, LogSeverit #endif // ART_TARGET_ANDROID } -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 185aa0e577..26ab1f9d0f 100644 --- a/runtime/base/logging.h +++ b/runtime/base/logging.h @@ -18,20 +18,16 @@ #define ART_RUNTIME_BASE_LOGGING_H_ #include <ostream> +#include <sstream> +#include "android-base/logging.h" #include "base/macros.h" namespace art { -enum LogSeverity { - VERBOSE, - DEBUG, - INFO, - WARNING, - ERROR, - FATAL, - INTERNAL_FATAL, // For Runtime::Abort. -}; +// Make libbase's LogSeverity more easily available. +using LogSeverity = ::android::base::LogSeverity; +using ScopedLogSeverity = ::android::base::ScopedLogSeverity; // The members of this struct are the valid arguments to VLOG and VLOG_IS_ON in code, // and the "-verbose:" command line argument. @@ -89,172 +85,28 @@ extern const char* ProgramInvocationName(); // hasn't been performed then just returns "art" extern const char* ProgramInvocationShortName(); -// Logs a message to logcat on Android otherwise to stderr. If the severity is FATAL it also causes -// an abort. For example: LOG(FATAL) << "We didn't expect to reach here"; -#define LOG(severity) ::art::LogMessage(__FILE__, __LINE__, severity, -1).stream() - -// A variant of LOG that also logs the current errno value. To be used when library calls fail. -#define PLOG(severity) ::art::LogMessage(__FILE__, __LINE__, severity, errno).stream() +class LogHelper { + public: + // A logging helper for logging a single line. Can be used with little stack. + static void LogLineLowStack(const char* file, + unsigned int line, + android::base::LogSeverity severity, + const char* msg); -// Marker that code is yet to be implemented. -#define UNIMPLEMENTED(level) LOG(level) << __PRETTY_FUNCTION__ << " unimplemented " + private: + DISALLOW_ALLOCATION(); + DISALLOW_COPY_AND_ASSIGN(LogHelper); +}; // Is verbose logging enabled for the given module? Where the module is defined in LogVerbosity. #define VLOG_IS_ON(module) UNLIKELY(::art::gLogVerbosity.module) // Variant of LOG that logs when verbose logging is enabled for a module. For example, // VLOG(jni) << "A JNI operation was performed"; -#define VLOG(module) \ - if (VLOG_IS_ON(module)) \ - ::art::LogMessage(__FILE__, __LINE__, INFO, -1).stream() +#define VLOG(module) if (VLOG_IS_ON(module)) LOG(INFO) // Return the stream associated with logging for the given module. -#define VLOG_STREAM(module) ::art::LogMessage(__FILE__, __LINE__, INFO, -1).stream() - -// Check whether condition x holds and LOG(FATAL) if not. The value of the expression x is only -// evaluated once. Extra logging can be appended using << after. For example, -// CHECK(false == true) results in a log message of "Check failed: false == true". -#define CHECK(x) \ - if (UNLIKELY(!(x))) \ - ::art::LogMessage(__FILE__, __LINE__, ::art::FATAL, -1).stream() \ - << "Check failed: " #x << " " - -// Helper for CHECK_xx(x,y) macros. -#define CHECK_OP(LHS, RHS, OP) \ - for (auto _values = ::art::MakeEagerEvaluator(LHS, RHS); \ - UNLIKELY(!(_values.lhs OP _values.rhs)); /* empty */) \ - ::art::LogMessage(__FILE__, __LINE__, ::art::FATAL, -1).stream() \ - << "Check failed: " << #LHS << " " << #OP << " " << #RHS \ - << " (" #LHS "=" << _values.lhs << ", " #RHS "=" << _values.rhs << ") " - - -// Check whether a condition holds between x and y, LOG(FATAL) if not. The value of the expressions -// x and y is evaluated once. Extra logging can be appended using << after. For example, -// CHECK_NE(0 == 1, false) results in "Check failed: false != false (0==1=false, false=false) ". -#define CHECK_EQ(x, y) CHECK_OP(x, y, ==) -#define CHECK_NE(x, y) CHECK_OP(x, y, !=) -#define CHECK_LE(x, y) CHECK_OP(x, y, <=) -#define CHECK_LT(x, y) CHECK_OP(x, y, <) -#define CHECK_GE(x, y) CHECK_OP(x, y, >=) -#define CHECK_GT(x, y) CHECK_OP(x, y, >) - -// Helper for CHECK_STRxx(s1,s2) macros. -#define CHECK_STROP(s1, s2, sense) \ - if (UNLIKELY((strcmp(s1, s2) == 0) != (sense))) \ - LOG(::art::FATAL) << "Check failed: " \ - << "\"" << (s1) << "\"" \ - << ((sense) ? " == " : " != ") \ - << "\"" << (s2) << "\"" - -// Check for string (const char*) equality between s1 and s2, LOG(FATAL) if not. -#define CHECK_STREQ(s1, s2) CHECK_STROP(s1, s2, true) -#define CHECK_STRNE(s1, s2) CHECK_STROP(s1, s2, false) - -// Perform the pthread function call(args), LOG(FATAL) on error. -#define CHECK_PTHREAD_CALL(call, args, what) \ - do { \ - int rc = call args; \ - if (rc != 0) { \ - errno = rc; \ - PLOG(::art::FATAL) << # call << " failed for " << (what); \ - } \ - } while (false) - - -// DCHECKs are debug variants of CHECKs only enabled in debug builds. Generally CHECK should be -// used unless profiling identifies a CHECK as being in performance critical code. -#if defined(NDEBUG) -static constexpr bool kEnableDChecks = false; -#else -static constexpr bool kEnableDChecks = true; -#endif - -#define DCHECK(x) if (::art::kEnableDChecks) CHECK(x) -#define DCHECK_EQ(x, y) if (::art::kEnableDChecks) CHECK_EQ(x, y) -#define DCHECK_NE(x, y) if (::art::kEnableDChecks) CHECK_NE(x, y) -#define DCHECK_LE(x, y) if (::art::kEnableDChecks) CHECK_LE(x, y) -#define DCHECK_LT(x, y) if (::art::kEnableDChecks) CHECK_LT(x, y) -#define DCHECK_GE(x, y) if (::art::kEnableDChecks) CHECK_GE(x, y) -#define DCHECK_GT(x, y) if (::art::kEnableDChecks) CHECK_GT(x, y) -#define DCHECK_STREQ(s1, s2) if (::art::kEnableDChecks) CHECK_STREQ(s1, s2) -#define DCHECK_STRNE(s1, s2) if (::art::kEnableDChecks) CHECK_STRNE(s1, s2) - -// Temporary class created to evaluate the LHS and RHS, used with MakeEagerEvaluator to infer the -// types of LHS and RHS. -template <typename LHS, typename RHS> -struct EagerEvaluator { - constexpr EagerEvaluator(LHS l, RHS r) : lhs(l), rhs(r) { } - LHS lhs; - RHS rhs; -}; - -// Helper function for CHECK_xx. -template <typename LHS, typename RHS> -constexpr EagerEvaluator<LHS, RHS> MakeEagerEvaluator(LHS lhs, RHS rhs) { - return EagerEvaluator<LHS, RHS>(lhs, rhs); -} - -// Explicitly instantiate EagerEvalue for pointers so that char*s aren't treated as strings. To -// compare strings use CHECK_STREQ and CHECK_STRNE. We rely on signed/unsigned warnings to -// protect you against combinations not explicitly listed below. -#define EAGER_PTR_EVALUATOR(T1, T2) \ - template <> struct EagerEvaluator<T1, T2> { \ - EagerEvaluator(T1 l, T2 r) \ - : lhs(reinterpret_cast<const void*>(l)), \ - rhs(reinterpret_cast<const void*>(r)) { } \ - const void* lhs; \ - const void* rhs; \ - } -EAGER_PTR_EVALUATOR(const char*, const char*); -EAGER_PTR_EVALUATOR(const char*, char*); -EAGER_PTR_EVALUATOR(char*, const char*); -EAGER_PTR_EVALUATOR(char*, char*); -EAGER_PTR_EVALUATOR(const unsigned char*, const unsigned char*); -EAGER_PTR_EVALUATOR(const unsigned char*, unsigned char*); -EAGER_PTR_EVALUATOR(unsigned char*, const unsigned char*); -EAGER_PTR_EVALUATOR(unsigned char*, unsigned char*); -EAGER_PTR_EVALUATOR(const signed char*, const signed char*); -EAGER_PTR_EVALUATOR(const signed char*, signed char*); -EAGER_PTR_EVALUATOR(signed char*, const signed char*); -EAGER_PTR_EVALUATOR(signed char*, signed char*); - -// Data for the log message, not stored in LogMessage to avoid increasing the stack size. -class LogMessageData; - -// A LogMessage is a temporarily scoped object used by LOG and the unlikely part of a CHECK. The -// destructor will abort if the severity is FATAL. -class LogMessage { - public: - LogMessage(const char* file, unsigned int line, LogSeverity severity, int error); - - ~LogMessage(); // TODO: enable REQUIRES(!Locks::logging_lock_). - - // Returns the stream associated with the message, the LogMessage performs output when it goes - // out of scope. - std::ostream& stream(); - - // The routine that performs the actual logging. - static void LogLine(const char* file, unsigned int line, LogSeverity severity, const char* msg); - - // A variant of the above for use with little stack. - static void LogLineLowStack(const char* file, unsigned int line, LogSeverity severity, - const char* msg); - - private: - const std::unique_ptr<LogMessageData> data_; - - 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_; -}; +#define VLOG_STREAM(module) LOG_STREAM(INFO) } // namespace art diff --git a/runtime/base/mutex.cc b/runtime/base/mutex.cc index 43c38c4363..9d56954445 100644 --- a/runtime/base/mutex.cc +++ b/runtime/base/mutex.cc @@ -328,14 +328,20 @@ Mutex::~Mutex() { bool shutting_down = IsShuttingDown(); #if ART_USE_FUTEXES if (state_.LoadRelaxed() != 0) { - LOG(shutting_down ? WARNING : FATAL) << "destroying mutex with owner: " << exclusive_owner_; + LOG(shutting_down + ? ::android::base::WARNING + : ::android::base::FATAL) << "destroying mutex with owner: " << exclusive_owner_; } else { if (exclusive_owner_ != 0) { - LOG(shutting_down ? WARNING : FATAL) << "unexpectedly found an owner on unlocked mutex " + LOG(shutting_down + ? ::android::base::WARNING + : ::android::base::FATAL) << "unexpectedly found an owner on unlocked mutex " << name_; } if (num_contenders_.LoadSequentiallyConsistent() != 0) { - LOG(shutting_down ? WARNING : FATAL) << "unexpectedly found a contender on mutex " << name_; + LOG(shutting_down + ? ::android::base::WARNING + : ::android::base::FATAL) << "unexpectedly found a contender on mutex " << name_; } } #else @@ -346,7 +352,9 @@ Mutex::~Mutex() { errno = rc; // TODO: should we just not log at all if shutting down? this could be the logging mutex! MutexLock mu(Thread::Current(), *Locks::runtime_shutdown_lock_); - PLOG(shutting_down ? WARNING : FATAL) << "pthread_mutex_destroy failed for " << name_; + PLOG(shutting_down + ? ::android::base::WARNING + : ::android::base::FATAL) << "pthread_mutex_destroy failed for " << name_; } #endif } @@ -480,9 +488,11 @@ void Mutex::ExclusiveUnlock(Thread* self) { if (this != Locks::logging_lock_) { LOG(FATAL) << "Unexpected state_ in unlock " << cur_state << " for " << name_; } else { - LogMessage::LogLine(__FILE__, __LINE__, INTERNAL_FATAL, - StringPrintf("Unexpected state_ %d in unlock for %s", - cur_state, name_).c_str()); + LogHelper::LogLineLowStack(__FILE__, + __LINE__, + ::android::base::FATAL_WITHOUT_ABORT, + StringPrintf("Unexpected state_ %d in unlock for %s", + cur_state, name_).c_str()); _exit(1); } } @@ -762,7 +772,10 @@ ConditionVariable::~ConditionVariable() { if (num_waiters_!= 0) { Runtime* runtime = Runtime::Current(); bool shutting_down = runtime == nullptr || runtime->IsShuttingDown(Thread::Current()); - LOG(shutting_down ? WARNING : FATAL) << "ConditionVariable::~ConditionVariable for " << name_ + LOG(shutting_down + ? ::android::base::WARNING + : ::android::base::FATAL) + << "ConditionVariable::~ConditionVariable for " << name_ << " called with " << num_waiters_ << " waiters."; } #else @@ -774,7 +787,9 @@ ConditionVariable::~ConditionVariable() { MutexLock mu(Thread::Current(), *Locks::runtime_shutdown_lock_); Runtime* runtime = Runtime::Current(); bool shutting_down = (runtime == nullptr) || runtime->IsShuttingDownLocked(); - PLOG(shutting_down ? WARNING : FATAL) << "pthread_cond_destroy failed for " << name_; + PLOG(shutting_down + ? ::android::base::WARNING + : ::android::base::FATAL) << "pthread_cond_destroy failed for " << name_; } #endif } diff --git a/runtime/base/unix_file/fd_file.cc b/runtime/base/unix_file/fd_file.cc index 48e3ceb064..4498198b34 100644 --- a/runtime/base/unix_file/fd_file.cc +++ b/runtime/base/unix_file/fd_file.cc @@ -64,16 +64,16 @@ FdFile::FdFile(const std::string& path, int flags, mode_t mode, bool check_usage void FdFile::Destroy() { if (kCheckSafeUsage && (guard_state_ < GuardState::kNoCheck)) { if (guard_state_ < GuardState::kFlushed) { - LOG(::art::ERROR) << "File " << file_path_ << " wasn't explicitly flushed before destruction."; + LOG(ERROR) << "File " << file_path_ << " wasn't explicitly flushed before destruction."; } if (guard_state_ < GuardState::kClosed) { - LOG(::art::ERROR) << "File " << file_path_ << " wasn't explicitly closed before destruction."; + LOG(ERROR) << "File " << file_path_ << " wasn't explicitly closed before destruction."; } CHECK_GE(guard_state_, GuardState::kClosed); } if (auto_close_ && fd_ != -1) { if (Close() != 0) { - PLOG(::art::WARNING) << "Failed to close file " << file_path_; + PLOG(WARNING) << "Failed to close file " << file_path_; } } } @@ -104,7 +104,7 @@ void FdFile::moveTo(GuardState target, GuardState warn_threshold, const char* wa if (kCheckSafeUsage) { if (guard_state_ < GuardState::kNoCheck) { if (warn_threshold < GuardState::kNoCheck && guard_state_ >= warn_threshold) { - LOG(::art::ERROR) << warning; + LOG(ERROR) << warning; } guard_state_ = target; } @@ -117,7 +117,7 @@ void FdFile::moveUp(GuardState target, const char* warning) { if (guard_state_ < target) { guard_state_ = target; } else if (target < guard_state_) { - LOG(::art::ERROR) << warning; + LOG(ERROR) << warning; } } } @@ -350,13 +350,13 @@ int FdFile::FlushCloseOrErase() { DCHECK(!read_only_mode_); int flush_result = TEMP_FAILURE_RETRY(Flush()); if (flush_result != 0) { - LOG(::art::ERROR) << "CloseOrErase failed while flushing a file."; + LOG(ERROR) << "CloseOrErase failed while flushing a file."; Erase(); return flush_result; } int close_result = TEMP_FAILURE_RETRY(Close()); if (close_result != 0) { - LOG(::art::ERROR) << "CloseOrErase failed while closing a file."; + LOG(ERROR) << "CloseOrErase failed while closing a file."; Erase(); return close_result; } @@ -367,11 +367,11 @@ int FdFile::FlushClose() { DCHECK(!read_only_mode_); int flush_result = TEMP_FAILURE_RETRY(Flush()); if (flush_result != 0) { - LOG(::art::ERROR) << "FlushClose failed while flushing a file."; + LOG(ERROR) << "FlushClose failed while flushing a file."; } int close_result = TEMP_FAILURE_RETRY(Close()); if (close_result != 0) { - LOG(::art::ERROR) << "FlushClose failed while closing a file."; + LOG(ERROR) << "FlushClose failed while closing a file."; } return (flush_result != 0) ? flush_result : close_result; } @@ -383,7 +383,7 @@ void FdFile::MarkUnchecked() { bool FdFile::ClearContent() { DCHECK(!read_only_mode_); if (SetLength(0) < 0) { - PLOG(art::ERROR) << "Failed to reset the length"; + PLOG(ERROR) << "Failed to reset the length"; return false; } return ResetOffset(); @@ -393,7 +393,7 @@ bool FdFile::ResetOffset() { DCHECK(!read_only_mode_); off_t rc = TEMP_FAILURE_RETRY(lseek(fd_, 0, SEEK_SET)); if (rc == static_cast<off_t>(-1)) { - PLOG(art::ERROR) << "Failed to reset the offset"; + PLOG(ERROR) << "Failed to reset the offset"; return false; } return true; diff --git a/runtime/check_jni.cc b/runtime/check_jni.cc index 6683f13fd0..a980535c40 100644 --- a/runtime/check_jni.cc +++ b/runtime/check_jni.cc @@ -275,7 +275,7 @@ class ScopedCheck { return false; } if (!Runtime::Current()->GetHeap()->IsValidObjectAddress(o)) { - Runtime::Current()->GetHeap()->DumpSpaces(LOG(ERROR)); + Runtime::Current()->GetHeap()->DumpSpaces(LOG_STREAM(ERROR)); AbortF("field operation on invalid %s: %p", ToStr<IndirectRefKind>(GetIndirectRefKind(java_object)).c_str(), java_object); @@ -783,7 +783,7 @@ class ScopedCheck { } if (!Runtime::Current()->GetHeap()->IsValidObjectAddress(obj)) { - Runtime::Current()->GetHeap()->DumpSpaces(LOG(ERROR)); + Runtime::Current()->GetHeap()->DumpSpaces(LOG_STREAM(ERROR)); AbortF("%s is an invalid %s: %p (%p)", what, ToStr<IndirectRefKind>(GetIndirectRefKind(java_object)).c_str(), java_object, obj); @@ -1109,7 +1109,7 @@ class ScopedCheck { mirror::Array* a = soa.Decode<mirror::Array*>(java_array); if (UNLIKELY(!Runtime::Current()->GetHeap()->IsValidObjectAddress(a))) { - Runtime::Current()->GetHeap()->DumpSpaces(LOG(ERROR)); + Runtime::Current()->GetHeap()->DumpSpaces(LOG_STREAM(ERROR)); AbortF("jarray is an invalid %s: %p (%p)", ToStr<IndirectRefKind>(GetIndirectRefKind(java_array)).c_str(), java_array, a); @@ -1146,7 +1146,7 @@ class ScopedCheck { ArtField* f = soa.DecodeField(fid); // TODO: Better check here. if (!Runtime::Current()->GetHeap()->IsValidObjectAddress(f->GetDeclaringClass())) { - Runtime::Current()->GetHeap()->DumpSpaces(LOG(ERROR)); + Runtime::Current()->GetHeap()->DumpSpaces(LOG_STREAM(ERROR)); AbortF("invalid jfieldID: %p", fid); return nullptr; } @@ -1162,7 +1162,7 @@ class ScopedCheck { ArtMethod* m = soa.DecodeMethod(mid); // TODO: Better check here. if (!Runtime::Current()->GetHeap()->IsValidObjectAddress(m->GetDeclaringClass())) { - Runtime::Current()->GetHeap()->DumpSpaces(LOG(ERROR)); + Runtime::Current()->GetHeap()->DumpSpaces(LOG_STREAM(ERROR)); AbortF("invalid jmethodID: %p", mid); return nullptr; } diff --git a/runtime/class_linker.cc b/runtime/class_linker.cc index 845e39aa85..678abe0bb6 100644 --- a/runtime/class_linker.cc +++ b/runtime/class_linker.cc @@ -7920,7 +7920,7 @@ class DumpClassVisitor : public ClassVisitor { explicit DumpClassVisitor(int flags) : flags_(flags) {} bool operator()(mirror::Class* klass) OVERRIDE REQUIRES_SHARED(Locks::mutator_lock_) { - klass->DumpClass(LOG(ERROR), flags_); + klass->DumpClass(LOG_STREAM(ERROR), flags_); return true; } diff --git a/runtime/common_runtime_test.cc b/runtime/common_runtime_test.cc index 8a486040b5..11722b2573 100644 --- a/runtime/common_runtime_test.cc +++ b/runtime/common_runtime_test.cc @@ -58,7 +58,7 @@ int main(int argc, char **argv) { setenv("ANDROID_LOG_TAGS", "*:e", 1); art::InitLogging(argv); - LOG(::art::INFO) << "Running main() from common_runtime_test.cc..."; + LOG(INFO) << "Running main() from common_runtime_test.cc..."; testing::InitGoogleTest(&argc, argv); return RUN_ALL_TESTS(); } diff --git a/runtime/entrypoints/quick/quick_deoptimization_entrypoints.cc b/runtime/entrypoints/quick/quick_deoptimization_entrypoints.cc index 5b9d03b7fa..343343fc3f 100644 --- a/runtime/entrypoints/quick/quick_deoptimization_entrypoints.cc +++ b/runtime/entrypoints/quick/quick_deoptimization_entrypoints.cc @@ -36,7 +36,7 @@ NO_RETURN static void artDeoptimizeImpl(Thread* self, bool single_frame) // specialized visitor that will show whether a method is Quick or Shadow. } else { LOG(INFO) << "Deopting:"; - self->Dump(LOG(INFO)); + self->Dump(LOG_STREAM(INFO)); } } diff --git a/runtime/fault_handler.cc b/runtime/fault_handler.cc index f86921c1b9..f9345b64a8 100644 --- a/runtime/fault_handler.cc +++ b/runtime/fault_handler.cc @@ -438,7 +438,7 @@ bool JavaStackTraceHandler::Action(int sig ATTRIBUTE_UNUSED, siginfo_t* siginfo, // above. abort(); #endif - self->DumpJavaStack(LOG(ERROR)); + self->DumpJavaStack(LOG_STREAM(ERROR)); } return false; // Return false since we want to propagate the fault to the main signal handler. diff --git a/runtime/gc/accounting/mod_union_table.cc b/runtime/gc/accounting/mod_union_table.cc index 24a2c1783e..3b6750ebdb 100644 --- a/runtime/gc/accounting/mod_union_table.cc +++ b/runtime/gc/accounting/mod_union_table.cc @@ -283,7 +283,7 @@ class CheckReferenceVisitor { << from_space->GetGcRetentionPolicy(); LOG(INFO) << "ToSpace " << to_space->GetName() << " type " << to_space->GetGcRetentionPolicy(); - heap->DumpSpaces(LOG(INFO)); + heap->DumpSpaces(LOG_STREAM(INFO)); LOG(FATAL) << "FATAL ERROR"; } } diff --git a/runtime/gc/allocator/dlmalloc.cc b/runtime/gc/allocator/dlmalloc.cc index dc4e31253f..0c84224fcb 100644 --- a/runtime/gc/allocator/dlmalloc.cc +++ b/runtime/gc/allocator/dlmalloc.cc @@ -37,6 +37,9 @@ static void art_heap_usage_error(const char* function, void* p); #pragma GCC diagnostic ignored "-Wempty-body" #pragma GCC diagnostic ignored "-Wstrict-aliasing" #include "../../../external/dlmalloc/malloc.c" +// Note: malloc.c uses a DEBUG define to drive debug code. This interferes with the DEBUG severity +// of libbase, so undefine it now. +#undef DEBUG #pragma GCC diagnostic pop static void* art_heap_morecore(void* m, intptr_t increment) { @@ -44,11 +47,11 @@ static void* art_heap_morecore(void* m, intptr_t increment) { } static void art_heap_corruption(const char* function) { - LOG(::art::FATAL) << "Corrupt heap detected in: " << function; + LOG(FATAL) << "Corrupt heap detected in: " << function; } static void art_heap_usage_error(const char* function, void* p) { - LOG(::art::FATAL) << "Incorrect use of function '" << function << "' argument " << p + LOG(FATAL) << "Incorrect use of function '" << function << "' argument " << p << " not expected"; } @@ -69,7 +72,7 @@ extern "C" void DlmallocMadviseCallback(void* start, void* end, size_t used_byte int rc = madvise(start, length, MADV_DONTNEED); if (UNLIKELY(rc != 0)) { errno = rc; - PLOG(::art::FATAL) << "madvise failed during heap trimming"; + PLOG(FATAL) << "madvise failed during heap trimming"; } size_t* reclaimed = reinterpret_cast<size_t*>(arg); *reclaimed += length; diff --git a/runtime/gc/collector/concurrent_copying.cc b/runtime/gc/collector/concurrent_copying.cc index 2750fea751..ab8942a4b8 100644 --- a/runtime/gc/collector/concurrent_copying.cc +++ b/runtime/gc/collector/concurrent_copying.cc @@ -430,7 +430,7 @@ void ConcurrentCopying::FlipThreadRoots() { TimingLogger::ScopedTiming split("FlipThreadRoots", GetTimings()); if (kVerboseMode) { LOG(INFO) << "time=" << region_space_->Time(); - region_space_->DumpNonFreeRegions(LOG(INFO)); + region_space_->DumpNonFreeRegions(LOG_STREAM(INFO)); } Thread* self = Thread::Current(); Locks::mutator_lock_->AssertNotHeld(self); @@ -447,7 +447,7 @@ void ConcurrentCopying::FlipThreadRoots() { QuasiAtomic::ThreadFenceForConstructor(); if (kVerboseMode) { LOG(INFO) << "time=" << region_space_->Time(); - region_space_->DumpNonFreeRegions(LOG(INFO)); + region_space_->DumpNonFreeRegions(LOG_STREAM(INFO)); LOG(INFO) << "GC end of FlipThreadRoots"; } } @@ -1622,7 +1622,7 @@ void ConcurrentCopying::AssertToSpaceInvariant(mirror::Object* obj, MemberOffset if (obj != nullptr) { LogFromSpaceRefHolder(obj, offset); } - ref->GetLockWord(false).Dump(LOG(INTERNAL_FATAL)); + ref->GetLockWord(false).Dump(LOG_STREAM(FATAL_WITHOUT_ABORT)); CHECK(false) << "Found from-space ref " << ref << " " << PrettyTypeOf(ref); } else { AssertToSpaceInvariantInNonMovingSpace(obj, ref); @@ -1645,13 +1645,13 @@ class RootPrinter { template <class MirrorType> void VisitRoot(mirror::Object** root) REQUIRES_SHARED(Locks::mutator_lock_) { - LOG(INTERNAL_FATAL) << "root=" << root << " ref=" << *root; + LOG(FATAL_WITHOUT_ABORT) << "root=" << root << " ref=" << *root; } template <class MirrorType> void VisitRoot(mirror::CompressedReference<MirrorType>* root) REQUIRES_SHARED(Locks::mutator_lock_) { - LOG(INTERNAL_FATAL) << "root=" << root << " ref=" << root->AsMirrorPtr(); + LOG(FATAL_WITHOUT_ABORT) << "root=" << root << " ref=" << root->AsMirrorPtr(); } }; @@ -1670,19 +1670,19 @@ void ConcurrentCopying::AssertToSpaceInvariant(GcRootSource* gc_root_source, // No info. } else if (gc_root_source->HasArtField()) { ArtField* field = gc_root_source->GetArtField(); - LOG(INTERNAL_FATAL) << "gc root in field " << field << " " << PrettyField(field); + LOG(FATAL_WITHOUT_ABORT) << "gc root in field " << field << " " << PrettyField(field); RootPrinter root_printer; field->VisitRoots(root_printer); } else if (gc_root_source->HasArtMethod()) { ArtMethod* method = gc_root_source->GetArtMethod(); - LOG(INTERNAL_FATAL) << "gc root in method " << method << " " << PrettyMethod(method); + LOG(FATAL_WITHOUT_ABORT) << "gc root in method " << method << " " << PrettyMethod(method); RootPrinter root_printer; method->VisitRoots(root_printer, kRuntimePointerSize); } - ref->GetLockWord(false).Dump(LOG(INTERNAL_FATAL)); - region_space_->DumpNonFreeRegions(LOG(INTERNAL_FATAL)); - PrintFileToLog("/proc/self/maps", LogSeverity::INTERNAL_FATAL); - MemMap::DumpMaps(LOG(INTERNAL_FATAL), true); + ref->GetLockWord(false).Dump(LOG_STREAM(FATAL_WITHOUT_ABORT)); + region_space_->DumpNonFreeRegions(LOG_STREAM(FATAL_WITHOUT_ABORT)); + PrintFileToLog("/proc/self/maps", LogSeverity::FATAL_WITHOUT_ABORT); + MemMap::DumpMaps(LOG_STREAM(FATAL_WITHOUT_ABORT), true); CHECK(false) << "Found from-space ref " << ref << " " << PrettyTypeOf(ref); } else { AssertToSpaceInvariantInNonMovingSpace(nullptr, ref); diff --git a/runtime/gc/collector/mark_compact.cc b/runtime/gc/collector/mark_compact.cc index d866106532..6d2f009868 100644 --- a/runtime/gc/collector/mark_compact.cc +++ b/runtime/gc/collector/mark_compact.cc @@ -139,7 +139,7 @@ inline mirror::Object* MarkCompact::MarkObject(mirror::Object* obj) { REQUIRES_SHARED(Locks::mutator_lock_) { // Marking a large object, make sure its aligned as a sanity check. if (!IsAligned<kPageSize>(ref)) { - Runtime::Current()->GetHeap()->DumpSpaces(LOG(ERROR)); + Runtime::Current()->GetHeap()->DumpSpaces(LOG_STREAM(ERROR)); LOG(FATAL) << ref; } }; diff --git a/runtime/gc/collector/mark_sweep.cc b/runtime/gc/collector/mark_sweep.cc index cbc4dc1df0..ad3dd33303 100644 --- a/runtime/gc/collector/mark_sweep.cc +++ b/runtime/gc/collector/mark_sweep.cc @@ -413,11 +413,11 @@ class MarkSweep::MarkObjectSlowPath { if (UNLIKELY(obj == nullptr || !IsAligned<kPageSize>(obj) || (kIsDebugBuild && large_object_space != nullptr && !large_object_space->Contains(obj)))) { - LOG(INTERNAL_FATAL) << "Tried to mark " << obj << " not contained by any spaces"; + LOG(FATAL_WITHOUT_ABORT) << "Tried to mark " << obj << " not contained by any spaces"; if (holder_ != nullptr) { size_t holder_size = holder_->SizeOf(); ArtField* field = holder_->FindFieldByOffset(offset_); - LOG(INTERNAL_FATAL) << "Field info: " + LOG(FATAL_WITHOUT_ABORT) << "Field info: " << " holder=" << holder_ << " holder is " << (mark_sweep_->GetHeap()->IsLiveObjectLocked(holder_) @@ -440,13 +440,13 @@ class MarkSweep::MarkObjectSlowPath { // Print the memory content of the holder. for (size_t i = 0; i < holder_size / sizeof(uint32_t); ++i) { uint32_t* p = reinterpret_cast<uint32_t*>(holder_); - LOG(INTERNAL_FATAL) << &p[i] << ": " << "holder+" << (i * sizeof(uint32_t)) << " = " + LOG(FATAL_WITHOUT_ABORT) << &p[i] << ": " << "holder+" << (i * sizeof(uint32_t)) << " = " << std::hex << p[i]; } } - PrintFileToLog("/proc/self/maps", LogSeverity::INTERNAL_FATAL); - MemMap::DumpMaps(LOG(INTERNAL_FATAL), true); - LOG(INTERNAL_FATAL) << "Attempting see if it's a bad thread root"; + PrintFileToLog("/proc/self/maps", LogSeverity::FATAL_WITHOUT_ABORT); + MemMap::DumpMaps(LOG_STREAM(FATAL_WITHOUT_ABORT), true); + LOG(FATAL_WITHOUT_ABORT) << "Attempting see if it's a bad thread root"; mark_sweep_->VerifySuspendedThreadRoots(); LOG(FATAL) << "Can't mark invalid object"; } @@ -574,7 +574,7 @@ class MarkSweep::VerifyRootVisitor : public SingleRootVisitor { if (heap->GetLiveBitmap()->GetContinuousSpaceBitmap(root) == nullptr) { space::LargeObjectSpace* large_object_space = heap->GetLargeObjectsSpace(); if (large_object_space != nullptr && !large_object_space->Contains(root)) { - LOG(INTERNAL_FATAL) << "Found invalid root: " << root << " " << info; + LOG(FATAL_WITHOUT_ABORT) << "Found invalid root: " << root << " " << info; } } } diff --git a/runtime/gc/collector/semi_space.cc b/runtime/gc/collector/semi_space.cc index 47e6ca3311..2e971729f0 100644 --- a/runtime/gc/collector/semi_space.cc +++ b/runtime/gc/collector/semi_space.cc @@ -296,7 +296,7 @@ class SemiSpace::VerifyNoFromSpaceReferencesVisitor { REQUIRES_SHARED(Locks::mutator_lock_) ALWAYS_INLINE { mirror::Object* ref = obj->GetFieldObject<mirror::Object>(offset); if (from_space_->HasAddress(ref)) { - Runtime::Current()->GetHeap()->DumpObject(LOG(INFO), obj); + Runtime::Current()->GetHeap()->DumpObject(LOG_STREAM(INFO), obj); LOG(FATAL) << ref << " found in from space"; } } diff --git a/runtime/gc/heap.cc b/runtime/gc/heap.cc index 11d4af8860..4e6dd2b13c 100644 --- a/runtime/gc/heap.cc +++ b/runtime/gc/heap.cc @@ -630,7 +630,7 @@ Heap::Heap(size_t initial_size, bool no_gap = MemMap::CheckNoGaps(first_space->GetMemMap(), non_moving_space_->GetMemMap()); if (!no_gap) { PrintFileToLog("/proc/self/maps", LogSeverity::ERROR); - MemMap::DumpMaps(LOG(ERROR), true); + MemMap::DumpMaps(LOG_STREAM(ERROR), true); LOG(FATAL) << "There's a gap between the image space and the non-moving space"; } } @@ -3157,14 +3157,14 @@ size_t Heap::VerifyHeapReferences(bool verify_referents) { // Dump mod-union tables. for (const auto& table_pair : mod_union_tables_) { accounting::ModUnionTable* mod_union_table = table_pair.second; - mod_union_table->Dump(LOG(ERROR) << mod_union_table->GetName() << ": "); + mod_union_table->Dump(LOG_STREAM(ERROR) << mod_union_table->GetName() << ": "); } // Dump remembered sets. for (const auto& table_pair : remembered_sets_) { accounting::RememberedSet* remembered_set = table_pair.second; - remembered_set->Dump(LOG(ERROR) << remembered_set->GetName() << ": "); + remembered_set->Dump(LOG_STREAM(ERROR) << remembered_set->GetName() << ": "); } - DumpSpaces(LOG(ERROR)); + DumpSpaces(LOG_STREAM(ERROR)); } return visitor.GetFailureCount(); } diff --git a/runtime/gc/reference_queue_test.cc b/runtime/gc/reference_queue_test.cc index 35bf718875..2a1635dff9 100644 --- a/runtime/gc/reference_queue_test.cc +++ b/runtime/gc/reference_queue_test.cc @@ -14,6 +14,8 @@ * limitations under the License. */ +#include <sstream> + #include "common_runtime_test.h" #include "reference_queue.h" #include "handle_scope-inl.h" @@ -65,7 +67,9 @@ TEST_F(ReferenceQueueTest, Dump) { StackHandleScope<20> hs(self); Mutex lock("Reference queue lock"); ReferenceQueue queue(&lock); - queue.Dump(LOG(INFO)); + std::ostringstream oss; + queue.Dump(oss); + LOG(INFO) << oss.str(); auto weak_ref_class = hs.NewHandle( Runtime::Current()->GetClassLinker()->FindClass(self, "Ljava/lang/ref/WeakReference;", ScopedNullHandle<mirror::ClassLoader>())); @@ -78,10 +82,16 @@ TEST_F(ReferenceQueueTest, Dump) { ASSERT_TRUE(ref1.Get() != nullptr); auto ref2(hs.NewHandle(finalizer_ref_class->AllocObject(self)->AsReference())); ASSERT_TRUE(ref2.Get() != nullptr); + queue.EnqueueReference(ref1.Get()); - queue.Dump(LOG(INFO)); + oss.str(""); + queue.Dump(oss); + LOG(INFO) << oss.str(); + queue.EnqueueReference(ref2.Get()); - queue.Dump(LOG(INFO)); + oss.str(""); + queue.Dump(oss); + LOG(INFO) << oss.str(); } } // namespace gc diff --git a/runtime/gc/space/image_space.cc b/runtime/gc/space/image_space.cc index 9c91732da7..a40e408bc8 100644 --- a/runtime/gc/space/image_space.cc +++ b/runtime/gc/space/image_space.cc @@ -728,7 +728,7 @@ class ImageSpaceLoader { VLOG(image) << "ImageSpace::Init exiting " << *space.get(); if (VLOG_IS_ON(image)) { - logger.Dump(LOG(INFO)); + logger.Dump(LOG_STREAM(INFO)); } return space; } @@ -1298,7 +1298,7 @@ class ImageSpaceLoader { } } if (VLOG_IS_ON(image)) { - logger.Dump(LOG(INFO)); + logger.Dump(LOG_STREAM(INFO)); } return true; } diff --git a/runtime/gc/space/large_object_space.cc b/runtime/gc/space/large_object_space.cc index 010f677885..16d1f939d7 100644 --- a/runtime/gc/space/large_object_space.cc +++ b/runtime/gc/space/large_object_space.cc @@ -192,7 +192,7 @@ size_t LargeObjectMapSpace::Free(Thread* self, mirror::Object* ptr) { auto it = large_objects_.find(ptr); if (UNLIKELY(it == large_objects_.end())) { ScopedObjectAccess soa(self); - Runtime::Current()->GetHeap()->DumpSpaces(LOG(INTERNAL_FATAL)); + Runtime::Current()->GetHeap()->DumpSpaces(LOG_STREAM(FATAL_WITHOUT_ABORT)); LOG(FATAL) << "Attempted to free large object " << ptr << " which was not live"; } MemMap* mem_map = it->second.mem_map; diff --git a/runtime/gc/space/large_object_space_test.cc b/runtime/gc/space/large_object_space_test.cc index ad38724e7d..2544914a95 100644 --- a/runtime/gc/space/large_object_space_test.cc +++ b/runtime/gc/space/large_object_space_test.cc @@ -98,7 +98,9 @@ void LargeObjectSpaceTest::LargeObjectTest() { } } // Test that dump doesn't crash. - los->Dump(LOG(INFO)); + std::ostringstream oss; + los->Dump(oss); + LOG(INFO) << oss.str(); size_t bytes_allocated = 0, bytes_tl_bulk_allocated; // Checks that the coalescing works. diff --git a/runtime/gc/space/region_space.cc b/runtime/gc/space/region_space.cc index e24741a4a6..23cae7c821 100644 --- a/runtime/gc/space/region_space.cc +++ b/runtime/gc/space/region_space.cc @@ -38,7 +38,7 @@ RegionSpace* RegionSpace::Create(const std::string& name, size_t capacity, if (mem_map.get() == nullptr) { LOG(ERROR) << "Failed to allocate pages for alloc space (" << name << ") of size " << PrettySize(capacity) << " with message " << error_msg; - MemMap::DumpMaps(LOG(ERROR)); + MemMap::DumpMaps(LOG_STREAM(ERROR)); return nullptr; } return new RegionSpace(name, mem_map.release()); diff --git a/runtime/indirect_reference_table.cc b/runtime/indirect_reference_table.cc index 4f81b59115..1f39a1e695 100644 --- a/runtime/indirect_reference_table.cc +++ b/runtime/indirect_reference_table.cc @@ -188,7 +188,7 @@ bool IndirectReferenceTable::Remove(uint32_t cookie, IndirectRef iref) { ScopedObjectAccess soa(self); LOG(WARNING) << "Attempt to remove non-JNI local reference, dumping thread"; if (kDumpStackOnNonLocalReference) { - self->Dump(LOG(WARNING)); + self->Dump(LOG_STREAM(WARNING)); } } return true; diff --git a/runtime/interpreter/mterp/mterp.cc b/runtime/interpreter/mterp/mterp.cc index a8c7d15fd0..cf8d4bd1b5 100644 --- a/runtime/interpreter/mterp/mterp.cc +++ b/runtime/interpreter/mterp/mterp.cc @@ -38,8 +38,8 @@ void CheckMterpAsmConstants() { int interp_size = (uintptr_t) artMterpAsmInstructionEnd - (uintptr_t) artMterpAsmInstructionStart; if ((interp_size == 0) || (interp_size != (art::kNumPackedOpcodes * width))) { - LOG(art::FATAL) << "ERROR: unexpected asm interp size " << interp_size - << "(did an instruction handler exceed " << width << " bytes?)"; + LOG(FATAL) << "ERROR: unexpected asm interp size " << interp_size + << "(did an instruction handler exceed " << width << " bytes?)"; } } diff --git a/runtime/interpreter/unstarted_runtime.cc b/runtime/interpreter/unstarted_runtime.cc index d505aea10a..98e358b8b8 100644 --- a/runtime/interpreter/unstarted_runtime.cc +++ b/runtime/interpreter/unstarted_runtime.cc @@ -858,7 +858,7 @@ void UnstartedRuntime::UnstartedThreadLocalGet( ArtMethod* init_method = h_real_to_string_class->FindDirectMethod( "<init>", "()V", cl->GetImagePointerSize()); if (init_method == nullptr) { - h_real_to_string_class->DumpClass(LOG(FATAL), mirror::Class::kDumpClassFullDetail); + h_real_to_string_class->DumpClass(LOG_STREAM(FATAL), mirror::Class::kDumpClassFullDetail); } else { JValue invoke_result; EnterInterpreterFromInvoke(self, init_method, h_real_to_string_obj.Get(), nullptr, diff --git a/runtime/jdwp/jdwp_socket.cc b/runtime/jdwp/jdwp_socket.cc index 2507fe9e6e..3be7fd6428 100644 --- a/runtime/jdwp/jdwp_socket.cc +++ b/runtime/jdwp/jdwp_socket.cc @@ -121,7 +121,7 @@ static JdwpSocketState* SocketStartup(JdwpState* state, uint16_t port, bool prob netState->listenSock = socket(PF_INET, SOCK_STREAM, IPPROTO_TCP); if (netState->listenSock < 0) { - PLOG(probe ? ERROR : FATAL) << "Socket create failed"; + PLOG(probe ? ::android::base::ERROR : ::android::base::FATAL) << "Socket create failed"; goto fail; } @@ -129,7 +129,8 @@ static JdwpSocketState* SocketStartup(JdwpState* state, uint16_t port, bool prob { int one = 1; if (setsockopt(netState->listenSock, SOL_SOCKET, SO_REUSEADDR, &one, sizeof(one)) < 0) { - PLOG(probe ? ERROR : FATAL) << "setsockopt(SO_REUSEADDR) failed"; + PLOG(probe ? ::android::base::ERROR : ::android::base::FATAL) + << "setsockopt(SO_REUSEADDR) failed"; goto fail; } } @@ -143,14 +144,15 @@ static JdwpSocketState* SocketStartup(JdwpState* state, uint16_t port, bool prob inet_aton("127.0.0.1", &addr.addrInet.sin_addr); if (bind(netState->listenSock, &addr.addrPlain, sizeof(addr)) != 0) { - PLOG(probe ? ERROR : FATAL) << "Attempt to bind to port " << port << " failed"; + PLOG(probe ? ::android::base::ERROR : ::android::base::FATAL) + << "Attempt to bind to port " << port << " failed"; goto fail; } netState->listenPort = port; if (listen(netState->listenSock, 5) != 0) { - PLOG(probe ? ERROR : FATAL) << "Listen failed"; + PLOG(probe ? ::android::base::ERROR : ::android::base::FATAL) << "Listen failed"; goto fail; } diff --git a/runtime/jit/jit.cc b/runtime/jit/jit.cc index d984f45253..afa52ca2c4 100644 --- a/runtime/jit/jit.cc +++ b/runtime/jit/jit.cc @@ -337,7 +337,7 @@ bool Jit::CanInvokeCompiledCode(ArtMethod* method) { Jit::~Jit() { DCHECK(!profile_saver_options_.IsEnabled() || !ProfileSaver::IsStarted()); if (dump_info_on_shutdown_) { - DumpInfo(LOG(INFO)); + DumpInfo(LOG_STREAM(INFO)); } DeleteThreadPool(); if (jit_compiler_handle_ != nullptr) { diff --git a/runtime/jit/profile_saver.cc b/runtime/jit/profile_saver.cc index 42916c3e1e..a4bc3fca47 100644 --- a/runtime/jit/profile_saver.cc +++ b/runtime/jit/profile_saver.cc @@ -447,7 +447,7 @@ void ProfileSaver::Stop(bool dump_info) { } instance_->shutting_down_ = true; if (dump_info) { - instance_->DumpInfo(LOG(INFO)); + instance_->DumpInfo(LOG_STREAM(INFO)); } } diff --git a/runtime/jni_env_ext-inl.h b/runtime/jni_env_ext-inl.h index dc6a3e8f62..5967eeee4b 100644 --- a/runtime/jni_env_ext-inl.h +++ b/runtime/jni_env_ext-inl.h @@ -32,9 +32,10 @@ inline T JNIEnvExt::AddLocalReference(mirror::Object* obj) { if (check_jni) { size_t entry_count = locals.Capacity(); if (entry_count > 16) { - locals.Dump(LOG(WARNING) << "Warning: more than 16 JNI local references: " - << entry_count << " (most recent was a " << PrettyTypeOf(obj) << ")\n"); - // TODO: LOG(FATAL) in a later release? + locals.Dump(LOG_STREAM(WARNING) << "Warning: more than 16 JNI local references: " + << entry_count << " (most recent was a " + << PrettyTypeOf(obj) << ")\n"); + // TODO: LOG(FATAL) in a later release? } } } diff --git a/runtime/jni_internal.cc b/runtime/jni_internal.cc index d9cb1c66a4..59b2b07096 100644 --- a/runtime/jni_internal.cc +++ b/runtime/jni_internal.cc @@ -100,8 +100,9 @@ static void ThrowNoSuchMethodError(ScopedObjectAccess& soa, mirror::Class* c, static void ReportInvalidJNINativeMethod(const ScopedObjectAccess& soa, mirror::Class* c, const char* kind, jint idx, bool return_errors) REQUIRES_SHARED(Locks::mutator_lock_) { - LOG(return_errors ? ERROR : FATAL) << "Failed to register native method in " - << PrettyDescriptor(c) << " in " << c->GetDexCache()->GetLocation()->ToModifiedUtf8() + LOG(return_errors ? ::android::base::ERROR : ::android::base::FATAL) + << "Failed to register native method in " << PrettyDescriptor(c) + << " in " << c->GetDexCache()->GetLocation()->ToModifiedUtf8() << ": " << kind << " is null at index " << idx; soa.Self()->ThrowNewExceptionF("Ljava/lang/NoSuchMethodError;", "%s is null at index %d", kind, idx); @@ -2226,16 +2227,20 @@ class JNI { } if (m == nullptr) { - LOG(return_errors ? ERROR : INTERNAL_FATAL) << "Failed to register native method " + c->DumpClass( + LOG_STREAM(return_errors + ? ::android::base::ERROR + : ::android::base::FATAL_WITHOUT_ABORT), + mirror::Class::kDumpClassFullDetail); + LOG(return_errors ? ::android::base::ERROR : ::android::base::FATAL) + << "Failed to register native method " << PrettyDescriptor(c) << "." << name << sig << " in " << c->GetDexCache()->GetLocation()->ToModifiedUtf8(); - // Safe to pass in LOG(FATAL) since the log object aborts in destructor and only goes - // out of scope after the DumpClass is done executing. - c->DumpClass(LOG(return_errors ? ERROR : FATAL), mirror::Class::kDumpClassFullDetail); ThrowNoSuchMethodError(soa, c, name, sig, "static or non-static"); return JNI_ERR; } else if (!m->IsNative()) { - LOG(return_errors ? ERROR : FATAL) << "Failed to register non-native method " + LOG(return_errors ? ::android::base::ERROR : ::android::base::FATAL) + << "Failed to register non-native method " << PrettyDescriptor(c) << "." << name << sig << " as native"; ThrowNoSuchMethodError(soa, c, name, sig, "native"); @@ -2478,7 +2483,7 @@ class JNI { } else if (kWarnJniAbort && memcmp(array_data, elements, bytes) != 0) { // Warn if we have JNI_ABORT and the arrays don't match since this is usually an error. LOG(WARNING) << "Possible incorrect JNI_ABORT in Release*ArrayElements"; - soa.Self()->DumpJavaStack(LOG(WARNING)); + soa.Self()->DumpJavaStack(LOG_STREAM(WARNING)); } } if (mode != JNI_COMMIT) { @@ -3042,7 +3047,7 @@ std::ostream& operator<<(std::ostream& os, const jobjectRefType& rhs) { os << "JNIWeakGlobalRefType"; return os; default: - LOG(::art::FATAL) << "jobjectRefType[" << static_cast<int>(rhs) << "]"; + LOG(FATAL) << "jobjectRefType[" << static_cast<int>(rhs) << "]"; UNREACHABLE(); } } diff --git a/runtime/mirror/class.cc b/runtime/mirror/class.cc index f21baed70f..2e5f532606 100644 --- a/runtime/mirror/class.cc +++ b/runtime/mirror/class.cc @@ -147,8 +147,8 @@ void Class::SetDexCache(DexCache* new_dex_cache) { void Class::SetClassSize(uint32_t new_class_size) { if (kIsDebugBuild && new_class_size < GetClassSize()) { - DumpClass(LOG(INTERNAL_FATAL), kDumpClassFullDetail); - LOG(INTERNAL_FATAL) << new_class_size << " vs " << GetClassSize(); + DumpClass(LOG_STREAM(FATAL_WITHOUT_ABORT), kDumpClassFullDetail); + LOG(FATAL_WITHOUT_ABORT) << new_class_size << " vs " << GetClassSize(); LOG(FATAL) << "class=" << PrettyTypeOf(this); } // Not called within a transaction. diff --git a/runtime/monitor.cc b/runtime/monitor.cc index 22cc197996..49b83a719d 100644 --- a/runtime/monitor.cc +++ b/runtime/monitor.cc @@ -457,7 +457,7 @@ static void ThrowIllegalMonitorStateExceptionF(const char* fmt, ...) if (!Runtime::Current()->IsStarted() || VLOG_IS_ON(monitor)) { std::ostringstream ss; self->Dump(ss); - LOG(Runtime::Current()->IsStarted() ? INFO : ERROR) + LOG(Runtime::Current()->IsStarted() ? ::android::base::INFO : ::android::base::ERROR) << self->GetException()->Dump() << "\n" << ss.str(); } va_end(args); diff --git a/runtime/native/dalvik_system_VMDebug.cc b/runtime/native/dalvik_system_VMDebug.cc index 8f108faa1f..f09c067cfd 100644 --- a/runtime/native/dalvik_system_VMDebug.cc +++ b/runtime/native/dalvik_system_VMDebug.cc @@ -240,8 +240,8 @@ static void VMDebug_dumpReferenceTables(JNIEnv* env, jclass) { ScopedObjectAccess soa(env); LOG(INFO) << "--- reference table dump ---"; - soa.Env()->DumpReferenceTables(LOG(INFO)); - soa.Vm()->DumpReferenceTables(LOG(INFO)); + soa.Env()->DumpReferenceTables(LOG_STREAM(INFO)); + soa.Vm()->DumpReferenceTables(LOG_STREAM(INFO)); LOG(INFO) << "---"; } diff --git a/runtime/openjdkjvm/Android.bp b/runtime/openjdkjvm/Android.bp index 5ed16153ef..37112b61e7 100644 --- a/runtime/openjdkjvm/Android.bp +++ b/runtime/openjdkjvm/Android.bp @@ -19,7 +19,10 @@ cc_defaults { host_supported: true, srcs: ["OpenjdkJvm.cc"], include_dirs: ["art/runtime"], - shared_libs: ["libnativehelper"], + shared_libs: [ + "libbase", + "libnativehelper" + ], } art_cc_library { diff --git a/runtime/openjdkjvm/OpenjdkJvm.cc b/runtime/openjdkjvm/OpenjdkJvm.cc index 54ec5d32f5..4a62ecdf4d 100644 --- a/runtime/openjdkjvm/OpenjdkJvm.cc +++ b/runtime/openjdkjvm/OpenjdkJvm.cc @@ -61,10 +61,10 @@ #undef LOG_TAG #define LOG_TAG "artopenjdk" -using art::WARNING; -using art::INFO; -using art::ERROR; -using art::FATAL; +using ::android::base::WARNING; +using ::android::base::INFO; +using ::android::base::ERROR; +using ::android::base::FATAL; /* posix open() with extensions; used by e.g. ZipFile */ JNIEXPORT jint JVM_Open(const char* fname, jint flags, jint mode) { diff --git a/runtime/openjdkjvmti/Android.bp b/runtime/openjdkjvmti/Android.bp index 08272fa999..d7a6c0a86c 100644 --- a/runtime/openjdkjvmti/Android.bp +++ b/runtime/openjdkjvmti/Android.bp @@ -20,7 +20,10 @@ cc_defaults { srcs: ["OpenjdkJvmTi.cc", "transform.cc"], include_dirs: ["art/runtime"], - shared_libs: ["libnativehelper"], + shared_libs: [ + "libbase", + "libnativehelper", + ], } art_cc_library { diff --git a/runtime/openjdkjvmti/transform.cc b/runtime/openjdkjvmti/transform.cc index a0d79f3982..b5622b5cad 100644 --- a/runtime/openjdkjvmti/transform.cc +++ b/runtime/openjdkjvmti/transform.cc @@ -201,8 +201,8 @@ static bool FindDalvikSystemDexFileAndLoaderForClass( art::Handle<art::mirror::Class> loader_class(hs.NewHandle(h_class_loader->GetClass())); // Check if loader is a BaseDexClassLoader if (!loader_class->IsSubClass(base_dex_loader_class.Get())) { - LOG(art::ERROR) << "The classloader is not a BaseDexClassLoader which is currently the only " - << "supported class loader type!"; + LOG(ERROR) << "The classloader is not a BaseDexClassLoader which is currently the only " + << "supported class loader type!"; return false; } art::Handle<art::mirror::Object> path_list( @@ -333,7 +333,7 @@ jvmtiError MoveTransformedFileIntoRuntime(jclass jklass, // Find dalvik.system.DexFile that represents the dex file we are changing. if (!FindDalvikSystemDexFileAndLoaderForClass(klass, &dex_file_ptr, &class_loader_ptr)) { self->TransitionFromRunnableToSuspended(old_state); - LOG(art::ERROR) << "Could not find DexFile."; + LOG(ERROR) << "Could not find DexFile."; return ERR(INTERNAL); } art::Handle<art::mirror::Object> dex_file_obj(hs.NewHandle(dex_file_ptr)); diff --git a/runtime/quick_exception_handler.cc b/runtime/quick_exception_handler.cc index b3f29c28e4..9056d96f79 100644 --- a/runtime/quick_exception_handler.cc +++ b/runtime/quick_exception_handler.cc @@ -145,7 +145,7 @@ void QuickExceptionHandler::FindCatch(mirror::Throwable* exception) { if (kDebugExceptionDelivery) { mirror::String* msg = exception->GetDetailMessage(); std::string str_msg(msg != nullptr ? msg->ToModifiedUtf8() : ""); - self_->DumpStack(LOG(INFO) << "Delivering exception: " << PrettyTypeOf(exception) + self_->DumpStack(LOG_STREAM(INFO) << "Delivering exception: " << PrettyTypeOf(exception) << ": " << str_msg << "\n"); } StackHandleScope<1> hs(self_); @@ -218,7 +218,7 @@ void QuickExceptionHandler::SetCatchEnvironmentForOptimizedHandler(StackVisitor* DCHECK(handler_method_ != nullptr && handler_method_header_->IsOptimized()); if (kDebugExceptionDelivery) { - self_->DumpStack(LOG(INFO) << "Setting catch phis: "); + self_->DumpStack(LOG_STREAM(INFO) << "Setting catch phis: "); } const size_t number_of_vregs = handler_method_->GetCodeItem()->registers_size_; @@ -520,7 +520,7 @@ void QuickExceptionHandler::PrepareForLongJumpToInvokeStubOrInterpreterBridge() void QuickExceptionHandler::DeoptimizeStack() { DCHECK(is_deoptimization_); if (kDebugExceptionDelivery) { - self_->DumpStack(LOG(INFO) << "Deoptimizing: "); + self_->DumpStack(LOG_STREAM(INFO) << "Deoptimizing: "); } DeoptimizeStackVisitor visitor(self_, context_, this, false); diff --git a/runtime/runtime.cc b/runtime/runtime.cc index 2be3b52ab1..5bb38f5af8 100644 --- a/runtime/runtime.cc +++ b/runtime/runtime.cc @@ -255,7 +255,7 @@ Runtime::~Runtime() { // This can't be called from the Heap destructor below because it // could call RosAlloc::InspectAll() which needs the thread_list // to be still alive. - heap_->DumpGcPerformanceInfo(LOG(INFO)); + heap_->DumpGcPerformanceInfo(LOG_STREAM(INFO)); } Thread* self = Thread::Current(); @@ -433,14 +433,14 @@ void Runtime::Abort() { // Many people have difficulty distinguish aborts from crashes, // so be explicit. AbortState state; - LOG(INTERNAL_FATAL) << Dumpable<AbortState>(state); + LOG(FATAL_WITHOUT_ABORT) << Dumpable<AbortState>(state); // Call the abort hook if we have one. if (Runtime::Current() != nullptr && Runtime::Current()->abort_ != nullptr) { - LOG(INTERNAL_FATAL) << "Calling abort hook..."; + LOG(FATAL_WITHOUT_ABORT) << "Calling abort hook..."; Runtime::Current()->abort_(); // notreached - LOG(INTERNAL_FATAL) << "Unexpectedly returned from abort hook!"; + LOG(FATAL_WITHOUT_ABORT) << "Unexpectedly returned from abort hook!"; } #if defined(__GLIBC__) diff --git a/runtime/runtime_android.cc b/runtime/runtime_android.cc index 33600ddba5..aed6a2b1cf 100644 --- a/runtime/runtime_android.cc +++ b/runtime/runtime_android.cc @@ -34,7 +34,10 @@ struct sigaction old_action; void HandleUnexpectedSignal(int signal_number, siginfo_t* info, void* raw_context) { static bool handling_unexpected_signal = false; if (handling_unexpected_signal) { - LogMessage::LogLine(__FILE__, __LINE__, INTERNAL_FATAL, "HandleUnexpectedSignal reentered\n"); + LogHelper::LogLineLowStack(__FILE__, + __LINE__, + ::android::base::FATAL_WITHOUT_ABORT, + "HandleUnexpectedSignal reentered\n"); _exit(1); } handling_unexpected_signal = true; @@ -44,11 +47,11 @@ void HandleUnexpectedSignal(int signal_number, siginfo_t* info, void* raw_contex Runtime* runtime = Runtime::Current(); if (runtime != nullptr) { // Print this out first in case DumpObject faults. - LOG(INTERNAL_FATAL) << "Fault message: " << runtime->GetFaultMessage(); + LOG(FATAL_WITHOUT_ABORT) << "Fault message: " << runtime->GetFaultMessage(); gc::Heap* heap = runtime->GetHeap(); if (kDumpHeapObjectOnSigsevg && heap != nullptr && info != nullptr) { - LOG(INTERNAL_FATAL) << "Dump heap object at fault address: "; - heap->DumpObject(LOG(INTERNAL_FATAL), reinterpret_cast<mirror::Object*>(info->si_addr)); + LOG(FATAL_WITHOUT_ABORT) << "Dump heap object at fault address: "; + heap->DumpObject(LOG_STREAM(FATAL_WITHOUT_ABORT), reinterpret_cast<mirror::Object*>(info->si_addr)); } } // Run the old signal handler. diff --git a/runtime/runtime_linux.cc b/runtime/runtime_linux.cc index 60ebabc109..cee73e175a 100644 --- a/runtime/runtime_linux.cc +++ b/runtime/runtime_linux.cc @@ -309,7 +309,10 @@ static bool IsTimeoutSignal(int signal_number) { void HandleUnexpectedSignal(int signal_number, siginfo_t* info, void* raw_context) { static bool handlingUnexpectedSignal = false; if (handlingUnexpectedSignal) { - LogMessage::LogLine(__FILE__, __LINE__, INTERNAL_FATAL, "HandleUnexpectedSignal reentered\n"); + LogHelper::LogLineLowStack(__FILE__, + __LINE__, + ::android::base::FATAL_WITHOUT_ABORT, + "HandleUnexpectedSignal reentered\n"); if (IsTimeoutSignal(signal_number)) { // Ignore a recursive timeout. return; @@ -334,7 +337,7 @@ void HandleUnexpectedSignal(int signal_number, siginfo_t* info, void* raw_contex UContext thread_context(raw_context); Backtrace thread_backtrace(raw_context); - LOG(INTERNAL_FATAL) << "*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***\n" + LOG(FATAL_WITHOUT_ABORT) << "*** *** *** *** *** *** *** *** *** *** *** *** *** *** *** ***\n" << StringPrintf("Fatal signal %d (%s), code %d (%s)", signal_number, GetSignalName(signal_number), info->si_code, @@ -346,7 +349,7 @@ void HandleUnexpectedSignal(int signal_number, siginfo_t* info, void* raw_contex << "Registers:\n" << Dumpable<UContext>(thread_context) << "\n" << "Backtrace:\n" << Dumpable<Backtrace>(thread_backtrace); if (kIsDebugBuild && signal_number == SIGSEGV) { - PrintFileToLog("/proc/self/maps", LogSeverity::INTERNAL_FATAL); + PrintFileToLog("/proc/self/maps", LogSeverity::FATAL_WITHOUT_ABORT); } Runtime* runtime = Runtime::Current(); if (runtime != nullptr) { @@ -354,17 +357,17 @@ void HandleUnexpectedSignal(int signal_number, siginfo_t* info, void* raw_contex // Special timeout signal. Try to dump all threads. // Note: Do not use DumpForSigQuit, as that might disable native unwind, but the native parts // are of value here. - runtime->GetThreadList()->Dump(LOG(INTERNAL_FATAL), kDumpNativeStackOnTimeout); + runtime->GetThreadList()->Dump(LOG_STREAM(FATAL_WITHOUT_ABORT), kDumpNativeStackOnTimeout); } gc::Heap* heap = runtime->GetHeap(); - LOG(INTERNAL_FATAL) << "Fault message: " << runtime->GetFaultMessage(); + LOG(FATAL_WITHOUT_ABORT) << "Fault message: " << runtime->GetFaultMessage(); if (kDumpHeapObjectOnSigsevg && heap != nullptr && info != nullptr) { - LOG(INTERNAL_FATAL) << "Dump heap object at fault address: "; - heap->DumpObject(LOG(INTERNAL_FATAL), reinterpret_cast<mirror::Object*>(info->si_addr)); + LOG(FATAL_WITHOUT_ABORT) << "Dump heap object at fault address: "; + heap->DumpObject(LOG_STREAM(FATAL_WITHOUT_ABORT), reinterpret_cast<mirror::Object*>(info->si_addr)); } } if (getenv("debug_db_uid") != nullptr || getenv("art_wait_for_gdb_on_crash") != nullptr) { - LOG(INTERNAL_FATAL) << "********************************************************\n" + LOG(FATAL_WITHOUT_ABORT) << "********************************************************\n" << "* Process " << getpid() << " thread " << tid << " \"" << thread_name << "\"" << " has been suspended while crashing.\n" diff --git a/runtime/signal_catcher.cc b/runtime/signal_catcher.cc index 6cb795061d..848c0e3b90 100644 --- a/runtime/signal_catcher.cc +++ b/runtime/signal_catcher.cc @@ -172,7 +172,7 @@ int SignalCatcher::WaitForSignal(Thread* self, SignalSet& signals) { LOG(INFO) << *self << ": reacting to signal " << signal_number; // If anyone's holding locks (which might prevent us from getting back into state Runnable), say so... - Runtime::Current()->DumpLockHolders(LOG(INFO)); + Runtime::Current()->DumpLockHolders(LOG_STREAM(INFO)); } return signal_number; diff --git a/runtime/thread.cc b/runtime/thread.cc index 89403545fd..7091e79c93 100644 --- a/runtime/thread.cc +++ b/runtime/thread.cc @@ -609,7 +609,7 @@ void Thread::CreateNativeThread(JNIEnv* env, jobject java_peer, size_t stack_siz } VLOG(threads) << "Creating native thread for " << thread_name; - self->Dump(LOG(INFO)); + self->Dump(LOG_STREAM(INFO)); } Runtime* runtime = Runtime::Current(); @@ -804,7 +804,7 @@ Thread* Thread::Attach(const char* thread_name, bool as_daemon, jobject thread_g VLOG(threads) << "Attaching unnamed thread."; } ScopedObjectAccess soa(self); - self->Dump(LOG(INFO)); + self->Dump(LOG_STREAM(INFO)); } { @@ -911,8 +911,10 @@ bool Thread::InitStackHwm() { + 4 * KB; if (read_stack_size <= min_stack) { // Note, as we know the stack is small, avoid operations that could use a lot of stack. - LogMessage::LogLineLowStack(__PRETTY_FUNCTION__, __LINE__, ERROR, - "Attempt to attach a thread with a too-small stack"); + LogHelper::LogLineLowStack(__PRETTY_FUNCTION__, + __LINE__, + ::android::base::ERROR, + "Attempt to attach a thread with a too-small stack"); return false; } @@ -2382,7 +2384,7 @@ void Thread::ThrowOutOfMemoryError(const char* msg) { ThrowNewException("Ljava/lang/OutOfMemoryError;", msg); tls32_.throwing_OutOfMemoryError = false; } else { - Dump(LOG(WARNING)); // The pre-allocated OOME has no stack, so help out and log one. + Dump(LOG_STREAM(WARNING)); // The pre-allocated OOME has no stack, so help out and log one. SetException(Runtime::Current()->GetPreAllocatedOutOfMemoryError()); } } @@ -2775,15 +2777,15 @@ class ReferenceMapVisitor : public StackVisitor { bool failed = false; if (!space->GetLiveBitmap()->Test(klass)) { failed = true; - LOG(INTERNAL_FATAL) << "Unmarked object in image " << *space; + LOG(FATAL_WITHOUT_ABORT) << "Unmarked object in image " << *space; } else if (!heap->GetLiveBitmap()->Test(klass)) { failed = true; - LOG(INTERNAL_FATAL) << "Unmarked object in image through live bitmap " << *space; + LOG(FATAL_WITHOUT_ABORT) << "Unmarked object in image through live bitmap " << *space; } if (failed) { - GetThread()->Dump(LOG(INTERNAL_FATAL)); - space->AsImageSpace()->DumpSections(LOG(INTERNAL_FATAL)); - LOG(INTERNAL_FATAL) << "Method@" << method->GetDexMethodIndex() << ":" << method + GetThread()->Dump(LOG_STREAM(FATAL_WITHOUT_ABORT)); + space->AsImageSpace()->DumpSections(LOG_STREAM(FATAL_WITHOUT_ABORT)); + LOG(FATAL_WITHOUT_ABORT) << "Method@" << method->GetDexMethodIndex() << ":" << method << " klass@" << klass; // Pretty info last in case it crashes. LOG(FATAL) << "Method " << PrettyMethod(method) << " klass " << PrettyClass(klass); @@ -2838,7 +2840,7 @@ class ReferenceMapVisitor : public StackVisitor { if (kIsDebugBuild && ref_addr == nullptr) { std::string thread_name; GetThread()->GetThreadName(thread_name); - LOG(INTERNAL_FATAL) << "On thread " << thread_name; + LOG(FATAL_WITHOUT_ABORT) << "On thread " << thread_name; DescribeStack(GetThread()); LOG(FATAL) << "Found an unsaved callee-save register " << i << " (null GPRAddress) " << "set in register_mask=" << register_mask << " at " << DescribeLocation(); @@ -2953,7 +2955,7 @@ void Thread::SetStackEndForStackOverflow() { // However, we seem to have already extended to use the full stack. LOG(ERROR) << "Need to increase kStackOverflowReservedBytes (currently " << GetStackOverflowReservedBytes(kRuntimeISA) << ")?"; - DumpStack(LOG(ERROR)); + DumpStack(LOG_STREAM(ERROR)); LOG(FATAL) << "Recursive stack overflow."; } diff --git a/runtime/thread_list.cc b/runtime/thread_list.cc index 5e6c8a40f1..07546404d5 100644 --- a/runtime/thread_list.cc +++ b/runtime/thread_list.cc @@ -214,7 +214,7 @@ class DumpCheckpoint FINAL : public Closure { bool timed_out = barrier_.Increment(self, threads_running_checkpoint, kDumpWaitTimeout); if (timed_out) { // Avoid a recursive abort. - LOG((kIsDebugBuild && (gAborting == 0)) ? FATAL : ERROR) + LOG((kIsDebugBuild && (gAborting == 0)) ? ::android::base::FATAL : ::android::base::ERROR) << "Unexpected time out during dump checkpoint."; } } @@ -628,7 +628,8 @@ void ThreadList::SuspendAllInternal(Thread* self, // EAGAIN and EINTR both indicate a spurious failure, try again from the beginning. if ((errno != EAGAIN) && (errno != EINTR)) { if (errno == ETIMEDOUT) { - LOG(kIsDebugBuild ? FATAL : ERROR) << "Unexpected time out during suspend all."; + LOG(kIsDebugBuild ? ::android::base::FATAL : ::android::base::ERROR) + << "Unexpected time out during suspend all."; } else { PLOG(FATAL) << "futex wait failed for SuspendAllInternal()"; } @@ -775,7 +776,10 @@ Thread* ThreadList::SuspendThreadByPeer(jobject peer, // ThreadList::WaitForOtherNonDaemonThreadsToExit. suspended_thread->ModifySuspendCount(soa.Self(), -1, nullptr, debug_suspension); } - ThreadSuspendByPeerWarning(self, WARNING, "No such thread for suspend", peer); + ThreadSuspendByPeerWarning(self, + ::android::base::WARNING, + "No such thread for suspend", + peer); return nullptr; } if (!Contains(thread)) { @@ -822,7 +826,10 @@ Thread* ThreadList::SuspendThreadByPeer(jobject peer, } const uint64_t total_delay = NanoTime() - start_time; if (total_delay >= MsToNs(kThreadSuspendTimeoutMs)) { - ThreadSuspendByPeerWarning(self, FATAL, "Thread suspension timed out", peer); + ThreadSuspendByPeerWarning(self, + ::android::base::FATAL, + "Thread suspension timed out", + peer); if (suspended_thread != nullptr) { CHECK_EQ(suspended_thread, thread); suspended_thread->ModifySuspendCount(soa.Self(), -1, nullptr, debug_suspension); @@ -882,7 +889,9 @@ Thread* ThreadList::SuspendThreadByThreadId(uint32_t thread_id, CHECK(suspended_thread == nullptr) << "Suspended thread " << suspended_thread << " no longer in thread list"; // There's a race in inflating a lock and the owner giving up ownership and then dying. - ThreadSuspendByThreadIdWarning(WARNING, "No such thread id for suspend", thread_id); + ThreadSuspendByThreadIdWarning(::android::base::WARNING, + "No such thread id for suspend", + thread_id); return nullptr; } VLOG(threads) << "SuspendThreadByThreadId found thread: " << *thread; @@ -923,7 +932,9 @@ Thread* ThreadList::SuspendThreadByThreadId(uint32_t thread_id, } const uint64_t total_delay = NanoTime() - start_time; if (total_delay >= MsToNs(kThreadSuspendTimeoutMs)) { - ThreadSuspendByThreadIdWarning(WARNING, "Thread suspension timed out", thread_id); + ThreadSuspendByThreadIdWarning(::android::base::WARNING, + "Thread suspension timed out", + thread_id); if (suspended_thread != nullptr) { thread->ModifySuspendCount(soa.Self(), -1, nullptr, debug_suspension); } diff --git a/runtime/verifier/method_verifier.cc b/runtime/verifier/method_verifier.cc index abd741cac4..13ef043174 100644 --- a/runtime/verifier/method_verifier.cc +++ b/runtime/verifier/method_verifier.cc @@ -434,14 +434,15 @@ MethodVerifier::FailureData MethodVerifier::VerifyMethod(Thread* self, severity = LogSeverity::WARNING; break; case HardFailLogMode::kLogInternalFatal: - severity = LogSeverity::INTERNAL_FATAL; + severity = LogSeverity::FATAL_WITHOUT_ABORT; break; default: LOG(FATAL) << "Unsupported log-level " << static_cast<uint32_t>(log_level); UNREACHABLE(); } - verifier.DumpFailures(LOG(severity) << "Verification error in " - << PrettyMethod(method_idx, *dex_file) << "\n"); + verifier.DumpFailures(LOG_STREAM(severity) << "Verification error in " + << PrettyMethod(method_idx, *dex_file) + << "\n"); } if (hard_failure_msg != nullptr) { CHECK(!verifier.failure_messages_.empty()); diff --git a/runtime/verifier/verifier_log_mode.h b/runtime/verifier/verifier_log_mode.h index 3744b9b416..e83d1749c8 100644 --- a/runtime/verifier/verifier_log_mode.h +++ b/runtime/verifier/verifier_log_mode.h @@ -24,7 +24,7 @@ enum class HardFailLogMode { kLogNone, // Don't log hard failures at all. kLogVerbose, // Log with severity VERBOSE. kLogWarning, // Log with severity WARNING. - kLogInternalFatal, // Log with severity INTERNAL_FATAL + kLogInternalFatal, // Log with severity FATAL_WITHOUT_ABORT }; } // namespace verifier diff --git a/runtime/well_known_classes.cc b/runtime/well_known_classes.cc index 16c7f773c8..eb5f68d857 100644 --- a/runtime/well_known_classes.cc +++ b/runtime/well_known_classes.cc @@ -182,7 +182,7 @@ static jfieldID CacheField(JNIEnv* env, jclass c, bool is_static, if (fid == nullptr) { ScopedObjectAccess soa(env); if (soa.Self()->IsExceptionPending()) { - LOG(INTERNAL_FATAL) << soa.Self()->GetException()->Dump(); + LOG(FATAL_WITHOUT_ABORT) << soa.Self()->GetException()->Dump(); } std::ostringstream os; WellKnownClasses::ToClass(c)->DumpClass(os, mirror::Class::kDumpClassFullDetail); @@ -199,7 +199,7 @@ jmethodID CacheMethod(JNIEnv* env, jclass c, bool is_static, if (mid == nullptr) { ScopedObjectAccess soa(env); if (soa.Self()->IsExceptionPending()) { - LOG(INTERNAL_FATAL) << soa.Self()->GetException()->Dump(); + LOG(FATAL_WITHOUT_ABORT) << soa.Self()->GetException()->Dump(); } std::ostringstream os; WellKnownClasses::ToClass(c)->DumpClass(os, mirror::Class::kDumpClassFullDetail); diff --git a/test/099-vmdebug/check b/test/099-vmdebug/check index 57111bcc99..d124ce8cfd 100755 --- a/test/099-vmdebug/check +++ b/test/099-vmdebug/check @@ -15,6 +15,6 @@ # limitations under the License. # Strip the process pids and line numbers from exact error messages. -sed -e '/^art E.*\] /d' "$2" > "$2.tmp" +sed -e '/^dalvikvm\(\|32\|64\) E.*\] /d' "$2" > "$2.tmp" diff --strip-trailing-cr -q "$1" "$2.tmp" >/dev/null diff --git a/test/119-noimage-patchoat/check b/test/119-noimage-patchoat/check index 57111bcc99..d124ce8cfd 100755 --- a/test/119-noimage-patchoat/check +++ b/test/119-noimage-patchoat/check @@ -15,6 +15,6 @@ # limitations under the License. # Strip the process pids and line numbers from exact error messages. -sed -e '/^art E.*\] /d' "$2" > "$2.tmp" +sed -e '/^dalvikvm\(\|32\|64\) E.*\] /d' "$2" > "$2.tmp" diff --strip-trailing-cr -q "$1" "$2.tmp" >/dev/null diff --git a/test/137-cfi/cfi.cc b/test/137-cfi/cfi.cc index 9f1499e38a..113b35f98d 100644 --- a/test/137-cfi/cfi.cc +++ b/test/137-cfi/cfi.cc @@ -91,7 +91,7 @@ static bool CheckStack(Backtrace* bt, const std::vector<std::string>& seq) { static void MoreErrorInfo(pid_t pid, bool sig_quit_on_fail) { printf("Secondary pid is %d\n", pid); - PrintFileToLog(StringPrintf("/proc/%d/maps", pid), ERROR); + PrintFileToLog(StringPrintf("/proc/%d/maps", pid), ::android::base::ERROR); if (sig_quit_on_fail) { int res = kill(pid, SIGQUIT); diff --git a/test/143-string-value/check b/test/143-string-value/check index 92f6e90023..2a3476c2ab 100755 --- a/test/143-string-value/check +++ b/test/143-string-value/check @@ -15,6 +15,6 @@ # limitations under the License. # Strip error log messages. -sed -e '/^art E.*\] /d' "$2" > "$2.tmp" +sed -e '/^dalvikvm\(\|32\|64\) E.*\] /d' "$2" > "$2.tmp" diff --strip-trailing-cr -q "$1" "$2.tmp" >/dev/null diff --git a/test/149-suspend-all-stress/suspend_all.cc b/test/149-suspend-all-stress/suspend_all.cc index dfd944a267..c1c0ff9f5f 100644 --- a/test/149-suspend-all-stress/suspend_all.cc +++ b/test/149-suspend-all-stress/suspend_all.cc @@ -42,14 +42,16 @@ extern "C" JNIEXPORT void JNICALL Java_Main_suspendAndResume(JNIEnv*, jclass) { break; } case kOPDumpStack: { - Runtime::Current()->GetThreadList()->Dump(LOG(INFO)); + Runtime::Current()->GetThreadList()->Dump(LOG_STREAM(INFO)); usleep(500); break; } case kOPSuspendAllDumpStack: { // Not yet supported. - // ScopedSuspendAll ssa(__FUNCTION__); - // Runtime::Current()->GetThreadList()->Dump(LOG(INFO)); + if ((false)) { + ScopedSuspendAll ssa(__FUNCTION__); + Runtime::Current()->GetThreadList()->Dump(LOG_STREAM(INFO)); + } break; } case kOPNumber: diff --git a/test/Android.bp b/test/Android.bp index 2d61000711..72dcbba9e2 100644 --- a/test/Android.bp +++ b/test/Android.bp @@ -63,6 +63,7 @@ art_cc_defaults { "libvixld-arm64", "libart-gtest", + "libbase", "libicuuc", "libicui18n", "libnativehelper", @@ -204,6 +205,7 @@ cc_defaults { ], shared_libs: [ "libbacktrace", + "libbase", "libnativehelper", ], target: { @@ -246,6 +248,7 @@ art_cc_test_library { ], shared_libs: [ "libart", + "libbase", "libopenjdkjvmti", ], } @@ -306,6 +309,7 @@ cc_defaults { ], shared_libs: [ "libbacktrace", + "libbase", "libnativehelper", ], target: { |