Android-logcat统计各进程的log输出

logd 是 Android 的日志系统,其基本构架如下:
logd-arch

本质上也是个 c/s 构架。应用作为客户端往服务端 logd 写数据, logd 作为服务端收到数据后会把数据写到 LogBuf 中。logcat 作为另外一个客户端,从 LogBuf 中读取数据。这个其实也是个生产者/消费者模型。应用可以看作生产者,logcat 可以看作是消费者,logd 可以看作是消息队列。
LogBuf 也是有一定大小限制的,当生产者写入 log 的速度太快,超出了 LogBuf 的容量,消费者 logcat 没来得及读取, 部分 log 就会被丢弃,因此有时候我们用 logcat 看日志可能会看不到我们关心日志。出现这种情况时,我们有两种方法来解决:

    1. logcat -G 50M 加大 LogBuf 的缓冲区,logcat -g 可以查看当前的缓冲区大小。
    1. logcat > /data/test.log 重定向到文件中,因为写入文件的速度远远大于写到终端的速度,这样可以加快消费者 logcat 的处理速度。

虽然我们可以通过以上两种方法来解决 log 丢失的问题,但我觉得本质上还是 log 太多了,应该要从根本上解决问题才行。而且 log 太多还会影响系统的性能。因此我们的目标是尽量减少 log 的输出。为了达到我们的目标,我们首先要统计一下哪些进程输出的 log 最多,然后制定一套 log 输出规范,让各应用负责人按规范执行。幸好,logd 已经帮我们统计了各进程的输出信息了:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
pure:/ # logcat -S
size/num main system crash Total
Total 813814/6044 241364/2849 0/0 1055178/8893
Now 810598/6038 234585/2794 1045183/8832
Logspan 2:17.291 2:12.983 2:17.646
Overhead 1148726 391049 1712031

# main log buffer 按 UID 来统计的数据, Pruned 意思是被丢弃的行数。
Chattiest UIDs in main log buffer: Size +/- Pruned
UID PACKAGE BYTES NUM
1000 system 212928 0.7% 15
PID/UID COMMAND LINE " "
1694/1000 system_server 174427 9
1406/1000 /system/bin/hwservicemanager 9934
1545/1000 /system/bin/surfaceflinger 5283
1519/1000 ...ndroid.hardware.graphics.allocator@2.0-service 3588 6
1047 cameraserver 108245
1073 network_stack 77144 1
10039 com.android.calllogbackup 74203
0 root 65947
1001 radio 45219
1046 mediacodec 28506
10078 com.android.systemui 27159
10087 com.android.launcher3 13328
10036 com.android.providers.media 10845
1041 audioserver 6893
10091 com.android.camera2 6767
10092 com.android.gallery3d 6332
10079 com.android.dialer 5686 +17%
10090 com.android.calendar 4668
50039 com.android.calllogbackup 4220
50036 com.android.providers.media 4215
1013 media 3494
50101 com.android.webview 3401
10095 com.android.inputmethod.latin 3314 1
10056 com.android.messaging 2823
10052 com.android.permissioncontroller 2329

# system log buffer 中按 UID 统计的数据
Chattiest UIDs in system log buffer: Size +/- Pruned
UID PACKAGE BYTES NUM
1000 system 181697 +0.3% 55
0 root 28799 -3.1% 20
1001 radio 15940 -1.4% 7
10078 com.android.systemui 2579
10097 com.android.email 2557
1010 wifi 2299


# 根据 PID 进程号来统计的数据
Chattiest PIDs: Size Pruned
PID/UID COMMAND LINE BYTES NUM
1694/1000 system_server 416009 64
2519/1001 com.android.phone 387115 111
2458/1073 com.android.networkstack 75058 1
2830/10039 android.process.acore 74329
1560/1047 /system/bin/cameraserver 29999
2282/10078 com.android.systemui 29965
1410/0 /system/bin/vold 28365 20
1599/1001 /vendor/bin/hw/rild 28060
1593/1046 media.codec 24754
1564/0 /system/bin/installd 17057
2970/10087 com.android.launcher3 13858
1502/0 /system/bin/netd 12354
3080/10036 android.process.media 11172
1503/0 zygote64 10013
1406/1000 /system/bin/hwservicemanager 9934
1559/0 /system/bin/bpfloader 9312
1504/0 zygote 7089
3311/10091 com.android.camera2 6767
3715/10092 com.android.gallery3d 5692
2803/10079 com.android.dialer 5686
1545/1000 /system/bin/surfaceflinger 5296
3286/10090 com.android.calendar 4668
1479/0 /system/bin/apexd 4317


# 根据 TID 线程号来统计的数据
Chattiest TIDs: Size Pruned
TID/UID COMM BYTES NUM
2519/1001 m.android.phon 237838 20
1694/1000 system_server 137970 4
3381/10039 Worker-1 71269
2458/1073 id.networkstac 61782 1
1752/1000 ActivityManager 46670
2663/1001 HwBinder:2519_1 42183
1746/1000 android.display 32051
1560/1047 /system/bin/cameraserver 29999
1751/1000 android.bg 25443 3
3029/1001 Binder:2519_F 23697 35
2282/10078 com.android.systemui 23594
1822/1000 NetworkWatchlis 19234
1593/1046 android.hardwar 19122
1599/1001 /vendor/bin/hw/rild 18694
1753/1000 ActivityManager 17815
2908/1001 Binder:2519_E 15796 26
2350/1000 Binder:1694_4 14960
2672/1001 DcHandlerThread 14187
1410/0 /system/bin/vold 12270 20
2390/1000 Binder:1694_5 11318 6
1719/1000 Binder:1694_2 11307 7
2970/10087 re-initialized> 10815
2565/1000 Binder:1694_8 10600 2
2246/1000 ConnectivitySer 10283 1
1406/1000 hwservicemanage 9934
2729/1001 Binder:2519_7 9717 17
1503/0 main 9704
2243/1000 ClientModeImpl 9314
1559/0 /system/bin/bpfloader 9312
2780/1001 Binder:2519_C 9210 2
1809/0 Binder:1564_6 9196
2706/1001 CellularNetwork 8211

# 根据 TAG 来统计的数据
Chattiest TAGs: Size
TID/PID/UID LOG_TAG NAME BYTES
StrictMode 235216
dex2oat 103753
2519/1001 SubscriptionController 79244
2519/1001 SST 65952
2519/1001 RILJ 47862
2519/1001 DCT-C 44175
1694/1000 PackageManager 39750
ServiceManagement 36339
/1047 android.hardware.camera.provider@2.4-service 34224
1410/0 vold 27758
1694/1000 ActivityManager 27459
1694/1000 PackageManager.DexOptimizer 26189
RefBase 26097
sysui_multi_action 22173
2519/1001 IccSmsInterfaceManager 17960
1564/0 installd 16945
1593/1046 MediaCodecsXmlParser 16674
2663/2519/1001 RilRequest 16612
2519/1001 DC-C-1 14478
2282/10078 KeyguardUpdateMonitor 14429
1694/1000 Telecom 14258
2519/1001 TelecomFramework 14039
1599/1001 RIL 13184
<NULL> 13046
/1047 CamPrvdr@2.4-legacy 11868
1599/1001 AT 11835
1694/1000 SystemServerTiming 11492
ServiceManager 10807
1694/1000 system_server 10281
1406/1000 hwservicemanager 9934
1559/0 LibBpfLoader 9169
2519/1001 NRM-C 9072

pure:/ #

统计结果我们可以分为几个维度来解读:

  • uid 用户id,这个数据我们可以不用关注
  • pid 进程号,从上面的例子看 system_server 进程的 log 最多,有 416009 bytes
  • tid 线程号,从上面的例子看 com.android.phone 这个线程的 log 最多, 有 237838 bytes。
  • TAG 从上面的例子看 StrictMode 这个 TAG 的 log 最多, 有 235216 bytes。