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 8, 2022
1 parent 11bc130 commit 994dd12
Show file tree
Hide file tree
Showing 27 changed files with 6,358 additions and 0 deletions.
126 changes: 126 additions & 0 deletions tracetool/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,126 @@
# 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 is driven by core, following interfaces are required by core:
|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
### class 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.py, wrap UI event for chrome://tracing.|
|Stack|sharedCtx['Stack']|instance of class callStack.py, 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 class statistic.py, 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 994dd12

Please sign in to comment.