Chromium许多日志被TraceEvent代替了,因此TraceEvent出现的频率要比Log高很多。
但是也有不少场景使用Log。
在blink,Log的实现由blink/base提供,而chromium的日志由blink/render/core/base/logging.h提供。一些底层的日志由absel的log模块提供。
说实话,日志模块的实现数量有点多。这些实现在使用时都是使用Stream的形式打印日志,使用形式大同小异。
日志系统的设计细节
错误对话框处理
- 错误消息显示: 当应用程序遇到断言失败或致命错误时,默认情况下会弹出一个对话框展示错误信息。然而,这个UI的创建会导致消息循环,这可能使应用在不好的状态中处理或分发消息到现有窗口,导致挂起或异常行为。
- 分离进程显示错误: 为了避免上述问题,可以在与主应用程序相同的目录下创建一个名为
DebugMessage.exe
的独立程序,用于专门显示致命错误对话框。这样即使主程序处于不稳定状态,错误信息也能正确显示而不影响主程序的其他部分。 - 简化命令行解析: 此独立程序接收错误信息作为命令行参数,不会包含应用程序名称,以便于解析。
日志宏
- 基本日志: 提供了一系列宏,如
LOG(INFO)
,用于在不同严重级别下记录日志信息。 - 条件日志: 可以使用
LOG_IF(INFO, condition)
根据条件记录日志。 - 断言宏:
CHECK(condition)
在所有构建模式下都有效,如果条件不满足,则记录FATAL级别的日志并终止程序。
调试模式日志
- 调试宏:
DLOG(INFO)
仅在调试模式下生效,而在非调试模式下会被编译器忽略。 - 调试断言:
DLOG_ASSERT(condition)
在调试模式下工作,类似于CHECK
。
详细日志
- 详细级别日志:
VLOG(1)
允许根据不同的详细级别记录日志,可以通过运行参数--v=<level>
开启。 - 模块特定日志: 可以指定特定模块的详细级别,例如
--vmodule=profile=2
。 - 通配符支持: 模块名可以使用通配符
*
和?
匹配多个文件或目录下的源文件。
其他特性
- 系统错误日志:
PLOG(ERROR)
附加系统错误信息到日志中。 - 特殊日志级别:
DFATAL
在DCHECK
启用的构建中等同于FATAL
,在普通构建中为ERROR
。 - 格式化输出: 日志输出包括PID、TID、日期时间、日志级别、文件名及行号等信息。
配置和偏好设置
- 用户可以通过
SetLogItems()
函数调整日志的可见性。 - 在Chrome OS上,日志输出可以切换到syslog-like格式。
LOG_STREAM
在实际打印日志的时候,是以流式打印的,例如:
LOG(INFO) << "Found " << num_cookies << " cookies";
LOG宏定义如下:
// We use the preprocessor's merging operator, "##", so that, e.g.,
// LOG(INFO) becomes the token COMPACT_GOOGLE_LOG_INFO. There's some funny
// subtle difference between ostream member streaming functions (e.g.,
// ostream::operator<<(int) and ostream non-member streaming functions
// (e.g., ::operator<<(ostream&, string&): it turns out that it's
// impossible to stream something like a string directly to an unnamed
// ostream. We employ a neat hack by calling the stream() member
// function of LogMessage which seems to avoid the problem.
#define LOG_STREAM(severity) COMPACT_GOOGLE_LOG_ ## severity.stream()
#define LOG(severity) LAZY_STREAM(LOG_STREAM(severity), LOG_IS_ON(severity))
#define LOG_IF(severity, condition) \
LAZY_STREAM(LOG_STREAM(severity), LOG_IS_ON(severity) && (condition))
// The VLOG macros log with negative verbosities.
#define VLOG_STREAM(verbose_level) \
::logging::LogMessage(__FILE__, __LINE__, -(verbose_level)).stream()
这段代码的解读如下:
-
LOG_STREAM 宏:
#define LOG_STREAM(severity) COMPACT_GOOGLE_LOG_ ## severity.stream()
这个宏接受一个参数
severity
,它是一个日志级别(例如,INFO、ERROR等)。宏中的##
是C++预处理器的字符串拼接操作符,它会将两个独立的标识符拼接成一个新的标识符。因此,LOG_STREAM(severity)
被展开为COMPACT_GOOGLE_LOG_severity.stream()
。 -
LOG 和 LOG_IF 宏:
#define LOG(severity) LAZY_STREAM(LOG_STREAM(severity), LOG_IS_ON(severity)) #define LOG_IF(severity, condition) \ LAZY_STREAM(LOG_STREAM(severity), LOG_IS_ON(severity) && (condition))
这些宏用于实际的日志输出。
LOG
和LOG_IF
都会调用LAZY_STREAM
宏,其中LOG_STREAM(severity)
提供了日志流对象,而LOG_IS_ON(severity)
检查日志级别是否被启用。LOG_IF
则额外检查一个条件condition
,只有当这个条件为真时才进行日志记录。 -
VLOG 和 VLOG_STREAM 宏:
#define VLOG_STREAM(verbose_level) \ ::logging::LogMessage(__FILE__, __LINE__, -(verbose_level)).stream() #define VLOG(verbose_level) \ LAZY_STREAM(VLOG_STREAM(verbose_level), VLOG_IS_ON(verbose_level))
VLOG
宏用于更详细的日志记录,通常用于调试。VLOG
和VLOG_STREAM
接受一个verbose_level
参数,表示日志的详细程度。VLOG_STREAM
创建一个LogMessage
对象,并通过传递文件名、行号和负数的verbose_level
来控制日志的详细度。VLOG
宏同样使用LAZY_STREAM
来决定是否真正执行日志记录,这依赖于VLOG_IS_ON(verbose_level)
的值。这种设计允许在编译时优化掉未启用的日志输出,从而提高运行时性能。
base 的 Log
Chromium的base模块里也有一个Log模块,使用形式大同小异,在base/loging.h中定义和实现,实现也比较简单:
base打印日志内容时,输出到perfetto库中,使用perfetto::protos::pbzero::LogMessage对象。
因此,base的log可以看作是trace系统(trace底层用的是perfetto库)的封装。
// Invokes macro to record trace event when a log message is emitted.
void TraceLogMessage(const char* file, int line, const std::string& message) {
TRACE_EVENT_INSTANT("log", "LogMessage", [&](perfetto::EventContext ctx) {
perfetto::protos::pbzero::LogMessage* log = ctx.event()->set_log_message();
log->set_source_location_iid(base::trace_event::InternedSourceLocation::Get(
&ctx, base::trace_event::TraceSourceLocation(/*function_name=*/nullptr,
file, line)));
log->set_body_iid(
base::trace_event::InternedLogMessage::Get(&ctx, message));
});
}
base的LogMessage声明大概如下:
// This class more or less represents a particular log message. You
// create an instance of LogMessage and then stream stuff to it.
// When you finish streaming to it, ~LogMessage is called and the
// full message gets streamed to the appropriate destination.
//
// You shouldn't actually use LogMessage's constructor to log things,
// though. You should use the LOG() macro (and variants thereof)
// above.
class BASE_EXPORT LogMessage {
public:
// Used for LOG(severity).
LogMessage(const char* file, int line, LogSeverity severity);
// Used for CHECK(). Implied severity = LOGGING_FATAL.
LogMessage(const char* file, int line, const char* condition);
LogMessage(const LogMessage&) = delete;
LogMessage& operator=(const LogMessage&) = delete;
virtual ~LogMessage();
std::ostream& stream() { return stream_; }
LogSeverity severity() const { return severity_; }
std::string str() const { return stream_.str(); }
const char* file() const { return file_; }
int line() const { return line_; }
// Gets file:line: message in a format suitable for crash reporting.
std::string BuildCrashString() const;
protected:
void Flush();
private:
void Init(const char* file, int line);
void HandleFatal(size_t stack_start, const std::string& str_newline) const;
const LogSeverity severity_;
std::ostringstream stream_;
size_t message_start_; // Offset of the start of the message (past prefix
// info).
// The file and line information passed in to the constructor.
const char* const file_;
const int line_;
#if BUILDFLAG(IS_CHROMEOS)
void InitWithSyslogPrefix(std::string_view filename,
int line,
uint64_t tick_count,
const char* log_severity_name_c_str,
const char* log_prefix,
bool enable_process_id,
bool enable_thread_id,
bool enable_timestamp,
bool enable_tickcount);
#endif
};
如果是Fatal日志,则会创建LogMessageFatal实例处理:
class BASE_EXPORT LogMessageFatal final : public LogMessage {
public:
using LogMessage::LogMessage;
[[noreturn]] ~LogMessageFatal() override;
};
[[noreturn]]表示LogMessageFatal的析构函数不会返回,因为Fatal级别日志出现就要退出程序,函数不需要返回。
LogMessageFatal::~LogMessageFatal() {
Flush();
base::ImmediateCrash();
}
ImmediateCrash的实现很有深度,需要考虑不同编译器、不同平台的处理细节:
-
条件编译:
#if BUILDFLAG(IS_NACL)
: 如果构建标志指示这是一个Native Client (NaCl)环境,则使用__builtin_trap()
来触发一个陷阱。elif defined(ARCH_CPU_X86_FAMILY)
: 如果是x86或x86_64架构,则使用不同的陷阱序列。elif defined(ARCH_CPU_ARMEL)
: 对于ARM架构的little-endian变体,使用bkpt
指令。elif defined(ARCH_CPU_ARM64)
: 对于ARM64架构,使用brk
指令。else
: 其他架构使用__builtin_trap()
作为默认的陷阱机制。
-
陷阱序列:
TRAP_SEQUENCE1_()
和TRAP_SEQUENCE2_()
是两个不同的宏,它们可以被一起调用来确保在多种情况下都能触发异常。- 在x86架构上,
TRAP_SEQUENCE1_()
使用int3
指令,这会产生一个SIGTRAP信号。TRAP_SEQUENCE2_()
在非Apple平台上使用ud2
指令,这会触发一个无效操作码错误(通常为SIGILL),但在Apple平台上是空的,因为__builtin_unreachable()
已经足够(在Mac上它会发出ud2
)。 - ARM架构使用
bkpt
和udf
指令,而ARM64使用brk
和hlt
指令,尽管hlt
通常用于关机或挂起处理器,这里可能作为附加的不可达指令使用。
absel的Log
在一Test模块,以及少数的chromiium的media模块,倾向于直接调用abseil-cpp\absl\log的日志模块,其使用方式也和上面大同小异。宏展开之后如下:
为什么这个宏要用switch-case的形式呢?这里有说明:
// `ABSL_LOG_INTERNAL_CONDITION` prefixes another macro that expands to a
// temporary `LogMessage` instantiation followed by zero or more streamed
// expressions. This definition is tricky to read correctly. It evaluates to
// either
//
// (void)0;
//
// or
//
// ::absl::log_internal::Voidify() &&
// ::absl::log_internal::LogMessage(...) << "the user's message";
//
// If the condition is evaluable at compile time, as is often the case, it
// compiles away to just one side or the other.
//
// Although this is not used anywhere a statement (e.g. `if`) could not go,
// the ternary expression does a better job avoiding spurious diagnostics
// (dangling else, missing switch case) and preserving noreturn semantics (e.g.
// on `LOG(FATAL)`) without requiring braces.
//
// The `switch` ensures that this expansion is the begnning of a statement (as
// opposed to an expression) and prevents shenanigans like
// `AFunction(LOG(INFO))` and `decltype(LOG(INFO))`. The apparently-redundant
// `default` case makes the condition more amenable to Clang dataflow analysis.
#define ABSL_LOG_INTERNAL_STATELESS_CONDITION(condition) \
switch (0) \
case 0: \
default: \
!(condition) ? (void)0 : ::absl::log_internal::Voidify()&&
简而言之,switch (0)确保宏展开后的代码始终从一个合法的语句开始,而不是表达式。这防止了诸如AFunction(LOG(INFO))或decltype(LOG(INFO))这样的非法用法。
case 0后面跟default,是为了默认情况使条件更适合Clang执行流分析,使得代码被优化得更好。
absel的日志写入逻辑在这里:
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 LogToSinks(const absl::LogEntry& entry,
absl::Span<absl::LogSink*> extra_sinks, bool extra_sinks_only) {
log_internal::GlobalSinks().LogToSinks(entry, extra_sinks, extra_sinks_only);
}
void AddLogSink(absl::LogSink* sink) {
log_internal::GlobalSinks().AddLogSink(sink);
}
void RemoveLogSink(absl::LogSink* sink) {
log_internal::GlobalSinks().RemoveLogSink(sink);
}
LogToSinks不实现写入文件,而是回调给上层,由上层写入文件。
windows下,默认的logsink是OutputDebugString:
class WindowsDebuggerLogSink final : public LogSink {
public:
~WindowsDebuggerLogSink() override = default;
void Send(const absl::LogEntry& entry) override {
if (entry.log_severity() < absl::StderrThreshold() &&
absl::log_internal::IsInitialized()) {
return;
}
::OutputDebugStringA(entry.text_message_with_prefix_and_newline_c_str());
}
};
日志的写入架构
日志没什么缓存,判断认为该写文件的就马上写文件了,这样的设计也是为了避免崩溃的时候日志不全。缓存的事情应该由操作系统的文件系统去处理: