contrib/debugcmdserver.py

procutil: avoid using os.fork() to implement runbgcommand

We ran into the following deadlock:

- some command creates an ssh peer, then raises without explicitly
  closing the peer (hg id + extension in our case)

- dispatch catches the exception, calls ui.log('commandfinish', ..)
  (the sshpeer is still not closed), which calls logtoprocess, which
  calls procutil.runbgcommand.

- in the child of runbgcommand's fork(), between the fork and the
  exec, the opening of file descriptors triggers a gc which runs the
  destructor for sshpeer, which waits on ssh's stderr being closed,
  which never happens since ssh's stderr is held open by the parent of
  the fork where said destructor hasn't run

Remotefilelog appears to have a hack around this deadlock as well.

I don't know if there's more subtlety to it, because even though the
problem is determistic, it is very fragile, so I didn't manage to
reduce it.

I can imagine three ways of tackling this problem:
1. don't run any python between fork and exec in runbgcommand
2. make the finalizer harmless after the fork
3. close the peer without relying on gc behavior

This commit goes with 1, as forking without exec'ing is tricky in
general in a language with gc finalizers. And maybe it's better in the
presence of rust threads. A future commit will try 2 or 3.

Performance wise: at low memory usage, it's an improvement. At higher
memory usage, it's about 2x faster than before when ensurestart=True,
but 2x slower when ensurestart=False. Not sure if that matters. The
reason for that last bit is that the subprocess.Popen always waits for
the execve to finish, and at high memory usage, execve is slow because
it deallocates the large page table. Numbers and script:

				 before after
    mem=1.0GB, ensurestart=True  52.1ms 26.0ms
    mem=1.0GB, ensurestart=False 14.7ms 26.0ms
    mem=0.5GB, ensurestart=True  23.2ms 11.2ms
    mem=0.5GB, ensurestart=False  6.2ms 11.3ms
    mem=0.2GB, ensurestart=True  15.7ms 7.4ms
    mem=0.2GB, ensurestart=False  4.3ms 8.1ms
    mem=0.0GB, ensurestart=True   2.3ms 0.7ms
    mem=0.0GB, ensurestart=False  0.8ms 0.8ms

    import time
    for memsize in [1_000_000_000, 500_000_000, 250_000_000, 0]:
        mem = 'a' * memsize
        for ensurestart in [True, False]:
            now = time.time()
            n = 100
            for i in range(n):
                procutil.runbgcommand([b'true'], {}, ensurestart=ensurestart)
            after = time.time()
            ms = (after - now) / float(n) * 1000
            print(f'mem={memsize / 1e9:.1f}GB, ensurestart={ensurestart} -> {ms:.1f}ms')

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

#!/usr/bin/env python3
#
# Dumps output generated by Mercurial's command server in a formatted style to a
# given file or stderr if '-' is specified. Output is also written in its raw
# format to stdout.
#
# $ ./hg serve --cmds pipe | ./contrib/debugcmdserver.py -
# o, 52   -> 'capabilities: getencoding runcommand\nencoding: UTF-8'

from __future__ import absolute_import, print_function
import struct
import sys

if len(sys.argv) != 2:
    print('usage: debugcmdserver.py FILE')
    sys.exit(1)

outputfmt = '>cI'
outputfmtsize = struct.calcsize(outputfmt)

if sys.argv[1] == '-':
    log = sys.stderr
else:
    log = open(sys.argv[1], 'a')


def read(size):
    data = sys.stdin.read(size)
    if not data:
        raise EOFError
    sys.stdout.write(data)
    sys.stdout.flush()
    return data


try:
    while True:
        header = read(outputfmtsize)
        channel, length = struct.unpack(outputfmt, header)
        log.write('%s, %-4d' % (channel, length))
        if channel in 'IL':
            log.write(' -> waiting for input\n')
        else:
            data = read(length)
            log.write(' -> %r\n' % data)
        log.flush()
except EOFError:
    pass
finally:
    if log != sys.stderr:
        log.close()