atrace和systrace和ftrace

概述

ftrace：是一个内核函数跟踪器，function tracer，旨在帮助开发人员和系统设计者可以找到内核内部发生的事情。

atrace：Android tracer，使用ftrace来跟踪Android上层的函数调用。为数据采集部分

systrace：Android的trace数据分析工具，将atrace采集上来的数据，以图形化的方式展现出来。

源码解析

1. atrace-进程打桩端

主要为android/system/core/libcutils/trace-dev.cpp和trace-dev.inc文件

#define ATRACE_TAG ATRACE_TAG_PACKAGE_MANAGER		// 定义tags，这里属于pm类，就是抓systrace的时候：python systrace.py -o mynewtrace.html pm	所选择的pm类

ATRACE_BEGIN("VoldNativeService::start");	// 往/sys/kernel/debug/tracing/trace_marker文件写一个时间点

ATRACE_END();	// 结束的时候，又写一个时间点

中间的trace文件生成

       <unknown>-4668  ( 4668) [001] .... 201.584372: tracing_mark_write: B|4668|main
       <unknown>-4668  ( 4668) [001] .... 201.594438: tracing_mark_write: B|4668|VolumeManager::start
       <unknown>-4668  ( 4668) [001] .... 201.594459: tracing_mark_write: B|4668|VolumeManager::unmountAll()
       <unknown>-4668  ( 4668) [001] .... 201.601562: tracing_mark_write: E|4668
       <unknown>-4668  ( 4668) [001] .... 201.601578: tracing_mark_write: B|4668|Devmapper::destroyAll
       <unknown>-4668  ( 4668) [001] .... 201.602094: tracing_mark_write: E|4668
       <unknown>-4668  ( 4668) [001] .... 201.602110: tracing_mark_write: B|4668|Loop::destroyAll
       <unknown>-4668  ( 4668) [001] .... 201.604609: tracing_mark_write: E|4668
       <unknown>-4668  ( 4668) [001] .... 201.604988: tracing_mark_write: B|4668|VolumeManager::updateVirtualDisk
       <unknown>-4668  ( 4668) [001] .... 201.605140: tracing_mark_write: E|4668
       <unknown>-4668  ( 4668) [001] .... 201.605147: tracing_mark_write: E|4668
       <unknown>-4668  ( 4668) [001] .... 201.605153: tracing_mark_write: B|4668|process_config
       <unknown>-4668  ( 4668) [001] .... 201.607640: tracing_mark_write: E|4668
       <unknown>-4668  ( 4668) [001] .... 201.607880: tracing_mark_write: B|4668|VoldNativeService::start
       <unknown>-4668  ( 4668) [001] .... 201.609138: tracing_mark_write: E|4668
       <unknown>-4668  ( 4668) [001] .... 201.609334: tracing_mark_write: B|4668|NetlinkManager::start
       <unknown>-4668  ( 4668) [001] .... 201.609720: tracing_mark_write: E|4668
       <unknown>-4668  ( 4668) [003] .... 201.610778: tracing_mark_write: B|4668|coldboot
       <unknown>-4670  ( 4668) [000] .... 201.647880: tracing_mark_write: B|4668|setListener
       <unknown>-4670  ( 4668) [000] .... 201.647894: tracing_mark_write: E|4668
       <unknown>-4670  ( 4668) [000] .... 201.649346: tracing_mark_write: B|4668|unmount
       <unknown>-4670  ( 4668) [000] .... 201.649660: tracing_mark_write: E|4668

1.1 vold进程中对atrace的使用

int main(int argc, char** argv) {
    // 设置atrace_enabled_tags = ATRACE_TAG_NOT_READY;
    // 设置atrace_is_enabled为false，相当于是关闭atrace
    // 需要将atrace_set_tracing_enabled设为true，打开systrace，选择pm项，才会抓到
    atrace_set_tracing_enabled(false);
    。。。。
    ATRACE_BEGIN("VoldNativeService::start");
    if (android::vold::VoldNativeService::start() != android::OK) {
        LOG(ERROR) << "Unable to start VoldNativeService";
        exit(1);
    }
    ATRACE_END();

    LOG(DEBUG) << "VoldNativeService::start() completed OK";

    ATRACE_BEGIN("NetlinkManager::start");
    if (nm->start()) {
        PLOG(ERROR) << "Unable to start NetlinkManager";
        exit(1);
    }
    ATRACE_END();

    // This call should go after listeners are started to avoid
    // a deadlock between vold and init (see b/34278978 for details)
    android::base::SetProperty("vold.has_adoptable", has_adoptable ? "1" : "0");
    android::base::SetProperty("vold.has_quota", has_quota ? "1" : "0");
    android::base::SetProperty("vold.has_reserved", has_reserved ? "1" : "0");

    // Do coldboot here so it won't block booting,
    // also the cold boot is needed in case we have flash drive
    // connected before Vold launched
    coldboot("/sys/block");

    ATRACE_END();
    。。。
}

1.2 atrace_set_tracing_enabled-设置atrace_is_enabled变量，设置atrace_enabled_tags

void atrace_set_tracing_enabled(bool enabled)
{
    atomic_store_explicit(&atrace_is_enabled, enabled, memory_order_release);
    atrace_update_tags();
}

1.3 atrace_update_tags-如果atrace_is_enabled为true则atrace_enabled_tags为debug.atrace.tags.enableflags属性值否则为ATRACE_TAG_NOT_READY

// Update tags if tracing is ready. Useful as a sysprop change callback.
void atrace_update_tags()
{
    uint64_t tags;
    // 为true，走这里
    if (atomic_load_explicit(&atrace_is_enabled, memory_order_acquire)) {
        // 获取debug.atrace.tags.enableflags的值，默认为ATRACE_TAG_ALWAYS，或者加上APP
        tags = atrace_get_property();
        pthread_mutex_lock(&atrace_tags_mutex);
        atrace_enabled_tags = tags;
        pthread_mutex_unlock(&atrace_tags_mutex);
    } else {
        // Tracing is disabled for this process, so we simply don't
        // initialize the tags.
        pthread_mutex_lock(&atrace_tags_mutex);
        // 第63位为1
        atrace_enabled_tags = ATRACE_TAG_NOT_READY;
        pthread_mutex_unlock(&atrace_tags_mutex);
    }
}

1.4 atrace_get_property-获取debug.atrace.tags.enableflags的值，默认为ATRACE_TAG_ALWAYS

// Read the sysprop and return the value tags should be set to
static uint64_t atrace_get_property()
{
    char value[PROPERTY_VALUE_MAX];
    char *endptr;
    uint64_t tags;

    property_get("debug.atrace.tags.enableflags", value, "0");
    errno = 0;
    tags = strtoull(value, &endptr, 0);
    if (value[0] == '\0' || *endptr != '\0') {
        ALOGE("Error parsing trace property: Not a number: %s", value);
        return 0;
    } else if (errno == ERANGE || tags == ULLONG_MAX) {
        ALOGE("Error parsing trace property: Number too large: %s", value);
        return 0;
    }

    // Only set the "app" tag if this process was selected for app-level debug
    // tracing.
    if (atrace_is_app_tracing_enabled()) {
        // 匹配的话，tags就有APP，APP的是第12位为1
        tags |= ATRACE_TAG_APP;
    } else {
        tags &= ~ATRACE_TAG_APP;
    }
// ATRACE_TAG_VALID_MASK表示前26位都为1，ATRACE_TAG_ALWAYS表示第1位为1
    return (tags | ATRACE_TAG_ALWAYS) & ATRACE_TAG_VALID_MASK;
}

1.5 atrace_is_app_tracing_enabled-进程名字和debug.atrace.app_%d属性值匹配

// Determine whether application-level tracing is enabled for this process.
static bool atrace_is_app_tracing_enabled()
{
    bool sys_debuggable = property_get_bool("ro.debuggable", 0);
    bool result = false;

    if (sys_debuggable || atrace_is_debuggable) {
        // Check whether tracing is enabled for this process.
        FILE * file = fopen("/proc/self/cmdline", "re");
        if (file) {
            char cmdline[4096];
            if (fgets(cmdline, sizeof(cmdline), file)) {
                // 进程名字和debug.atrace.app_%d属性值匹配，debug.atrace.app_%d属性值可为*
                result = atrace_is_cmdline_match(cmdline);
            } else {
                ALOGE("Error reading cmdline: %s (%d)", strerror(errno), errno);
            }
            fclose(file);
        } else {
            ALOGE("Error opening /proc/self/cmdline: %s (%d)", strerror(errno),
                    errno);
        }
    }

    return result;
}

1.6 atrace_is_cmdline_match-进程名字和debug.atrace.app_%d属性值匹配

// Check whether the given command line matches one of the comma-separated
// values listed in the app_cmdlines property.
static bool atrace_is_cmdline_match(const char* cmdline)
{
    int count = property_get_int32("debug.atrace.app_number", 0);

    char buf[PROPERTY_KEY_MAX];
    char value[PROPERTY_VALUE_MAX];

    for (int i = 0; i < count; i++) {
        snprintf(buf, sizeof(buf), "debug.atrace.app_%d", i);
        property_get(buf, value, "");
        if (strcmp(value, "*") == 0 || strcmp(value, cmdline) == 0) {
            return true;
        }
    }

    return false;
}

1.7 ATRACE_BEGIN-初始化atrace并写trace信息

// vold中定义#define ATRACE_TAG ATRACE_TAG_PACKAGE_MANAGER，属于pm
#define ATRACE_BEGIN(name) atrace_begin(ATRACE_TAG, name)
static inline void atrace_begin(uint64_t tag, const char* name)
{// 为false，则打印
    if (CC_UNLIKELY(atrace_is_tag_enabled(tag))) {
        void atrace_begin_body(const char*);
        // 走这里
        atrace_begin_body(name);
    }
}

1.8 ATRACE_ENABLED-atrace_is_tag_enabled-初始化atrace

#define ATRACE_ENABLED() atrace_is_tag_enabled(ATRACE_TAG)
static inline uint64_t atrace_is_tag_enabled(uint64_t tag)
{// atrace_get_enabled_tags返回为ATRACE_TAG_ALWAYS，vold的话，tag就是pm，所以这里false
    return atrace_get_enabled_tags() & tag;
}

1.9 atrace_get_enabled_tags-初始化atrace，更新tags

uint64_t atrace_get_enabled_tags()
{
    atrace_init();
    return atrace_enabled_tags;
}

1.10 atrace_init-初始化atrace，更新tags

void atrace_init() {
#if defined(__BIONIC__)
    // 获取__system_property_serial，用来判断属性更新的
    uint32_t seq_no = __system_property_serial(atrace_property_info);  // Acquire semantics.
#else
    uint32_t seq_no = 0;
#endif
    uint32_t prev_seq_no = atomic_load_explicit(&last_sequence_number, memory_order_relaxed);
    // 如果属性更新了
    if (CC_UNLIKELY(seq_no != prev_seq_no)) {
        // 初始化atrace，更新tags
        atrace_seq_number_changed(prev_seq_no, seq_no);
    }
}

1.11 atrace_seq_number_changed-初始化atrace，更新tags

static void atrace_seq_number_changed(uint32_t prev_seq_no, uint32_t seq_no) {
    // atrace_is_enabled的值为false，直接返回了；它默认是true的，如果不设置的话，默认是可以抓trace的
    if (!atomic_load_explicit(&atrace_is_enabled, memory_order_acquire)) {
        return;
    }

    // Someone raced us.
    if (!atomic_compare_exchange_strong(&last_sequence_number, &prev_seq_no, seq_no)) {
        return;
    }

    if (CC_UNLIKELY(prev_seq_no == kSeqNoNotInit)) {
#if defined(__BIONIC__)
        const prop_info* new_pi = __system_property_find("debug.atrace.tags.enableflags");
        if (new_pi) atrace_property_info = new_pi;
#endif
        // 在这里调用atrace_init_once函数，打开trace_marker文件初始化atrace
        pthread_once(&atrace_once_control, atrace_init_once);
    }
//  更新tags
    atrace_update_tags();
}

1.12 atrace_init_once-打开trace_marker文件初始化atrace

static void atrace_init_once()
{
    atrace_marker_fd = open("/sys/kernel/debug/tracing/trace_marker", O_WRONLY | O_CLOEXEC);
    if (atrace_marker_fd == -1) {
        atrace_marker_fd = open("/sys/kernel/tracing/trace_marker", O_WRONLY | O_CLOEXEC);
    }

    if (atrace_marker_fd == -1) {
        ALOGE("Error opening trace file: %s (%d)", strerror(errno), errno);
        atrace_enabled_tags = 0;
    } else {
      atrace_enabled_tags = atrace_get_property();
    }
}

1.13 atrace_begin_body-写到trace_marker文件中

void atrace_begin_body(const char* name)
{
    WRITE_MSG("B|%d|", "%s", name, "");
}

1.14 WRITE_MSG-写到trace_marker文件中

#define WRITE_MSG(format_begin, format_end, name, value) { \
    char buf[ATRACE_MESSAGE_LENGTH] __attribute__((uninitialized));     \
    int pid = getpid(); \
    int len = snprintf(buf, sizeof(buf), format_begin "%s" format_end, pid, \
        name, value); \
    if (len >= (int) sizeof(buf)) { \
        /* Given the sizeof(buf), and all of the current format buffers, \
         * it is impossible for name_len to be < 0 if len >= sizeof(buf). */ \
        int name_len = strlen(name) - (len - sizeof(buf)) - 1; \
        /* Truncate the name to make the message fit. */ \
        ALOGW("Truncated name in %s: %s\n", __FUNCTION__, name); \
        len = snprintf(buf, sizeof(buf), format_begin "%.*s" format_end, pid, \
            name_len, name, value); \
    } \
    write(atrace_marker_fd, buf, len); \
}

2. atrace-数据采集端

3. ftrace

systrace工具的使用

1. 使用adb的systrace工具

该命令在android-sdk/platform-tools/systrace/中，需要安装python
python systrace.py -o mynewtrace.html sched freq idle am wm gfx view binder_driver hal dalvik camera input res
python systrace.py --list-categories	列出支持的策略
也可以使用android-studio中的monitor.bat工具来抓systrace

2. 使用perfetto工具或者开发者选项打开

perfetto -o /data/misc/perfetto-traces/trace -t 10s sched freq idle am wm gfx view
也可以在开发者选项中，打开System Tracing，源码在android/packages/apps/Traceur，用的也是perfetto工具
打开开关，就可以抓trace了
然后可以使用android-sdk/platform-tools/systrace/中的systrace工具，转成网页形式的
python systrace.py --from-file=trace

转换的过程中，会有错误：这是因为如果不是adb形式的，它是没有开头和结尾的，所以不需要辨认了，直接把读到的data传进去就好了
    data_start = re.search(TRACE_START_REGEXP, result).end(0)
AttributeError: 'NoneType' object has no attribute 'end'

  def _read_trace_data(self):
    with open(self._filename, 'rb') as f:
      result = f.read()
    try:
      data_start = re.search(TRACE_START_REGEXP, result).end(0)
      data = re.sub(ADB_IGNORE_REGEXP, '', result[data_start:])
    except:
      data = result
    return self._preprocess_data(data)

问题

1. perfetto文件转html出错

Reading results from file.
Tracing completed. Collecting output...
Traceback (most recent call last):
  File "systrace.py", line 49, in <module>
    sys.exit(run_systrace.main())
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/run_systrace.py", line 205, in main
    main_impl(sys.argv)
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/run_systrace.py", line 200, in main_impl
    controller.StopTracing()
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/systrace_runner.py", line 49, in StopTracing
    self._tracing_controller.StopTracing()
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/tracing_controller.py", line 187, in StopTracing
    if agent.StopAgentTracing(timeout=self._controller_config.timeout):
  File "/home/a/Downloads/platform-tools/systrace/catapult/common/py_utils/py_utils/__init__.py", line 103, in RunWithTimeout
    return timeout_retry.Run(func, timeout, 0, args=args)
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/../../devil/devil/utils/timeout_retry.py", line 164, in Run
    error_log_func=error_log_func)
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/../../devil/devil/utils/reraiser_thread.py", line 199, in JoinAll
    self._JoinAll(watcher, timeout)
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/../../devil/devil/utils/reraiser_thread.py", line 171, in _JoinAll
    thread.ReraiseIfException()
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/../../devil/devil/utils/reraiser_thread.py", line 94, in run
    self._ret = self._func(*self._args, **self._kwargs)
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/../../devil/devil/utils/timeout_retry.py", line 156, in <lambda>
    lambda: func(*args, **kwargs), name=thread_name)
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/tracing_agents/atrace_from_file_agent.py", line 104, in StopAgentTracing
    self._trace_data = self._read_trace_data()
  File "/home/a/Downloads/platform-tools/systrace/catapult/systrace/systrace/tracing_agents/atrace_from_file_agent.py", line 120, in _read_trace_data
    data_start = re.search(TRACE_START_REGEXP, result).end(0)
AttributeError: 'NoneType' object has no attribute 'end'

解决办法：

systrace/systrace/tracing_agents/atrace_from_file_agent.py文件：加个异常处理，就可以转为html文件了
  def _read_trace_data(self):
    with open(self._filename, 'rb') as f:
      result = f.read()
    try:
      data_start = re.search(TRACE_START_REGEXP, result).end(0)
      data = re.sub(ADB_IGNORE_REGEXP, '', result[data_start:])
    except:
      data = result
    return self._preprocess_data(data)

补充

参考

1. Android Systrace 基础知识 -- Systrace 简介
https://www.androidperformance.com/2019/05/28/Android-Systrace-About/
2. ftrace - Function Tracer - 内核文档
https://www.kernel.org/doc/Documentation/trace/ftrace.txt