summarize-profile.py

#!/usr/bin/python

import argparse
import json
import os
import sys

from collections import defaultdict

parser = argparse.ArgumentParser(description='Summarize a Cleopatra profile')
parser.add_argument('--show', default='', metavar='CATEGORY',
                    help='Print stacks categorized as CATEGORY or subcategories')
parser.add_argument('--show-exact', default='', metavar='CATEGORY',
                    help='Print stacks categorized as CATEGORY')
parser.add_argument('--thread', default='0',
                    help='Summarize thread THREAD')
parser.add_argument('--nowait', action='store_true',
                    help='Do not include wait time in percentages')
parser.add_argument('--start',
                    help='Start the summary from the given marker name')
parser.add_argument('--stop',
                    help='Stop the summary at the given marker name')
parser.add_argument('--list-markers', action='store_true',
                    help='Display the list of markers for the given thread')
parser.add_argument('--list-marker-summary', action='store_true',
                    help='Summarize the list of markers for the given thread (names are truncated unless --verbose)')
parser.add_argument('--verbose', action='store_true',
                    help='Do not truncate any output')
parser.add_argument('profile',
                    help='Filename of profile to load')
args = parser.parse_args()

with open(args.profile, 'r') as fp:
    profile = json.load(fp)

threads = profile['profileJSON']['threads']
thread_ids = {info['name']: tid for tid, info in threads.items()}

thread = thread_ids.get(args.thread, args.thread)
print("Note: thread %s only!" % threads[thread]['name'])
print("Available threads: " + ", ".join(name + '=' + tid for name, tid in thread_ids.items()))

all_markers = profile['profileJSON']['threads'][thread]['markers']

if args.list_markers or args.list_marker_summary:
    hist = defaultdict(list)
    for marker in all_markers:
        if args.list_markers:
            print("%.6f %s" % (marker['time'], marker['name']))
        hist[marker['name']].append(marker['time'])

    print('Summary of markers on thread %s' % args.thread)
    for marker, occurs in sorted(hist.items(), key=lambda item: item[1][0]):
        if len(marker) > 50 and not args.verbose:
            marker = marker[0:50] + '...'
        s = '%.6f' % occurs[0]
        if len(occurs) > 1:
            s += '..%.6f %d x' % (occurs[-1], len(occurs))
        s += ' %s' % marker
        print(s)

    sys.exit(0)

tofind = [m for m in [args.start, args.stop] if m]
marker = {}
for marker_name in tofind:
    matches = [m['time'] for m in all_markers if m['name'] == marker_name]
    if len(matches) == 0:
        print("Marker %s not found" % marker_name)
    elif len(matches) > 1:
        print("Marker %s found %d times" % (marker_name, len(matches)))
    else:
        marker[marker_name] = matches[0]

samples = profile['profileJSON']['threads'][thread]['samples']

# Process start, stop
sample_range = [0, len(samples)]
if args.start:
    while samples[sample_range[0]]['extraInfo']['time'] < marker[args.start]:
        sample_range[0] += 1
    print("%s found at sample %d time %s" % (args.start, sample_range[0], samples[sample_range[0]]['extraInfo']['time']))
if args.stop:
    while samples[sample_range[1]-1]['extraInfo']['time'] > marker[args.stop]:
        sample_range[1] -= 1
    print("%s found at sample %d-1 time %s" % (args.start, sample_range[1], samples[sample_range[1]-1]['extraInfo']['time']))

if args.start or args.stop:
    print("Narrowing original %d samples down to %d, in the range %d..%d" %
          (len(samples), sample_range[1] - sample_range[0], sample_range[0], sample_range[1]))

samples = samples[sample_range[0]:sample_range[1]]

symbols_text = profile['symbolicationTable']
symbols = ['' for _ in symbols_text.keys()]
symbol_to_ids = {}
for id, name in symbols_text.iteritems():
    symbols[int(id)] = name
    symbol_to_ids.setdefault(name, []).append(int(id))

print("%d samples" % len(samples))
print("%d symbols" % len(symbols))

# From bz:
#   'RestyleManagerHandle::Ptr::ProcessPendingRestyles': 'restyle',
#   'RestyleManager::ProcessPendingRestyles': 'restyle',
#   'PresShell::ProcessReflowCommands': 'layout',
#   'nsCSSFrameConstructor::ContentAppended': 'frameconstruction',
#   'nsCSSFrameConstructor::ContentInserted': 'frameconstruction',
#   'nsCSSFrameConstructor::ContentRemoved': 'frameconstruction',
#   'PresShell::DoReflow': 'layout',

category_info = {
    ('exact', 'js::RunScript'): 'script',
    ('stem', 'js::Nursery::collect'): 'GC',
    ('stem', 'js::GCRuntime::collect'): 'GC',
    ('prefix', 'mozilla::RestyleManager::'): 'restyle',
    ('substring', 'RestyleManager'): 'restyle',
    ('stem', 'PresShell::ProcessReflowCommands'): 'layout',
    ('prefix', 'nsCSSFrameConstructor::'): 'frameconstruction',
    ('stem', 'PresShell::DoReflow'): 'layout',
    ('substring', '::compileScript('): 'script',

    ('prefix', 'nsCycleCollector'): 'CC',
    ('prefix', 'nsPurpleBuffer'): 'CC',
    ('substring', 'pthread_mutex_lock'): 'wait',  # eg __GI___pthread_mutex_lock
    ('prefix', 'nsRefreshDriver::IsWaitingForPaint'): 'paint',  # arguable, I suppose
    ('stem', 'PresShell::Paint'): 'paint',
    ('prefix', '__poll'): 'wait',
    ('prefix', '__pthread_cond_wait'): 'wait',
    ('stem', 'PresShell::DoUpdateApproximateFrameVisibility'): 'layout',  # could just as well be paint
    ('substring', 'mozilla::net::'): 'network',
    ('stem', 'nsInputStreamReadyEvent::Run'): 'network',

    #('stem', 'NS_ProcessNextEvent'): 'eventloop',
    ('exact', 'nsJSUtil::EvaluateString'): 'script',
    ('prefix', 'js::frontend::Parser'): 'script.parse',
    ('prefix', 'js::jit::IonCompile'): 'script.compile.ion',
    ('prefix', 'js::jit::BaselineCompiler::compile'): 'script.compile.baseline',

    ('prefix', 'CompositorBridgeParent::Composite'): 'paint',
    ('prefix', 'mozilla::layers::PLayerTransactionParent::Read('): 'messageread',

    # Can't do this until we come up with a way of labeling ion/baseline.
    # ('prefix', 'Interpret('): 'script.interpreter',
}

category = {}
unused_rules = set(category_info.keys())
for name, ids in symbol_to_ids.iteritems():
    for key, classification in category_info.items():
        keytype, pattern = key
        assigned = None
        if keytype == 'exact':
            if name == pattern:
                assigned = classification
        elif keytype == 'prefix':
            if name.startswith(pattern):
                assigned = classification
        elif keytype == 'substring':
            if pattern in name:
                assigned = classification
        elif keytype == 'stem':
            if name == pattern or name.startswith(pattern + "("):
                assigned = classification
        else:
            raise Exception("internal error: invalid keytype '%s'" % (keytype,))

        if assigned is not None:
            unused_rules.discard(key)
            if category.get(ids[0], assigned) != assigned:
                print("%s assigned to both %s and %s" % (name, category[ids[0]], assigned))
            for id in ids:
                category[id] = assigned

for keytype, pattern in unused_rules:
    print("%s key is unused, pattern = %s" % (keytype, pattern))
if unused_rules:
    with open("frame-names.txt", "w") as fp:
        for name in symbols:
            fp.write(name)
            fp.write("\n")

histo = defaultdict(int)
histo['uncategorized'] = 0

def gen_ancestors(cat):
    while True:
        yield cat
        cat, ext = os.path.splitext(cat)
        if ext == '':
            break

def categorize_sample(sample):
    scat = 'uncategorized'
    for id in sample['frames']:
        if int(id) in category:
            cat = category[int(id)]
            if cat != 'wait' or scat == 'uncategorized':
                scat = cat
    return scat

for sample in samples:
    for cat in gen_ancestors(categorize_sample(sample)):
        histo[cat] += 1

print("\nCategory breakdown:")
for cat, count in sorted(histo.items(), key=lambda item: item[1], reverse=True):
    percent = 100 * count / len(samples)
    if args.nowait:
        if cat.startswith('wait'):
            cat = '(%s, percent of total)' % cat
        else:
            percent = 100 * count/ (len(samples) - histo['wait'])
    if percent >= 2:
        print("%s: %d%%" % (cat, percent))

if args.show or args.show_exact:
    # Print out some uncategorized samples, or samples in the requested category.
    print("\nSamples in category '%s':\n" % args.show)
    for sample in samples:
        scat = categorize_sample(sample)
        if args.show_exact and scat != args.show_exact:
            continue
        if args.show and args.show not in gen_ancestors(scat):
            continue
        for id in sample['frames']:
            cat = category.get(int(id))
            print("%s%s" % ("{%s} " % cat if cat else "", symbols[id]))
        print("")