Skip to content

Commit

Permalink
add trace tool to support libva trace process
Browse files Browse the repository at this point in the history
Signed-off-by: Lindong Wu <lindong.wu@intel.com>
  • Loading branch information
lindongw committed Jun 7, 2022
1 parent 11bc130 commit f58b610
Show file tree
Hide file tree
Showing 27 changed files with 6,357 additions and 0 deletions.
125 changes: 125 additions & 0 deletions tracetool/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,125 @@
# Linux trace tool


## Introduction

This is python tool helps to analysis media stack trace logs combining ftrace events from libva, media driver and Linux kernel mode driver (e.g. i915).


## Linux trace capture

1. Install trace-cmd:

sudo apt-get install trace-cmd

2. Grant write access to trace node for application:

sudo chmod 777 /sys/kernel/debug/
sudo chmod 777 /sys/kernel/debug/tracing/
sudo chmod 777 /sys/kernel/debug/tracing/trace_marker_raw

3. Enable libva trace:

export LIBVA_TRACE = FTRACE

to enable libva buffer data capture

export LIBVA_TRACE_BUFDATA = 1

4. Run application under trace-cmd in a proxy mode:

trace-cmd record -e i915 <workflow-cmd-line>

5. Output is "trace.dat"

Alternatively you can collect trace data in separate terminal.
It is useful if you want to profile daemon or a service:

1. Start trace capture:

sudo trace-cmd record -e i915

2. Run test app in another terminal
3. Stop capturing in the first terminal
4. Output is "trace.dat"


## Trace post-processing and analysis

python3 main.py [-raw] file.dat|file.etl [file.dat|file.etl ...]

Options:

* `-raw` - Parse trace events and dump into <trace-file>.csv file.

Output:

* `<trace-file>.json.gz` - visualized trace activity, open in `<chrome://tracing/>` or `<edge://tracing/>`
* `<trace-file>_stat.csv` - statistic of trace activity, open in Excel
* `<trace-file>_surface.csv` - surface attributes and runtime usage in GPU, open in Excel
* `<trace-file>_rtlog.txt` - iHD driver runtime log


## Trace tool manifests

Manifests are for decoding trace data. Each trace system supported by trace tool need have a manifest file in manifests folder.
The manifest file could be in MSFT ETW XML manifest format or json format. Current supported traces:
* libva_trace.man - libva trace manifest in MSFT ETW XML
* Intel-Media-Open.json - iHD open source media driver trace manifest in json.


## Trace Modules

Trace tool dynamic load functional module in modules folders. Each module should have its own standalone function.
Two types of module supported: traceReader and traceHandler.
Each module should have 1 class traceReader or class traceHandler implemented. Trace tool load module by class name, so no change on class name.
### class traceReader
trace file reader module, responsible for parsing trace file into trace events, and call core handler one by one in event timestamp order.
trace reader external interface:
|interface|description|
|---|---|
|open(self, file, options)->int|open trace file, return 0 for sucess, negative for failure. user command line options are provided in args.|
|setParser(self, parsers)->None|set trace head parsers. Since all Linux user space trace share single trace_marker_raw entry, each user trace(libva and iHD) need register its own header parser to identify itself.|
|syncSource(self, src)->int|for sync timestamp across multi trace readers. return -1 for no support.|
|process(self, filter, handler)->None|start trace event process with filter and handler callbacks. Filt events with filter callback could speed up event process.|

add new reader to support more trace file format
### traceHandler
trace event handler module to customize event handling.
core interface for trace handler:
|interface|description|
|---|---|
|core.regParser(id, parser)->int|register trace header parser, id is 4bytes trace identifier, parer callback is to parser event header.|
|core.regHandler(sys, name, handler)->None|register event handler, set name to None for common trace handler.|
|core.getContext()->dict|get share context from core.|

Since all handler modules are in seperated instance, could not share anything across modules, core provide shared context for sharing.
by default, shared context provide following class instance:
|name in context|access example| description|
|---|---|---|
|UI|sharedCtx['UI']|instance of class writeUI, wrap UI event for chrome://tracing.|
|Stack|sharedCtx['Stack']|instance of class callStack, provide call stack of trace event. call stack is built from event sequence from the same process id and thread id.|
|Stat|sharedCtx['Stat']|instace of statistic, build statistic for specific events.|
|Output|sharedCtx['Output']|output path string, in case module need to create its own output file.|

developer could add more in shared context.
Note: It is possible multi modules register their own handers for one specific event. core will call these callback one by one when target event occurs.

current modules:
|module|description|
|---|---|
|ftrace.py|Linux ftace file parser, trace file from trace-cmd.|
|i915.py|i915 trace handler to extract GPU workload submit&execution timing.|
|libva.py|libva trace handler.|
|iHD.py|Intel iHD open source media driver trace handler.|
|surface.py|track surface object & attributes across iHD and i915 traces.|

## Making changes in the tool

Make sure to run unit tests before creating PR:

cd tracetool
python3 -m unittest

Make sure trace event and event data are backward compatible.

70 changes: 70 additions & 0 deletions tracetool/callStack.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,70 @@
#
# Copyright (C) Intel Corporation. All rights reserved.
# Licensed under the MIT License.
#

# build call stack from events with the same process and thread id
class callStack:

def __init__(self):
self.context = {} # maintain call stack

# get latest pushed call event in stack
def current(self, pid, tid):
if pid not in self.context or tid not in self.context[pid]:
return None
if self.context[pid][tid]:
return self.context[pid][tid][0]
return None

# get full call stack record
def get(self, pid, tid):
if pid not in self.context:
self.context[pid] = {}
if tid not in self.context[pid]:
self.context[pid][tid] = []
return self.context[pid][tid]

# push event into stack
def push(self, evt):
if evt['pid'] not in self.context:
self.context[evt['pid']] = {}
if evt['tid'] not in self.context[evt['pid']]:
self.context[evt['pid']][evt['tid']] = []
self.context[evt['pid']][evt['tid']].insert(0, evt)

# pop event from stack
def pop(self, evt):
if evt['pid'] not in self.context:
return None
if evt['tid'] not in self.context[evt['pid']] or not self.context[evt['pid']][evt['tid']]:
thrds = self.context[evt['pid']]
for t in thrds.values():
if t and t[0]['name'] == evt['name']:
return t.pop(0)
return None
ctx = self.context[evt['pid']][evt['tid']]
name = evt['name']
idx = 0
ret = None
# find target in the stack
for i in range(len(ctx)):
if ctx[i]['name'] == name:
idx = i+1
ret = ctx[i]
break
# remove target from stack
del ctx[0:idx]
return ret

# find top event with the same sys id + pid + tid
def find(self, evt):
if evt['pid'] not in self.context or evt['tid'] not in self.context[evt['pid']]:
return None
for e in self.context[evt['pid']][evt['tid']]:
if e['sys'] == evt['sys']:
return e
return None

def __del__(self):
del self.context
160 changes: 160 additions & 0 deletions tracetool/core.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,160 @@
#
# Copyright (C) Intel Corporation. All rights reserved.
# Licensed under the MIT License.
#

import os
import sys
import importlib
from writeUI import writeUI
from statistic import statistic
from callStack import callStack
from util import *

class core:

def __init__(self):
self.source = None
self.sharedCtx = {} # shared context for all handlers, dict for flexible usage
self.handlers = {}
self.instances = []
self.readers = []
self.parsers = {}
self.dumpRaw = False

cur = os.path.abspath(os.path.dirname(__file__))
sys.path.append(cur+os.sep+'modules')
for py in os.listdir('modules'):
name = os.path.splitext(py)[0]
m = importlib.import_module(name)
if hasattr(m, 'traceHandler'):
cls = getattr(m, 'traceHandler')
# create handler instace, the class init should call register of this instance
instance = cls(self)
# just for keep instance ref
self.instances.append(instance)
elif hasattr(m, 'traceReader'):
cls = getattr(m, 'traceReader')
self.readers.append(cls)

# open trace file
def open(self, input, options) -> int:
ret = -1
if isinstance(input, list) and len(input) == 1:
input = input[0]
if isinstance(input, list):
# enumerate and open trace files
names = []
readers = []
for i in input:
for cls in self.readers:
reader = cls()
sts = reader.open(i, options)
if sts == 0:
names.append(i)
readers.append(reader)
break
if len(input) == len(readers):
# sync time stamp across multi trace files, need find single source reader
print('Multi trace input files, sync time line ...')
for i in readers:
for j in readers:
if i != j and i.syncSource(j) == 0:
self.source = i
self.sharedCtx['sourceFile'] = names[readers.index(i)]
break
if self.source != None:
break
if self.source != None:
print('done')
ret = 0
else:
print('Error! could not syn time line')
else:
for cls in self.readers:
reader = cls()
sts = reader.open(input, options)
if sts == 0:
self.source = reader
self.sharedCtx['sourceFile'] = input
ret = 0
break
# setup handlers and output if success
if ret == 0:
self.source.setParser(self.parsers)

baseName = self.sharedCtx['sourceFile']
baseName = os.path.splitext(baseName)[0]
self.sharedCtx['Output'] = baseName
self.sharedCtx['UI'] = writeUI(baseName)
self.sharedCtx['Stat'] = statistic(baseName)
self.sharedCtx['Stack'] = callStack()
self.sharedCtx['Opt'] = options
return ret

# start process event from trace file
def process(self) -> None:
self.source.process(self.filter, self.callback)

# close
def __del__(self):
del self.source
del self.readers
del self.instances
del self.handlers
del self.sharedCtx

# test if event handler is set for this event
def filter(self, evt) -> bool:
if 'raw' in self.sharedCtx['Opt']:
return True
if 'sys' not in evt or 'name' not in evt:
return False
if evt['sys'] not in self.handlers:
return False
handler = self.handlers[evt['sys']]
if evt['name'] not in handler and 'allEvent' not in handler:
return False
return True

# call back function to process event with handler
def callback(self, evt) -> None:
if evt['sys'] not in self.handlers:
return
# get handler, could be a list, multi handler for single event
hnd = self.handlers[evt['sys']]
flag = 0
if evt['name'] in hnd:
for h in hnd[evt['name']]:
sts = h(evt)
if sts != None and sts < 0:
flag = 1
# call all event handler at last step, skip if any handler has returned -1
if 'allEvent' in hnd and flag == 0:
for h in hnd['allEvent']:
h(evt)

# register event handler
def regHandler(self, sys, name, handler) -> None:
if name == None:
name = 'allEvent' # name = None means handler for all events of this trace system
if sys not in self.handlers:
self.handlers[sys] = {}
# add handler to list
hnd = self.handlers[sys]
if name in hnd:
hnd[name].append(handler)
else:
hnd[name] = [handler]

# register event head parser from raw message
def regParser(self, id, parser) -> int:
if id in self.parsers:
print('Warning! duplicated event header id')
return -1
self.parsers[id] = parser
return 0

# get shared context
def getContext(self) -> dict:
return self.sharedCtx
Loading

0 comments on commit f58b610

Please sign in to comment.