[Android] dumpsys cpuinfoの見方

dumpsysとは

Androidのsystem serviceの状態を出力するコマンド。
オプション無しだと全サービスの情報を出力してくれる。
dumpsys -lで対応するserviceの一覧を取得し、dumpsys SERVICEで特定のserviceの情報だけ出力することも可能。

dumpsys自体はserviceに対してdump要求を投げるだけで、実際の情報出力はservice側でおこなう。
この作りのおかげで柔軟にdumpsysを拡張できる。
逆に言えばdumpsysに対応するserviceはシステムごとに異なる。
今回はとっかかりとして、どこでも使えるであろう"cpuinfo"を深堀してみる。

dumpsys cpuinfo

プロセスごとのCPU使用率を確認するためのコマンド。
ざっくり言えば、/proc/loadavg + /proc/[pid]/stat + /proc/stat。
これらの中身を定期的にサンプリングして差分表示するとともに、ミリ秒などのわかりやすい単位に変換している。

$ adb shell dumpsys cpuinfo
Load: 10.22 / 9.43 / 9.08
CPU usage from 72305ms to 50387ms ago (2019-08-26 13:56:41.550 to 2019-08-26 13:57:03.468):
  25% 1540/system_server: 16% user + 9% kernel / faults: 25370 minor 193 major
  14% 22936/com.android.settings: 11% user + 3.2% kernel / faults: 9095 minor 23 major
  10% 695/surfaceflinger: 7.3% user + 3.3% kernel / faults: 379 minor 6 major
  ...
 +0% 23681/com.samsung.android.app.appsedge: 0% user + 0% kernel
18% TOTAL: 8.8% user + 7.8% kernel + 0.3% iowait + 1.1% irq + 0.2% softirq

参照したソースコードは以下のとおり。
Android OS: 8.1
Linux kernel: 4.4.138

1行目: ロードアベレージ

Load: 10.22 / 9.43 / 9.08

/proc/loadavgをほぼそのまま出力。

$ adb shell cat /proc/loadavg
10.22 9.43 9.08 1/1904 5527

すなわち、全CPUのTASK_RUNNING (R) or TASK_UNINTERRUPTIBLE (D)のタスク数の平均（順に直近1分 / 5分 / 15分の平均）。

man(5)proc

       /proc/loadavg
              The first three fields in this file are load average figures giving the number of jobs in the run queue (state R) or waiting for disk I/O (state D) averaged over 1, 5, and 15 minutes.

man(1)ps

PROCESS STATE CODES
               D    uninterruptible sleep (usually IO)
               R    running or runnable (on run queue)

出力関数はprintCurrentLoad()。

frameworks/base/core/java/com/android/internal/os/ProcessCpuTracker.java

    final public String printCurrentLoad() {
        StringWriter sw = new StringWriter();
        PrintWriter pw = new FastPrintWriter(sw, false, 128);
        pw.print("Load: ");
        pw.print(mLoad1);
        pw.print(" / ");
        pw.print(mLoad5);
        pw.print(" / ");
        pw.println(mLoad15);
        pw.flush();
        return sw.toString();
    }

今回初めてLinux kernelのloadavgの実装を見て知ったが、loadavgは単純な加算平均ではなく指数移動平均を使っている。

sched/loadavg.c

/*
 * a1 = a0 * e + a * (1 - e)
 */
static unsigned long
calc_load(unsigned long load, unsigned long exp, unsigned long active)
{
    unsigned long newload;

    newload = load * exp + active * (FIXED_1 - exp);
    if (active >= load)
        newload += FIXED_1-1;

    return newload / FIXED_1;
}

2行目：サンプリング時間情報

CPU usage from 72305ms to 50387ms ago (2019-08-26 23:56:41.550 to 2019-08-26 23:57:03.468):

dumpsysで取得した場合、一回前にサンプリングした時点(72305ms前)から、最後にサンプリングした時点(50387ms前)までの平均となる。
ANRからdumpsysする場合は、サンプリングがANR発生時刻よりもあとになりうる。その場合は、"ago"ではなく"later"となる。

前２つの時刻(72305, 50387)は、SystemClock.uptimeMillis()（clock_gettime(CLOCK_MONOTONIC)をミリ秒単位に変換した値）の差分。
あと２つの時刻は、System.currentTimeMillis()で取得した、一回前にサンプリングしたwallclock時間と最後にサンプリングしたwallclock時間。

frameworks/base/core/java/com/android/internal/os/ProcessCpuTracker.java

    final public String printCurrentState(long now) {
        final SimpleDateFormat sdf = new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");

        buildWorkingProcs();

        StringWriter sw = new StringWriter();
        PrintWriter pw = new FastPrintWriter(sw, false, 1024);

        pw.print("CPU usage from ");
        if (now > mLastSampleTime) {
            pw.print(now-mLastSampleTime);
            pw.print("ms to ");
            pw.print(now-mCurrentSampleTime);
            pw.print("ms ago");
        } else {
            pw.print(mLastSampleTime-now);
            pw.print("ms to ");
            pw.print(mCurrentSampleTime-now);
            pw.print("ms later");
        }
        pw.print(" (");
        pw.print(sdf.format(new Date(mLastSampleWallTime)));
        pw.print(" to ");
        pw.print(sdf.format(new Date(mCurrentSampleWallTime)));
        pw.print(")");

3〜(n-1)行目：各プロセスのCPU使用率

  25% 1540/system_server: 16% user + 9% kernel / faults: 25370 minor 193 major
  14% 22936/com.android.settings: 11% user + 3.2% kernel / faults: 9095 minor 23 major
  10% 695/surfaceflinger: 7.3% user + 3.3% kernel / faults: 379 minor 6 major
  ...
 +0% 23681/com.samsung.android.app.appsedge: 0% user + 0% kernel

/proc/[pid]/statから算出した、プロセスごとのサマリ。
計算式からわかるように、上限は{CPUコア数} ×100%。

dumpsys	/proc/[pid]/stat
1. CPU使用率	utime+stimeの増分 / clock_gettime(CLOCK_MONOTONIC)の増分
2. pid	pid
3. name	comm
4. CPU使用率(user)	utimeの増分 / clock_gettime(CLOCK_MONOTONIC)の増分
5. CPU使用率(kernel)	stimeの増分 / clock_gettime(CLOCK_MONOTONIC)の増分
6. minor faults	minfltの増分
7. major faults	majfltの増分

man(5)proc

       /proc/[pid]/stat
              Status information about the process.  This is used by ps(1).  It is defined in the kernel source file fs/proc/array.c.

              (2) comm  %s
                        The filename of the executable, in parentheses.  This is visible whether or not the executable is swapped out.

              (10) minflt  %lu
                        The number of minor faults the process has made which have not required loading a memory page from disk.

              (12) majflt  %lu
                        The number of major faults the process has made which have required loading a memory page from disk.

              (14) utime  %lu
                        Amount of time that this process has been scheduled in user mode, measured in clock ticks (divide by sysconf(_SC_CLK_TCK)).  This includes guest time, guest_time (time spent  run‐
                        ning a virtual CPU, see below), so that applications that are not aware of the guest time field do not lose that time from their calculations.

              (15) stime  %lu
                        Amount of time that this process has been scheduled in kernel mode, measured in clock ticks (divide by sysconf(_SC_CLK_TCK)).

出力関数はprintProcessCPU()。

前回サンプリング時から新しく起動したプロセスは"+"が、終了したプロセスは"-"が行頭につけられる。

frameworks/base/core/java/com/android/internal/os/ProcessCpuTracker.java

    private void printProcessCPU(PrintWriter pw, String prefix, int pid, String label,
            int totalTime, int user, int system, int iowait, int irq, int softIrq,
            int minFaults, int majFaults) {
        pw.print(prefix);
        if (totalTime == 0) totalTime = 1;
        printRatio(pw, user+system+iowait+irq+softIrq, totalTime);
        pw.print("% ");
        if (pid >= 0) {
            pw.print(pid);
            pw.print("/");
        }
        pw.print(label);
        pw.print(": ");
        printRatio(pw, user, totalTime);
        pw.print("% user + ");
        printRatio(pw, system, totalTime);
        pw.print("% kernel");
        if (iowait > 0) {
            pw.print(" + ");
            printRatio(pw, iowait, totalTime);
            pw.print("% iowait");
        }
        if (irq > 0) {
            pw.print(" + ");
            printRatio(pw, irq, totalTime);
            pw.print("% irq");
        }
        if (softIrq > 0) {
            pw.print(" + ");
            printRatio(pw, softIrq, totalTime);
            pw.print("% softirq");
        }
        if (minFaults > 0 || majFaults > 0) {
            pw.print(" / faults:");
            if (minFaults > 0) {
                pw.print(" ");
                pw.print(minFaults);
                pw.print(" minor");
            }
            if (majFaults > 0) {
                pw.print(" ");
                pw.print(majFaults);
                pw.print(" major");
            }
        }
        pw.println();
    }

n行目：合計CPU使用量

18% TOTAL: 8.8% user + 7.8% kernel + 0.3% iowait + 1.1% irq + 0.2% softirq

/proc/statの１行目から算出した、全CPUについてのサマリ。
計算式からわかるように、上限はCPUのコア数によらず100%。

dumpsys	/proc/stat
1. CPU使用率	user+nice+system+iowait+irq+softirq (idle以外)の増分 / user+nice+system+idle+iowait+irq+softirqの増分
2. CPU使用率(user)	user+niceの増分 / user+nice+system+idle+iowait+irq+softirqの増分
3. CPU使用率(kernel)	systemの増分 / user+nice+system+idle+iowait+irq+softirqの増分
4. CPU使用率(iowait)	iowaitの増分 / user+nice+system+idle+iowait+irq+softirqの増分
5. CPU使用率(irq)	irqの増分 / user+nice+system+idle+iowait+irq+softirqの増分
6. CPU使用率(softirq)	softirqの増分 / user+nice+system+idle+iowait+irq+softirqの増分

$ adb shell cat /proc/stat | head -1
cpu  2831807 1074597 3736372 75794589 301073 570279 244610 0 0 0

man(5)proc

       /proc/stat
              kernel/system statistics.  Varies with architecture.  Common entries include:

              cpu  3357 0 4313 1362393
                     The amount of time, measured in units of USER_HZ (1/100ths of a second on most architectures, use sysconf(_SC_CLK_TCK) to obtain the right value), that the system  spent  in  various
                     states:

                     user   (1) Time spent in user mode.

                     nice   (2) Time spent in user mode with low priority (nice).

                     system (3) Time spent in system mode.

                     idle   (4) Time spent in the idle task.  This value should be USER_HZ times the second entry in the /proc/uptime pseudo-file.

                     iowait (since Linux 2.5.41)
                            (5) Time waiting for I/O to complete.

                     irq (since Linux 2.6.0-test4)
                            (6) Time servicing interrupts.

                     softirq (since Linux 2.6.0-test4)
                            (7) Time servicing softirqs.

その他

"cpuinfo" serviceはActivitManagerServiceが登録している。

frameworks/base/services/core/java/com/android/server/am/ActivityManagerService.java

    public void setSystemProcess() {
        try {
            ServiceManager.addService(Context.ACTIVITY_SERVICE, this, true);
            ServiceManager.addService(ProcessStats.SERVICE_NAME, mProcessStats);
            ServiceManager.addService("meminfo", new MemBinder(this));
            ServiceManager.addService("gfxinfo", new GraphicsBinder(this));
            ServiceManager.addService("dbinfo", new DbBinder(this));
            if (MONITOR_CPU_USAGE) {
                ServiceManager.addService("cpuinfo", new CpuBinder(this));
            }
            ServiceManager.addService("permission", new PermissionController(this));
            ServiceManager.addService("processinfo", new ProcessInfoService(this));

            ApplicationInfo info = mContext.getPackageManager().getApplicationInfo(
                    "android", STOCK_PM_FLAGS | MATCH_SYSTEM_ONLY);
            mSystemThread.installSystemApplicationInfo(info, getClass().getClassLoader());

            synchronized (this) {
                ProcessRecord app = newProcessRecordLocked(info, info.processName, false, 0);
                app.persistent = true;
                app.pid = MY_PID;
                app.maxAdj = ProcessList.SYSTEM_ADJ;
                app.makeActive(mSystemThread.getApplicationThread(), mProcessStats);
                synchronized (mPidsSelfLocked) {
                    mPidsSelfLocked.put(app.pid, app);
                }
                updateLruProcessLocked(app, false, null);
                updateOomAdjLocked();
            }
        } catch (PackageManager.NameNotFoundException e) {
            throw new RuntimeException(
                    "Unable to find android system package", e);
        }
    }

おわりに

ロードアベレージは、全CPUで実行中or待ちのタスク数の1,5,15分間の平均。
プロセス毎のCPU使用率は、プロセスに割り当てられたCPU時間/実時間。上限はCPUコア数×100%。
全体のCPU使用率は、上限はコア数によらず100%。

Androidは解析に有用な仕組み、ツールをたくさん用意してくれているが、意外とそれらに関する情報が見つからない。
コードを確認しつつ、使いこなせるようになっていきたい。

参考

dumpsys
man(5)proc
man(1)ps
Linux Load Averages: Solving the Mystery
Load Average はどうやって算出されているのか