view mercurial/loggingutil.py @ 48687:f8f2ecdde4b5

branchmap: skip obsolete revisions while computing heads

It's time to make this part of core Mercurial obsolescence-aware.

Not considering obsolete revisions when computing heads is clearly what
Mercurial should do. But there are a couple of small issues:

- Let's say tip of the repo is obsolete. There are two ways of finding tiprev
  for branchcache (both are in use): looking at input data for update() and
  looking at computed heads after update(). Previously, repo tip would be
  tiprev of the branchcache. With this patch, an obsolete revision can no
  longer be tiprev. And depending on what way we use for finding tiprev (input
  data vs computed heads) we'll get a different result. This is relevant when
  recomputing cache key from cache contents, and may lead to updating cache for
  obsolete revisions multiple times (not from scratch, because it still would
  be considered valid for a subset of revisions in the repo).

- If all commits on a branch are obsolete, the branchcache will include that
  branch, but the list of heads will be empty (that's why there's now `if not
  heads` when recomputing tiprev/tipnode from cache contents). Having an entry
  for every branch is currently required for notify extension (and
  test-notify.t to pass), because notify doesn't handle revsets in its
  subscription config very well and will throw an error if e.g. a branch
  doesn't exist.

- Cloning static HTTP repos may try to stat() a non-existent obsstore file. The
  issue is that we now care about obsolescence during clone, but statichttpvfs
  doesn't implement a stat method, so a regular vfs.stat() is used, and it
  assumes that file is local and calls os.stat().  During a clone, we're trying
  to stat() .hg/store/obsstore, but in static HTTP case we provide a literal
  URL to the obsstore file on the remote as if it were a local file path. On
  windows it actually results in a failure in test-static-http.t.

The first issue is going to be addressed in a series dedicated to making sure
branchcache is properly and timely written on disk (it wasn't perfect even
before this patch, but there aren't enough tests to demonstrate that). The
second issue will be addressed in a future patch for notify extension that will
make it not raise an exception if a branch doesn't exist. And the third one was
partially addressed in the previous patch in this series and will be properly
fixed in a future patch when this series is accepted.

filteredhash() grows a keyword argument to make sure that branchcache is also
invalidated when there are new obsolete revisions in its repo view. This way
the on-disk cache format is unchanged and compatible between versions (although
it will obviously be recomputed when switching versions before/after this patch
and the repo has obsolete revisions).

There's one test that uses plain `hg up` without arguments while updated to a
pruned commit. To make this test pass, simply return current working directory
parent. Later in this series this code will be replaced by what prune command
does: updating to the closest non-obsolete ancestor.

Test changes:

test-branch-change.t: update branch head and cache update message. The head of
default listed in hg heads is changed because revision 2 was rewritten as 7,
and 1 is the closest ancestor on the same branch, so it's the head of default
now.

The cache invalidation message appears now because of the cache hash change,
since we're now accounting for obsolete revisions. Here's some context:

"served.hidden" repo filter means everything is visible (no filtered
revisions), so before this series branch2-served.hidden file would not contain
any cache hash, only revnum and node. Now it also has a hash when there are
obsolete changesets in the repo. The command that the message appears for is
changing branch of 5 and 6, which are now obsolete, so the cache hash changes.

In general, when cache is simply out-of-date, it can be updated using the old
version as a base. But if cache hash differs, then the cache for that
particular repo filter is recomputed (at least with the current
implementation). This is what happens here.

test-obsmarker-template.t: the pull reports 2 heads changed, but after that the
repo correctly sees only 1. The new message could be better, but it's still an
improvement over the previous one where hg pull suggested merging with an
obsolete revision.

test-obsolete.t: we can see these revisions in hg log --hidden, but they
shouldn't be considered heads even with --hidden.

test-rebase-obsolete{,2}.t: there were new heads created previously after
making new orphan changesets, but they weren't detected. Now we are properly
detecting and reporting them.

test-rebase-obsolete4.t: there's only one head now because the other head is
pruned and was falsely reported before.

test-static-http.t: add obsstore to the list of requested files. This file
doesn't exist on the remotes, but clients want it anyway (they get 404). This
is fine, because there are other nonexistent files that clients request, like
.hg/bookmarks or .hg/cache/tags2-served.

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

# loggingutil.py - utility for logging events
#
# Copyright 2010 Nicolas Dumazet
# Copyright 2013 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.

from __future__ import absolute_import

import errno

from . import (
    encoding,
    pycompat,
)

from .utils import (
    dateutil,
    procutil,
    stringutil,
)


def openlogfile(ui, vfs, name, maxfiles=0, maxsize=0):
    """Open log file in append mode, with optional rotation

    If maxsize > 0, the log file will be rotated up to maxfiles.
    """

    def rotate(oldpath, newpath):
        try:
            vfs.unlink(newpath)
        except OSError as err:
            if err.errno != errno.ENOENT:
                ui.debug(
                    b"warning: cannot remove '%s': %s\n"
                    % (newpath, encoding.strtolocal(err.strerror))
                )
        try:
            if newpath:
                vfs.rename(oldpath, newpath)
        except OSError as err:
            if err.errno != errno.ENOENT:
                ui.debug(
                    b"warning: cannot rename '%s' to '%s': %s\n"
                    % (newpath, oldpath, encoding.strtolocal(err.strerror))
                )

    if maxsize > 0:
        try:
            st = vfs.stat(name)
        except OSError:
            pass
        else:
            if st.st_size >= maxsize:
                path = vfs.join(name)
                for i in pycompat.xrange(maxfiles - 1, 1, -1):
                    rotate(
                        oldpath=b'%s.%d' % (path, i - 1),
                        newpath=b'%s.%d' % (path, i),
                    )
                rotate(oldpath=path, newpath=maxfiles > 0 and path + b'.1')
    return vfs(name, b'a', makeparentdirs=False)


def _formatlogline(msg):
    date = dateutil.datestr(format=b'%Y/%m/%d %H:%M:%S')
    pid = procutil.getpid()
    return b'%s (%d)> %s' % (date, pid, msg)


def _matchevent(event, tracked):
    return b'*' in tracked or event in tracked


class filelogger(object):
    """Basic logger backed by physical file with optional rotation"""

    def __init__(self, vfs, name, tracked, maxfiles=0, maxsize=0):
        self._vfs = vfs
        self._name = name
        self._trackedevents = set(tracked)
        self._maxfiles = maxfiles
        self._maxsize = maxsize

    def tracked(self, event):
        return _matchevent(event, self._trackedevents)

    def log(self, ui, event, msg, opts):
        line = _formatlogline(msg)
        try:
            with openlogfile(
                ui,
                self._vfs,
                self._name,
                maxfiles=self._maxfiles,
                maxsize=self._maxsize,
            ) as fp:
                fp.write(line)
        except IOError as err:
            ui.debug(
                b'cannot write to %s: %s\n'
                % (self._name, stringutil.forcebytestr(err))
            )


class fileobjectlogger(object):
    """Basic logger backed by file-like object"""

    def __init__(self, fp, tracked):
        self._fp = fp
        self._trackedevents = set(tracked)

    def tracked(self, event):
        return _matchevent(event, self._trackedevents)

    def log(self, ui, event, msg, opts):
        line = _formatlogline(msg)
        try:
            self._fp.write(line)
            self._fp.flush()
        except IOError as err:
            ui.debug(
                b'cannot write to %s: %s\n'
                % (
                    stringutil.forcebytestr(self._fp.name),
                    stringutil.forcebytestr(err),
                )
            )


class proxylogger(object):
    """Forward log events to another logger to be set later"""

    def __init__(self):
        self.logger = None

    def tracked(self, event):
        return self.logger is not None and self.logger.tracked(event)

    def log(self, ui, event, msg, opts):
        assert self.logger is not None
        self.logger.log(ui, event, msg, opts)