annotate mercurial/profiling.py @ 52155:74e16d8ca5f3 stable tip

tests: disable a section of `test-hgrc.t` that may hit a zeroconf bug

This effectively re-disables the same test as cce9e7d2fb92, but unconditionally
because it's not a pyoxidizer-specific problem (see below and 997c9b2069d1).

I can run the test locally fine, with the same venv as CI is using, and have had
multiple CI runs that don't hit this.  But one failed with this:

    --- /private/tmp/mercurial-ci/tests/test-hgrc.t
    +++ /private/tmp/mercurial-ci/tests/test-hgrc.t.err
    @@ -305,5 +305,17 @@
       [255]

       $ HGRCSKIPREPO=1 hg paths --config extensions.zeroconf=
    +  Traceback (most recent call last):
    +    File "/private/tmp/hgtests.7idf706t/install/lib/python/hgext/zeroconf/Zeroconf.py", line 966, in run
    +      self.readers[sock].handle_read()
    +    File "/private/tmp/hgtests.7idf706t/install/lib/python/hgext/zeroconf/Zeroconf.py", line 1020, in handle_read
    +      msg = DNSIncoming(data)
    +    File "/private/tmp/hgtests.7idf706t/install/lib/python/hgext/zeroconf/Zeroconf.py", line 537, in __init__
    +      self.readOthers()
    +    File "/private/tmp/hgtests.7idf706t/install/lib/python/hgext/zeroconf/Zeroconf.py", line 650, in readOthers
    +      self.readCharacterString(),
    +    File "/private/tmp/hgtests.7idf706t/install/lib/python/hgext/zeroconf/Zeroconf.py", line 584, in readCharacterString
    +      length = ord(self.data[self.offset])
    +  TypeError: ord() expected string of length 1, but int found
       foo = $TESTTMP/bar

The zeroconf extension has bytes vs str problems that are obvious from
inspection alone, and nobody has complained, so I'm not going to let this block
getting CI for macOS up and running.  Given that it's in the packet read code,
I suspect that this 1) requires something on the network to speak mDNS, and 2)
it is a timing issue if this is seen or not.  (The bytes vs str issue itself is
real, but only happen if a response is received quickly.)

# 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 annotations

import contextlib
import os
import signal
import subprocess
import sys

from .i18n import _
from .pycompat import (
    open,
)
from . import (
    encoding,
    error,
    extensions,
    pycompat,
    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(b'profiling', b'format')
    field = ui.config(b'profiling', b'sort')
    limit = ui.configint(b'profiling', b'limit')
    climit = ui.configint(b'profiling', b'nested')

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

    try:
        from . import lsprof
    except ImportError:
        raise error.Abort(
            _(
                b'lsprof not available - install from '
                b'http://codespeak.net/svn/user/arigo/hack/misc/lsprof/'
            )
        )
    p = lsprof.Profiler()
    try:
        p.enable(subcalls=True)
    except ValueError as exc:
        if str(exc) != "Another profiling tool is already active":
            raise
        if not hasattr(sys, "monitoring"):
            raise
        # python >=3.12 prevent more than one profiler to run at the same
        # time, tries to improve the report to help the user understand
        # what is going on.
        other_tool_name = sys.monitoring.get_tool(sys.monitoring.PROFILER_ID)
        if other_tool_name == "cProfile":
            msg = b'cannot recursively call `lsprof`'
            raise error.Abort(msg) from None
        else:
            tool = b'<unknown>'
            if other_tool_name:
                tool = encoding.strtolocal(other_tool_name)
            m = b'failed to start "lsprofile"; another profiler already running: %s'
            raise error.Abort(_(m) % tool) from None
    try:
        yield
    finally:
        p.disable()

        if format == b'kcachegrind':
            from . import lsprofcalltree

            calltree = lsprofcalltree.KCacheGrind(p)
            calltree.output(fp)
        else:
            # format == 'text'
            stats = lsprof.Stats(p.getstats())
            stats.sort(pycompat.sysstr(field))
            stats.pprint(limit=limit, file=fp, climit=climit)
        fp.flush()


@contextlib.contextmanager
def flameprofile(ui, fp):
    try:
        from flamegraph import flamegraph  # pytype: disable=import-error
    except ImportError:
        raise error.Abort(
            _(
                b'flamegraph not available - install from '
                b'https://github.com/evanhempel/python-flamegraph'
            )
        )
    # developer config: profiling.freq
    freq = ui.configint(b'profiling', b'freq')
    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()
        m = b'Collected %d stack frames (%d unique) in %2.2f seconds.'
        m %= (
            (
                util.timer() - start_time,
                thread.num_frames(),
                thread.num_frames(unique=True),
            ),
        )
        print(m, flush=True)


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

    freq = ui.configint(b'profiling', b'freq')
    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(_(b"invalid sampling frequency '%s' - ignoring\n") % freq)

    track = ui.config(
        b'profiling', b'time-track', pycompat.iswindows and b'cpu' or b'real'
    )
    statprof.start(mechanism=b'thread', track=track)

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

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

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

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

        kwargs = {}

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

        if profformat == b'chrome':
            showmin = ui.configwith(fraction, b'profiling', b'showmin', 0.005)
            showmax = ui.configwith(fraction, b'profiling', b'showmax')
            kwargs.update(minthreshold=showmin, maxthreshold=showmax)
        elif profformat == b'hotpath':
            # inconsistent config: profiling.showmin
            limit = ui.configwith(fraction, b'profiling', b'showmin', 0.05)
            kwargs['limit'] = limit
            showtime = ui.configbool(b'profiling', b'showtime')
            kwargs['showtime'] = showtime

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


@contextlib.contextmanager
def pyspy_profile(ui, fp):
    exe = ui.config(b'profiling', b'py-spy.exe')

    freq = ui.configint(b'profiling', b'py-spy.freq')

    format = ui.config(b'profiling', b'py-spy.format')

    fd = fp.fileno()

    output_path = "/dev/fd/%d" % (fd)

    my_pid = os.getpid()

    cmd = [
        exe,
        "record",
        "--pid",
        str(my_pid),
        "--native",
        "--rate",
        str(freq),
        "--output",
        output_path,
    ]

    if format:
        cmd.extend(["--format", format])

    proc = subprocess.Popen(
        cmd,
        pass_fds={fd},
        stdout=subprocess.PIPE,
    )

    _ = proc.stdout.readline()

    try:
        yield
    finally:
        os.kill(proc.pid, signal.SIGINT)
        proc.communicate()


class profile:
    """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.
    """

    def __init__(self, ui, enabled=True):
        self._ui = ui
        self._output = None
        self._fp = None
        self._fpdoclose = True
        self._flushfp = None
        self._profiler = None
        self._enabled = enabled
        self._entered = False
        self._started = False

    def __enter__(self):
        self._entered = True
        if self._enabled:
            self.start()
        return self

    def start(self):
        """Start profiling.

        The profiling will stop at the context exit.

        If the profiler was already started, this has no effect."""
        if not self._entered:
            raise error.ProgrammingError(b'use a context manager to start')
        if self._started:
            return
        self._started = True
        profiler = encoding.environ.get(b'HGPROF')
        proffn = None
        if profiler is None:
            profiler = self._ui.config(b'profiling', b'type')
        if profiler not in (b'ls', b'stat', b'flame', b'py-spy'):
            # try load profiler from extension with the same name
            proffn = _loadprofiler(self._ui, profiler)
            if proffn is None:
                self._ui.warn(
                    _(b"unrecognized profiler '%s' - ignored\n") % profiler
                )
                profiler = b'stat'

        self._output = self._ui.config(b'profiling', b'output')

        try:
            if self._output == b'blackbox':
                self._fp = util.stringio()
            elif self._output:
                path = util.expandpath(self._output)
                self._fp = open(path, b'wb')
            elif pycompat.iswindows:
                # parse escape sequence by win32print()
                class uifp:
                    def __init__(self, ui):
                        self._ui = ui

                    def write(self, data):
                        self._ui.write_err(data)

                    def flush(self):
                        self._ui.flush()

                self._fpdoclose = False
                self._fp = uifp(self._ui)
            else:
                self._fpdoclose = False
                self._fp = self._ui.ferr
                # Ensure we've flushed fout before writing to ferr.
                self._flushfp = self._ui.fout

            if proffn is not None:
                pass
            elif profiler == b'ls':
                proffn = lsprofile
            elif profiler == b'flame':
                proffn = flameprofile
            elif profiler == b'py-spy':
                proffn = pyspy_profile
            else:
                proffn = statprofile

            self._profiler = proffn(self._ui, self._fp)
            self._profiler.__enter__()
        except:  # re-raises
            self._closefp()
            raise

    def __exit__(self, exception_type, exception_value, traceback):
        propagate = None
        if self._profiler is not None:
            self._uiflush()
            propagate = self._profiler.__exit__(
                exception_type, exception_value, traceback
            )
            if self._output == b'blackbox':
                val = b'Profile:\n%s' % self._fp.getvalue()
                # ui.log treats the input as a format string,
                # so we need to escape any % signs.
                val = val.replace(b'%', b'%%')
                self._ui.log(b'profile', val)
        self._closefp()
        return propagate

    def _closefp(self):
        if self._fpdoclose and self._fp is not None:
            self._fp.close()

    def _uiflush(self):
        if self._flushfp:
            self._flushfp.flush()