view mercurial/profiling.py @ 32476:e5e31b0fc924

hidden: use _domainancestors to compute revs revealed by dynamic blocker

The complexity of computing the revealed changesets is now 'O(revealed)'.
This massively speeds up the computation on large repository. Moving it to the
millisecond range.

Below are timing from two Mozilla repositories with different contents:

1) mozilla repository with:
 * 400667 changesets
 * 35 hidden changesets (first rev-268334)
 * 288 visible drafts
 * obsolete working copy (dynamicblockers),

Before:
! visible
! wall 0.030247 comb 0.030000 user 0.030000 sys 0.000000 (best of 100)

After:
! visible
! wall 0.000585 comb 0.000000 user 0.000000 sys 0.000000 (best of 4221)

The timing above include the computation of obsolete changeset:
! obsolete
! wall 0.000396 comb 0.000000 user 0.000000 sys 0.000000 (best of 6816)

So adjusted time give 30ms before versus 0.2ms after. A 150x speedup.

2) mozilla repository with:
 * 405645 changesets
 * 4312 hidden changesets (first rev-326004)
 * 264 visible drafts
 * obsolete working copy (dynamicblockers),

Before:
! visible
! wall 0.168658 comb 0.170000 user 0.170000 sys 0.000000 (best of 48)

After
! visible
! wall 0.008612 comb 0.010000 user 0.010000 sys 0.000000 (best of 325)

The timing above include the computation of obsolete changeset:
! obsolete
! wall 0.006408 comb 0.010000 user 0.010000 sys 0.000000 (best of 404)

So adjusted time give 160ms before versus 2ms after. A 75x speedup.

# profiling.py - profiling functions
#
# Copyright 2016 Gregory Szorc <[e-mail]>
#
# This software may be used and distributed according to the terms of the
# GNU General Public License version 2 or any later version.

from __future__ import absolute_import, print_function

import contextlib

from .i18n import _
from . import (
    encoding,
    error,
    extensions,
    util,
)

def _loadprofiler(ui, profiler):
    """load profiler extension. return profile method, or None on failure"""
    extname = profiler
    extensions.loadall(ui, whitelist=[extname])
    try:
        mod = extensions.find(extname)
    except KeyError:
        return None
    else:
        return getattr(mod, 'profile', None)

@contextlib.contextmanager
def lsprofile(ui, fp):
    format = ui.config('profiling', 'format', default='text')
    field = ui.config('profiling', 'sort', default='inlinetime')
    limit = ui.configint('profiling', 'limit', default=30)
    climit = ui.configint('profiling', 'nested', default=0)

    if format not in ['text', 'kcachegrind']:
        ui.warn(_("unrecognized profiling format '%s'"
                    " - Ignored\n") % format)
        format = 'text'

    try:
        from . import lsprof
    except ImportError:
        raise error.Abort(_(
            'lsprof not available - install from '
            'http://codespeak.net/svn/user/arigo/hack/misc/lsprof/'))
    p = lsprof.Profiler()
    p.enable(subcalls=True)
    try:
        yield
    finally:
        p.disable()

        if format == 'kcachegrind':
            from . import lsprofcalltree
            calltree = lsprofcalltree.KCacheGrind(p)
            calltree.output(fp)
        else:
            # format == 'text'
            stats = lsprof.Stats(p.getstats())
            stats.sort(field)
            stats.pprint(limit=limit, file=fp, climit=climit)

@contextlib.contextmanager
def flameprofile(ui, fp):
    try:
        from flamegraph import flamegraph
    except ImportError:
        raise error.Abort(_(
            'flamegraph not available - install from '
            'https://github.com/evanhempel/python-flamegraph'))
    # developer config: profiling.freq
    freq = ui.configint('profiling', 'freq', default=1000)
    filter_ = None
    collapse_recursion = True
    thread = flamegraph.ProfileThread(fp, 1.0 / freq,
                                      filter_, collapse_recursion)
    start_time = util.timer()
    try:
        thread.start()
        yield
    finally:
        thread.stop()
        thread.join()
        print('Collected %d stack frames (%d unique) in %2.2f seconds.' % (
            util.timer() - start_time, thread.num_frames(),
            thread.num_frames(unique=True)))

@contextlib.contextmanager
def statprofile(ui, fp):
    from . import statprof

    freq = ui.configint('profiling', 'freq', default=1000)
    if freq > 0:
        # Cannot reset when profiler is already active. So silently no-op.
        if statprof.state.profile_level == 0:
            statprof.reset(freq)
    else:
        ui.warn(_("invalid sampling frequency '%s' - ignoring\n") % freq)

    statprof.start(mechanism='thread')

    try:
        yield
    finally:
        data = statprof.stop()

        profformat = ui.config('profiling', 'statformat', 'hotpath')

        formats = {
            'byline': statprof.DisplayFormats.ByLine,
            'bymethod': statprof.DisplayFormats.ByMethod,
            'hotpath': statprof.DisplayFormats.Hotpath,
            'json': statprof.DisplayFormats.Json,
            'chrome': statprof.DisplayFormats.Chrome,
        }

        if profformat in formats:
            displayformat = formats[profformat]
        else:
            ui.warn(_('unknown profiler output format: %s\n') % profformat)
            displayformat = statprof.DisplayFormats.Hotpath

        kwargs = {}

        def fraction(s):
            if s.endswith('%'):
                v = float(s[:-1]) / 100
            else:
                v = float(s)
            if 0 <= v <= 1:
                return v
            raise ValueError(s)

        if profformat == 'chrome':
            showmin = ui.configwith(fraction, 'profiling', 'showmin', 0.005)
            showmax = ui.configwith(fraction, 'profiling', 'showmax', 0.999)
            kwargs.update(minthreshold=showmin, maxthreshold=showmax)

        statprof.display(fp, data=data, format=displayformat, **kwargs)

@contextlib.contextmanager
def profile(ui):
    """Start profiling.

    Profiling is active when the context manager is active. When the context
    manager exits, profiling results will be written to the configured output.
    """
    profiler = encoding.environ.get('HGPROF')
    proffn = None
    if profiler is None:
        profiler = ui.config('profiling', 'type', default='stat')
    if profiler not in ('ls', 'stat', 'flame'):
        # try load profiler from extension with the same name
        proffn = _loadprofiler(ui, profiler)
        if proffn is None:
            ui.warn(_("unrecognized profiler '%s' - ignored\n") % profiler)
            profiler = 'stat'

    output = ui.config('profiling', 'output')

    if output == 'blackbox':
        fp = util.stringio()
    elif output:
        path = ui.expandpath(output)
        fp = open(path, 'wb')
    else:
        fp = ui.ferr

    try:
        if proffn is not None:
            pass
        elif profiler == 'ls':
            proffn = lsprofile
        elif profiler == 'flame':
            proffn = flameprofile
        else:
            proffn = statprofile

        with proffn(ui, fp):
            yield

    finally:
        if output:
            if output == 'blackbox':
                val = 'Profile:\n%s' % fp.getvalue()
                # ui.log treats the input as a format string,
                # so we need to escape any % signs.
                val = val.replace('%', '%%')
                ui.log('profile', val)
            fp.close()

@contextlib.contextmanager
def maybeprofile(ui):
    """Profile if enabled, else do nothing.

    This context manager can be used to optionally profile if profiling
    is enabled. Otherwise, it does nothing.

    The purpose of this context manager is to make calling code simpler:
    just use a single code path for calling into code you may want to profile
    and this function determines whether to start profiling.
    """
    if ui.configbool('profiling', 'enabled'):
        with profile(ui):
            yield
    else:
        yield