blob: b878358572898805a70c90b07576af9f1e3086c7 [file] [log] [blame]
Vitalii Tomkived4c98c2016-04-28 15:20:57 -07001#!/usr/bin/python
2
3# Copyright (C) 2016 The Android Open Source Project
4#
5# Licensed under the Apache License, Version 2.0 (the "License");
6# you may not use this file except in compliance with the License.
7# You may obtain a copy of the License at
8#
9# http://www.apache.org/licenses/LICENSE-2.0
10#
11# Unless required by applicable law or agreed to in writing, software
12# distributed under the License is distributed on an "AS IS" BASIS,
13# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14# See the License for the specific language governing permissions and
15# limitations under the License.
16#
17"""Tool to analyze logcat and dmesg logs.
18
19bootanalyze read logcat and dmesg loga and determines key points for boot.
20"""
21
Vitalii Tomkivd704edd2016-07-13 17:27:03 -070022import argparse
Keun-young Park9b2ac712016-12-15 15:23:16 -080023import collections
Keun-young Parkcea1c732017-03-22 15:28:11 -070024import datetime
25import math
26import operator
27import os
28import re
29import select
30import subprocess
31import sys
32import time
Keun-young Park8f193c12017-08-04 18:16:23 -070033import threading
Keun-young Parkcea1c732017-03-22 15:28:11 -070034import yaml
35
Keun-young Parkc27316d2016-12-06 18:19:00 -080036from datetime import datetime, date
Vitalii Tomkived4c98c2016-04-28 15:20:57 -070037
Keun-young Park9b2ac712016-12-15 15:23:16 -080038
Vitalii Tomkived4c98c2016-04-28 15:20:57 -070039TIME_DMESG = "\[\s*(\d+\.\d+)\]"
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -070040TIME_LOGCAT = "[0-9]+\.?[0-9]*"
Keun-young Parke17b25b2016-11-30 16:43:31 -080041KERNEL_TIME_KEY = "kernel"
42BOOT_ANIM_END_TIME_KEY = "BootAnimEnd"
Keun-young Park1524bc02016-12-05 19:20:39 -080043KERNEL_BOOT_COMPLETE = "BootComplete_kernel"
44LOGCAT_BOOT_COMPLETE = "BootComplete"
Keun-young Park7b71b4d2017-02-13 11:03:15 -080045LAUNCHER_START = "LauncherStart"
Keun-young Park1524bc02016-12-05 19:20:39 -080046BOOT_TIME_TOO_BIG = 200.0
Vitalii Tomkivabc92332016-09-20 11:55:44 -070047MAX_RETRIES = 5
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -070048DEBUG = False
Wei Wang27404092016-12-02 22:00:31 -080049ADB_CMD = "adb"
Keun-young Park9b2ac712016-12-15 15:23:16 -080050TIMING_THRESHOLD = 5.0
Keun-young Parke3accfd2016-12-20 14:07:01 -080051BOOT_PROP = "\[ro\.boottime\.([^\]]+)\]:\s+\[(\d+)\]"
Keun-young Park32866e92017-05-15 09:16:38 -070052BOOTLOADER_TIME_PROP = "\[ro\.boot\.boottime\]:\s+\[([^\]]+)\]"
Vitalii Tomkived4c98c2016-04-28 15:20:57 -070053
Keun-young Park6dfb4762017-03-13 15:57:13 -070054max_wait_time = BOOT_TIME_TOO_BIG
55
Vitalii Tomkived4c98c2016-04-28 15:20:57 -070056def main():
Wei Wang27404092016-12-02 22:00:31 -080057 global ADB_CMD
58
Vitalii Tomkivd704edd2016-07-13 17:27:03 -070059 args = init_arguments()
Vitalii Tomkived4c98c2016-04-28 15:20:57 -070060
Vitalii Tomkivabc92332016-09-20 11:55:44 -070061 if args.iterate < 1:
62 raise Exception('Number of iteration must be >=1');
63
64 if args.iterate > 1 and not args.reboot:
65 print "Forcing reboot flag"
66 args.reboot = True
Vitalii Tomkived4c98c2016-04-28 15:20:57 -070067
Wei Wang27404092016-12-02 22:00:31 -080068 if args.serial:
69 ADB_CMD = "%s %s" % ("adb -s", args.serial)
70
Keun-young Parkc27316d2016-12-06 18:19:00 -080071 error_time = BOOT_TIME_TOO_BIG * 10
72 if args.errortime:
73 error_time = float(args.errortime)
Keun-young Park6dfb4762017-03-13 15:57:13 -070074 if args.maxwaittime:
75 global max_wait_time
76 max_wait_time = float(args.maxwaittime)
Keun-young Parkc27316d2016-12-06 18:19:00 -080077
Keun-young Parkda874db2017-01-31 14:39:09 -080078 components_to_monitor = {}
79 if args.componentmonitor:
80 items = args.componentmonitor.split(",")
81 for item in items:
82 kv = item.split("=")
83 key = kv[0]
84 value = float(kv[1])
85 components_to_monitor[key] = value
86
Vitalii Tomkivd704edd2016-07-13 17:27:03 -070087 cfg = yaml.load(args.config)
Vitalii Tomkived4c98c2016-04-28 15:20:57 -070088
Bryan Eylerb7ee7cc2017-03-29 14:52:12 -070089 if args.stressfs:
Keun-young Parkcf4d0282017-05-31 12:14:37 -070090 if run_adb_cmd('install -r -g ' + args.stressfs) != 0:
Bryan Eylerb7ee7cc2017-03-29 14:52:12 -070091 raise Exception('StressFS APK not installed');
92
Keun-young Parkcf4d0282017-05-31 12:14:37 -070093 if args.iterate > 1 and args.bootchart:
94 run_adb_shell_cmd_as_root('touch /data/bootchart/enabled')
Bryan Eylerb7ee7cc2017-03-29 14:52:12 -070095
Keun-young Park8f193c12017-08-04 18:16:23 -070096 search_events_pattern = {key: re.compile(pattern)
Vitalii Tomkivd704edd2016-07-13 17:27:03 -070097 for key, pattern in cfg['events'].iteritems()}
Keun-young Park8f193c12017-08-04 18:16:23 -070098 timing_events_pattern = {key: re.compile(pattern)
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -070099 for key, pattern in cfg['timings'].iteritems()}
Keun-young Park8f193c12017-08-04 18:16:23 -0700100 shutdown_events_pattern = {key: re.compile(pattern)
101 for key, pattern in cfg['shutdown_events'].iteritems()}
Vitalii Tomkived4c98c2016-04-28 15:20:57 -0700102
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700103 data_points = {}
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700104 kernel_timing_points = collections.OrderedDict()
105 logcat_timing_points = collections.OrderedDict()
Keun-young Parke3accfd2016-12-20 14:07:01 -0800106 boottime_points = collections.OrderedDict()
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700107 boot_chart_file_name_prefix = "bootchart-" + datetime.now().strftime("%Y-%m-%d-%H-%M-%S")
108 systrace_file_name_prefix = "systrace-" + datetime.now().strftime("%Y-%m-%d-%H-%M-%S")
Keun-young Park8f193c12017-08-04 18:16:23 -0700109 shutdown_event_all = collections.OrderedDict()
110 shutdown_timing_event_all = collections.OrderedDict()
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700111 for it in range(0, args.iterate):
112 if args.iterate > 1:
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700113 print "Run: {0}".format(it)
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700114 attempt = 1
115 processing_data = None
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700116 timings = None
Keun-young Parke3accfd2016-12-20 14:07:01 -0800117 boottime_events = None
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700118 while attempt <= MAX_RETRIES and processing_data is None:
119 attempt += 1
Keun-young Park8f193c12017-08-04 18:16:23 -0700120 processing_data, kernel_timings, logcat_timings, boottime_events, shutdown_events,\
121 shutdown_timing_events = iterate(\
122 args, search_events_pattern, timing_events_pattern, shutdown_events_pattern, cfg,\
123 error_time, components_to_monitor)
124 if shutdown_events:
125 for k, v in shutdown_events.iteritems():
126 events = shutdown_event_all.get(k)
127 if not events:
128 events = []
129 shutdown_event_all[k] = events
130 events.append(v)
131 if shutdown_timing_events:
132 for k, v in shutdown_timing_events.iteritems():
133 events = shutdown_timing_event_all.get(k)
134 if not events:
135 events = []
136 shutdown_timing_event_all[k] = events
137 events.append(v)
Keun-young Parke3accfd2016-12-20 14:07:01 -0800138 if not processing_data or not boottime_events:
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700139 # Processing error
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700140 print "Failed to collect valid samples for run {0}".format(it)
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700141 continue
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700142 if args.bootchart:
143 grab_bootchart(boot_chart_file_name_prefix + "_run_" + str(it))
144
145 if args.systrace:
146 grab_systrace(systrace_file_name_prefix + "_run_" + str(it))
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700147 for k, v in processing_data.iteritems():
148 if k not in data_points:
149 data_points[k] = []
150 data_points[k].append(v['value'])
151
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700152 if kernel_timings is not None:
153 for k, v in kernel_timings.iteritems():
154 if k not in kernel_timing_points:
155 kernel_timing_points[k] = []
156 kernel_timing_points[k].append(v)
157 if logcat_timings is not None:
158 for k, v in logcat_timings.iteritems():
159 if k not in logcat_timing_points:
160 logcat_timing_points[k] = []
161 logcat_timing_points[k].append(v)
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700162
Keun-young Parke3accfd2016-12-20 14:07:01 -0800163 for k, v in boottime_events.iteritems():
164 if not k in boottime_points:
165 boottime_points[k] = []
166 boottime_points[k].append(v)
167
Bryan Eylerb7ee7cc2017-03-29 14:52:12 -0700168 if args.stressfs:
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700169 run_adb_cmd('uninstall com.android.car.test.stressfs')
170 run_adb_shell_cmd('"rm -rf /storage/emulated/0/stressfs_data*"')
Bryan Eylerb7ee7cc2017-03-29 14:52:12 -0700171
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700172 if args.iterate > 1:
Keun-young Parke3accfd2016-12-20 14:07:01 -0800173 print "-----------------"
Keun-young Park8f193c12017-08-04 18:16:23 -0700174 print "\nshutdown events after {0} runs".format(args.iterate)
175 print '{0:30}: {1:<7} {2:<7} {3}'.format("Event", "Mean", "stddev", "#runs")
176 for item in shutdown_event_all.items():
177 num_runs = len(item[1])
178 print '{0:30}: {1:<7.5} {2:<7.5} {3} {4}'.format(
179 item[0], sum(item[1])/num_runs, stddev(item[1]),\
180 "*time taken" if item[0].startswith("init.") else "",\
181 num_runs if num_runs != args.iterate else "")
182 print "\nshutdown timing events after {0} runs".format(args.iterate)
183 print '{0:30}: {1:<7} {2:<7} {3}'.format("Event", "Mean", "stddev", "#runs")
184 for item in shutdown_timing_event_all.items():
185 num_runs = len(item[1])
186 print '{0:30}: {1:<7.5} {2:<7.5} {3} {4}'.format(
187 item[0], sum(item[1])/num_runs, stddev(item[1]),\
188 "*time taken" if item[0].startswith("init.") else "",\
189 num_runs if num_runs != args.iterate else "")
190
191 print "-----------------"
Keun-young Parke3accfd2016-12-20 14:07:01 -0800192 print "ro.boottime.* after {0} runs".format(args.iterate)
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700193 print '{0:30}: {1:<7} {2:<7} {3}'.format("Event", "Mean", "stddev", "#runs")
Keun-young Parke3accfd2016-12-20 14:07:01 -0800194 for item in boottime_points.items():
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700195 num_runs = len(item[1])
196 print '{0:30}: {1:<7.5} {2:<7.5} {3} {4}'.format(
197 item[0], sum(item[1])/num_runs, stddev(item[1]),\
198 "*time taken" if item[0].startswith("init.") else "",\
199 num_runs if num_runs != args.iterate else "")
Keun-young Parke3accfd2016-12-20 14:07:01 -0800200
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700201 if args.timings:
202 dump_timings_points_summary("Kernel", kernel_timing_points, args)
203 dump_timings_points_summary("Logcat", logcat_timing_points, args)
204
205
206 print "-----------------"
207 print "Avg values after {0} runs".format(args.iterate)
208 print '{0:30}: {1:<7} {2:<7} {3}'.format("Event", "Mean", "stddev", "#runs")
209
210 average_with_stddev = []
211 for item in data_points.items():
212 average_with_stddev.append((item[0], sum(item[1])/len(item[1]), stddev(item[1]),\
213 len(item[1])))
214 for item in sorted(average_with_stddev, key=lambda entry: entry[1]):
215 print '{0:30}: {1:<7.5} {2:<7.5} {3}'.format(
216 item[0], item[1], item[2], item[3] if item[3] != args.iterate else "")
217
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700218 run_adb_shell_cmd_as_root('rm /data/bootchart/enabled')
219
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700220
221def dump_timings_points_summary(msg_header, timing_points, args):
Keun-young Park9aae8c92017-01-31 12:53:19 -0800222 averaged_timing_points = []
223 for item in timing_points.items():
224 average = sum(item[1])/len(item[1])
225 std_dev = stddev(item[1])
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700226 averaged_timing_points.append((item[0], average, std_dev, len(item[1])))
Keun-young Park9aae8c92017-01-31 12:53:19 -0800227
Keun-young Park9b2ac712016-12-15 15:23:16 -0800228 print "-----------------"
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700229 print msg_header + " timing in order, Avg time values after {0} runs".format(args.iterate)
230 print '{0:30}: {1:<7} {2:<7} {3}'.format("Event", "Mean", "stddev", "#runs")
Keun-young Park9aae8c92017-01-31 12:53:19 -0800231 for item in averaged_timing_points:
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700232 print '{0:30}: {1:<7.5} {2:<7.5} {3}'.format(
233 item[0], item[1], item[2], item[3] if item[3] != args.iterate else "")
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700234
Keun-young Park9b2ac712016-12-15 15:23:16 -0800235 print "-----------------"
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700236 print msg_header + " timing top items, Avg time values after {0} runs".format(args.iterate)
237 print '{0:30}: {1:<7} {2:<7} {3}'.format("Event", "Mean", "stddev", "#runs")
Keun-young Park9aae8c92017-01-31 12:53:19 -0800238 for item in sorted(averaged_timing_points, key=lambda entry: entry[1], reverse=True):
239 if item[1] < TIMING_THRESHOLD:
Keun-young Park9b2ac712016-12-15 15:23:16 -0800240 break
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700241 print '{0:30}: {1:<7.5} {2:<7.5} {3}'.format(
242 item[0], item[1], item[2], item[3] if item[3] != args.iterate else "")
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700243
Keun-young Parkda874db2017-01-31 14:39:09 -0800244def capture_bugreport(bugreport_hint, boot_complete_time):
245 now = datetime.now()
246 bugreport_file = ("bugreport-%s-" + bugreport_hint + "-%s.zip") \
247 % (now.strftime("%Y-%m-%d-%H-%M-%S"), str(boot_complete_time))
248 print "Boot up time too big, will capture bugreport %s" % (bugreport_file)
249 os.system(ADB_CMD + " bugreport " + bugreport_file)
250
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700251def generate_timing_points(timing_events, timings):
252 timing_points = collections.OrderedDict()
253 for k, l in timing_events.iteritems():
254 for v in l:
255 name, time_v = extract_timing(v, timings)
256 if name and time_v:
257 if v.find("SystemServerTimingAsync") > 0:
258 name = "(" + name + ")"
259 new_name = name
260 name_index = 0
261 while timing_points.get(new_name): # if the name is already taken, append #digit
262 name_index += 1
263 new_name = name + "#" + str(name_index)
264 name = new_name
265 if k.endswith("_secs"):
266 timing_points[name] = time_v * 1000.0
267 else:
268 timing_points[name] = time_v
269 return timing_points
270
271def dump_timing_points(msg_header, timing_points):
272 print msg_header + " event timing in time order, key: time"
273 for item in timing_points.items():
274 print '{0:30}: {1:<7.5}'.format(item[0], item[1])
275 print "-----------------"
276 print msg_header + " event timing top items"
277 for item in sorted(timing_points.items(), key=operator.itemgetter(1), reverse = True):
278 if item[1] < TIMING_THRESHOLD:
279 break
280 print '{0:30}: {1:<7.5}'.format(
281 item[0], item[1])
282 print "-----------------"
283
Keun-young Park8f193c12017-08-04 18:16:23 -0700284def handle_reboot_log(capture_log_on_error, shutdown_events_pattern, components_to_monitor):
285 shutdown_events, shutdown_timing_events = collect_logcat_for_shutdown(capture_log_on_error,\
286 shutdown_events_pattern, components_to_monitor)
287 print "\nshutdown events: time"
288 for item in shutdown_events.items():
289 print '{0:30}: {1:<7.5}'.format(item[0], item[1])
290 print "\nshutdown timing events: time"
291 for item in shutdown_timing_events.items():
292 print '{0:30}: {1:<7.5}'.format(item[0], item[1])
293 return shutdown_events, shutdown_timing_events
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700294
Keun-young Park8f193c12017-08-04 18:16:23 -0700295def iterate(args, search_events_pattern, timings_pattern, shutdown_events_pattern, cfg, error_time,\
296 components_to_monitor):
297 shutdown_events = None
298 shutdown_timing_events = None
299 if args.reboot:
300 # sleep to make sure that logcat reader is reading before adb is gone by reboot. ugly but make
301 # impl simple.
302 t = threading.Thread(target = lambda : (time.sleep(2), reboot(args.serial, args.stressfs != '',\
303 args.permissive, args.adb_reboot)))
304 t.start()
305 shutdown_events, shutdown_timing_events = handle_reboot_log(True, shutdown_events_pattern,\
306 components_to_monitor)
307 t.join()
308
309 dmesg_events, kernel_timing_events = collect_events(search_events_pattern, ADB_CMD +\
310 ' shell su root dmesg -w', timings_pattern,\
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700311 [ KERNEL_BOOT_COMPLETE ], True)
Vitalii Tomkived4c98c2016-04-28 15:20:57 -0700312
Keun-young Park6dfb4762017-03-13 15:57:13 -0700313 logcat_stop_events = [ LOGCAT_BOOT_COMPLETE, KERNEL_BOOT_COMPLETE, LAUNCHER_START]
314 if args.fs_check:
315 logcat_stop_events.append("FsStat")
Keun-young Park7b71b4d2017-02-13 11:03:15 -0800316 logcat_events, logcat_timing_events = collect_events(
Keun-young Park8f193c12017-08-04 18:16:23 -0700317 search_events_pattern, ADB_CMD + ' logcat -b all -v epoch', timings_pattern,\
318 logcat_stop_events, False)
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700319 logcat_event_time = extract_time(
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700320 logcat_events, TIME_LOGCAT, float);
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700321 logcat_original_time = extract_time(
322 logcat_events, TIME_LOGCAT, str);
323 dmesg_event_time = extract_time(
324 dmesg_events, TIME_DMESG, float);
Keun-young Parke3accfd2016-12-20 14:07:01 -0800325 boottime_events = fetch_boottime_property()
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700326 events = {}
327 diff_time = 0
328 max_time = 0
329 events_to_correct = []
330 replaced_from_dmesg = set()
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700331
332 time_correction_delta = 0
333 time_correction_time = 0
334 if ('time_correction_key' in cfg
335 and cfg['time_correction_key'] in logcat_events):
336 match = search_events[cfg['time_correction_key']].search(
337 logcat_events[cfg['time_correction_key']])
338 if match and logcat_event_time[cfg['time_correction_key']]:
339 time_correction_delta = float(match.group(1))
340 time_correction_time = logcat_event_time[cfg['time_correction_key']]
341
342 debug("time_correction_delta = {0}, time_correction_time = {1}".format(
343 time_correction_delta, time_correction_time))
344
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700345 for k, v in logcat_event_time.iteritems():
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700346 if v <= time_correction_time:
347 logcat_event_time[k] += time_correction_delta
348 v = v + time_correction_delta
349 debug("correcting event to event[{0}, {1}]".format(k, v))
350
Keun-young Parke17b25b2016-11-30 16:43:31 -0800351 if not logcat_event_time.get(KERNEL_TIME_KEY):
352 print "kernel time not captured in logcat, cannot get time diff"
Keun-young Park32866e92017-05-15 09:16:38 -0700353 return None, None, None, None
Keun-young Parkb4305092016-12-13 17:32:56 -0800354 diffs = []
355 diffs.append((logcat_event_time[KERNEL_TIME_KEY], logcat_event_time[KERNEL_TIME_KEY]))
356 if logcat_event_time.get(BOOT_ANIM_END_TIME_KEY) and dmesg_event_time.get(BOOT_ANIM_END_TIME_KEY):
357 diffs.append((logcat_event_time[BOOT_ANIM_END_TIME_KEY],\
358 logcat_event_time[BOOT_ANIM_END_TIME_KEY] -\
359 dmesg_event_time[BOOT_ANIM_END_TIME_KEY]))
360 if not dmesg_event_time.get(KERNEL_BOOT_COMPLETE):
361 print "BootAnimEnd time or BootComplete-kernel not captured in both log" +\
362 ", cannot get time diff"
Keun-young Park32866e92017-05-15 09:16:38 -0700363 return None, None, None, None
Keun-young Parkb4305092016-12-13 17:32:56 -0800364 diffs.append((logcat_event_time[KERNEL_BOOT_COMPLETE],\
365 logcat_event_time[KERNEL_BOOT_COMPLETE] - dmesg_event_time[KERNEL_BOOT_COMPLETE]))
Keun-young Parke17b25b2016-11-30 16:43:31 -0800366
Keun-young Parke17b25b2016-11-30 16:43:31 -0800367 for k, v in logcat_event_time.iteritems():
368 debug("event[{0}, {1}]".format(k, v))
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700369 events[k] = v
370 if k in dmesg_event_time:
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700371 debug("{0} is in dmesg".format(k))
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700372 events[k] = dmesg_event_time[k]
373 replaced_from_dmesg.add(k)
374 else:
375 events_to_correct.append(k)
376
Keun-young Park179f6662017-01-27 16:14:01 -0800377 diff_prev = diffs[0]
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700378 for k in events_to_correct:
Keun-young Parkb4305092016-12-13 17:32:56 -0800379 diff = diffs[0]
Wei Wang883d06a2016-12-15 13:28:21 -0800380 while diff[0] < events[k] and len(diffs) > 1:
Keun-young Parkb4305092016-12-13 17:32:56 -0800381 diffs.pop(0)
Keun-young Park179f6662017-01-27 16:14:01 -0800382 diff_prev = diff
Keun-young Parkb4305092016-12-13 17:32:56 -0800383 diff = diffs[0]
384 events[k] = events[k] - diff[1]
Keun-young Parke17b25b2016-11-30 16:43:31 -0800385 if events[k] < 0.0:
Keun-young Park179f6662017-01-27 16:14:01 -0800386 if events[k] < -0.1: # maybe previous one is better fit
387 events[k] = events[k] + diff[1] - diff_prev[1]
388 else:
389 events[k] = 0.0
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700390
Keun-young Park32866e92017-05-15 09:16:38 -0700391 data_points = collections.OrderedDict()
Keun-young Park9e1dd6a2016-12-21 16:08:49 -0800392
393 print "-----------------"
394 print "ro.boottime.*: time"
395 for item in boottime_events.items():
396 print '{0:30}: {1:<7.5} {2}'.format(item[0], item[1],\
397 "*time taken" if item[0].startswith("init.") else "")
398 print "-----------------"
399
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700400 if args.timings:
Keun-young Park8f193c12017-08-04 18:16:23 -0700401 kernel_timing_points = generate_timing_points(kernel_timing_events, timings_pattern)
402 logcat_timing_points = generate_timing_points(logcat_timing_events, timings_pattern)
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700403 dump_timing_points("Kernel", kernel_timing_points)
404 dump_timing_points("Logcat", logcat_timing_points)
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700405
406 for item in sorted(events.items(), key=operator.itemgetter(1)):
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700407 data_points[item[0]] = {
408 'value': item[1],
409 'from_dmesg': item[0] in replaced_from_dmesg,
410 'logcat_value': logcat_original_time[item[0]]
411 }
Keun-young Park32866e92017-05-15 09:16:38 -0700412 # add times with bootloader
413 if events.get("BootComplete") and boottime_events.get("bootloader"):
414 total = events["BootComplete"] + boottime_events["bootloader"]
415 data_points["*BootComplete+Bootloader"] = {
416 'value': total,
417 'from_dmesg': False,
418 'logcat_value': 0.0
419 }
420 if events.get("LauncherStart") and boottime_events.get("bootloader"):
421 total = events["LauncherStart"] + boottime_events["bootloader"]
422 data_points["*LauncherStart+Bootloader"] = {
423 'value': total,
424 'from_dmesg': False,
425 'logcat_value': 0.0
426 }
427 for k, v in data_points.iteritems():
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700428 print '{0:30}: {1:<7.5} {2:1} ({3})'.format(
Keun-young Park32866e92017-05-15 09:16:38 -0700429 k, v['value'], '*' if v['from_dmesg'] else '', v['logcat_value'])
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700430
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700431 print '\n* - event time was obtained from dmesg log\n'
Keun-young Parke3accfd2016-12-20 14:07:01 -0800432
Wei Wang6bd67962017-01-11 19:54:48 -0800433 if events[LOGCAT_BOOT_COMPLETE] > error_time and not args.ignore:
Keun-young Parkda874db2017-01-31 14:39:09 -0800434 capture_bugreport("bootuptoolong", events[LOGCAT_BOOT_COMPLETE])
Keun-young Parkc27316d2016-12-06 18:19:00 -0800435
Keun-young Parkda874db2017-01-31 14:39:09 -0800436 for k, v in components_to_monitor.iteritems():
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700437 logcat_value_measured = logcat_timing_points.get(k)
438 kernel_value_measured = kernel_timing_points.get(k)
439 data_from_data_points = data_points.get(k)
440 if logcat_value_measured and logcat_value_measured > v:
441 capture_bugreport(k + "-" + str(logcat_value_measured), events[LOGCAT_BOOT_COMPLETE])
442 break
443 elif kernel_value_measured and kernel_value_measured > v:
444 capture_bugreport(k + "-" + str(kernel_value_measured), events[LOGCAT_BOOT_COMPLETE])
445 break
446 elif data_from_data_points and data_from_data_points['value'] * 1000.0 > v:
447 capture_bugreport(k + "-" + str(data_from_data_points['value']), events[LOGCAT_BOOT_COMPLETE])
Keun-young Parkda874db2017-01-31 14:39:09 -0800448 break
449
Keun-young Park6dfb4762017-03-13 15:57:13 -0700450 if args.fs_check:
451 fs_stat = None
452 if logcat_events.get("FsStat"):
453 fs_stat_pattern = cfg["events"]["FsStat"]
454 m = re.search(fs_stat_pattern, logcat_events.get("FsStat"))
455 if m:
456 fs_stat = m.group(1)
457 print 'fs_stat:', fs_stat
458
Keun-young Park1fab3982017-04-14 15:21:13 -0700459 if fs_stat:
460 fs_stat_val = int(fs_stat, 0)
461 if (fs_stat_val & ~0x17) != 0:
462 capture_bugreport("fs_stat_" + fs_stat, events[LOGCAT_BOOT_COMPLETE])
Keun-young Park6dfb4762017-03-13 15:57:13 -0700463
Keun-young Park8f193c12017-08-04 18:16:23 -0700464 return data_points, kernel_timing_points, logcat_timing_points, boottime_events, shutdown_events,\
465 shutdown_timing_events
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700466
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700467def debug(string):
468 if DEBUG:
469 print string
470
471def extract_timing(s, patterns):
472 for k, p in patterns.iteritems():
473 m = p.search(s)
474 if m:
475 g_dict = m.groupdict()
476 return g_dict['name'], float(g_dict['time'])
Keun-young Park9b2ac712016-12-15 15:23:16 -0800477 return None, None
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700478
479def init_arguments():
480 parser = argparse.ArgumentParser(description='Measures boot time.')
481 parser.add_argument('-r', '--reboot', dest='reboot',
482 action='store_true',
Wei Wang27404092016-12-02 22:00:31 -0800483 help='reboot device for measurement', )
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700484 parser.add_argument('-c', '--config', dest='config',
485 default='config.yaml', type=argparse.FileType('r'),
486 help='config file for the tool', )
Bryan Eylerb7ee7cc2017-03-29 14:52:12 -0700487 parser.add_argument('-s', '--stressfs', dest='stressfs',
488 default='', type=str,
489 help='APK file for the stressfs tool used to write to the data partition ' +\
490 'during shutdown')
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700491 parser.add_argument('-n', '--iterate', dest='iterate', type=int, default=1,
492 help='number of time to repeat the measurement', )
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700493 parser.add_argument('-g', '--ignore', dest='ignore', action='store_true',
494 help='ignore too big values error', )
495 parser.add_argument('-t', '--timings', dest='timings', action='store_true',
496 help='print individual component times', default=True, )
Wei Wang27404092016-12-02 22:00:31 -0800497 parser.add_argument('-p', '--serial', dest='serial', action='store',
498 help='android device serial number')
Keun-young Parkc27316d2016-12-06 18:19:00 -0800499 parser.add_argument('-e', '--errortime', dest='errortime', action='store',
500 help='handle bootup time bigger than this as error')
Keun-young Park6dfb4762017-03-13 15:57:13 -0700501 parser.add_argument('-w', '--maxwaittime', dest='maxwaittime', action='store',
502 help='wait for up to this time to collect logs. Retry after this time.' +\
503 ' Default is 200 sec.')
504 parser.add_argument('-f', '--fs_check', dest='fs_check',
505 action='store_true',
506 help='check fs_stat after reboot', )
Keun-young Park8c443642017-04-06 13:38:24 -0700507 parser.add_argument('-a', '--adb_reboot', dest='adb_reboot',
508 action='store_true',
509 help='reboot with adb reboot', )
510 parser.add_argument('-v', '--permissive', dest='permissive',
511 action='store_true',
512 help='set selinux into permissive before reboot', )
Keun-young Parkda874db2017-01-31 14:39:09 -0800513 parser.add_argument('-m', '--componentmonitor', dest='componentmonitor', action='store',
514 help='capture bugreport if specified timing component is taking more than ' +\
515 'certain time. Unlike errortime, the result will not be rejected in' +\
516 'averaging. Format is key1=time1,key2=time2...')
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700517 parser.add_argument('-b', '--bootchart', dest='bootchart',
518 action='store_true',
519 help='collect bootchart from the device.', )
520 parser.add_argument('-y', '--systrace', dest='systrace',
521 action='store_true',
522 help='collect systrace from the device. kernel trace should be already enabled', )
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700523 return parser.parse_args()
524
Keun-young Park15f805e2016-12-07 17:34:50 -0800525def handle_zygote_event(zygote_pids, events, event, line):
526 words = line.split()
527 if len(words) > 1:
528 pid = int(words[1])
529 if len(zygote_pids) == 2:
530 if pid == zygote_pids[1]: # secondary
531 event = event + "-secondary"
532 elif len(zygote_pids) == 1:
533 if zygote_pids[0] != pid: # new pid, need to decide if old ones were secondary
534 primary_pid = min(pid, zygote_pids[0])
535 secondary_pid = max(pid, zygote_pids[0])
Keun-young Parkae517482016-12-14 16:04:58 -0800536 zygote_pids.pop()
537 zygote_pids.append(primary_pid)
538 zygote_pids.append(secondary_pid)
Keun-young Park15f805e2016-12-07 17:34:50 -0800539 if pid == primary_pid: # old one was secondary:
540 move_to_secondary = []
541 for k, l in events.iteritems():
542 if k.startswith("zygote"):
543 move_to_secondary.append((k, l))
544 for item in move_to_secondary:
545 del events[item[0]]
Keun-young Parkae517482016-12-14 16:04:58 -0800546 if item[0].endswith("-secondary"):
547 print "Secondary already exists for event %s while found new pid %d, primary %d "\
548 % (item[0], secondary_pid, primary_pid)
549 else:
550 events[item[0] + "-secondary"] = item[1]
Keun-young Park15f805e2016-12-07 17:34:50 -0800551 else:
552 event = event + "-secondary"
553 else:
554 zygote_pids.append(pid)
555 events[event] = line
556
Keun-young Parkeb14fde2017-05-22 18:41:55 -0700557def update_name_if_already_exist(events, name):
558 existing_event = events.get(name)
559 i = 0
560 new_name = name
561 while existing_event:
562 i += 1
563 new_name = name + "_" + str(i)
564 existing_event = events.get(new_name)
565 return new_name
566
Keun-young Park8f193c12017-08-04 18:16:23 -0700567def collect_logcat_for_shutdown(capture_log_on_error, shutdown_events_pattern,\
568 log_capture_conditions):
569 events = collections.OrderedDict()
570 # shutdown does not have timing_events but calculated from checking Xyz - XyzDone / XyzTimeout
571 timing_events = collections.OrderedDict()
572 process = subprocess.Popen(ADB_CMD + ' logcat -b all -v epoch', shell=True,
573 stdout=subprocess.PIPE);
574 lines = []
575 capture_log = False
576 shutdown_start_time = 0
577 while (True):
578 line = process.stdout.readline().lstrip().rstrip()
579 if not line:
580 break
581 lines.append(line)
582 event = get_boot_event(line, shutdown_events_pattern);
583 if not event:
584 continue
585 time = extract_a_time(line, TIME_LOGCAT, float)
586 if not time:
587 print "cannot get time from: " + line
588 continue
589 if shutdown_start_time == 0:
590 shutdown_start_time = time
591 time = time - shutdown_start_time
592 events[event] = time
593 time_limit1 = log_capture_conditions.get(event)
594 if time_limit1 and time_limit1 <= time:
595 capture_log = True
596 pair_event = None
597 if event.endswith('Done'):
598 pair_event = event[:-4]
599 elif event.endswith('Timeout'):
600 pair_event = event[:-7]
601 if capture_log_on_error:
602 capture_log = True
603 if not pair_event:
604 continue
605 start_time = events.get(pair_event)
606 if not start_time:
607 print "No start event for " + event
608 continue
609 time_spent = time - start_time
610 timing_event_name = pair_event + "Duration"
611 timing_events[timing_event_name] = time_spent
612 time_limit2 = log_capture_conditions.get(timing_event_name)
613 if time_limit2 and time_limit2 <= time_spent:
614 capture_log = True
615
616 if capture_log:
617 now = datetime.now()
618 log_file = ("shutdownlog-error-%s.txt") % (now.strftime("%Y-%m-%d-%H-%M-%S"))
619 print "Shutdown error, capture log to %s" % (log_file)
620 with open(log_file, 'w') as f:
621 f.write('\n'.join(lines))
622 return events, timing_events
623
624
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700625def collect_events(search_events, command, timings, stop_events, disable_timing_after_zygote):
Keun-young Park9b2ac712016-12-15 15:23:16 -0800626 events = collections.OrderedDict()
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700627 timing_events = {}
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700628 process = subprocess.Popen(command, shell=True,
629 stdout=subprocess.PIPE);
Keun-young Parkb4305092016-12-13 17:32:56 -0800630 data_available = stop_events is None
Keun-young Park15f805e2016-12-07 17:34:50 -0800631 zygote_pids = []
Keun-young Park6dfb4762017-03-13 15:57:13 -0700632 start_time = time.time()
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700633 zygote_found = False
Keun-young Park15f805e2016-12-07 17:34:50 -0800634
Keun-young Parkcea1c732017-03-22 15:28:11 -0700635 line = None
636 read_poll = select.poll()
637 read_poll.register(process.stdout, select.POLLIN)
638 while True:
639 time_left = start_time + max_wait_time - time.time()
640 if time_left <= 0:
641 print "timeout waiting for event, continue", time_left
642 break
643 read_r = read_poll.poll(time_left * 1000.0)
Bryan Eylerb352c002017-05-30 17:51:37 -0700644 if len(read_r) > 0 and read_r[0][1] == select.POLLIN:
Keun-young Parkcea1c732017-03-22 15:28:11 -0700645 line = process.stdout.readline()
646 else:
647 print "poll timeout waiting for event, continue", time_left
648 break
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700649 if not data_available:
Wei Wang883d06a2016-12-15 13:28:21 -0800650 print "Collecting data samples from '%s'. Please wait...\n" % command
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700651 data_available = True
652 event = get_boot_event(line, search_events);
653 if event:
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700654 debug("event[{0}] captured: {1}".format(event, line))
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700655 if event == "starting_zygote":
656 events[event] = line
657 zygote_found = True
658 elif event.startswith("zygote"):
Keun-young Park15f805e2016-12-07 17:34:50 -0800659 handle_zygote_event(zygote_pids, events, event, line)
660 else:
Keun-young Parkeb14fde2017-05-22 18:41:55 -0700661 new_event = update_name_if_already_exist(events, event)
662 events[new_event] = line
Keun-young Parkb4305092016-12-13 17:32:56 -0800663 if event in stop_events:
664 stop_events.remove(event)
Keun-young Parkcea1c732017-03-22 15:28:11 -0700665 print "remaining stop_events:", stop_events
Keun-young Parkb4305092016-12-13 17:32:56 -0800666 if len(stop_events) == 0:
667 break;
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700668
669 timing_event = get_boot_event(line, timings);
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700670 if timing_event and (not disable_timing_after_zygote or not zygote_found):
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700671 if timing_event not in timing_events:
672 timing_events[timing_event] = []
673 timing_events[timing_event].append(line)
674 debug("timing_event[{0}] captured: {1}".format(timing_event, line))
675
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700676 process.terminate()
Vitalii Tomkiv49dcaf22016-10-31 11:25:01 -0700677 return events, timing_events
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700678
Keun-young Parke3accfd2016-12-20 14:07:01 -0800679def fetch_boottime_property():
680 cmd = ADB_CMD + ' shell su root getprop'
681 events = {}
682 process = subprocess.Popen(cmd, shell=True,
683 stdout=subprocess.PIPE);
684 out = process.stdout
685 pattern = re.compile(BOOT_PROP)
Keun-young Park32866e92017-05-15 09:16:38 -0700686 pattern_bootloader = re.compile(BOOTLOADER_TIME_PROP)
687 bootloader_time = 0.0
Keun-young Parke3accfd2016-12-20 14:07:01 -0800688 for line in out:
689 match = pattern.match(line)
690 if match:
Keun-young Parka44dc6c2017-04-24 17:52:16 -0700691 if match.group(1).startswith("init."):
692 events[match.group(1)] = float(match.group(2)) / 1000.0 #ms to s
693 else:
694 events[match.group(1)] = float(match.group(2)) / 1000000000.0 #ns to s
Keun-young Park32866e92017-05-15 09:16:38 -0700695 match = pattern_bootloader.match(line)
696 if match:
697 items = match.group(1).split(",")
698 for item in items:
699 entry_pair = item.split(":")
700 entry_name = entry_pair[0]
701 time_spent = float(entry_pair[1]) / 1000 #ms to s
702 if entry_name != "SW":
703 bootloader_time = bootloader_time + time_spent
Keun-young Parke3accfd2016-12-20 14:07:01 -0800704 ordered_event = collections.OrderedDict()
Keun-young Park32866e92017-05-15 09:16:38 -0700705 if bootloader_time != 0.0:
706 ordered_event["bootloader"] = bootloader_time;
Keun-young Parke3accfd2016-12-20 14:07:01 -0800707 for item in sorted(events.items(), key=operator.itemgetter(1)):
708 ordered_event[item[0]] = item[1]
709 return ordered_event
710
711
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700712def get_boot_event(line, events):
713 for event_key, event_pattern in events.iteritems():
714 if event_pattern.search(line):
715 return event_key
Vitalii Tomkived4c98c2016-04-28 15:20:57 -0700716 return None
717
Keun-young Park9b2ac712016-12-15 15:23:16 -0800718def extract_a_time(line, pattern, date_transform_function):
719 found = re.findall(pattern, line)
Vitalii Tomkived4c98c2016-04-28 15:20:57 -0700720 if len(found) > 0:
Keun-young Park9b2ac712016-12-15 15:23:16 -0800721 return date_transform_function(found[0])
722 else:
723 return None
724
725def extract_time(events, pattern, date_transform_function):
726 result = collections.OrderedDict()
727 for event, data in events.iteritems():
728 time = extract_a_time(data, pattern, date_transform_function)
729 if time:
730 result[event] = time
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700731 else:
732 print "Failed to find time for event: ", event, data
733 return result
Vitalii Tomkived4c98c2016-04-28 15:20:57 -0700734
Keun-young Park6dfb4762017-03-13 15:57:13 -0700735
Keun-young Park8c443642017-04-06 13:38:24 -0700736def do_reboot(serial, use_adb_reboot):
737 original_devices = subprocess.check_output("adb devices", shell=True)
738 if use_adb_reboot:
739 print 'Rebooting the device using adb reboot'
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700740 run_adb_cmd('reboot')
Keun-young Park8c443642017-04-06 13:38:24 -0700741 else:
742 print 'Rebooting the device using svc power reboot'
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700743 run_adb_shell_cmd_as_root('svc power reboot')
Keun-young Park8c443642017-04-06 13:38:24 -0700744 # Wait for the device to go away
745 retry = 0
746 while retry < 20:
747 current_devices = subprocess.check_output("adb devices", shell=True)
748 if original_devices != current_devices:
749 if not serial or (serial and current_devices.find(serial) < 0):
750 return True
751 time.sleep(1)
752 retry += 1
753 return False
Keun-young Park6dfb4762017-03-13 15:57:13 -0700754
Keun-young Park8c443642017-04-06 13:38:24 -0700755def reboot(serial, use_stressfs, permissive, use_adb_reboot):
Bryan Eylerb7ee7cc2017-03-29 14:52:12 -0700756 if use_stressfs:
757 print 'Starting write to data partition'
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700758 run_adb_shell_cmd('am start' +\
759 ' -n com.android.car.test.stressfs/.WritingActivity' +\
760 ' -a com.android.car.test.stressfs.START')
Bryan Eylerb7ee7cc2017-03-29 14:52:12 -0700761 # Give this app some time to start.
762 time.sleep(1)
Keun-young Park8c443642017-04-06 13:38:24 -0700763 if permissive:
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700764 run_adb_shell_cmd_as_root('setenforce 0')
Keun-young Park8c443642017-04-06 13:38:24 -0700765
766 retry = 0
767 while retry < 5:
768 if do_reboot(serial, use_adb_reboot):
769 break
770 retry += 1
771
Wei Wang883d06a2016-12-15 13:28:21 -0800772 print 'Waiting the device'
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700773 run_adb_cmd('wait-for-device')
774
775def run_adb_cmd(cmd):
776 return subprocess.call(ADB_CMD + ' ' + cmd, shell=True)
777
778def run_adb_shell_cmd(cmd):
779 return subprocess.call(ADB_CMD + ' shell ' + cmd, shell=True)
780
781def run_adb_shell_cmd_as_root(cmd):
782 return subprocess.call(ADB_CMD + ' shell su root ' + cmd, shell=True)
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700783
784def logcat_time_func(offset_year):
785 def f(date_str):
786 ndate = datetime.datetime.strptime(str(offset_year) + '-' +
787 date_str, '%Y-%m-%d %H:%M:%S.%f')
788 return datetime_to_unix_time(ndate)
789 return f
790
Vitalii Tomkivd704edd2016-07-13 17:27:03 -0700791def datetime_to_unix_time(ndate):
Vitalii Tomkived4c98c2016-04-28 15:20:57 -0700792 return time.mktime(ndate.timetuple()) + ndate.microsecond/1000000.0
793
Vitalii Tomkivabc92332016-09-20 11:55:44 -0700794def stddev(data):
795 items_count = len(data)
796 avg = sum(data) / items_count
797 sq_diffs_sum = sum([(v - avg) ** 2 for v in data])
798 variance = sq_diffs_sum / items_count
799 return math.sqrt(variance)
800
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700801def grab_bootchart(boot_chart_file_name):
Keun-young Park40c29002017-06-05 09:27:25 -0700802 subprocess.call("./system/core/init/grab-bootchart.sh", shell=True)
Keun-young Parkcf4d0282017-05-31 12:14:37 -0700803 print "Saving boot chart as " + boot_chart_file_name + ".tgz"
804 subprocess.call('cp /tmp/android-bootchart/bootchart.tgz ./' + boot_chart_file_name + '.tgz',\
805 shell=True)
806 subprocess.call('cp ./bootchart.png ./' + boot_chart_file_name + '.png', shell=True)
807
808def grab_systrace(systrace_file_name):
809 trace_file = systrace_file_name + "_trace.txt"
810 with open(trace_file, 'w') as f:
811 f.write("TRACE:\n")
812 run_adb_shell_cmd_as_root("cat /d/tracing/trace >> " + trace_file)
813 html_file = systrace_file_name + ".html"
814 subprocess.call("./external/chromium-trace/systrace.py --from-file=" + trace_file + " -o " +\
815 html_file, shell=True)
816
Vitalii Tomkived4c98c2016-04-28 15:20:57 -0700817if __name__ == '__main__':
818 main()