|
#!/usr/bin/python3
|
|
import babeltrace
|
|
#import sys
|
|
|
|
|
|
# For each of the 100 traces, keep just the Firefox events (main process ID or threads too?);
|
|
# Count the number of syscalls;
|
|
# Count the number of occurrences of each syscall;
|
|
# Chop the single-process trace in 10-event sequences;
|
|
# Count the number of occurrences of each syscall in each of the sequene positions.
|
|
|
|
|
|
class CTFScopeIterator():
|
|
def __iter__(self):
|
|
"""
|
|
Return an iterator.
|
|
:rtype: iterator
|
|
:returns: the CTFScopeIterator object itself, since it implements the iterator interface
|
|
"""
|
|
self.index = None
|
|
return self
|
|
|
|
|
|
def __next__(self):
|
|
"""
|
|
Return the next CTFScope. Raise StopIteration if done.
|
|
CTFScopes are presented in the babeltrace.EventDeclaration.fields sequence.
|
|
:rtype: int
|
|
:returns: the next CTFScope in the current iterator
|
|
"""
|
|
if self.index is None:
|
|
self.index = babeltrace.CTFScope.EVENT_FIELDS
|
|
elif self.index == babeltrace.CTFScope.EVENT_FIELDS:
|
|
self.index = babeltrace.CTFScope.EVENT_CONTEXT
|
|
elif self.index == babeltrace.CTFScope.EVENT_CONTEXT:
|
|
self.index = babeltrace.CTFScope.STREAM_EVENT_CONTEXT
|
|
elif self.index == babeltrace.CTFScope.STREAM_EVENT_CONTEXT:
|
|
self.index = babeltrace.CTFScope.STREAM_EVENT_HEADER
|
|
elif self.index == babeltrace.CTFScope.STREAM_EVENT_HEADER:
|
|
self.index = babeltrace.CTFScope.STREAM_PACKET_CONTEXT
|
|
elif self.index == babeltrace.CTFScope.STREAM_PACKET_CONTEXT:
|
|
self.index = babeltrace.CTFScope.TRACE_PACKET_HEADER
|
|
elif self.index == babeltrace.CTFScope.TRACE_PACKET_HEADER:
|
|
raise StopIteration
|
|
return self.index
|
|
|
|
|
|
#def print_context(event):
|
|
# print(" pid {0} ppid {1} tid {2} vpid {3} vppid {4} vtid {5}".format(
|
|
# event.field_with_scope('pid', babeltrace.CTFScope.STREAM_EVENT_CONTEXT),
|
|
# event.field_with_scope('ppid', babeltrace.CTFScope.STREAM_EVENT_CONTEXT),
|
|
# event.field_with_scope('tid', babeltrace.CTFScope.STREAM_EVENT_CONTEXT),
|
|
# event.field_with_scope('vpid', babeltrace.CTFScope.STREAM_EVENT_CONTEXT),
|
|
# event.field_with_scope('vppid', babeltrace.CTFScope.STREAM_EVENT_CONTEXT),
|
|
# event.field_with_scope('vtid', babeltrace.CTFScope.STREAM_EVENT_CONTEXT)
|
|
# ))
|
|
|
|
|
|
def get_id(event, id):
|
|
"""
|
|
Get an event context field value.
|
|
:param event: the TraceEvent
|
|
:param id: a str, one of 'pid', 'ppid', 'tid', 'vpid', 'vppid', 'vtid'
|
|
:rtype: int
|
|
:returns: the context field value
|
|
"""
|
|
return event.field_with_scope(id, babeltrace.CTFScope.STREAM_EVENT_CONTEXT)
|
|
|
|
|
|
def get_pid(event):
|
|
return get_id(event, 'pid')
|
|
|
|
|
|
def get_ppid(event):
|
|
return get_id(event, 'ppid')
|
|
|
|
|
|
def get_tid(event):
|
|
return get_id(event, 'tid')
|
|
|
|
|
|
def event_name_sort_key(event_name):
|
|
if event_name.find('_entry_') > -1:
|
|
return event_name.partition('_entry_')[2] + '_entry'
|
|
elif event_name.find('_exit_') > -1:
|
|
return event_name.partition('_exit_')[2] + '_exit'
|
|
else:
|
|
raise Exception("Unrecognized syscall {}".format(event_name))
|
|
|
|
|
|
# From /usr/local/lib/python3.2/dist-packages/babeltrace.py : add_traces_recursive
|
|
def find_traces(path, format_str):
|
|
"""
|
|
Find traces recursively.
|
|
Find each trace present within the subdirectories of the given path.
|
|
:param path: the directory path to root the search at
|
|
:param format_str: the type of trace to look for (currently ignored, 'ctf' is the only known value)
|
|
:rtype: list of str
|
|
:returns: a list of paths to traces, None on error
|
|
"""
|
|
import os
|
|
|
|
traces = []
|
|
for fullpath, dirs, files in os.walk(path):
|
|
if "metadata" in files:
|
|
traces += [fullpath]
|
|
|
|
if len(traces) == 0:
|
|
return None
|
|
traces.sort()
|
|
return traces
|
|
|
|
|
|
#verbose = True
|
|
verbose = False
|
|
|
|
# The root to look for traces in
|
|
#trace_paths = "/home/daniel/lttng-traces/ffx-session-sandbox"
|
|
trace_paths = "/home/daniel/lttng-traces/ffx-session-all"
|
|
skip = 84
|
|
max_traces = 12
|
|
# The root folder of the trace collection
|
|
#trace_path = "/home/daniel/lttng-traces/ffx-session"
|
|
#trace_path = "/home/daniel/lttng-traces/ffx-session-sandbox"
|
|
|
|
# add_trace returns the TraceHandle (you can later get the handle from each event but not from the collection)
|
|
#trace_handle1 = trace_collection.add_trace(trace_path1, 'ctf')
|
|
#if trace_handle1 is None:
|
|
# raise RuntimeError('Cannot add trace {0:s}'.format(trace_path1))
|
|
|
|
# add_traces_recursive(path, 'ctf') adds traces by recursively searching in the path directory.
|
|
# It returns a dict object mapping full paths to trace handles, or None on error.
|
|
#traces = babeltrace.TraceCollection()
|
|
#trace_handles = traces.add_traces_recursive(trace_path, 'ctf')
|
|
##trace_handle = None
|
|
##for event in traces.events:
|
|
## if (trace_handle is None) or (trace_handle.id != event.handle.id):
|
|
# New trace (they don't overlap)
|
|
## trace_handle = event.handle
|
|
## print("Trace {0}".format(trace_handle.path))
|
|
|
|
# Because the above will exit code 139, we break up the traces
|
|
#newtraces = []
|
|
#for path in trace_handles:
|
|
# trace = babeltrace.TraceCollection()
|
|
# trace.add_trace(path, 'ctf')
|
|
# newtraces += [trace]
|
|
|
|
# New approach: we scan ourselves trace_paths for traces, and treat them one at a time
|
|
# This should resolve the memory and file handle problems we run into otherwise
|
|
# Update: Well, not really. On the ~14th trace, this core-dumps without any warning.
|
|
paths = find_traces(trace_paths, 'ctf')
|
|
trace_number = 0
|
|
#for trace in newtraces:
|
|
for path in paths:
|
|
trace_number += 1
|
|
if trace_number <= skip: continue
|
|
|
|
trace = babeltrace.TraceCollection()
|
|
trace.add_trace(path, 'ctf')
|
|
tids_firefox = [] # A list of TIDs "owned" by Firefox
|
|
threads = {} # A dictionary of threads: TID is key, value is { begin_time, end_time, last_event, PID (thread leader), PPID }
|
|
thread_groups = {} # A dictionary of thread groups; leader (PID) is key, value is list of threads (TIDs)
|
|
dying_thread_groups = [] # A list of thread groups for which exit_group has occurred
|
|
n_events = 0
|
|
offsets = {} # A dict of TIDs whose values are offsets into 10-element lists (offset values range over 0..9)
|
|
event_counts = {} # A dict of TIDs whose values are dicts of event_names whose values are 10-element lists
|
|
first_event = True
|
|
for event in trace.events:
|
|
if first_event:
|
|
first_event = False
|
|
print("***Trace path: {}".format(event.handle.path))
|
|
|
|
# Careful of the event.name.find order, since we have [compat_]syscall_entry_exit_group to deal with
|
|
if event.name.find('_entry_') > -1:
|
|
true_event_name = event.name.partition('_entry_')[2]
|
|
tid = get_tid(event)
|
|
# Watch for the firefox launch if not known already
|
|
# Note that there is a syscall_exit_execve even though execve() never returns
|
|
if (len(tids_firefox) == 0) \
|
|
and (true_event_name == 'execve') \
|
|
and (event.field_with_scope('filename', babeltrace.CTFScope.EVENT_FIELDS).endswith('/firefox')):
|
|
# We checked for '/firefox' to avoid the false positive of e.g. "./ltrace-firefox"
|
|
# Yes: Seed tids_firefox with the TID
|
|
tids_firefox = [tid]
|
|
|
|
n_events += 1
|
|
offsets[tid] = 0
|
|
event_counts[tid] = {}
|
|
event_counts[tid][event.name] = [1] + 9*[0]
|
|
|
|
pid = get_pid(event)
|
|
thread_groups[pid] = [tid]
|
|
threads[tid] = {}
|
|
threads[tid]['begin_time'] = event.timestamp
|
|
threads[tid]['end_time'] = None
|
|
threads[tid]['last_event'] = None
|
|
threads[tid]['PID'] = pid
|
|
threads[tid]['PPID'] = get_ppid(event)
|
|
if verbose:
|
|
print("execve ({0}): firefox is PID {1} TID {2}".format(
|
|
event.timestamp, pid, tid))
|
|
fmt_str = "{0:>%d}: thread group {1} : [{2}] created" % \
|
|
(len(str(event.timestamp)) + 9)
|
|
print(fmt_str.format(' ', pid, tid))
|
|
# execve replaces the executable (does not change the PID and TID)
|
|
# exit and exit_group signal the end of a process, to be removed from tids_firefox
|
|
elif (tid in tids_firefox):
|
|
n_events += 1
|
|
if tid not in offsets:
|
|
offsets[tid] = 0
|
|
event_counts[tid] = {}
|
|
offsets[tid] = (offsets[tid] + 1) % 10
|
|
if event.name not in event_counts[tid]:
|
|
event_counts[tid][event.name] = 10*[0]
|
|
event_counts[tid][event.name][offsets[tid]] += 1
|
|
|
|
if (true_event_name in ['exit', 'exit_group']):
|
|
pid = get_pid(event)
|
|
if verbose:
|
|
print("{3} ({0}): PID {1} TID {2} terminates".format(
|
|
event.timestamp, pid, tid, true_event_name))
|
|
tids_firefox.remove(tid)
|
|
thread_groups[pid].remove(tid)
|
|
threads[tid]['end_time'] = event.timestamp
|
|
threads[tid]['last_event'] = event.name
|
|
if verbose:
|
|
fmt_str = "{0:>%d}: thread {2} removed from thread group {1}" % \
|
|
(len(str(event.timestamp)) + len(true_event_name) + 3)
|
|
print(fmt_str.format(' ', pid, tid))
|
|
if len(thread_groups[pid]) == 0:
|
|
thread_groups.pop(pid)
|
|
if verbose:
|
|
fmt_str = "{0:>%d}: thread group {1} deleted" % \
|
|
(len(str(event.timestamp)) + len(true_event_name) + 3)
|
|
print(fmt_str.format(' ', pid))
|
|
# In the exit_group case, any TIDs belonging to the PID will die with their next syscall exit
|
|
# (if any are pending), typically poll or futex (there may be some other wait modes).
|
|
# We do an elif here because if the thread group has been emptied, there is no point in watching it
|
|
elif true_event_name == 'exit_group':
|
|
dying_thread_groups += [pid]
|
|
if verbose:
|
|
fmt_str = "{0:>%d}: thread group {1} added to dying thread list" % \
|
|
(len(str(event.timestamp)) + len(true_event_name) + 3)
|
|
print(fmt_str.format(' ', pid))
|
|
elif event.name.find('_exit_') > -1:
|
|
# Can't use rpartition because of syscall_exit_exit_group (although that's not supposed to happen ever)
|
|
true_event_name = event.name.partition('_exit_')[2]
|
|
tid = get_tid(event)
|
|
if tid in tids_firefox:
|
|
n_events += 1
|
|
if tid not in offsets:
|
|
offsets[tid] = 0
|
|
event_counts[tid] = {}
|
|
offsets[tid] = (offsets[tid] + 1) % 10
|
|
if event.name not in event_counts[tid]:
|
|
event_counts[tid][event.name] = 10*[0]
|
|
event_counts[tid][event.name][offsets[tid]] += 1
|
|
|
|
pid = get_pid(event)
|
|
# I don't think you can get exit_clone from a dying thread group's thread
|
|
if true_event_name == 'clone':
|
|
# Each entry_clone is matched by two clone exits,
|
|
# the first from the parent (ret = child tid), the second from the child or thread (ret = 0)
|
|
# verbose
|
|
clone_tid = event.field_with_scope('ret', babeltrace.CTFScope.EVENT_FIELDS)
|
|
if clone_tid != 0:
|
|
# First exit_clone, clone_tid is the child or thread (can't tell the cases apart yet)
|
|
tids_firefox += [clone_tid]
|
|
# offsets[clone_tid] = -1 # Because there has yet not been an event
|
|
# event_counts[clone_tid] = {}
|
|
if verbose:
|
|
print("exit_clone ({0}): PID {1} TID {2} joins tids_firefox".format(
|
|
event.timestamp, pid, clone_tid))
|
|
else:
|
|
# Second exit_clone
|
|
# Because it always occurs second, its TID will already have been added to tids_firefox
|
|
if pid == tid:
|
|
# A child, head of its own thread group
|
|
thread_groups[pid] = [tid]
|
|
if verbose:
|
|
print("exit_clone ({0}): thread group {1} : [{2}] created".format(
|
|
event.timestamp, pid, tid))
|
|
else:
|
|
# A thread, member of the PID's thread group
|
|
thread_groups[pid] += [tid]
|
|
if verbose:
|
|
print("exit_clone ({0}): thread {2} added to thread group {1}".format(
|
|
event.timestamp, pid, tid))
|
|
threads[tid] = {}
|
|
threads[tid]['begin_time'] = event.timestamp
|
|
threads[tid]['end_time'] = None
|
|
threads[tid]['last_event'] = None
|
|
threads[tid]['PID'] = pid
|
|
threads[tid]['PPID'] = get_ppid(event)
|
|
elif pid in dying_thread_groups:
|
|
# exit_futex or exit_poll (maybe others) from an interrupted thread
|
|
assert((pid in thread_groups) and (tid in thread_groups[pid]))
|
|
thread_groups[pid].remove(tid)
|
|
tids_firefox.remove(tid)
|
|
threads[tid]['end_time'] = event.timestamp
|
|
threads[tid]['last_event'] = event.name
|
|
if verbose:
|
|
print("{3} ({0}): thread {2} removed from thread group {1}".format(
|
|
event.timestamp, pid, tid, true_event_name))
|
|
if len(thread_groups[pid]) == 0:
|
|
thread_groups.pop(pid)
|
|
dying_thread_groups.remove(pid)
|
|
if verbose:
|
|
fmt_str = "{0:>%d}: thread group {1} deleted and removed from dying thread list" % \
|
|
(len(str(event.timestamp)) + len(true_event_name) + 3)
|
|
print(fmt_str.format(' ', pid))
|
|
# elif (true_event_name == 'poll') and (event.field_with_scope('ret', babeltrace.CTFScope.EVENT_FIELDS) < 0):
|
|
# print(">>poll ({0}): TID {1} returns {2}".format(event.timestamp, get_tid(event), event.field_with_scope('ret', babeltrace.CTFScope.EVENT_FIELDS)))
|
|
# elif (true_event_name == 'futex') and (event.field_with_scope('ret', babeltrace.CTFScope.EVENT_FIELDS) < -110):
|
|
# Nearly all exit_futex events return -110
|
|
# print(">>futex ({0}): TID {1} returns {2}".format(event.timestamp, get_tid(event), event.field_with_scope('ret', babeltrace.CTFScope.EVENT_FIELDS)))
|
|
|
|
else:
|
|
raise Exception("Unrecognized syscall {}".format(event.name))
|
|
|
|
# kill, tkill, tgkill?
|
|
print("Total number of Firefox syscalls: {}".format(n_events))
|
|
# Longest event name is 43 chars: "compat_syscall_entry_sched_get_priority_max"
|
|
print("Event counts of each TID:")
|
|
for tid in sorted(event_counts.keys()):
|
|
print(" TID {:>5}: thread leader (PID) {:>5} parent (PPID) {:>5} begins {} ends {} last event {}".format(
|
|
tid, threads[tid]['PID'], threads[tid]['PPID'],
|
|
threads[tid]['begin_time'], threads[tid]['end_time'], threads[tid]['last_event']))
|
|
for event_name in sorted(event_counts[tid].keys(), key=event_name_sort_key):
|
|
# Assuming list {1} is 10 four-digit numbers, plus comma and space
|
|
# print("{:>43}: {:<60} sum {:>5}".format(
|
|
# event_name, event_counts[tid][event_name], sum(event_counts[tid][event_name])))
|
|
print("{:>43}: [{}] sum {:>5}".format(
|
|
event_name,
|
|
', '.join(map("{:>4}".format, event_counts[tid][event_name])),
|
|
sum(event_counts[tid][event_name])))
|
|
|
|
if trace_number >= (skip + max_traces): break
|
|
|
|
#print("***{} traces processed".format(len(paths)))
|
|
print("***{} traces processed".format(trace_number - skip))
|