# Copyright (c) 2013 The Chromium OS Authors. All rights reserved.
# Use of this source code is governed by a BSD-style license that can be
# found in the LICENSE file.
import logging
import numpy
import os
import re
import threading
import time
TRACING_DIR = '/sys/kernel/debug/tracing'
BUFFER_SIZE_RUNNING = '5000'
BUFFER_SIZE_IDLE = '1408'
def tracing_write(file_name, msg):
"""Helper method to write a file in kernel debugfs.
@param file_name: The file to write in debugfs.
@param msg: The content to write.
"""
with open(os.path.join(TRACING_DIR, file_name), 'w') as f:
f.write(msg)
f.flush()
def enable_tracing(events_list=None):
"""Enable kernel tracing.
@param events_list: The list of events to monitor. Defaults to None to
monitor all events.
"""
tracing_write('trace_clock', 'global')
tracing_write('buffer_size_kb', BUFFER_SIZE_RUNNING)
if events_list:
tracing_write('set_event', '\n'.join(events_list))
tracing_write('tracing_on', '1')
def disable_tracing():
"""Disable kernel tracing."""
tracing_write('tracing_on', '0')
tracing_write('set_event', '')
tracing_write('trace', '0')
tracing_write('buffer_size_kb', BUFFER_SIZE_IDLE)
def get_trace_log():
"""Get kernel tracing log."""
with open(os.path.join(TRACING_DIR, 'trace'), 'r') as f:
return f.read()
class Sampler(object):
"""Base sampler class."""
def __init__(self, period, duration, events=None):
self.period = period
self.duration = duration
self.events = events or []
self.sampler_callback = None
self.stop_sampling = threading.Event()
self.sampling_thread = None
@property
def stopped(self):
"""Check if sampler is stopped."""
return self.stop_sampling.is_set()
def _do_sampling(self):
"""Main sampling loop."""
while True:
next_sampling_time = time.time() + self.period
try:
enable_tracing(events_list=self.events)
if self.stop_sampling.wait(self.duration):
return
self.parse_ftrace(get_trace_log())
self.sampler_callback(self)
finally:
disable_tracing()
self.reset()
if self.stop_sampling.wait(next_sampling_time - time.time()):
return
def start_sampling_thread(self):
"""Start a thread to sample events."""
if not self.sampler_callback:
raise RuntimeError('Sampler callback function is not set')
self.stop_sampling.clear()
self.sampling_thread = threading.Thread(target=self._do_sampling)
self.sampling_thread.daemon = True
self.sampling_thread.start()
def stop_sampling_thread(self):
"""Stop sampling thread."""
self.stop_sampling.set()
self.reset()
def parse_ftrace(self, data):
"""Parse ftrace data.
@param data: The ftrace data to parse.
"""
raise NotImplementedError
def reset(self):
"""Reset the sampler."""
raise NotImplementedError
class ExynosSampler(Sampler):
"""Sampler for Exynos platform."""
def __init__(self, *args, **kwargs):
kwargs['events'] = ['exynos_page_flip_state']
super(ExynosSampler, self).__init__(*args, **kwargs)
self.frame_buffers = {}
def reset(self):
self.frame_buffers.clear()
def parse_ftrace(self, data):
"""Read and parse the ftrace file"""
# Parse using RE and named group match (?P<xxx>yyy) for clarity.
# Format:
# TASK-PID CPU# |||| TIMESTAMP FUNCTION
# X-007 [001] .... 001.000001: (a line-wrap in Python here ...)
# exynos_page_flip_state: pipe=0, fb=25, state=wait_kds
re_pattern = (
'\s*(?P<task>.+)-' + # task
'(?P<pid>\d+)\s+' + # pid
'\[(?P<cpu>\d+)\]\s+' + # cpu#
'(?P<inhp>....)\s+' + # inhp: irqs-off, need-resched,
# hardirq/softirq, preempt-depth
'(?P<timestamp>\d+\.\d+):\s+' + # timestamp
'(?P<head>exynos_page_flip_state):\s+' + # head
'(?P<detail>.*)') # detail: 'pipe=0, fb=25, state=wait_kds'
for line in data.split('\n'):
m = re.match(re_pattern, line)
if m is None: # not a valid trace line (e.g. comment)
continue
m_dict = m.groupdict() # named group of RE match (m_dict['task']...)
pipe, fb, state = self.exynos_parser(m_dict['detail'])
timestamp = float(m_dict['timestamp'])
self.end_last_fb_state(pipe, fb, timestamp)
self.start_new_fb_state(pipe, fb, state, timestamp)
self.calc_stat()
def exynos_parser(self, detail):
"""Parse exynos event's detail.
@param detail: a string like 'pipe=0, fb=25, state=wait_kds'
@return: tuple of (pipe, fb, state), pipe and fb in int,
state in string
"""
re_pattern = (
'pipe=(?P<pipe>\d+), ' + # pipe
'fb=(?P<fb>\d+), ' + # fb
'state=(?P<state>.*)') # state
if re.match(re_pattern, detail) is None:
logging.debug('==fail==' + re_pattern + ', ' + detail)
m_dict = re.match(re_pattern, detail).groupdict()
return int(m_dict['pipe']), int(m_dict['fb']), m_dict['state']
def end_last_fb_state(self, pipe, fb, end_time):
"""End the currently opened state of the specified frame buffer
@param pipe: the pipe id
@param fb: the frame buffer id
@param end_time: timestamp when the state ends
"""
self.get_frame_buffer(pipe, fb).end_state(end_time)
def start_new_fb_state(self, pipe, fb, state, start_time):
"""Start the specified state on the specified frame buffer
@param pipe: the pipe id
@param fb: the frame buffer id
@param state: which state to start
@param start_time: timestamp when the state starts
"""
self.get_frame_buffer(pipe, fb).start_state(state, start_time)
def calc_stat(self):
"""Calculate the statistics of state duration of all frame buffers"""
for fb in self.frame_buffers.values():
fb.calc_state_avg_stdev()
def frame_buffer_unique_hash(self, pipe, fb):
"""A hash function that returns the unique identifier of a frame buffer.
The hash is a string that is unique in the sense of pipe and fb.
@param pipe: the pipe id
@param fb: the frame buffer id
@return: a unique hash string, like "pipe:0,fb:25"
"""
return "pipe:%d,fb:%d" % (pipe, fb)
def get_frame_buffer(self, pipe, fb):
"""Return the frame buffer with specified pipe and fb.
If the frame buffer does not exist, create one and return it.
@param pipe: the pipe id
@param fb: the frame buffer id
@return: the frame buffer specified by pipe and fb
"""
key = self.frame_buffer_unique_hash(pipe, fb)
if key not in self.frame_buffers:
self.frame_buffers[key] = FrameBuffer(pipe, fb)
return self.frame_buffers[key]
class FrameBuffer():
"""Represents a frame buffer, which holds all its states"""
def __init__(self, pipe, fb):
"""Initialize the frame buffer.
@param pipe: the pipe id of the frame buffer
@param fb: the fb id of the frame buffer
"""
self.pipe = pipe
self.fb = fb
self.states = {}
self.active_state = None # currently active state (to be ended later)
def start_state(self, state_name, start_time):
"""Start the specified state
@param state_name: name of the state to be started
@param start_time: timestamp when the state starts
"""
if state_name not in self.states:
self.states[state_name] = State(state_name)
self.states[state_name].start(start_time)
self.active_state = state_name
def end_state(self, end_time):
"""End the specified state, in which the duration will be stored
@param end_time: timestamp when the state ends
"""
if self.active_state is not None:
self.states[self.active_state].end(end_time)
self.active_state = None
def calc_state_avg_stdev(self):
"""Call all states to compute its own average and standard deviation"""
logging.debug("====pipe:%d, fb:%d====", self.pipe, self.fb)
for s in self.states.values():
s.calc_avg_stdev()
class State():
"""Hold the data of a specific state (e.g. wait_kds, wait_apply, ...)"""
def __init__(self, state_name):
"""Initialize data
@param state_name: name of this state
"""
self.state_name = state_name
self.last_start_time = None
self.duration_data = []
self.avg = None
self.stdev = None
def start(self, start_time):
"""Mark this state as started by saving the start time
@param start_time: timestamp when the state starts
"""
self.last_start_time = start_time
def end(self, end_time):
"""Save the state's duration and mark this state as ended
@param end_time: timestamp when the state ends
"""
if self.last_start_time is not None:
self.duration_data.append(end_time - self.last_start_time)
self.last_start_time = None
def calc_avg_stdev(self):
"""Calculate the average and standard deviation of all duration data"""
self.avg = numpy.mean(self.duration_data)
self.stdev = numpy.std(self.duration_data)