查看日志

日志主要在与实时设备的交互(“在线”)上下文中使用,或者在“离线”上下文中使用从设备的过往执行中收集的日志。

排序

所有日志都附加了时间戳,在记录消息时从单调时钟读取。LogSink 可以通过多种方式以不同于时间戳指示的顺序接收消息。

主要 fuchsia.logger.Log 实现会对通过 fuchsia.logger.LogListenerSafeLogMany 方法发送的消息进行排序。每当将已收集的消息发送到新连接的监听器时,系统都会调用此方法。但是,当消息首次到达时时间戳没有顺序,任何处于活跃状态的监听器都将以任意顺序接收这些消息。如果工具显示对 fuchsia.logger/LogListenerSafe.Log 的连续调用累积的日志,那么当收到消息时没有在时间戳中采用严格线性排序时,应该提醒用户。

在线

由于有两个缓冲区可以存储日志,因此当您拥有实际设备时,可通过两种主要方式查看这些缓冲区。如需详细了解日志在设备上的位置,请参阅概念:存储

syslog 和内核日志

在开发期间,最好默认运行 ffx log 来查看所有日志。从本质上讲,此命令会运行 log_listener 程序,输出系统日志中的每条消息。其中包括从 klog 转发的日志。

log_listener 通过 fuchsia.logger.Logfuchsia.logger.LogListenerSafe 协议接收日志。

此外,系统会将 syslog 的一些日志输出到串行控制台。默认情况下,这包含驱动程序和 driver_manager 日志。

格式

默认情况下,log_listener 会按以下格式发出行:

[seconds][pid][tid][tags] LEVEL: message

默认情况下,时间戳采用单调时钟,采用微秒级粒度格式。

如果消息“something earned”在 WARN 级别由 process=1902 和 thread=1904(时间=278.14)写入,默认输出将为:

[278.14][1902][1904][my-component] WARN: something happened

log_listener 具有 --hide_metadata--pretty 标志,可分别按严重级别减少输出的元数据和颜色代码日志行。借助这些标志,一些元数据(PID、TID 等)会被隐藏,而另一些元数据会被删减(时间戳、严重级别)。

例如,如果 my-component 在 time=278.14 时在 WARN 级别输出消息“something events”,美观输出将如下所示:

[278.14][my-component][W] something happened

有正在运行的设备后,运行 ffx log --help 以查看修改输出格式的选项。

fx test

在后台,fx test 会调用 run-test-suite,它会从测试组件收集隔离的 stdoutstderrLogSink 连接,以内嵌方式输出输出,并阻止它们显示在全局日志缓冲区中。

对于还不是组件的测试,不会执行日志拦截。

仅限内核日志

klog 会通过内核控制台输出并序列号。

它还会由 netsvc 通过 UDP 转发,这是运行 fx klog 时输出的内容。如果您的 SSH 会话失败,在后台终端运行 fx klog 是一种捕获日志的好方法,或者在运行 ffx log 时发生其他问题时作为备份。

如果以上两种方案都不是,您还可以直接在设备 shell 中使用 dlog 转储内核调试日志。

格式

内核日志的转储器按以下格式发出行:

[timestamp] pid:tid> message

时间戳来自单调时钟。其格式为:5 位数(前导零)表示秒,三位数表示毫秒(尾随零)。

进程和线程 koid 分别以 5 位数(前导零)编写。

如果消息“something earned”在 process=1902 中写入,并在 time=278.14 时 thread=1904 写入,输出结果将为:

[00278.140] 01902:01904> something happened

fx pretty_serial 命令可用于按严重级别减少 klog 和颜色代码日志行输出的元数据。如果使用此命令,一些元数据(PID、TID、文件名等)会被隐藏,而其他元数据(时间戳、严重级别)会被删减。

串行输出应从模拟器或其他来源输入管道:

ffx emu start --console | ffx debug symbolize

例如,如果 my-component 在 time=278.14 时,在 WARN 级别将消息“something earned”输出到 klog,美观输出将如下所示:

[278.14][my-component][W] something happened

例如,如果在 time=278.14 时,某个严重程度未知的未知组件将消息“something earned”输出到 klog,则美观输出将如下所示:

[278.14] something happened

线下:CQ/GI

运行测试时,Swarming 聊天机器人会调用 botanist,它会收集要呈现在网页界面中的多个输出流。植物学家的 stdoutstderr 显示在“大量任务界面”中。

对于单个测试可执行文件,植物学家会使用 testrunner 库并单独收集该输出。 这是测试失败后的输出,包含名为 stdio 的链接。testrunner 调用的大多数测试都通过 SSH 连接到目标设备来运行 run-test-suite。这会从测试环境中收集 stdout、stderr 和日志,并以内嵌方式输出这些日志。

syslog.txt

Botanist 会在目标设备上运行 log_listener,并将该输出保存到 syslog.txt。这相当于在开发机器上运行 ffx log

infra_and_test_std_and_klog.txt

此日志包含由 Swarming 任务运行的命令的 stdout 和 stderr。 通常,这包括以下重要项,这些项全部交错:

  • botanist 的日志消息
  • 来自 netsvc 的内核日志(等同于 fx klog
  • 测试运行程序运行的 stdoutstderr 测试

在上传之前,此汇总日志会通过等效的 ffx debug symbolize 运行。