首页 > Android, System > Android进程统计信息

Android进程统计信息

2012-07-16 16:31 星期一    浏览: 5,939    绿 发表评论 阅读评论

在Android报ANR错误时,会在logcat输出的log中包含有系统负载和进程统计信息,例如:

01-18 22:11:21.490 I/Process ( 1785): Sending signal. PID: 1901 SIG: 3
01-18 22:11:21.490 I/dalvikvm( 1901): threadid=4: reacting to signal 3
01-18 22:11:21.490 I/dalvikvm( 1901): Wrote stack traces to '/data/anr/traces.txt'
01-18 22:11:21.500 I/Process ( 1785): Sending signal. PID: 1785 SIG: 3
01-18 22:11:21.500 I/dalvikvm( 1785): threadid=4: reacting to signal 3
01-18 22:11:21.500 I/dalvikvm( 1785): Wrote stack traces to '/data/anr/traces.txt'
01-18 22:11:21.510 I/Process ( 1785): Sending signal. PID: 1947 SIG: 3
01-18 22:11:21.510 I/dalvikvm( 1947): threadid=4: reacting to signal 3
01-18 22:11:21.510 I/dalvikvm( 1947): Wrote stack traces to '/data/anr/traces.txt'
01-18 22:11:21.860 D/dalvikvm( 1785): GC_CONCURRENT freed 1249K, 46% free 4684K/8519K, external 3650K/4558K, paused 2ms+5ms
01-18 22:11:21.930 W/ProcessStats( 1785): Skipping unknown process pid 28817
01-18 22:11:22.020 D/dalvikvm( 1785): GC_EXPLICIT freed 278K, 46% free 4680K/8519K, external 3650K/4558K, paused 87ms
01-18 22:11:22.060 W/ProcessStats( 1785): Skipping unknown process pid 28870
01-18 22:11:22.440 W/SharedBufferStack( 1901): waitForCondition(LockCondition) timed out (identity=3, status=0). CPU may be pegged. trying again.
01-18 22:11:22.600 I/Process ( 1785): Sending signal. PID: 24085 SIG: 3
01-18 22:11:22.600 I/dalvikvm(24085): threadid=4: reacting to signal 3
01-18 22:11:22.610 I/dalvikvm(24085): Wrote stack traces to '/data/anr/traces.txt'
01-18 22:11:22.640 I/Process ( 1785): Sending signal. PID: 1901 SIG: 9
01-18 22:11:22.640 E/ActivityManager( 1785): ANR in com.android.systemui
01-18 22:11:22.640 E/ActivityManager( 1785): Reason: Broadcast of Intent { act=android.intent.action.TIME_TICK flg=0x40000004 (has extras) }
01-18 22:11:22.640 E/ActivityManager( 1785): Load: 3.55 / 2.35 / 1.79
01-18 22:11:22.640 E/ActivityManager( 1785): CPU usage from 5018ms to 0ms ago:
01-18 22:11:22.640 E/ActivityManager( 1785): 94% 5644/sh: 48% user + 46% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 0.9% 1805/ipolldevd: 0% user + 0.9% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 0.9% 24085/com.android.browser: 0.7% user + 0.1% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 0.7% 1785/system_server: 0% user + 0.7% kernel / faults: 5 minor
01-18 22:11:22.640 E/ActivityManager( 1785): 0.3% 5762/logcat: 0.1% user + 0.1% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 0.1% 881/mmcqd: 0% user + 0.1% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 0.1% 21939/sh: 0% user + 0.1% kernel / faults: 55 minor
01-18 22:11:22.640 E/ActivityManager( 1785): 0.1% 21944/logcat: 0.1% user + 0% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): +0% 28817/sleep: 0% user + 0% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): +0% 28867/sleep: 0% user + 0% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 100% TOTAL: 50% user + 49% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): CPU usage from 563ms to 1105ms later with 99% awake:
01-18 22:11:22.640 E/ActivityManager( 1785): 94% 5644/sh: 49% user + 45% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 71% 1785/system_server: 35% user + 35% kernel / faults: 3 minor
01-18 22:11:22.640 E/ActivityManager( 1785): 66% 1795/SurfaceFlinger: 1.8% user + 64% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 5.6% 1864/ActivityManager: 1.8% user + 3.7% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 1.1% 1805/ipolldevd: 0% user + 1.1% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 1.4% 24085/com.android.browser: 1.4% user + 0% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 1.4% 24104/WebViewCoreThre: 1.4% user + 0% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): +0% 28871/sleep: 0% user + 0% kernel
01-18 22:11:22.640 E/ActivityManager( 1785): 100% TOTAL: 53% user + 46% kernel

该log的输出在代码frameworks/base/core/java/com/android/internal/os/ProcessStats.java中,见其函数:

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

final public String printCurrentState(long now) {
buildWorkingProcs();

StringWriter sw = new StringWriter();
PrintWriter pw = new PrintWriter(sw);

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”);
}

那么它们的含义是什么呢?

1.系统负载信息:/proc/loadavg
系统负载Load的输出的三个数据来自于/proc/loadavg。我本人笔记本Ububtu上的一个示例如下:
cat /proc/loadavg
1.32 1.01 0.93 2/417 3312

依据参考链接(1)CentOS官方文档的介绍,头三列的数据是最后1、5、15分钟时间段的CPU与IO的占用率,数据越大表示占用越高,它包括CPU和磁盘IO的影响,某一项荷载高都会影响它们;第4列数据是当前正在运行的进程和系统的总进程数;最后一列是已经使用的最后进程号。可以对报告的数据这样简单理解:若是单核CPU,表示过去1分钟有1.32-1=0.32个任务在等待执行;或是再快到1.32倍,就刚好满足执行,既不富余又不会有等待。过去5分钟则有0.01个任务等待,过去15分钟则资源有剩余。

对于多核和多线程情况,计算方式可能是,每有一个线程等待,load数就加1,这将导致一个并不准确反应系统荷载的数据。

对于logcat上输出:
Load: 11.0 / 9.23 / 4.72
对于单核情况,则意味着过去1分钟有10个任务处在等待状态,5分钟有8.23个任务等待,15分钟有3.72个任务等待。等待包括CPU等待或IO等待。

 

在桌面Linux系统中,使用uptime命令亦可得到相关信息:

uptime
11:10:32 up 1:44, 2 users, load average: 0.30, 0.57, 0.58

11:10:32表示当前时间;up 1:44表示系统已开机运行的时间;2 users表示登录的用户数;load average: 0.30, 0.57, 0.58表示最后1、5、15分钟的系统资源占用情况,与上相同。更详细可参考“参考链接2”。

 

在桌面Linux系统中,使用命令w可以得到更详细的信息:

w
11:12:20 up 1:46, 2 users, load average: 0.77, 0.63, 0.59
USER TTY FROM LOGIN@ IDLE JCPU PCPU WHAT
bill tty7 :0 09:26 1:45m 5:03 0.31s gnome-session
bill pts/0 :0.0 10:02 0.00s 0.80s 0.01s w

 

2. 系统统计:/proc/stat

可用“man 5 proc” 查看/proc下的文件的介绍。

我本人笔记本上的Ubuntu上的一个例子:

cat /proc/stat
cpu 169080 3896 124493 3579120 61642 1614 11123 0 0
cpu0 92221 3327 58968 1735886 47236 1267 5811 0 0
cpu1 76859 568 65524 1843233 14406 347 5311 0 0
intr 10839066 2736541 10435 0 0 0 0 0 0 1 163 0 0 23569 0 173 85627 140 11057 0 3 167596 0 6 0 0 0 0 0 0 296862 37139 1975450 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
ctxt 156735415
btime 1342401970
processes 3972
procs_running 1
procs_blocked 0
softirq 10791641 0 2630694 1132104 299593 85838 0 2915289 704204 6718 3017201

前三行是CPU各种模式下的时间片的统计信息,单位为USER_HZ (1/100ths of a second on most architectures, use sysconf(_SC_CLK_TCK) to obtain the right value)。第一行是下面各个CPU核的总计。

从左往右:

user:用户模式(user)下的时间片

nice:用户模式下的nice时间片。nice用于改变进程执行的优先级,通常的优先级为0,可以改为最高优先级(-20)或最低(20)。

system:kernel模式下的时间片

Idle:空闲时间片

IOWait:等待IO操作完成的时间片

irq:中断服务历程执行时间片

softirq: 软中断执行时间片

倒数第二列:steal(自2.6.11): 花费在别的系统上的时间,意味着虚拟OS(stolen time which is the time spent in other operating systems when running in a virtualized environment)

最后一列:guest(自2.6.24):花费在虚拟CPU上的时间( which is the time spent running a virtual CPU for guest operating systems under the control of the Linux kernel.)

本例这最后两列均为0。 前7列数据将被ProcessStats的update函数读取:

public void update() {
if (DEBUG) Slog.v(TAG, “Update: ” + this);
mLastSampleTime = mCurrentSampleTime;
mCurrentSampleTime = SystemClock.uptimeMillis();
mLastSampleRealTime = mCurrentSampleRealTime;
mCurrentSampleRealTime = SystemClock.elapsedRealtime();

final long[] sysCpu = mSystemCpuData;
if (Process.readProcFile(“/proc/stat”, SYSTEM_CPU_FORMAT,
null, sysCpu, null)) {
// Total user time is user + nice time.
final long usertime = sysCpu[0]+sysCpu[1];
// Total system time is simply system time.
final long systemtime = sysCpu[2];
// Total idle time is simply idle time.
final long idletime = sysCpu[3];
// Total irq time is iowait + irq + softirq time.
final long iowaittime = sysCpu[4];
final long irqtime = sysCpu[5];
final long softirqtime = sysCpu[6];

 

intr行:表示系统启动以来的中断数(This line shows counts of interrupts serviced since boot time, for each of the possible system interrupts. The first column is the total of all interrupts serviced; each subsequent column is the total for a particular interrupt.)

ctxt:系统的上下文切换次数

btime:系统启动以来的运行时间,自1970.1.1开始的秒数(boot time, in seconds since the Epoch (January 1, 1970).)

processes:系统自启动以来fork出的进程数量

procs_running:处在runnable状态(已就绪等待运行)的进程数量

procs_blocked: 等待IO完成的进程数量

 

3.  进程信息统计 /proc/[pid]/*

上面logcat的后面部分输出了各进程的信息,这些信息来自于/proc/[pid]/目录下的信息,如android.os.Process中的嵌套类Stats完全依赖于/proc/[pid]/stat、/proc/[pid]/cmdline和/proc/[pid]/task/(进程中的线程信息:This  is  a directory that contains one subdirectory for each thread in the process).

在ProcessStats中,collectStats用于收集进程的信息,它首先使用Process.getPids得到/proc下的进程号,然后使用Process.readProcFile(st.statFile.toString(),去读取进程/proc/[pid]/stat的统计信息。

可用“man 5 proc” 查看/proc下的文件的介绍。

 

参考链接:

(1)http://www.centos.org/docs/5/html/5.2/Deployment_Guide/s2-proc-loadavg.html

(2)http://www.hosting.com/support/linux/using-the-linux-uptime-command

(3)http://en.wikipedia.org/wiki/Load_(computing)

(4)http://www.linuxhowtos.org/System/procstat.htm

本文链接地址: http://blog.redwolf-soft.com/?p=1695

原创文章,版权©红狼博客所有, 转载随意,但请注明出处。

    分享到:

相关文章:

  • 无相关文章
分类: Android, System 标签: , ,
  1. 本文目前尚无任何评论.
  1. 本文目前尚无任何 trackbacks 和 pingbacks.
订阅评论
  欢迎参与讨论,请在这里发表您的看法、交流您的观点。