65.9K
CodeProject 正在变化。 阅读更多。
Home

将Android Logcat消息与VTune Amplifier时间线关联起来

2015 年 7 月 6 日

CPOL

7分钟阅读

viewsIcon

9212

VTune™ Amplifier for systems 是一款用于系统或应用程序性能调优的分析工具。

英特尔® 开发者专区提供用于跨平台应用开发的工具和操作指南信息、平台和技术信息、代码示例以及同行专业知识,以帮助开发者创新和成功。加入我们的社区,面向 Android物联网英特尔® 实感™ 技术Windows,下载工具、访问开发工具包、与志同道合的开发者分享想法,并参加黑客马拉松、竞赛、路演和本地活动。

引言

Android logcat 是一个非常强大的调试工具。通过 Android logcat,我们可以看到大量来自系统或应用程序的随时间变化的有用信息。Android 为日志提供了标准化的 API。在我们的开发中,我们可以轻松地添加日志,并使用 logcat 来查看我们程序的日志。VTune™ Amplifier for systems 是一款用于系统或应用程序性能调优的分析工具。VTune Amplifier 提供了一个强大的时间线窗格,帮助开发者查看随时间变化的性能指标。

如何将 logcat 消息与 VTune Amplifier 时间线窗格关联起来?对于开发者来说,将 logcat 的日志与 VTune Amplifier 时间线窗格中的其他性能指标一起查看是合乎情理的。通过这样做,我们可以知道在特定时间发生了什么,以及该时间点周围的相关性能数据。

英特尔® VTune™ Amplifier 可以处理并集成通过自定义收集器或目标应用程序与 VTune Amplifier 原生分析并行收集的外部性能统计数据。为此,需要将收集到的自定义数据以预定义结构的 csv 文件形式提供,并将此文件加载到 VTune Amplifier 结果中。

有关如何创建包含外部数据的 CSV 文件的详细信息,在 VTune Amplifier 用户指南中有描述。打开 VTune Amplifier 帮助文档,转到 Intel VTune™ Amplifier > User’s Guide > External Data Import,我们可以找到如何创建包含外部数据的 CSV 文件以及 CSV 文件格式的示例。为了在 VTune 时间线窗格中查看 logcat 消息,请按照指南将 logcat 消息转换为 CSV 文件,然后在 VTune Amplifier 中加载该消息。

一个示例

这里有一个例子。我有一个 JAVA 应用程序“com.example.Thread1”。在我的应用程序中,我有一个包含大量计算的函数。伪代码如下所示:

void myfunction ()
{
        Log.v("MYTEST", "start block 1");
        {
		...//my computation block 1
	}
        Log.v("MYTEST", "start block 2");
        {
		...//my computation block 2
	}
	Log.v("MYTEST", "my computation finished");
}

在下面显示的 Vtune Amplifier 时间线窗格中,我们可以看到这个函数被执行了 6 次。我的应用程序的主线程 ID 是 12271。棕色列显示了我们在 VTune Amplifier 分析期间收集的性能数据(CPU 时间)。

对于函数的每次执行,如果我们用“logcat -v threadtime”收集 logcat 消息,我们可能会得到类似下面的内容:

01-12 11:13:19.090  2174  2174 V MYTEST  : start block 1
01-12 11:13:19.260  2174  2174 V MYTEST  : start block 2
01-12 11:13:19.500  2174  2174 V MYTEST  : my computation finished

现在我们可以将 logcat 的消息转换成可以加载到 VTune Amplifier 的格式的 csv 文件。根据 VTune Amplifier 的文档,我们可以得到如下例子的 csv 文件:

name,start_tsc.UTC,end_tsc,pid,tid
V/MYTEST : start block 1,2015-01-12 03:13:19.090,2015-01-12 03:13:19.090,2174,2174
V/MYTEST : start block 2,2015-01-12 03:13:19.260,2015-01-12 03:13:19.260,2174,2174
V/MYTEST:my computation finished,2015-01-12 03:13:19.500, 2015-01-12 03:13:19.500, 2174, 2174

这里我们使用日志标签和消息字符串作为“name”。我们使用消息的时间作为 start_tsc.UTC 和 end_tsc,使用 logcat 中的进程 ID 和线程 ID 作为 pid 和 tid。字段由逗号分隔。

在 VTune Amplifier 中,从“Analysis Type” > “Import from CSV”选择我们创建的 csv 文件,VTune Amplifier 将加载数据并在时间线上显示相关的 logcat 消息和性能数据。请看下面的输出截图,将鼠标移到消息点上(黄色小三角形),我们可以看到来自 logcat 的关于我们应用程序的每条消息。

创建 CSV 文件有几个技巧和诀窍。

  1. logcat 中的时间是来自 Android 操作系统的时间,它与特定的时区相关。这个时间需要在 CSV 文件中更改为 VTune Amplifier 接受的 UTC 时间。
  2. CSV 文件名应指定您的自定义收集器收集数据的主机名。例如:[user-defined]-hostname-<hostname-of-system>.csv。对于 Android 目标,您可以通过从 adb shell 读取文件 /proc/sys/kernel/hostname 来获取主机名。
  3. 您可以自定义 CSV 文件中“name”列的字符串。在上面显示的截图中,我只是简单地将整个 logcat 消息行用作“name”。请注意,如果 logcat 消息中存在逗号,您需要从“name”字符串中移除它。逗号“,”是保留的分隔符,不应出现在 name 字符串中。
  4. 您也可以将内核消息(例如来自“dmesg”)转换为 CSV 文件,并在 VTune Amplifier 时间线窗格中查看内核日志。这对于系统级开发人员非常有用,例如当您在开发内核模块或设备驱动程序时。对于来自内核的消息,进程 ID 和线程 ID 应指定为 0。请注意,内核消息时间戳(例如来自 dmesg)是自系统启动以来的秒数偏移量。您需要将该时间戳转换为消息生成时的 UTC 时间。例如,使用这种方式获取消息时间:“消息时间” = “现在时间” - “系统运行时间” + “消息的时间戳”。这里的“现在时间”是系统的当前时间。您可以使用 adb shell 中的“date”命令获取“现在时间”。“系统运行时间”是系统启动后经过的秒数。您可以从文件 /proc/uptime 获取此数据。

一个脚本

我创建了一个实验性的 bash 脚本来简化操作。您可以使用“logcat2vtune.sh”脚本来收集 logcat 数据并自动生成所需的 CSV 文件。该脚本可以收集 logcat 和/或内核消息,读取目标系统信息,解析日志并自动将其转换为 CSV 文件。

要使用此脚本文件,您需要一个在 Linux 主机上原生可用的 bash 环境。如果您在 Windows 主机上工作,我建议安装 Cygwin*,它在 Windows 系统上提供了一个类似 Linux 的 bash 环境。以下是在 VTune Amplifier 分析期间获取 CSV 文件的基本步骤。

  1. 在 shell 命令中,确保您可以访问“adb”,使用适当的选项启动 logcat2vtune.sh 脚本,例如:> ./logcat2vtune.sh -c logcat -g MYTEST
  2. 开始 VTune Amplifier 性能数据收集。这可以从 VTune Amplifier GUI 或命令行完成。
  3. 停止 VTune Amplifier 性能数据收集。
  4. logcat2vtune.sh shell 窗口中按任意键停止日志收集。脚本将读取收集到的日志数据,用 bash 正则表达式解析日志并将其转换为 CSV 文件。您会发现在当前 shell 文件夹中创建了一个 .csv 文件。
  5. 将 CSV 文件加载到 VTune Amplifier 中,并从 VTune 时间线视图中检查日志消息。

以下是使用该脚本文件的一些典型使用模式。

$logcat2vtune.sh -c logcat -g MYTEST

收集 logcat 数据,用字符串“MYTEST”过滤 logcat 消息并生成 CSV 文件。logcat 是在脚本内部使用以下命令收集的。
$adb shell logcat -v threadtime
“MYTEST”是用于过滤 logcat 消息的字符串。强烈建议使用过滤器,因为 logcat 可能会产生非常大的日志,而我们只关心我们自己进程的日志。过滤器可以是我的 logcat 标签名称、进程 ID、线程 ID 或任何其他字符串。您可以使用逗号“,”来指定多个字符串。与“-g”选项中任何字符串匹配的日志都将被解析并生成到 CSV 文件中。

$logcat2vtune.sh -c dmesg -g "MYDRIVER"

收集“dmesg”输出,用“MYDRIVER”字符串过滤并生成 CSV 文件。

$logcat2vtune.sh -c logcatk -g MYTEST,MYDRIVER

同时收集 logcat 数据和内核消息数据,通过字符串“MYTEST”或“MYDRIVER”进行过滤并生成 CSV 文件。在这种情况下,您将在 VTune Amplifier 时间线窗格中同时看到来自 logcat 的用户级日志和来自“dmesg”的内核级日志。日志是在脚本内部使用以下命令收集的:
>adb shell logcat -v threadtime -f /dev/kmsg | adb shell cat /proc/kmsg
在这种情况下,您可以看到来自 vmlinux 的 TID 为 0 的内核日志,以及来自 logcat 的 TID 为 1922 的用户级日志。

请使用命令“logcat2vtune.sh -h”获取有关脚本用法的更多详细信息。您可以根据自己的目的自定义该脚本。请注意,此脚本是一个实验性脚本,尚未经过充分验证。如果您在使用此脚本时遇到任何问题,请随时告诉我。

© . All rights reserved.