view hgext/logtoprocess.py @ 30155:b7a966ce89ed

changelog: disable delta chains This patch disables delta chains on changelogs. After this patch, new entries on changelogs - including existing changelogs - will be stored as the fulltext of that data (likely compressed). No delta computation will be performed. An overview of delta chains and data justifying this change follows. Revlogs try to store entries as a delta against a previous entry (either a parent revision in the case of generaldelta or the previous physical revision when not using generaldelta). Most of the time this is the correct thing to do: it frequently results in less CPU usage and smaller storage. Delta chains are most effective when the base revision being deltad against is similar to the current data. This tends to occur naturally for manifests and file data, since only small parts of each tend to change with each revision. Changelogs, however, are a different story. Changelog entries represent changesets/commits. And unless commits in a repository are homogonous (same author, changing same files, similar commit messages, etc), a delta from one entry to the next tends to be relatively large compared to the size of the entry. This means that delta chains tend to be short. How short? Here is the full vs delta revision breakdown on some real world repos: Repo % Full % Delta Max Length hg 45.8 54.2 6 mozilla-central 42.4 57.6 8 mozilla-unified 42.5 57.5 17 pypy 46.1 53.9 6 python-zstandard 46.1 53.9 3 (I threw in python-zstandard as an example of a repo that is homogonous. It contains a small Python project with changes all from the same author.) Contrast this with the manifest revlog for these repos, where 99+% of revisions are deltas and delta chains run into the thousands. So delta chains aren't as useful on changelogs. But even a short delta chain may provide benefits. Let's measure that. Delta chains may require less CPU to read revisions if the CPU time spent reading smaller deltas is less than the CPU time used to decompress larger individual entries. We can measure this via `hg perfrevlog -c -d 1` to iterate a revlog to resolve each revision's fulltext. Here are the results of that command on a repo using delta chains in its changelog and on a repo without delta chains: hg (forward) ! wall 0.407008 comb 0.410000 user 0.410000 sys 0.000000 (best of 25) ! wall 0.390061 comb 0.390000 user 0.390000 sys 0.000000 (best of 26) hg (reverse) ! wall 0.515221 comb 0.520000 user 0.520000 sys 0.000000 (best of 19) ! wall 0.400018 comb 0.400000 user 0.390000 sys 0.010000 (best of 25) mozilla-central (forward) ! wall 4.508296 comb 4.490000 user 4.490000 sys 0.000000 (best of 3) ! wall 4.370222 comb 4.370000 user 4.350000 sys 0.020000 (best of 3) mozilla-central (reverse) ! wall 5.758995 comb 5.760000 user 5.720000 sys 0.040000 (best of 3) ! wall 4.346503 comb 4.340000 user 4.320000 sys 0.020000 (best of 3) mozilla-unified (forward) ! wall 4.957088 comb 4.950000 user 4.940000 sys 0.010000 (best of 3) ! wall 4.660528 comb 4.650000 user 4.630000 sys 0.020000 (best of 3) mozilla-unified (reverse) ! wall 6.119827 comb 6.110000 user 6.090000 sys 0.020000 (best of 3) ! wall 4.675136 comb 4.670000 user 4.670000 sys 0.000000 (best of 3) pypy (forward) ! wall 1.231122 comb 1.240000 user 1.230000 sys 0.010000 (best of 8) ! wall 1.164896 comb 1.160000 user 1.160000 sys 0.000000 (best of 9) pypy (reverse) ! wall 1.467049 comb 1.460000 user 1.460000 sys 0.000000 (best of 7) ! wall 1.160200 comb 1.170000 user 1.160000 sys 0.010000 (best of 9) The data clearly shows that it takes less wall and CPU time to resolve revisions when there are no delta chains in the changelogs, regardless of the direction of traversal. Furthermore, not using a delta chain means that fulltext resolution in reverse is as fast as iterating forward. So not using delta chains on the changelog is a clear CPU win for reading operations. An example of a user-visible operation showing this speed-up is revset evaluation. Here are results for `hg perfrevset 'author(gps) or author(mpm)'`: hg ! wall 1.655506 comb 1.660000 user 1.650000 sys 0.010000 (best of 6) ! wall 1.612723 comb 1.610000 user 1.600000 sys 0.010000 (best of 7) mozilla-central ! wall 17.629826 comb 17.640000 user 17.600000 sys 0.040000 (best of 3) ! wall 17.311033 comb 17.300000 user 17.260000 sys 0.040000 (best of 3) What about 00changelog.i size? Repo Delta Chains No Delta Chains hg 7,033,250 6,976,771 mozilla-central 82,978,748 81,574,623 mozilla-unified 88,112,349 86,702,162 pypy 20,740,699 20,659,741 The data shows that removing delta chains from the changelog makes the changelog smaller. Delta chains are also used during changegroup generation. This operation essentially converts a series of revisions to one large delta chain. And changegroup generation is smart: if the delta in the revlog matches what the changegroup is emitting, it will reuse the delta instead of recalculating it. We can measure the impact removing changelog delta chains has on changegroup generation via `hg perfchangegroupchangelog`: hg ! wall 1.589245 comb 1.590000 user 1.590000 sys 0.000000 (best of 7) ! wall 1.788060 comb 1.790000 user 1.790000 sys 0.000000 (best of 6) mozilla-central ! wall 17.382585 comb 17.380000 user 17.340000 sys 0.040000 (best of 3) ! wall 20.161357 comb 20.160000 user 20.120000 sys 0.040000 (best of 3) mozilla-unified ! wall 18.722839 comb 18.720000 user 18.680000 sys 0.040000 (best of 3) ! wall 21.168075 comb 21.170000 user 21.130000 sys 0.040000 (best of 3) pypy ! wall 4.828317 comb 4.830000 user 4.820000 sys 0.010000 (best of 3) ! wall 5.415455 comb 5.420000 user 5.410000 sys 0.010000 (best of 3) The data shows eliminating delta chains makes the changelog part of changegroup generation slower. This is expected since we now have to compute deltas for revisions where we could recycle the delta before. It is worth putting this regression into context of overall changegroup times. Here is the rough total CPU time spent in changegroup generation for various repos while using delta chains on the changelog: Repo CPU Time (s) CPU Time w/ compression hg 4.50 7.05 mozilla-central 111.1 222.0 pypy 28.68 75.5 Before compression, removing delta chains from the changegroup adds ~4.4% overhead to hg changegroup generation, 1.3% to mozilla-central, and 2.0% to pypy. When you factor in zlib compression, these percentages are roughly divided by 2. While the increased CPU usage for changegroup generation is unfortunate, I think it is acceptable because the percentage is small, server operators (those likely impacted most by this) have other mechanisms to mitigate CPU consumption (namely reducing zlib compression level and pre-generated clone bundles), and because there is room to optimize this in the future. For example, we could use the nullid as the base revision, effectively encoding the full revision for each entry in the changegroup. When doing this, `hg perfchangegroupchangelog` nearly halves: mozilla-unified ! wall 21.168075 comb 21.170000 user 21.130000 sys 0.040000 (best of 3) ! wall 11.196461 comb 11.200000 user 11.190000 sys 0.010000 (best of 3) This looks very promising as a future optimization opportunity. It's worth that the changes in test-acl.t to the changegroup part size. This is because revision 6 in the changegroup had a delta chain of length 2 before and after this patch the base revision is nullrev. When the base revision is nullrev, cg2packer.deltaparent() hardcodes the *previous* revision from the changegroup as the delta parent. This caused the delta in the changegroup to switch base revisions, the delta to change, and the size to change accordingly. While the size increased in this case, I think sizes will remain the same on average, as the delta base for changelog revisions doesn't matter too much (as this patch shows). So, I don't consider this a regression.
author Gregory Szorc <gregory.szorc@gmail.com>
date Thu, 13 Oct 2016 12:50:27 +0200
parents d5883fd055c6
children 318a24b52eeb
line wrap: on
line source

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

Each positional argument to the method results in a `MSG[N]` key in the
environment, starting at 1 (so `MSG1`, `MSG2`, etc.). 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', 'baz', spam='eggs'), a script configured
for the `foo` event can expect an environment with `MSG1=bar`, `MSG2=baz`, and
`OPT_SPAM=eggs`.

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

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

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

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

"""

from __future__ import absolute_import

import itertools
import os
import platform
import subprocess
import sys

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

def uisetup(ui):
    if platform.system() == 'Windows':
        # no fork on Windows, but we can create a detached process
        # https://msdn.microsoft.com/en-us/library/windows/desktop/ms684863.aspx
        # No stdlib constant exists for this value
        DETACHED_PROCESS = 0x00000008
        _creationflags = DETACHED_PROCESS | subprocess.CREATE_NEW_PROCESS_GROUP

        def runshellcommand(script, env):
            # we can't use close_fds *and* redirect stdin. I'm not sure that we
            # need to because the detached process has no console connection.
            subprocess.Popen(
                script, shell=True, env=env, close_fds=True,
                creationflags=_creationflags)
    else:
        def runshellcommand(script, env):
            # double-fork to completely detach from the parent process
            # based on http://code.activestate.com/recipes/278731
            pid = os.fork()
            if pid:
                # parent
                return
            # subprocess.Popen() forks again, all we need to add is
            # flag the new process as a new session.
            if sys.version_info < (3, 2):
                newsession = {'preexec_fn': os.setsid}
            else:
                newsession = {'start_new_session': True}
            try:
                # connect stdin to devnull to make sure the subprocess can't
                # muck up that stream for mercurial.
                subprocess.Popen(
                    script, shell=True, stdin=open(os.devnull, 'r'), env=env,
                    close_fds=True, **newsession)
            finally:
                # mission accomplished, this child needs to exit and not
                # continue the hg process here.
                os._exit(0)

    class logtoprocessui(ui.__class__):
        def log(self, event, *msg, **opts):
            """Map log events to external commands

            Arguments are passed on as environment variables.

            """
            script = self.config('logtoprocess', event)
            if script:
                if msg:
                    # try to format the log message given the remaining
                    # arguments
                    try:
                        # Python string formatting with % either uses a
                        # dictionary *or* tuple, but not both. If we have
                        # keyword options, assume we need a mapping.
                        formatted = msg[0] % (opts or msg[1:])
                    except (TypeError, KeyError):
                        # Failed to apply the arguments, ignore
                        formatted = msg[0]
                    messages = (formatted,) + msg[1:]
                else:
                    messages = msg
                # positional arguments are listed as MSG[N] keys in the
                # environment
                msgpairs = (
                    ('MSG{0:d}'.format(i), str(m))
                    for i, m in enumerate(messages, 1))
                # keyword arguments get prefixed with OPT_ and uppercased
                optpairs = (
                    ('OPT_{0}'.format(key.upper()), str(value))
                    for key, value in opts.iteritems())
                env = dict(itertools.chain(os.environ.items(),
                                           msgpairs, optpairs),
                           EVENT=event, HGPID=str(os.getpid()))
                # Connect stdin to /dev/null to prevent child processes messing
                # with mercurial's stdin.
                runshellcommand(script, env)
            return super(logtoprocessui, self).log(event, *msg, **opts)

    # Replace the class for this instance and all clones created from it:
    ui.__class__ = logtoprocessui