1 # Copyright (c) 2013 The Chromium OS Authors. All rights reserved. 2 # Use of this source code is governed by a BSD-style license that can be 3 # found in the LICENSE file. 4 5 import logging 6 import numpy 7 import os 8 import re 9 import threading 10 import time 11 12 TRACING_DIR = '/sys/kernel/debug/tracing' 13 BUFFER_SIZE_RUNNING = '5000' 14 BUFFER_SIZE_IDLE = '1408' 15 16 def tracing_write(file_name, msg): 17 """Helper method to write a file in kernel debugfs. 18 19 @param file_name: The file to write in debugfs. 20 @param msg: The content to write. 21 """ 22 with open(os.path.join(TRACING_DIR, file_name), 'w') as f: 23 f.write(msg) 24 f.flush() 25 26 27 def enable_tracing(events_list=None): 28 """Enable kernel tracing. 29 30 @param events_list: The list of events to monitor. Defaults to None to 31 monitor all events. 32 """ 33 tracing_write('trace_clock', 'global') 34 tracing_write('buffer_size_kb', BUFFER_SIZE_RUNNING) 35 if events_list: 36 tracing_write('set_event', '\n'.join(events_list)) 37 tracing_write('tracing_on', '1') 38 39 40 def disable_tracing(): 41 """Disable kernel tracing.""" 42 tracing_write('tracing_on', '0') 43 tracing_write('set_event', '') 44 tracing_write('trace', '0') 45 tracing_write('buffer_size_kb', BUFFER_SIZE_IDLE) 46 47 48 def get_trace_log(): 49 """Get kernel tracing log.""" 50 with open(os.path.join(TRACING_DIR, 'trace'), 'r') as f: 51 return f.read() 52 53 54 class Sampler(object): 55 """Base sampler class.""" 56 57 def __init__(self, period, duration, events=None): 58 self.period = period 59 self.duration = duration 60 self.events = events or [] 61 self.sampler_callback = None 62 self.stop_sampling = threading.Event() 63 self.sampling_thread = None 64 65 @property 66 def stopped(self): 67 """Check if sampler is stopped.""" 68 return self.stop_sampling.is_set() 69 70 def _do_sampling(self): 71 """Main sampling loop.""" 72 while True: 73 next_sampling_time = time.time() + self.period 74 try: 75 enable_tracing(events_list=self.events) 76 if self.stop_sampling.wait(self.duration): 77 return 78 self.parse_ftrace(get_trace_log()) 79 self.sampler_callback(self) 80 finally: 81 disable_tracing() 82 self.reset() 83 if self.stop_sampling.wait(next_sampling_time - time.time()): 84 return 85 86 def start_sampling_thread(self): 87 """Start a thread to sample events.""" 88 if not self.sampler_callback: 89 raise RuntimeError('Sampler callback function is not set') 90 self.stop_sampling.clear() 91 self.sampling_thread = threading.Thread(target=self._do_sampling) 92 self.sampling_thread.daemon = True 93 self.sampling_thread.start() 94 95 def stop_sampling_thread(self): 96 """Stop sampling thread.""" 97 self.stop_sampling.set() 98 self.reset() 99 100 def parse_ftrace(self, data): 101 """Parse ftrace data. 102 103 @param data: The ftrace data to parse. 104 """ 105 raise NotImplementedError 106 107 def reset(self): 108 """Reset the sampler.""" 109 raise NotImplementedError 110 111 112 class ExynosSampler(Sampler): 113 """Sampler for Exynos platform.""" 114 def __init__(self, *args, **kwargs): 115 kwargs['events'] = ['exynos_page_flip_state'] 116 super(ExynosSampler, self).__init__(*args, **kwargs) 117 self.frame_buffers = {} 118 119 def reset(self): 120 self.frame_buffers.clear() 121 122 def parse_ftrace(self, data): 123 """Read and parse the ftrace file""" 124 # Parse using RE and named group match (?P<xxx>yyy) for clarity. 125 # Format: 126 # TASK-PID CPU# |||| TIMESTAMP FUNCTION 127 # X-007 [001] .... 001.000001: (a line-wrap in Python here ...) 128 # exynos_page_flip_state: pipe=0, fb=25, state=wait_kds 129 re_pattern = ( 130 '\s*(?P<task>.+)-' + # task 131 '(?P<pid>\d+)\s+' + # pid 132 '\[(?P<cpu>\d+)\]\s+' + # cpu# 133 '(?P<inhp>....)\s+' + # inhp: irqs-off, need-resched, 134 # hardirq/softirq, preempt-depth 135 '(?P<timestamp>\d+\.\d+):\s+' + # timestamp 136 '(?P<head>exynos_page_flip_state):\s+' + # head 137 '(?P<detail>.*)') # detail: 'pipe=0, fb=25, state=wait_kds' 138 139 for line in data.split('\n'): 140 m = re.match(re_pattern, line) 141 if m is None: # not a valid trace line (e.g. comment) 142 continue 143 m_dict = m.groupdict() # named group of RE match (m_dict['task']...) 144 pipe, fb, state = self.exynos_parser(m_dict['detail']) 145 timestamp = float(m_dict['timestamp']) 146 self.end_last_fb_state(pipe, fb, timestamp) 147 self.start_new_fb_state(pipe, fb, state, timestamp) 148 149 self.calc_stat() 150 151 def exynos_parser(self, detail): 152 """Parse exynos event's detail. 153 154 @param detail: a string like 'pipe=0, fb=25, state=wait_kds' 155 @return: tuple of (pipe, fb, state), pipe and fb in int, 156 state in string 157 """ 158 re_pattern = ( 159 'pipe=(?P<pipe>\d+), ' + # pipe 160 'fb=(?P<fb>\d+), ' + # fb 161 'state=(?P<state>.*)') # state 162 if re.match(re_pattern, detail) is None: 163 logging.debug('==fail==' + re_pattern + ', ' + detail) 164 m_dict = re.match(re_pattern, detail).groupdict() 165 return int(m_dict['pipe']), int(m_dict['fb']), m_dict['state'] 166 167 def end_last_fb_state(self, pipe, fb, end_time): 168 """End the currently opened state of the specified frame buffer 169 170 @param pipe: the pipe id 171 @param fb: the frame buffer id 172 @param end_time: timestamp when the state ends 173 """ 174 self.get_frame_buffer(pipe, fb).end_state(end_time) 175 176 def start_new_fb_state(self, pipe, fb, state, start_time): 177 """Start the specified state on the specified frame buffer 178 179 @param pipe: the pipe id 180 @param fb: the frame buffer id 181 @param state: which state to start 182 @param start_time: timestamp when the state starts 183 """ 184 self.get_frame_buffer(pipe, fb).start_state(state, start_time) 185 186 def calc_stat(self): 187 """Calculate the statistics of state duration of all frame buffers""" 188 for fb in self.frame_buffers.values(): 189 fb.calc_state_avg_stdev() 190 191 def frame_buffer_unique_hash(self, pipe, fb): 192 """A hash function that returns the unique identifier of a frame buffer. 193 The hash is a string that is unique in the sense of pipe and fb. 194 195 @param pipe: the pipe id 196 @param fb: the frame buffer id 197 @return: a unique hash string, like "pipe:0,fb:25" 198 """ 199 return "pipe:%d,fb:%d" % (pipe, fb) 200 201 def get_frame_buffer(self, pipe, fb): 202 """Return the frame buffer with specified pipe and fb. 203 If the frame buffer does not exist, create one and return it. 204 205 @param pipe: the pipe id 206 @param fb: the frame buffer id 207 @return: the frame buffer specified by pipe and fb 208 """ 209 key = self.frame_buffer_unique_hash(pipe, fb) 210 if key not in self.frame_buffers: 211 self.frame_buffers[key] = FrameBuffer(pipe, fb) 212 return self.frame_buffers[key] 213 214 215 class FrameBuffer(): 216 """Represents a frame buffer, which holds all its states""" 217 def __init__(self, pipe, fb): 218 """Initialize the frame buffer. 219 220 @param pipe: the pipe id of the frame buffer 221 @param fb: the fb id of the frame buffer 222 """ 223 self.pipe = pipe 224 self.fb = fb 225 self.states = {} 226 self.active_state = None # currently active state (to be ended later) 227 228 def start_state(self, state_name, start_time): 229 """Start the specified state 230 231 @param state_name: name of the state to be started 232 @param start_time: timestamp when the state starts 233 """ 234 if state_name not in self.states: 235 self.states[state_name] = State(state_name) 236 self.states[state_name].start(start_time) 237 self.active_state = state_name 238 239 def end_state(self, end_time): 240 """End the specified state, in which the duration will be stored 241 242 @param end_time: timestamp when the state ends 243 """ 244 if self.active_state is not None: 245 self.states[self.active_state].end(end_time) 246 self.active_state = None 247 248 def calc_state_avg_stdev(self): 249 """Call all states to compute its own average and standard deviation""" 250 logging.debug("====pipe:%d, fb:%d====", self.pipe, self.fb) 251 for s in self.states.values(): 252 s.calc_avg_stdev() 253 254 255 class State(): 256 """Hold the data of a specific state (e.g. wait_kds, wait_apply, ...)""" 257 def __init__(self, state_name): 258 """Initialize data 259 260 @param state_name: name of this state 261 """ 262 self.state_name = state_name 263 self.last_start_time = None 264 self.duration_data = [] 265 self.avg = None 266 self.stdev = None 267 268 def start(self, start_time): 269 """Mark this state as started by saving the start time 270 271 @param start_time: timestamp when the state starts 272 """ 273 self.last_start_time = start_time 274 275 def end(self, end_time): 276 """Save the state's duration and mark this state as ended 277 278 @param end_time: timestamp when the state ends 279 """ 280 if self.last_start_time is not None: 281 self.duration_data.append(end_time - self.last_start_time) 282 self.last_start_time = None 283 284 def calc_avg_stdev(self): 285 """Calculate the average and standard deviation of all duration data""" 286 self.avg = numpy.mean(self.duration_data) 287 self.stdev = numpy.std(self.duration_data) 288
