1 #!/usr/bin/env python 2 3 # Copyright (C) 2015 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 """Compare two bootcharts and list start/end timestamps on key processes. 18 19 This script extracts two bootchart.tgz files and compares the timestamps 20 in proc_ps.log for selected processes. The proc_ps.log file consists of 21 repetitive blocks of the following format: 22 23 timestamp1 (jiffies) 24 dumps of /proc/<pid>/stat 25 26 timestamp2 27 dumps of /proc/<pid>/stat 28 29 The timestamps are 200ms apart, and the creation time of selected processes 30 are listed. The termination time of the boot animation process is also listed 31 as a coarse indication about when the boot process is complete as perceived by 32 the user. 33 """ 34 35 import sys 36 import tarfile 37 38 # The bootchart timestamps are 200ms apart, but the USER_HZ value is not 39 # reported in the bootchart, so we use the first two timestamps to calculate 40 # the wall clock time of a jiffy. 41 jiffy_to_wallclock = { 42 '1st_timestamp': -1, 43 '2nd_timestamp': -1, 44 'jiffy_to_wallclock': -1 45 } 46 47 def analyze_process_maps(process_map1, process_map2, jiffy_record): 48 # List interesting processes here 49 processes_of_interest = [ 50 '/init', 51 '/system/bin/surfaceflinger', 52 '/system/bin/bootanimation', 53 'zygote64', 54 'zygote', 55 'system_server' 56 ] 57 58 jw = jiffy_record['jiffy_to_wallclock'] 59 print "process: baseline experiment (delta)" 60 print " - Unit is ms (a jiffy is %d ms on the system)" % jw 61 print "------------------------------------" 62 for p in processes_of_interest: 63 # e.g., 32-bit system doesn't have zygote64 64 if p in process_map1 and p in process_map2: 65 print "%s: %d %d (%+d)" % ( 66 p, process_map1[p]['start_time'] * jw, 67 process_map2[p]['start_time'] * jw, 68 (process_map2[p]['start_time'] - 69 process_map1[p]['start_time']) * jw) 70 71 # Print the last tick for the bootanimation process 72 print "bootanimation ends at: %d %d (%+d)" % ( 73 process_map1['/system/bin/bootanimation']['last_tick'] * jw, 74 process_map2['/system/bin/bootanimation']['last_tick'] * jw, 75 (process_map2['/system/bin/bootanimation']['last_tick'] - 76 process_map1['/system/bin/bootanimation']['last_tick']) * jw) 77 78 def parse_proc_file(pathname, process_map, jiffy_record=None): 79 # Uncompress bootchart.tgz 80 with tarfile.open(pathname + '/bootchart.tgz', 'r:*') as tf: 81 try: 82 # Read proc_ps.log 83 f = tf.extractfile('proc_ps.log') 84 85 # Break proc_ps into chunks based on timestamps 86 blocks = f.read().split('\n\n') 87 for b in blocks: 88 lines = b.split('\n') 89 if not lines[0]: 90 break 91 92 # 200ms apart in jiffies 93 timestamp = int(lines[0]); 94 95 # Figure out the wall clock time of a jiffy 96 if jiffy_record is not None: 97 if jiffy_record['1st_timestamp'] == -1: 98 jiffy_record['1st_timestamp'] = timestamp 99 elif jiffy_record['jiffy_to_wallclock'] == -1: 100 # Not really needed but for debugging purposes 101 jiffy_record['2nd_timestamp'] = timestamp 102 value = 200 / (timestamp - 103 jiffy_record['1st_timestamp']) 104 # Fix the rounding error 105 # e.g., 201 jiffies in 200ms when USER_HZ is 1000 106 if value == 0: 107 value = 1 108 # e.g., 21 jiffies in 200ms when USER_HZ is 100 109 elif value == 9: 110 value = 10 111 jiffy_record['jiffy_to_wallclock'] = value 112 113 # Populate the process_map table 114 for line in lines[1:]: 115 segs = line.split(' ') 116 117 # 0: pid 118 # 1: process name 119 # 17: priority 120 # 18: nice 121 # 21: creation time 122 123 proc_name = segs[1].strip('()') 124 if proc_name in process_map: 125 process = process_map[proc_name] 126 else: 127 process = {'start_time': int(segs[21])} 128 process_map[proc_name] = process 129 130 process['last_tick'] = timestamp 131 finally: 132 f.close() 133 134 def main(): 135 if len(sys.argv) != 3: 136 print "Usage: %s base_bootchart_dir exp_bootchart_dir" % sys.argv[0] 137 sys.exit(1) 138 139 process_map1 = {} 140 process_map2 = {} 141 parse_proc_file(sys.argv[1], process_map1, jiffy_to_wallclock) 142 parse_proc_file(sys.argv[2], process_map2) 143 analyze_process_maps(process_map1, process_map2, jiffy_to_wallclock) 144 145 if __name__ == "__main__": 146 main() 147