copies: add a devel debug mode to trace what copy tracing does

copies: add a devel debug mode to trace what copy tracing does

Mercurial can spend a lot of time finding renames between two commits. Having
more information about that process help to understand what makes it slow in
an individual instance. (eg: many files vs 1 file, etc...)

--- a/mercurial/configitems.py	Tue Oct 02 17:34:34 2018 -0700
+++ b/mercurial/configitems.py	Fri Sep 07 11:16:06 2018 -0400
@@ -377,6 +377,9 @@
 coreconfigitem('devel', 'warn-config-unknown',
     default=None,
 )
+coreconfigitem('devel', 'debug.copies',
+    default=False,
+)
 coreconfigitem('devel', 'debug.extensions',
     default=False,
 )

--- a/mercurial/copies.py	Tue Oct 02 17:34:34 2018 -0700
+++ b/mercurial/copies.py	Fri Sep 07 11:16:06 2018 -0400
@@ -163,9 +163,17 @@
     """Like _forwardcopies(), but b.rev() cannot be None (working copy)"""
     # files might have to be traced back to the fctx parent of the last
     # one-side-only changeset, but not further back than that
-    limit = _findlimit(a._repo, a.rev(), b.rev())
+    repo = a._repo
+    debug = repo.ui.debugflag and repo.ui.configbool('devel', 'debug.copies')
+    dbg = repo.ui.debug
+    if debug:
+        dbg('debug.copies:    looking into rename from %s to %s\n'
+            % (a, b))
+    limit = _findlimit(repo, a.rev(), b.rev())
     if limit is None:
         limit = -1
+    if debug:
+        dbg('debug.copies:      search limit: %d\n' % limit)
     am = a.manifest()
 
     # find where new files came from
@@ -186,11 +194,20 @@
     missing = _computeforwardmissing(a, b, match=forwardmissingmatch)
 
     ancestrycontext = a._repo.changelog.ancestors([b.rev()], inclusive=True)
+
+    if debug:
+        dbg('debug.copies:      missing file to search: %d\n' % len(missing))
+
     for f in missing:
+        if debug:
+            dbg('debug.copies:        tracing file: %s\n' % f)
         fctx = b[f]
         fctx._ancestrycontext = ancestrycontext
+
         ofctx = _tracefile(fctx, am, limit)
         if ofctx:
+            if debug:
+                dbg('debug.copies:          rename of: %s\n' % ofctx._path)
             cm[f] = ofctx.path()
     return cm
 
@@ -226,13 +243,24 @@
 
 def pathcopies(x, y, match=None):
     """find {dst@y: src@x} copy mapping for directed compare"""
+    repo = x._repo
+    debug = repo.ui.debugflag and repo.ui.configbool('devel', 'debug.copies')
+    if debug:
+        repo.ui.debug('debug.copies: searching copies from %s to %s\n'
+                      % (x, y))
     if x == y or not x or not y:
         return {}
     a = y.ancestor(x)
     if a == x:
+        if debug:
+            repo.ui.debug('debug.copies: search mode: forward\n')
         return _forwardcopies(x, y, match=match)
     if a == y:
+        if debug:
+            repo.ui.debug('debug.copies: search mode: backward\n')
         return _backwardrenames(x, y)
+    if debug:
+        repo.ui.debug('debug.copies: search mode: combined\n')
     return _chain(x, y, _backwardrenames(x, a),
                   _forwardcopies(a, y, match=match))
 

--- a/tests/test-mv-cp-st-diff.t	Tue Oct 02 17:34:34 2018 -0700
+++ b/tests/test-mv-cp-st-diff.t	Fri Sep 07 11:16:06 2018 -0400
@@ -1666,4 +1666,18 @@
   @@ -0,0 +1,1 @@
   +change
 
+Check debug output for copy tracing
+
+  $ hg status --copies --rev 'desc(dev)' --rev . --config devel.debug.copies=yes --debug
+  debug.copies: searching copies from a51f36ab1704 to 7935fd48a8f9
+  debug.copies: search mode: forward
+  debug.copies:    looking into rename from a51f36ab1704 to 7935fd48a8f9
+  debug.copies:      search limit: 2
+  debug.copies:      missing file to search: 1
+  debug.copies:        tracing file: renamed
+  debug.copies:          rename of: f
+  A renamed
+    f
+  R f
+
   $ cd ..