changeset 46110:d90f439ff19f

debugdiscovery: display the number of roundtrip used This is a good metric of the complexity of a discovery process. Differential Revision: https://phab.mercurial-scm.org/D9565
author Pierre-Yves David <pierre-yves.david@octobus.net>
date Fri, 11 Dec 2020 12:51:09 +0100
parents 2f357d053df2
children 9e24b3d8e896
files mercurial/debugcommands.py mercurial/setdiscovery.py mercurial/treediscovery.py tests/test-setdiscovery.t
diffstat 4 files changed, 60 insertions(+), 4 deletions(-) [+]
line wrap: on
line diff
--- a/mercurial/debugcommands.py	Fri Dec 11 13:39:56 2020 -0800
+++ b/mercurial/debugcommands.py	Fri Dec 11 12:51:09 2020 +0100
@@ -978,6 +978,7 @@
     # make sure tests are repeatable
     random.seed(int(opts[b'seed']))
 
+    data = {}
     if opts.get(b'old'):
 
         def doit(pushedrevs, remoteheads, remote=remote):
@@ -985,7 +986,7 @@
                 # enable in-client legacy support
                 remote = localrepo.locallegacypeer(remote.local())
             common, _in, hds = treediscovery.findcommonincoming(
-                repo, remote, force=True
+                repo, remote, force=True, audit=data
             )
             common = set(common)
             if not opts.get(b'nonheads'):
@@ -1007,7 +1008,7 @@
                 revs = scmutil.revrange(repo, pushedrevs)
                 nodes = [repo[r].node() for r in revs]
             common, any, hds = setdiscovery.findcommonheads(
-                ui, repo, remote, ancestorsof=nodes
+                ui, repo, remote, ancestorsof=nodes, audit=data
             )
             return common, hds
 
@@ -1042,7 +1043,6 @@
     common_initial_undecided = initial_undecided & common
     missing_initial_undecided = initial_undecided & missing
 
-    data = {}
     data[b'elapsed'] = t.elapsed
     data[b'nb-common-heads'] = len(heads_common)
     data[b'nb-common-heads-local'] = len(heads_common_local)
@@ -1068,6 +1068,7 @@
 
     # display discovery summary
     ui.writenoi18n(b"elapsed time:  %(elapsed)f seconds\n" % data)
+    ui.writenoi18n(b"round-trips:           %(total-roundtrips)9d\n" % data)
     ui.writenoi18n(b"heads summary:\n")
     ui.writenoi18n(b"  total common heads:  %(nb-common-heads)9d\n" % data)
     ui.writenoi18n(
--- a/mercurial/setdiscovery.py	Fri Dec 11 13:39:56 2020 -0800
+++ b/mercurial/setdiscovery.py	Fri Dec 11 12:51:09 2020 +0100
@@ -291,9 +291,14 @@
     abortwhenunrelated=True,
     ancestorsof=None,
     samplegrowth=1.05,
+    audit=None,
 ):
     """Return a tuple (common, anyincoming, remoteheads) used to identify
     missing nodes from or in remote.
+
+    The audit argument is an optional dictionnary that a caller can pass. it
+    will be updated with extra data about the discovery, this is useful for
+    debug.
     """
     start = util.timer()
 
@@ -379,6 +384,9 @@
 
     srvheadhashes, yesno = fheads.result(), fknown.result()
 
+    if audit is not None:
+        audit[b'total-roundtrips'] = 1
+
     if cl.tip() == nullid:
         if srvheadhashes != [nullid]:
             return [nullid], True, srvheadhashes
@@ -473,6 +481,9 @@
     missing = set(result) - set(knownsrvheads)
     ui.log(b'discovery', msg, len(result), len(missing), roundtrips, elapsed)
 
+    if audit is not None:
+        audit[b'total-roundtrips'] = roundtrips
+
     if not result and srvheadhashes != [nullid]:
         if abortwhenunrelated:
             raise error.Abort(_(b"repository is unrelated"))
--- a/mercurial/treediscovery.py	Fri Dec 11 13:39:56 2020 -0800
+++ b/mercurial/treediscovery.py	Fri Dec 11 12:51:09 2020 +0100
@@ -20,7 +20,7 @@
 )
 
 
-def findcommonincoming(repo, remote, heads=None, force=False):
+def findcommonincoming(repo, remote, heads=None, force=False, audit=None):
     """Return a tuple (common, fetch, heads) used to identify the common
     subset of nodes between repo and remote.
 
@@ -41,6 +41,9 @@
         with remote.commandexecutor() as e:
             heads = e.callcommand(b'heads', {}).result()
 
+    if audit is not None:
+        audit[b'total-roundtrips'] = 1
+
     if repo.changelog.tip() == nullid:
         base.add(nullid)
         if heads != [nullid]:
@@ -181,5 +184,7 @@
 
     progress.complete()
     repo.ui.debug(b"%d total queries\n" % reqcnt)
+    if audit is not None:
+        audit[b'total-roundtrips'] = reqcnt
 
     return base, list(fetch), heads
--- a/tests/test-setdiscovery.t	Fri Dec 11 13:39:56 2020 -0800
+++ b/tests/test-setdiscovery.t	Fri Dec 11 12:51:09 2020 +0100
@@ -44,6 +44,7 @@
   searching for changes
   unpruned common: 01241442b3c2 66f7d451a68b b5714e113bc0
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          2
       also local heads:          2
@@ -75,6 +76,7 @@
   searching for changes
   all local changesets known remotely
   elapsed time:  * seconds (glob)
+  round-trips:                   1
   heads summary:
     total common heads:          2
       also local heads:          2
@@ -106,6 +108,7 @@
   searching for changes
   all local changesets known remotely
   elapsed time:  * seconds (glob)
+  round-trips:                   1
   heads summary:
     total common heads:          1
       also local heads:          1
@@ -136,6 +139,7 @@
   searching for changes
   unpruned common: 01241442b3c2 b5714e113bc0
   elapsed time:  * seconds (glob)
+  round-trips:                   1
   heads summary:
     total common heads:          2
       also local heads:          1
@@ -167,6 +171,7 @@
   searching for changes
   all remote heads known locally
   elapsed time:  * seconds (glob)
+  round-trips:                   1
   heads summary:
     total common heads:          2
       also local heads:          1
@@ -198,6 +203,7 @@
   searching for changes
   all remote heads known locally
   elapsed time:  * seconds (glob)
+  round-trips:                   1
   heads summary:
     total common heads:          2
       also local heads:          1
@@ -235,6 +241,7 @@
   searching for changes
   unpruned common: bebd167eb94d
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          1
@@ -269,6 +276,7 @@
   query 2; still undecided: 29, sample size is: 29
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          1
@@ -303,6 +311,7 @@
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -333,6 +342,7 @@
   searching for changes
   unpruned common: 66f7d451a68b bebd167eb94d
   elapsed time:  * seconds (glob)
+  round-trips:                   4
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -367,6 +377,7 @@
   query 2; still undecided: 2, sample size is: 2
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -401,6 +412,7 @@
   query 2; still undecided: 2, sample size is: 2
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -437,6 +449,7 @@
   searching for changes
   unpruned common: 2dc09a01254d
   elapsed time:  * seconds (glob)
+  round-trips:                   4
   heads summary:
     total common heads:          1
       also local heads:          1
@@ -471,6 +484,7 @@
   query 2; still undecided: 29, sample size is: 29
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          1
@@ -505,6 +519,7 @@
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -535,6 +550,7 @@
   searching for changes
   unpruned common: 2dc09a01254d 66f7d451a68b
   elapsed time:  * seconds (glob)
+  round-trips:                   4
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -569,6 +585,7 @@
   query 2; still undecided: 29, sample size is: 29
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -603,6 +620,7 @@
   query 2; still undecided: 29, sample size is: 29
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -640,6 +658,7 @@
   searching for changes
   unpruned common: 66f7d451a68b
   elapsed time:  * seconds (glob)
+  round-trips:                   4
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -674,6 +693,7 @@
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -708,6 +728,7 @@
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -738,6 +759,7 @@
   searching for changes
   unpruned common: 66f7d451a68b
   elapsed time:  * seconds (glob)
+  round-trips:                   4
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -772,6 +794,7 @@
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -806,6 +829,7 @@
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -843,6 +867,7 @@
   searching for changes
   unpruned common: 66f7d451a68b
   elapsed time:  * seconds (glob)
+  round-trips:                   4
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -877,6 +902,7 @@
   query 2; still undecided: 51, sample size is: 51
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -911,6 +937,7 @@
   query 2; still undecided: 51, sample size is: 51
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -941,6 +968,7 @@
   searching for changes
   unpruned common: 66f7d451a68b
   elapsed time:  * seconds (glob)
+  round-trips:                   3
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -975,6 +1003,7 @@
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1009,6 +1038,7 @@
   query 2; still undecided: 31, sample size is: 31
   2 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   2
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1046,6 +1076,7 @@
   searching for changes
   unpruned common: 7ead0cba2838
   elapsed time:  * seconds (glob)
+  round-trips:                   4
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1083,6 +1114,7 @@
   query 3; still undecided: 31, sample size is: 31
   3 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   3
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1120,6 +1152,7 @@
   query 3; still undecided: 31, sample size is: 31
   3 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   3
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1150,6 +1183,7 @@
   searching for changes
   unpruned common: 7ead0cba2838
   elapsed time:  * seconds (glob)
+  round-trips:                   3
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1187,6 +1221,7 @@
   query 3; still undecided: 15, sample size is: 15
   3 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   3
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1224,6 +1259,7 @@
   query 3; still undecided: 15, sample size is: 15
   3 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   3
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1313,6 +1349,7 @@
   query 6; still undecided: 63, sample size is: 63
   6 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   6
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1349,6 +1386,7 @@
   query 3; still undecided: 3, sample size is: 3
   3 total queries in *.????s (glob)
   elapsed time:  * seconds (glob)
+  round-trips:                   3
   heads summary:
     total common heads:          1
       also local heads:          0
@@ -1476,6 +1514,7 @@
   comparing with $TESTTMP/ancestorsof/a
   searching for changes
   elapsed time:  * seconds (glob)
+  round-trips:                   1
   heads summary:
     total common heads:          1
       also local heads:          1