diff options
author | Keun-young Park <keunyoung@google.com> | 2019-02-20 20:01:32 -0800 |
---|---|---|
committer | Keun-young Park <keunyoung@google.com> | 2019-02-22 13:24:11 -0800 |
commit | f0701bae250242cb560708c2ea89e41651b45b23 (patch) | |
tree | bf0c4e1ec056bbce4fdfbd766b52d4bbac61ab08 | |
parent | fc7c82e6c9a78c7d5760fd43c70d49e0c418766a (diff) | |
download | extras-f0701bae250242cb560708c2ea89e41651b45b23.tar.gz |
Add dump of long monitor contention
- Long monitor contention during boot up affects boot up performance.
- Dump long monitor contention over 100ms.
Bug: 124950798
Test: python system/extras/boottime_tools/bootanalyze/bootanalyze.py -c system/extras/boottime_tools/bootanalyze/config.yaml -n 10 -r -t
Change-Id: I22cc7bc3d19f53acb8e213d9155f6f2390292d92
-rwxr-xr-x | boottime_tools/bootanalyze/bootanalyze.py | 33 | ||||
-rw-r--r-- | boottime_tools/bootanalyze/config.yaml | 2 |
2 files changed, 24 insertions, 11 deletions
diff --git a/boottime_tools/bootanalyze/bootanalyze.py b/boottime_tools/bootanalyze/bootanalyze.py index a899f925..f765cb99 100755 --- a/boottime_tools/bootanalyze/bootanalyze.py +++ b/boottime_tools/bootanalyze/bootanalyze.py @@ -250,23 +250,25 @@ def capture_bugreport(bugreport_hint, boot_complete_time): def generate_timing_points(timing_events, timings): timing_points = collections.OrderedDict() + monitor_contention_points = collections.OrderedDict() for k, l in timing_events.iteritems(): for v in l: - name, time_v = extract_timing(v, timings) + name, time_v, dict = extract_timing(v, timings) if name and time_v: if v.find("SystemServerTimingAsync") > 0: name = "(" + name + ")" + if k.endswith("_secs"): + time_v = time_v * 1000.0 + if k.startswith("long_monitor_contention"): + monitor_contention_points[v] = time_v + continue new_name = name name_index = 0 while timing_points.get(new_name): # if the name is already taken, append #digit name_index += 1 new_name = name + "#" + str(name_index) - name = new_name - if k.endswith("_secs"): - timing_points[name] = time_v * 1000.0 - else: - timing_points[name] = time_v - return timing_points + timing_points[new_name] = time_v + return timing_points, monitor_contention_points def dump_timing_points(msg_header, timing_points): print msg_header + " event timing in time order, key: time" @@ -281,6 +283,13 @@ def dump_timing_points(msg_header, timing_points): item[0], item[1]) print "-----------------" +def dump_monitor_contentions(logcat_monitor_contentions): + print "Monitor contentions over 100ms:" + for item in logcat_monitor_contentions.items(): + if item[1] > 100: + print '{0:<7.5}ms: {1}'.format(item[1], item[0]) + print "-----------------" + def handle_reboot_log(capture_log_on_error, shutdown_events_pattern, components_to_monitor): shutdown_events, shutdown_timing_events = collect_logcat_for_shutdown(capture_log_on_error,\ shutdown_events_pattern, components_to_monitor) @@ -398,10 +407,12 @@ def iterate(args, search_events_pattern, timings_pattern, shutdown_events_patter print "-----------------" if args.timings: - kernel_timing_points = generate_timing_points(kernel_timing_events, timings_pattern) - logcat_timing_points = generate_timing_points(logcat_timing_events, timings_pattern) + kernel_timing_points, _ = generate_timing_points(kernel_timing_events, timings_pattern) + logcat_timing_points, logcat_monitor_contentions =\ + generate_timing_points(logcat_timing_events, timings_pattern) dump_timing_points("Kernel", kernel_timing_points) dump_timing_points("Logcat", logcat_timing_points) + dump_monitor_contentions(logcat_monitor_contentions) for item in sorted(events.items(), key=operator.itemgetter(1)): data_points[item[0]] = { @@ -472,8 +483,8 @@ def extract_timing(s, patterns): for k, p in patterns.iteritems(): m = p.search(s) if m: - g_dict = m.groupdict() - return g_dict['name'], float(g_dict['time']) + dict = m.groupdict() + return dict['name'], float(dict['time']), dict return None, None def init_arguments(): diff --git a/boottime_tools/bootanalyze/config.yaml b/boottime_tools/bootanalyze/config.yaml index ee97d38a..e4f0ef42 100644 --- a/boottime_tools/bootanalyze/config.yaml +++ b/boottime_tools/bootanalyze/config.yaml @@ -9,6 +9,8 @@ timings: init_service_exec_secs: init:\sService\s.*exec\s\S+\s\((?P<name>\S.+)\).*pid.*\swaiting\stook\s(?P<time>[.0-9]+)\sseconds zygote64_timing: (?P<name>Zygote64Timing\:\s\S+)\stook\sto\scomplete\:\s(?P<time>[0-9]+)ms zygote32_timing: (?P<name>Zygote32Timing\:\s\S+)\stook\sto\scomplete\:\s(?P<time>[0-9]+)ms + long_monitor_contention_secs: \s(?P<component>\S+)\sLong\smonitor\scontention\swith\sowner\s(?P<name>\S.+).*\sfor\s(?P<time>[.0-9]+)s + long_monitor_contention_ms: \s(?P<component>\S+)\sLong\smonitor\scontention\swith\sowner\s(?P<name>\S.+).*\sfor\s(?P<time>[.0-9]+)ms events: kernel: Linux version android_init_1st_stage: init first stage started |