view hgext/logtoprocess.py @ 42354:dbd0fcca6dfc

discovery: slowly increase sampling size

Some pathological discovery runs can requires many roundtrip. When this happens
things can get very slow.

To make the algorithm more resilience again such pathological case. We slowly
increase the sample size with each roundtrip (+5%). This will have a negligible
impact on "normal" discovery with few roundtrips, but a large positive impact of
case with many roundtrips. Asking more question per roundtrip helps to reduce
the undecided set faster. Instead of reducing the undecided set a linear speed
(in the worst case), we reduce it as a guaranteed (small) exponential rate. The
data below show this slow ramp up in sample size:

round trip    |    1 |     5 |    10 |    20 |     50 |     100 |       130 |
sample size   |  200 |   254 |   321 |   517 |  2 199 |  25 123 |   108 549 |
covered nodes |  200 | 1 357 | 2 821 | 7 031 | 42 658 | 524 530 | 2 276 755 |

To be a bit more concrete, lets take a very pathological case as an example. We
are doing discovery from a copy of Mozilla-try to a more recent version of
mozilla-unified. Mozilla-unified heads are unknown to the mozilla-try repo and
there are over 1 million "missing" changesets. (the discovery is "local" to
avoid network interference)

Without this change, the discovery:
- last 1858 seconds (31 minutes),
- does 1700 round trip,
- asking about 340 000 nodes.

With this change, the discovery:
- last 218 seconds (3 minutes, 38 seconds a -88% improvement),
- does 94 round trip (-94%),
- asking about 344 211 nodes (+1%).

Of course, this is an extreme case (and 3 minutes is still slow). However this
give a good example of how this sample size increase act as a safety net
catching any bad situations.

We could image a steeper increase than 5%. For example 10% would give the
following number:

round trip    |    1 |     5 |    10 |     20 |     50  |        75 |        100 |
sample size   |  200 |   321 |   514 |  1 326 |  23 060 |   249 812 |  2 706 594 |
covered nodes |  200 | 1 541 | 3 690 | 12 671 | 251 871 | 2 746 254 | 29 770 966 |

In parallel, it is useful to understand these pathological cases and improve
them. However the current change provides a general purpose safety net to smooth
the impact of pathological cases.

To avoid issue with older http server, the increase in sample size only occurs
if the protocol has not limit on command argument size.

# logtoprocess.py - send ui.log() data to a subprocess
#
# Copyright 2016 Facebook, Inc.
#
# This software may be used and distributed according to the terms of the
# GNU General Public License version 2 or any later version.
"""send ui.log() data to a subprocess (EXPERIMENTAL)

This extension lets you specify a shell command per ui.log() event,
sending all remaining arguments to as environment variables to that command.

Positional arguments construct a log message, which is passed in the `MSG1`
environment variables. Each keyword argument is set as a `OPT_UPPERCASE_KEY`
variable (so the key is uppercased, and prefixed with `OPT_`). The original
event name is passed in the `EVENT` environment variable, and the process ID
of mercurial is given in `HGPID`.

So given a call `ui.log('foo', 'bar %s\n', 'baz', spam='eggs'), a script
configured for the `foo` event can expect an environment with `MSG1=bar baz`,
and `OPT_SPAM=eggs`.

Scripts are configured in the `[logtoprocess]` section, each key an event name.
For example::

  [logtoprocess]
  commandexception = echo "$MSG1" > /var/log/mercurial_exceptions.log

would log the warning message and traceback of any failed command dispatch.

Scripts are run asynchronously as detached daemon processes; mercurial will
not ensure that they exit cleanly.

"""

from __future__ import absolute_import

import os

from mercurial.utils import (
    procutil,
)

# Note for extension authors: ONLY specify testedwith = 'ships-with-hg-core' for
# extensions which SHIP WITH MERCURIAL. Non-mainline extensions should
# be specifying the version(s) of Mercurial they are tested with, or
# leave the attribute unspecified.
testedwith = 'ships-with-hg-core'

class processlogger(object):
    """Map log events to external commands

    Arguments are passed on as environment variables.
    """

    def __init__(self, ui):
        self._scripts = dict(ui.configitems(b'logtoprocess'))

    def tracked(self, event):
        return bool(self._scripts.get(event))

    def log(self, ui, event, msg, opts):
        script = self._scripts[event]
        env = {
            b'EVENT': event,
            b'HGPID': os.getpid(),
            b'MSG1': msg,
        }
        # keyword arguments get prefixed with OPT_ and uppercased
        env.update((b'OPT_%s' % key.upper(), value)
                   for key, value in opts.items())
        fullenv = procutil.shellenviron(env)
        procutil.runbgcommand(script, fullenv, shell=True)

def uipopulate(ui):
    ui.setlogger(b'logtoprocess', processlogger(ui))