# HG changeset patch
# User Pierre-Yves David <pierre-yves.david@octobus.net>
# Date 2017-06-07 09:44:11
# Node ID 28240b75e880ee24b89789bb2d5f159354b52e2b
# Parent  43bda143e3b2a75a79df102ef228620425ccfcc4

discovery: log discovery result in non-trivial cases

We log the discovery summary, the number of roundtrips and the elapsed time.
This is useful to understand where slow push might come from when lloking at
the blackbox.

diff --git a/mercurial/setdiscovery.py b/mercurial/setdiscovery.py
--- a/mercurial/setdiscovery.py
+++ b/mercurial/setdiscovery.py
@@ -241,6 +241,9 @@ def findcommonheads(ui, local, remote,
     elapsed = util.timer() - start
     ui.progress(_('searching'), None)
     ui.debug("%d total queries in %.4fs\n" % (roundtrips, elapsed))
+    msg = 'found %d common and %d missing heads, %d roundtrips in %.4fs\n'
+    ui.log('discovery', msg, len(result), len(srvheadhashes), roundtrips,
+           elapsed)
 
     if not result and srvheadhashes != [nullid]:
         if abortwhenunrelated:
diff --git a/tests/test-setdiscovery.t b/tests/test-setdiscovery.t
--- a/tests/test-setdiscovery.t
+++ b/tests/test-setdiscovery.t
@@ -398,8 +398,13 @@ fixed in 86c35b7ae300:
   > unrandomsample = $TESTTMP/unrandomsample.py
   > EOF
 
-  $ hg -R r1 outgoing r2 -T'{rev} '
+  $ hg -R r1 outgoing r2 -T'{rev} ' --config extensions.blackbox=
   comparing with r2
   searching for changes
   101 102 103 104 105 106 107 108 109 110  (no-eol)
+  $ hg -R r1 --config extensions.blackbox= blackbox
+  * @5d0b986a083e0d91f116de4691e2aaa54d5bbec0 (*)> outgoing r2 '-T{rev} ' (glob)
+  * @5d0b986a083e0d91f116de4691e2aaa54d5bbec0 (*)> found 101 common and 101 missing heads, 2 roundtrips in *.????s (glob)
+  * @5d0b986a083e0d91f116de4691e2aaa54d5bbec0 (*)> -R r1 outgoing r2 '-T{rev} ' --config 'extensions.blackbox=' exited 0 after *.?? seconds (glob)
+  * @5d0b986a083e0d91f116de4691e2aaa54d5bbec0 (*)> blackbox (glob)
   $ cd ..