// // Copyright 2022 The Abseil Authors. // // Licensed under the Apache License, Version 2.0 (the "License"); // you may not use this file except in compliance with the License. // You may obtain a copy of the License at // // https://www.apache.org/licenses/LICENSE-2.0 // // Unless required by applicable law or agreed to in writing, software // distributed under the License is distributed on an "AS IS" BASIS, // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. // See the License for the specific language governing permissions and // limitations under the License. #include "absl/log/internal/log_message.h" #include #include #include #include #ifndef _WIN32 #include #endif #include #include #include #include #include #include #include #include "absl/base/attributes.h" #include "absl/base/config.h" #include "absl/base/internal/raw_logging.h" #include "absl/base/internal/strerror.h" #include "absl/base/internal/sysinfo.h" #include "absl/base/log_severity.h" #include "absl/container/inlined_vector.h" #include "absl/debugging/internal/examine_stack.h" #include "absl/log/globals.h" #include "absl/log/internal/append_truncated.h" #include "absl/log/internal/globals.h" #include "absl/log/internal/log_format.h" #include "absl/log/internal/log_sink_set.h" #include "absl/log/log_entry.h" #include "absl/log/log_sink.h" #include "absl/log/log_sink_registry.h" #include "absl/memory/memory.h" #include "absl/strings/string_view.h" #include "absl/time/clock.h" #include "absl/time/time.h" #include "absl/types/span.h" extern "C" ABSL_ATTRIBUTE_WEAK void ABSL_INTERNAL_C_SYMBOL( AbslInternalOnFatalLogMessage)(const absl::LogEntry&) { // Default - Do nothing } namespace absl { ABSL_NAMESPACE_BEGIN namespace log_internal { namespace { absl::string_view Basename(absl::string_view filepath) { #ifdef _WIN32 size_t path = filepath.find_last_of("/\\"); #else size_t path = filepath.find_last_of('/'); #endif if (path != filepath.npos) filepath.remove_prefix(path + 1); return filepath; } void WriteToString(const char* data, void* str) { reinterpret_cast(str)->append(data); } void WriteToStream(const char* data, void* os) { auto* cast_os = static_cast(os); *cast_os << data; } } // namespace // A write-only `std::streambuf` that writes into an `absl::Span`. // // This class is responsible for writing a metadata prefix just before the // first data are streamed in. The metadata are subject to change (cf. // `LogMessage::AtLocation`) until then, so we wait as long as possible. // // This class is also responsible for reserving space for a trailing newline // so that one can be added later by `Finalize` no matter how many data are // streamed in. class LogEntryStreambuf final : public std::streambuf { public: explicit LogEntryStreambuf(absl::Span buf, const absl::LogEntry& entry) : buf_(buf), entry_(entry), prefix_len_(0), finalized_(false) { // To detect when data are first written, we leave the put area null, // override `overflow`, and check ourselves in `xsputn`. } LogEntryStreambuf(LogEntryStreambuf&&) = delete; LogEntryStreambuf& operator=(LogEntryStreambuf&&) = delete; absl::Span Finalize() { assert(!finalized_); // If no data were ever streamed in, this is where we must write the // prefix. if (pbase() == nullptr) Initialize(); // Here we reclaim the two bytes we reserved. ptrdiff_t idx = pptr() - pbase(); setp(buf_.data(), buf_.data() + buf_.size()); pbump(static_cast(idx)); sputc('\n'); sputc('\0'); finalized_ = true; return absl::Span(pbase(), static_cast(pptr() - pbase())); } size_t prefix_len() const { return prefix_len_; } protected: std::streamsize xsputn(const char* s, std::streamsize n) override { if (n < 0) return 0; if (pbase() == nullptr) Initialize(); return static_cast( Append(absl::string_view(s, static_cast(n)))); } int overflow(int ch = EOF) override { if (pbase() == nullptr) Initialize(); if (ch == EOF) return 0; if (pptr() == epptr()) return EOF; *pptr() = static_cast(ch); pbump(1); return 1; } private: void Initialize() { // Here we reserve two bytes in our buffer to guarantee `Finalize` space // to add a trailing "\n\0". assert(buf_.size() >= 2); setp(buf_.data(), buf_.data() + buf_.size() - 2); if (entry_.prefix()) { absl::Span remaining = buf_; prefix_len_ = log_internal::FormatLogPrefix( entry_.log_severity(), entry_.timestamp(), entry_.tid(), entry_.source_basename(), entry_.source_line(), log_internal::ThreadIsLoggingToLogSink() ? PrefixFormat::kRaw : PrefixFormat::kNotRaw, remaining); pbump(static_cast(prefix_len_)); } } size_t Append(absl::string_view data) { absl::Span remaining(pptr(), static_cast(epptr() - pptr())); const size_t written = log_internal::AppendTruncated(data, remaining); pbump(static_cast(written)); return written; } const absl::Span buf_; const absl::LogEntry& entry_; size_t prefix_len_; bool finalized_; }; struct LogMessage::LogMessageData final { LogMessageData(const char* file, int line, absl::LogSeverity severity, absl::Time timestamp); LogMessageData(const LogMessageData&) = delete; LogMessageData& operator=(const LogMessageData&) = delete; // `LogEntry` sent to `LogSink`s; contains metadata. absl::LogEntry entry; // true => this was first fatal msg bool first_fatal; // true => all failures should be quiet bool fail_quietly; // true => PLOG was requested bool is_perror; // Extra `LogSink`s to log to, in addition to `global_sinks`. absl::InlinedVector extra_sinks; // If true, log to `extra_sinks` but not to `global_sinks` or hardcoded // non-sink targets (e.g. stderr, log files). bool extra_sinks_only; // A formatted string message is built in `string_buf`. std::array string_buf; // A `std::streambuf` that stores into `string_buf`. LogEntryStreambuf streambuf_; }; LogMessage::LogMessageData::LogMessageData(const char* file, int line, absl::LogSeverity severity, absl::Time timestamp) : extra_sinks_only(false), streambuf_(absl::MakeSpan(string_buf), entry) { entry.full_filename_ = file; entry.base_filename_ = Basename(file); entry.line_ = line; entry.prefix_ = absl::ShouldPrependLogPrefix(); entry.severity_ = absl::NormalizeLogSeverity(severity); entry.verbose_level_ = absl::LogEntry::kNoVerbosityLevel; entry.timestamp_ = timestamp; entry.tid_ = absl::base_internal::GetCachedTID(); } LogMessage::LogMessage(const char* file, int line, absl::LogSeverity severity) : data_( absl::make_unique(file, line, severity, absl::Now())) , stream_(&data_->streambuf_) { data_->first_fatal = false; data_->is_perror = false; data_->fail_quietly = false; // Legacy defaults for LOG's ostream: stream_.setf(std::ios_base::showbase | std::ios_base::boolalpha); // `fill('0')` is omitted here because its effects are very different // without structured logging. Resolution is tracked in b/111310488. // This logs a backtrace even if the location is subsequently changed using // AtLocation. This quirk, and the behavior when AtLocation is called twice, // are fixable but probably not worth fixing. LogBacktraceIfNeeded(); } LogMessage::~LogMessage() { #ifdef ABSL_MIN_LOG_LEVEL if (data_->entry.log_severity() < static_cast(ABSL_MIN_LOG_LEVEL) && data_->entry.log_severity() < absl::LogSeverity::kFatal) { return; } #endif Flush(); } LogMessage& LogMessage::AtLocation(absl::string_view file, int line) { data_->entry.full_filename_ = file; data_->entry.base_filename_ = Basename(file); data_->entry.line_ = line; LogBacktraceIfNeeded(); return *this; } LogMessage& LogMessage::NoPrefix() { data_->entry.prefix_ = false; return *this; } LogMessage& LogMessage::WithVerbosity(int verbose_level) { if (verbose_level == absl::LogEntry::kNoVerbosityLevel) { data_->entry.verbose_level_ = absl::LogEntry::kNoVerbosityLevel; } else { data_->entry.verbose_level_ = std::max(0, verbose_level); } return *this; } LogMessage& LogMessage::WithTimestamp(absl::Time timestamp) { data_->entry.timestamp_ = timestamp; return *this; } LogMessage& LogMessage::WithThreadID(absl::LogEntry::tid_t tid) { data_->entry.tid_ = tid; return *this; } LogMessage& LogMessage::WithMetadataFrom(const absl::LogEntry& entry) { data_->entry.full_filename_ = entry.full_filename_; data_->entry.base_filename_ = entry.base_filename_; data_->entry.line_ = entry.line_; data_->entry.prefix_ = entry.prefix_; data_->entry.severity_ = entry.severity_; data_->entry.verbose_level_ = entry.verbose_level_; data_->entry.timestamp_ = entry.timestamp_; data_->entry.tid_ = entry.tid_; return *this; } LogMessage& LogMessage::WithPerror() { data_->is_perror = true; return *this; } LogMessage& LogMessage::ToSinkAlso(absl::LogSink* sink) { ABSL_INTERNAL_CHECK(sink, "null LogSink*"); data_->extra_sinks.push_back(sink); return *this; } LogMessage& LogMessage::ToSinkOnly(absl::LogSink* sink) { ABSL_INTERNAL_CHECK(sink, "null LogSink*"); data_->extra_sinks.clear(); data_->extra_sinks.push_back(sink); data_->extra_sinks_only = true; return *this; } #ifdef __ELF__ extern "C" void __gcov_dump() ABSL_ATTRIBUTE_WEAK; extern "C" void __gcov_flush() ABSL_ATTRIBUTE_WEAK; #endif void LogMessage::FailWithoutStackTrace() { // Now suppress repeated trace logging: log_internal::SetSuppressSigabortTrace(true); #if defined _DEBUG && defined COMPILER_MSVC // When debugging on windows, avoid the obnoxious dialog. __debugbreak(); #endif #ifdef __ELF__ // For b/8737634, flush coverage if we are in coverage mode. if (&__gcov_dump != nullptr) { __gcov_dump(); } else if (&__gcov_flush != nullptr) { __gcov_flush(); } #endif abort(); } void LogMessage::FailQuietly() { // _exit. Calling abort() would trigger all sorts of death signal handlers // and a detailed stack trace. Calling exit() would trigger the onexit // handlers, including the heap-leak checker, which is guaranteed to fail in // this case: we probably just new'ed the std::string that we logged. // Anyway, if you're calling Fail or FailQuietly, you're trying to bail out // of the program quickly, and it doesn't make much sense for FailQuietly to // offer different guarantees about exit behavior than Fail does. (And as a // consequence for QCHECK and CHECK to offer different exit behaviors) _exit(1); } template LogMessage& LogMessage::operator<<(const char& v); template LogMessage& LogMessage::operator<<(const signed char& v); template LogMessage& LogMessage::operator<<(const unsigned char& v); template LogMessage& LogMessage::operator<<(const short& v); // NOLINT template LogMessage& LogMessage::operator<<(const unsigned short& v); // NOLINT template LogMessage& LogMessage::operator<<(const int& v); template LogMessage& LogMessage::operator<<(const unsigned int& v); template LogMessage& LogMessage::operator<<(const long& v); // NOLINT template LogMessage& LogMessage::operator<<(const unsigned long& v); // NOLINT template LogMessage& LogMessage::operator<<(const long long& v); // NOLINT template LogMessage& LogMessage::operator<<( const unsigned long long& v); // NOLINT template LogMessage& LogMessage::operator<<(void* const& v); template LogMessage& LogMessage::operator<<(const void* const& v); template LogMessage& LogMessage::operator<<(const float& v); template LogMessage& LogMessage::operator<<(const double& v); template LogMessage& LogMessage::operator<<(const bool& v); template LogMessage& LogMessage::operator<<(const std::string& v); template LogMessage& LogMessage::operator<<(const absl::string_view& v); void LogMessage::Flush() { if (data_->entry.log_severity() < absl::MinLogLevel()) return; if (data_->is_perror) { InternalStream() << ": " << absl::base_internal::StrError(errno_saver_()) << " [" << errno_saver_() << "]"; } // Have we already seen a fatal message? ABSL_CONST_INIT static std::atomic seen_fatal(false); if (data_->entry.log_severity() == absl::LogSeverity::kFatal && absl::log_internal::ExitOnDFatal()) { // Exactly one LOG(FATAL) message is responsible for aborting the process, // even if multiple threads LOG(FATAL) concurrently. bool expected_seen_fatal = false; if (seen_fatal.compare_exchange_strong(expected_seen_fatal, true, std::memory_order_relaxed)) { data_->first_fatal = true; } } data_->entry.text_message_with_prefix_and_newline_and_nul_ = data_->streambuf_.Finalize(); data_->entry.prefix_len_ = data_->streambuf_.prefix_len(); SendToLog(); } void LogMessage::SetFailQuietly() { data_->fail_quietly = true; } bool LogMessage::IsFatal() const { return data_->entry.log_severity() == absl::LogSeverity::kFatal && absl::log_internal::ExitOnDFatal(); } void LogMessage::PrepareToDie() { // If we log a FATAL message, flush all the log destinations, then toss // a signal for others to catch. We leave the logs in a state that // someone else can use them (as long as they flush afterwards) if (data_->first_fatal) { // Notify observers about the upcoming fatal error. ABSL_INTERNAL_C_SYMBOL(AbslInternalOnFatalLogMessage)(data_->entry); } if (!data_->fail_quietly) { // Log the message first before we start collecting stack trace. log_internal::LogToSinks(data_->entry, absl::MakeSpan(data_->extra_sinks), data_->extra_sinks_only); // `DumpStackTrace` generates an empty string under MSVC. // Adding the constant prefix here simplifies testing. data_->entry.stacktrace_ = "*** Check failure stack trace: ***\n"; debugging_internal::DumpStackTrace( 0, log_internal::MaxFramesInLogStackTrace(), log_internal::ShouldSymbolizeLogStackTrace(), WriteToString, &data_->entry.stacktrace_); } } void LogMessage::Die() { absl::FlushLogSinks(); if (data_->fail_quietly) { FailQuietly(); } else { FailWithoutStackTrace(); } } void LogMessage::SendToLog() { if (IsFatal()) PrepareToDie(); // Also log to all registered sinks, even if OnlyLogToStderr() is set. log_internal::LogToSinks(data_->entry, absl::MakeSpan(data_->extra_sinks), data_->extra_sinks_only); if (IsFatal()) Die(); } void LogMessage::LogBacktraceIfNeeded() { if (!absl::log_internal::IsInitialized()) return; if (!absl::log_internal::ShouldLogBacktraceAt(data_->entry.source_basename(), data_->entry.source_line())) return; stream_ << " (stacktrace:\n"; debugging_internal::DumpStackTrace( 1, log_internal::MaxFramesInLogStackTrace(), log_internal::ShouldSymbolizeLogStackTrace(), WriteToStream, &stream_); stream_ << ") "; } LogMessageFatal::LogMessageFatal(const char* file, int line) : LogMessage(file, line, absl::LogSeverity::kFatal) {} LogMessageFatal::LogMessageFatal(const char* file, int line, absl::string_view failure_msg) : LogMessage(file, line, absl::LogSeverity::kFatal) { *this << "Check failed: " << failure_msg << " "; } // ABSL_ATTRIBUTE_NORETURN doesn't seem to work on destructors with msvc, so // disable msvc's warning about the d'tor never returning. #if defined(_MSC_VER) && !defined(__clang__) #pragma warning(push) #pragma warning(disable : 4722) #endif LogMessageFatal::~LogMessageFatal() { Flush(); FailWithoutStackTrace(); } #if defined(_MSC_VER) && !defined(__clang__) #pragma warning(pop) #endif LogMessageQuietlyFatal::LogMessageQuietlyFatal(const char* file, int line) : LogMessage(file, line, absl::LogSeverity::kFatal) { SetFailQuietly(); } LogMessageQuietlyFatal::LogMessageQuietlyFatal(const char* file, int line, absl::string_view failure_msg) : LogMessage(file, line, absl::LogSeverity::kFatal) { SetFailQuietly(); *this << "Check failed: " << failure_msg << " "; } // ABSL_ATTRIBUTE_NORETURN doesn't seem to work on destructors with msvc, so // disable msvc's warning about the d'tor never returning. #if defined(_MSC_VER) && !defined(__clang__) #pragma warning(push) #pragma warning(disable : 4722) #endif LogMessageQuietlyFatal::~LogMessageQuietlyFatal() { Flush(); FailQuietly(); } #if defined(_MSC_VER) && !defined(__clang__) #pragma warning(pop) #endif } // namespace log_internal ABSL_NAMESPACE_END } // namespace absl