view contrib/hgperf @ 36528:72e487851a53

debugcommands: add debugwireproto command

We currently don't have a low-level mechanism for sending
arbitrary wire protocol commands. Having a generic and robust
mechanism for sending wire protocol commands, examining wire
data, etc would make it vastly easier to test the wire protocol
and debug server operation. This is a problem I've wanted a
solution for numerous times, especially recently as I've been
hacking on a new version of the wire protocol.

This commit establishes a `hg debugwireproto` command for sending
data to a peer.

The command invents a mini language for specifying actions to take.
This will enable a lot of flexibility for issuing commands and testing
variations for how commands are sent.

Right now, we only support low-level raw sends and receives. These
are probably the least valuable commands to intended users of this
command. But they are the most useful commands to implement to
bootstrap the feature (I've chosen to reimplement test-ssh-proto.t
using this command to prove its usefulness).

My eventual goal of `hg debugwireproto` is to allow calling wire
protocol commands with a human-friendly interface. Essentially,
people can type in a command name and arguments and
`hg debugwireproto` will figure out how to send that on the wire.
I'd love to eventually be able to save the server's raw response
to a file. This would allow us to e.g. call "getbundle" wire
protocol commands easily.

test-ssh-proto.t has been updated to use the new command in lieu
of piping directly to a server process. As part of the transition,
test behavior improved. Before, we piped all request data to the
server at once. Now, we have explicit control over the ordering of
operations. e.g. we can send one command, receive its response,
then send another command. This will allow us to more robustly
test race conditions, buffering behavior, etc.

There were some subtle changes in test behavior. For example,
previous behavior would often send trailing newlines to the server.
The new mechanism doesn't treat literal newlines specially and
requires newlines be escaped in the payload.

Because the new logging code is very low level, it is easy to
introduce race conditions in tests. For example, the number of bytes
returned by a read() may vary depending on load. This is why tests
make heavy use of "readline" for consuming data: the result of
that operation should be deterministic and not subject to race
conditions. There are still some uses of "readavailable." However,
those are only for reading from stderr. I was able to reproduce
timing issues with my system under load when using "readavailable"
globally. But if I "readline" to grab stdout, "readavailable"
appears to work deterministically for stderr. I think this is
because the server writes to stderr first. As long as the OS
delivers writes to pipes in the same order they were made, this
should work. If there are timing issues, we can introduce a
mechanism to readline from stderr.

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

#!/usr/bin/env python
#
# hgperf - measure performance of Mercurial commands
#
# Copyright 2014 Matt Mackall <[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.

'''measure performance of Mercurial commands

Using ``hgperf`` instead of ``hg`` measures performance of the target
Mercurial command. For example, the execution below measures
performance of :hg:`heads --topo`::

    $ hgperf heads --topo

All command output via ``ui`` is suppressed, and just measurement
result is displayed: see also "perf" extension in "contrib".

Costs of processing before dispatching to the command function like
below are not measured::

    - parsing command line (e.g. option validity check)
    - reading configuration files in

But ``pre-`` and ``post-`` hook invocation for the target command is
measured, even though these are invoked before or after dispatching to
the command function, because these may be required to repeat
execution of the target command correctly.
'''

import os
import sys

libdir = '@LIBDIR@'

if libdir != '@' 'LIBDIR' '@':
    if not os.path.isabs(libdir):
        libdir = os.path.join(os.path.dirname(os.path.realpath(__file__)),
                              libdir)
        libdir = os.path.abspath(libdir)
    sys.path.insert(0, libdir)

# enable importing on demand to reduce startup time
try:
    from mercurial import demandimport; demandimport.enable()
except ImportError:
    import sys
    sys.stderr.write("abort: couldn't find mercurial libraries in [%s]\n" %
                     ' '.join(sys.path))
    sys.stderr.write("(check your install and PYTHONPATH)\n")
    sys.exit(-1)

from mercurial import (
    dispatch,
    util,
)

def timer(func, title=None):
    results = []
    begin = util.timer()
    count = 0
    while True:
        ostart = os.times()
        cstart = util.timer()
        r = func()
        cstop = util.timer()
        ostop = os.times()
        count += 1
        a, b = ostart, ostop
        results.append((cstop - cstart, b[0] - a[0], b[1]-a[1]))
        if cstop - begin > 3 and count >= 100:
            break
        if cstop - begin > 10 and count >= 3:
            break
    if title:
        sys.stderr.write("! %s\n" % title)
    if r:
        sys.stderr.write("! result: %s\n" % r)
    m = min(results)
    sys.stderr.write("! wall %f comb %f user %f sys %f (best of %d)\n"
                     % (m[0], m[1] + m[2], m[1], m[2], count))

orgruncommand = dispatch.runcommand

def runcommand(lui, repo, cmd, fullargs, ui, options, d, cmdpats, cmdoptions):
    ui.pushbuffer()
    lui.pushbuffer()
    timer(lambda : orgruncommand(lui, repo, cmd, fullargs, ui,
                                 options, d, cmdpats, cmdoptions))
    ui.popbuffer()
    lui.popbuffer()

dispatch.runcommand = runcommand

dispatch.run()