diff --git a/tracer/gsttr-stats.py b/tracer/gsttr-stats.py index de4bc8fb6b..fb434c9dfd 100644 --- a/tracer/gsttr-stats.py +++ b/tracer/gsttr-stats.py @@ -6,8 +6,100 @@ GST_DEBUG="GST_TRACER:7" GST_TRACERS="stats;rusage;latency" GST_DEBUG_FILE=trace python3 gsttr-stats.py trace.log ''' +# TODO: +# options +# - list what is in the log +# - select which values to extract +# - live-update interval (for file=='-') + +from tracer.analysis_runner import AnalysisRunner from tracer.analyzer import Analyzer from tracer.parser import Parser +from tracer.structure import Structure + +_SCOPE_RELATED_TO = { + 'GST_TRACER_VALUE_SCOPE_PAD': 'Pad', + 'GST_TRACER_VALUE_SCOPE_ELEMENT': 'Element', + 'GST_TRACER_VALUE_SCOPE_THREAD': 'Thread', + 'GST_TRACER_VALUE_SCOPE_PROCESS': 'Process', +} + +_NUMERIC_TYPES = ('int', 'uint', 'gint', 'guint', 'gint64', 'guint64') + +class Stats(Analyzer): + + def __init__(self): + super(Stats, self).__init__() + self.records = {} + self.data = {} + + def handle_tracer_class(self, event): + s = Structure(event[Parser.F_MESSAGE]) + # TODO only for debugging + #print("tracer class:", repr(s)) + name = s.name[:-len('.class')] + record = { + 'class': s, + 'scope' : {}, + 'value' : {}, + } + self.records[name] = record + for k,v in s.values.items(): + if v.name == 'scope': + # TODO only for debugging + #print("scope: [%s]=%s" % (k, v)) + record['scope'][k] = v + elif v.name == 'value': + # skip non numeric and those without min/max + if (v.values['type'] in _NUMERIC_TYPES and + 'min' in v.values and 'max' in v.values): + # TODO only for debugging + #print("value: [%s]=%s" % (k, v)) + record['value'][k] = v + #else: + # TODO only for debugging + #print("skipping value: [%s]=%s" % (k, v)) + + def handle_tracer_entry(self, event): + # use first field in message (structure-id) if none + if event[Parser.F_FUNCTION]: + # TODO: parse params in event[Parser.F_MESSAGE] + entry_name = event[Parser.F_FUNCTION] + else: + s = Structure(event[Parser.F_MESSAGE]) + entry_name = s.name + record = self.records.get(entry_name) + if record: + # aggregate event based on class + for sk,sv in record['scope'].items(): + # look up bin by scope (or create new) + key = (_SCOPE_RELATED_TO[sv.values['related-to']] + + ":" + str(s.values[sk])) + scope = self.data.get(key) + if not scope: + scope = {} + self.data[key] = scope + for vk,vv in record['value'].items(): + key = entry_name + "/" + vk + data = scope.get(key) + if not data: + data = { + 'num': 0, + 'sum': 0, + } + if 'max' in vv.values and 'min' in vv.values: + data['min'] = int(vv.values['max']) + data['max'] = int(vv.values['min']) + scope[key] = data + # update min/max/sum and count via value + dv = int(s.values[vk]) + # TODO: skip 64bit -1 values ? + data['num'] += 1 + data['sum'] += dv + if 'min' in data: + data['min'] = min(dv, data['min']) + if 'max' in data: + data['max'] = max(dv, data['max']) def format_ts(ts): sec = 1e9 @@ -23,8 +115,10 @@ if __name__ == '__main__': args = parser.parse_args() with Parser(args.file) as log: - stats = Analyzer(log) - stats.run() + stats = Stats() + runner = AnalysisRunner(log) + runner.add_analyzer(stats) + runner.run() # iterate scopes for sk,sv in stats.data.items(): diff --git a/tracer/tracer/analysis_runner.py b/tracer/tracer/analysis_runner.py new file mode 100644 index 0000000000..e43f288f29 --- /dev/null +++ b/tracer/tracer/analysis_runner.py @@ -0,0 +1,38 @@ +from tracer.parser import Parser +from tracer.structure import Structure + +class AnalysisRunner(object): + '''Iterate over a log and dispatch to a set of analyzers''' + + def __init__(self, log): + self.log = log + self.analyzers = [] + + def add_analyzer(self, analyzer): + self.analyzers.append(analyzer) + + def handle_tracer_class(self, event): + for analyzer in self.analyzers: + analyzer.handle_tracer_class(event) + + def handle_tracer_entry(self, event): + for analyzer in self.analyzers: + analyzer.handle_tracer_entry(event) + + def is_tracer_class(self, event): + return (event[Parser.F_FILENAME] == 'gsttracerrecord.c' and + event[Parser.F_CATEGORY] == 'GST_TRACER' and + '.class' in event[Parser.F_MESSAGE]) + + def is_tracer_entry(self, event): + return (not event[Parser.F_LINE] and not event[Parser.F_FILENAME]) + + def run(self): + for event in self.log: + # check if it is a tracer.class or tracer event + if self.is_tracer_class(event): + self.handle_tracer_class(event) + elif self.is_tracer_entry(event): + self.handle_tracer_entry(event) + #else: + # print("unhandled:", repr(event)) diff --git a/tracer/tracer/analyzer_test.py b/tracer/tracer/analysis_runner_test.py similarity index 88% rename from tracer/tracer/analyzer_test.py rename to tracer/tracer/analysis_runner_test.py index fac00ee7ca..88611abfdd 100644 --- a/tracer/tracer/analyzer_test.py +++ b/tracer/tracer/analysis_runner_test.py @@ -1,18 +1,18 @@ import unittest -from tracer.analyzer import Analyzer +from tracer.analysis_runner import AnalysisRunner TRACER_CLASS = ('0:00:00.036373170', 1788, '0x23bca70', 'TRACE', 'GST_TRACER', 'gsttracerrecord.c', 110, 'gst_tracer_record_build_format', None, r'latency.class, src=(structure)"scope\\,\\ type\\=\\(type\\)gchararray\\,\\ related-to\\=\\(GstTracerValueScope\\)GST_TRACER_VALUE_SCOPE_PAD\\;", sink=(structure)"scope\\,\\ type\\=\\(type\\)gchararray\\,\\ related-to\\=\\(GstTracerValueScope\\)GST_TRACER_VALUE_SCOPE_PAD\\;", time=(structure)"value\\,\\ type\\=\\(type\\)guint64\\,\\ description\\=\\(string\\)\\"time\\\\\\ it\\\\\\ took\\\\\\ for\\\\\\ the\\\\\\ buffer\\\\\\ to\\\\\\ go\\\\\\ from\\\\\\ src\\\\\\ to\\\\\\ sink\\\\\\ ns\\"\\,\\ flags\\=\\(GstTracerValueFlags\\)GST_TRACER_VALUE_FLAGS_AGGREGATED\\,\\ min\\=\\(guint64\\)0\\,\\ max\\=\\(guint64\\)18446744073709551615\\;";') TRACER_ENTRY = ('0:00:00.142391137', 1788, '0x7f8a201056d0', 'TRACE', 'GST_TRACER', '', 0, '', None, r'latency, src=(string)source_src, sink=(string)pulsesink0_sink, time=(guint64)47091349;') -class TestAnalyzer(unittest.TestCase): +class TestAnalysisRunner(unittest.TestCase): def test_detect_tracer_class(self): - a = Analyzer(None) + a = AnalysisRunner(None) self.assertTrue(a.is_tracer_class(TRACER_CLASS)) def test_detect_tracer_entry(self): - a = Analyzer(None) + a = AnalysisRunner(None) self.assertTrue(a.is_tracer_entry(TRACER_ENTRY)) diff --git a/tracer/tracer/analyzer.py b/tracer/tracer/analyzer.py index f9c4b92104..4841eeec02 100644 --- a/tracer/tracer/analyzer.py +++ b/tracer/tracer/analyzer.py @@ -1,116 +1,11 @@ -import re -import sys - -from tracer.parser import Parser -from tracer.structure import Structure - -_SCOPE_RELATED_TO = { - 'GST_TRACER_VALUE_SCOPE_PAD': 'Pad', - 'GST_TRACER_VALUE_SCOPE_ELEMENT': 'Element', - 'GST_TRACER_VALUE_SCOPE_THREAD': 'Thread', - 'GST_TRACER_VALUE_SCOPE_PROCESS': 'Process', -} - -_NUMERIC_TYPES = ('int', 'uint', 'gint', 'guint', 'gint64', 'guint64') - class Analyzer(object): '''Base class for a gst tracer analyzer.''' - def __init__(self, log): - self.log = log - self.records = {} - self.data = {} + def __init__(self): + pass def handle_tracer_class(self, event): - s = Structure(event[Parser.F_MESSAGE]) - # TODO only for debugging - #print("tracer class:", repr(s)) - name = s.name[:-len('.class')] - record = { - 'class': s, - 'scope' : {}, - 'value' : {}, - } - self.records[name] = record - for k,v in s.values.items(): - if v.name == 'scope': - # TODO only for debugging - #print("scope: [%s]=%s" % (k, v)) - record['scope'][k] = v - elif v.name == 'value': - # skip non numeric and those without min/max - if (v.values['type'] in _NUMERIC_TYPES and - 'min' in v.values and 'max' in v.values): - # TODO only for debugging - #print("value: [%s]=%s" % (k, v)) - record['value'][k] = v - #else: - # TODO only for debugging - #print("skipping value: [%s]=%s" % (k, v)) - + pass def handle_tracer_entry(self, event): - # use first field in message (structure-id) if none - if event[Parser.F_FUNCTION]: - # TODO: parse params in event[Parser.F_MESSAGE] - vmethod_name = event[Parser.F_FUNCTION] - else: - s = Structure(event[Parser.F_MESSAGE]) - vmethod_name = s.name - record = self.records.get(vmethod_name) - if record: - # aggregate event based on class - for sk,sv in record['scope'].items(): - # look up bin by scope (or create new) - key = (_SCOPE_RELATED_TO[sv.values['related-to']] + - ":" + str(s.values[sk])) - scope = self.data.get(key) - if not scope: - scope = {} - self.data[key] = scope - for vk,vv in record['value'].items(): - key = vmethod_name + "/" + vk - data = scope.get(key) - if not data: - data = { - 'num': 0, - 'sum': 0, - } - if 'max' in vv.values and 'min' in vv.values: - data['min'] = int(vv.values['max']) - data['max'] = int(vv.values['min']) - scope[key] = data - # update min/max/sum and count via value - dv = int(s.values[vk]) - data['num'] += 1 - data['sum'] += dv - if 'min' in data: - data['min'] = min(dv, data['min']) - if 'max' in data: - data['max'] = max(dv, data['max']) - - # TODO: check if self has a catch-all handler and call first (check this in init) - # - we can use this to chain filters, allthough the chained filter - # would be doing the same as below - # check if self['vmethod'] is a function, if so call - vmethod = getattr (self, vmethod_name, None) - if callable(vmethod): - vmethod (event) - - def is_tracer_class(self, event): - return (event[Parser.F_FILENAME] == 'gsttracerrecord.c' and - event[Parser.F_CATEGORY] == 'GST_TRACER' and - '.class' in event[Parser.F_MESSAGE]) - - def is_tracer_entry(self, event): - return (not event[Parser.F_LINE] and not event[Parser.F_FILENAME]) - - def run(self): - for event in self.log: - # check if it is a tracer.class or tracer event - if self.is_tracer_class(event): - self.handle_tracer_class(event) - elif self.is_tracer_entry(event): - self.handle_tracer_entry(event) - #else: - # print("unhandled:", repr(event)) + pass \ No newline at end of file