Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

add trace tool to support libva trace process #251

Open
wants to merge 1 commit into
base: master
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
157 changes: 157 additions & 0 deletions tracetool/README.md
Original file line number Diff line number Diff line change
@@ -0,0 +1,157 @@
# Linux trace tool


## Introduction

This 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:
lindongw marked this conversation as resolved.
Show resolved Hide resolved

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

Trace tool uses manifests to decode trace data. Each trace module available in trace tool
needs to have a manifest file in manifests folder. The manifest file could be either in
MSFT ETW XML manifest format or in json format. Current supported traces:

* [libva_trace.man](./manifests/libva_trace.man) - libva trace manifest in MSFT ETW XML
* [Intel-Media-Open.json](./manifests/Intel-Media-Open.json) - iHD media driver trace manifest in json

## Trace Modules

Trace tool loads trace modules from the [modules](./modules) folder. Two types of modules
are supported:

* Trace readers
* Trace handlers

Readers support reading data from the trace without performing any action on the read data.
Handlers perform actions over read data. Effectively trace readers provide input to trace
handlers.

Trace tool loads modules by class names.

### Trace core

Trace core loads trace modules making them available for trace tool. Key interfaces:

| Interface | Description |
| --------- | ----------- |
| `core.regParser(id, parser) -> int` | Registers trace header `parser` to the core. `id` is 4bytes trace identifier. |
| `core.regHandler(sys, name, handler) -> None` | Registers event handler. Set name to None for common trace handler. |
| `core.getContext() -> dict` | Get share context from the core. |

### Trace readers

Trace reader module is responsible for parsing trace file into trace events and call
trace handlers one by one in event timestamp order.

Trace reader is driven by trace core. The following interfaces are required to be
provide by the trace reader module implentation:

| Interface | Description |
| --------- | ----------- |
| `open(self, file, options) -> int` | Open trace file, returns 0 for sucess, < 0 for failures. User command line options are provided in args. |
| `setParser(self, parsers) -> None` | Set trace header parsers. Since all Linux user space traces 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` | Starts trace event process with filter and handler callbacks. Filter callback could speed up event process. |

Currently supported trace reader modules:

| Module | Description |
| ---------- | ----------- |
| ftrace.py | Linux ftace file reader, trace file from trace-cmd |

### Trace handlers

Trace event handler module customizes events handling. Since all handler modules are
seperate instances, trace core provides shared context to share data between modules.

By default, shared context provides the following:

| Name in context | Description |
| --------------- | ----------- |
| `UI` | Instance of class `writeUI` (see [writeUI.py](./writeUI.py). Class writes events for chrome://tracing. |
| `Stack` | Instance of class `callStack` (see [callStack.py](./callStack.py). Class provides call stack of trace event. Call stack is built from event sequence from the same process id and thread id. |
| `Stat` | Instance of class `statistic` (see [statistic.py](./statistic.py). Class provides statistics for specific events. |
| `Output` | Output path string in case module needs to create its own output file. |

Handler module only interact with core, should not export interface to external directly. Module register its own event handlers to core through `core.regHandler(sys, name, handler)`.

It is possible that multi modules register their own handlers for the same event. Core will call these callbacks one by one when target event occurs.

Handler module could write output into `UI` or `Stat` in share context, also could create and write its own output file and format. Output file path is available in share context `Output`.

In case a handler module is targeted to provide a common service, it could export its name and instance in share context. Its name in share context should be unique, other module use this name to get service instance. The service interface is defined by module itself. see example [surface.py](./modules/surface.py).

To add new trace support, handler module for this new trace MUST register event header parser to core, through `core.regParser(id, parser)`. This event header parser is to detect and parse trace header, otherwise trace reader could not recognize this new trace. The id for this new trace should be unique. refer example [libva.py](./modules/libva.py).

Currently supported handler modules:
| Module | Description |
| ---------- | ----------- |
| 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 | Handler tracks 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