comparison mercurial/extensions.py @ 39511:1ab185c78cc3

extension: add a summary of total loading time per extension

Differential Revision: https://phab.mercurial-scm.org/D4513

39510:340170192874

        o = getattr(mod, t, None)
        if o:
            _rejectunicode(t, o._table)
    _validatecmdtable(ui, getattr(mod, 'cmdtable', {}))

def load(ui, name, path, log=lambda *a: None):
    if name.startswith('hgext.') or name.startswith('hgext/'):
        shortname = name[6:]
    else:
        shortname = name
    if shortname in _builtin:

    log('  - loading extension: %r\n', shortname)
    _extensions[shortname] = None
    with util.timedcm('load extension %r', shortname) as stats:
        mod = _importext(name, path, bind(_reportimporterror, ui))
    log('  > %r extension loaded in %s\n', shortname, stats)

    # Before we do anything with the extension, check against minimum stated
    # compatibility. This gives extension authors a mechanism to have their
    # extensions short circuit when loaded with a known incompatible version
    # of Mercurial.

    if ui.configbool('devel', 'debug.extensions'):
        log = lambda msg, *values: ui.debug('debug.extensions: ',
            msg % values, label='debug.extensions')
    else:
        log = lambda *a, **kw: None
    result = ui.configitems("extensions")
    if whitelist is not None:
        result = [(k, v) for (k, v) in result if k in whitelist]
    newindex = len(_order)
    log('loading %sextensions\n', 'additional ' if newindex else '')

                    if name not in _disabledextensions:
                        log('  - skipping disabled extension: %r\n', name)
                    _disabledextensions[name] = path[1:]
                    continue
            try:
                load(ui, name, path, log)
            except Exception as inst:
                msg = stringutil.forcebytestr(inst)
                if path:
                    ui.warn(_("*** failed to import extension %s from %s: %s\n")
                            % (name, path, msg))

            with util.timedcm('uisetup %r', name) as stats:
                if not _runuisetup(name, ui):
                    log('    - the %r extension uisetup failed\n', name)
                    broken.add(name)
            log('  > uisetup for %r took %s\n', name, stats)
    log('> all uisetup took %s\n', alluisetupstats)

    log('- executing extsetup hooks\n')
    with util.timedcm('all extsetup') as allextetupstats:
        for name in _order[newindex:]:

            with util.timedcm('extsetup %r', name) as stats:
                if not _runextsetup(name, ui):
                    log('    - the %r extension extsetup failed\n', name)
                    broken.add(name)
            log('  > extsetup for %r took %s\n', name, stats)
    log('> all extsetup took %s\n', allextetupstats)

    for name in broken:
        log('    - disabling broken %r extension\n', name)
        _extensions[name] = None

        ('templatekeyword', templatekw, 'loadkeyword'),
    ]
    with util.timedcm('load registration objects') as stats:
        _loadextra(ui, newindex, extraloaders)
    log('> extension registration object loading took %s\n', stats)
    log('extension loading complete\n')

def _loadextra(ui, newindex, extraloaders):
    for name in _order[newindex:]:
        module = _extensions[name]

39511:1ab185c78cc3

        o = getattr(mod, t, None)
        if o:
            _rejectunicode(t, o._table)
    _validatecmdtable(ui, getattr(mod, 'cmdtable', {}))

def load(ui, name, path, log=lambda *a: None, loadingtime=None):
    if name.startswith('hgext.') or name.startswith('hgext/'):
        shortname = name[6:]
    else:
        shortname = name
    if shortname in _builtin:

    log('  - loading extension: %r\n', shortname)
    _extensions[shortname] = None
    with util.timedcm('load extension %r', shortname) as stats:
        mod = _importext(name, path, bind(_reportimporterror, ui))
    log('  > %r extension loaded in %s\n', shortname, stats)
    if loadingtime is not None:
        loadingtime[shortname] += stats.elapsed

    # Before we do anything with the extension, check against minimum stated
    # compatibility. This gives extension authors a mechanism to have their
    # extensions short circuit when loaded with a known incompatible version
    # of Mercurial.

    if ui.configbool('devel', 'debug.extensions'):
        log = lambda msg, *values: ui.debug('debug.extensions: ',
            msg % values, label='debug.extensions')
    else:
        log = lambda *a, **kw: None
    loadingtime = collections.defaultdict(int)
    result = ui.configitems("extensions")
    if whitelist is not None:
        result = [(k, v) for (k, v) in result if k in whitelist]
    newindex = len(_order)
    log('loading %sextensions\n', 'additional ' if newindex else '')

                    if name not in _disabledextensions:
                        log('  - skipping disabled extension: %r\n', name)
                    _disabledextensions[name] = path[1:]
                    continue
            try:
                load(ui, name, path, log, loadingtime)
            except Exception as inst:
                msg = stringutil.forcebytestr(inst)
                if path:
                    ui.warn(_("*** failed to import extension %s from %s: %s\n")
                            % (name, path, msg))

            with util.timedcm('uisetup %r', name) as stats:
                if not _runuisetup(name, ui):
                    log('    - the %r extension uisetup failed\n', name)
                    broken.add(name)
            log('  > uisetup for %r took %s\n', name, stats)
            loadingtime[name] += stats.elapsed
    log('> all uisetup took %s\n', alluisetupstats)

    log('- executing extsetup hooks\n')
    with util.timedcm('all extsetup') as allextetupstats:
        for name in _order[newindex:]:

            with util.timedcm('extsetup %r', name) as stats:
                if not _runextsetup(name, ui):
                    log('    - the %r extension extsetup failed\n', name)
                    broken.add(name)
            log('  > extsetup for %r took %s\n', name, stats)
            loadingtime[name] += stats.elapsed
    log('> all extsetup took %s\n', allextetupstats)

    for name in broken:
        log('    - disabling broken %r extension\n', name)
        _extensions[name] = None

        ('templatekeyword', templatekw, 'loadkeyword'),
    ]
    with util.timedcm('load registration objects') as stats:
        _loadextra(ui, newindex, extraloaders)
    log('> extension registration object loading took %s\n', stats)

    # Report per extension loading time (except reposetup)
    for name in sorted(loadingtime):
        extension_msg = '> extension %s take a total of %s to load\n'
        log(extension_msg, name, util.timecount(loadingtime[name]))

    log('extension loading complete\n')

def _loadextra(ui, newindex, extraloaders):
    for name in _order[newindex:]:
        module = _extensions[name]