# HG changeset patch
# User Pierre-Yves David <pierre-yves.david@octobus.net>
# Date 1495119565 -7200
# Node ID 0af6bb0bfdc3a90309d5ffac83d813818b41f21a
# Parent  783a74c60a5ef3cdef0a6f918168a50a0a20d339
discovery: log information about obshashrange

We augment the blackbox output to help with data gathering.

diff -r 783a74c60a5e -r 0af6bb0bfdc3 README
--- a/README	Thu May 18 11:29:27 2017 +0200
+++ b/README	Thu May 18 16:59:25 2017 +0200
@@ -121,7 +121,8 @@
    markers without changesets
  - obshashrange-cache: update incrementally in the (common) case of a
    transaction not affecting existing range,
- - obshashrange-cache: keep the cache mostly warm after each transaction.
+ - obshashrange-cache: keep the cache mostly warm after each transaction,
+ - blackbox: log more information about discovery and cache computation.
 
 6.1.1 - in progress
 -------------------
diff -r 783a74c60a5e -r 0af6bb0bfdc3 hgext3rd/evolve/obsdiscovery.py
--- a/hgext3rd/evolve/obsdiscovery.py	Thu May 18 11:29:27 2017 +0200
+++ b/hgext3rd/evolve/obsdiscovery.py	Thu May 18 16:59:25 2017 +0200
@@ -215,6 +215,7 @@
                      initialsamplesize=100,
                      fullsamplesize=200):
     missing = set()
+    starttime = util.timer()
 
     heads = local.revs('heads(%ld)', probeset)
     local.stablerange.warmup(local)
@@ -302,6 +303,11 @@
         ui.progress(_("comparing obsmarker with other"), querycount)
     ui.progress(_("comparing obsmarker with other"), None)
     local.obsstore.rangeobshashcache.save(local)
+    duration = util.timer() - starttime
+    logmsg = ('obsdiscovery, %d/%d mismatch'
+              ' - %d obshashrange queries in %.4f seconds\n')
+    logmsg %= (len(missing), len(probeset), querycount, duration)
+    ui.log('evoext-obsdiscovery', logmsg)
     return sorted(missing)
 
 def _queryrange(ui, repo, remote, allentries):
diff -r 783a74c60a5e -r 0af6bb0bfdc3 tests/test-discovery-obshashrange.t
--- a/tests/test-discovery-obshashrange.t	Thu May 18 11:29:27 2017 +0200
+++ b/tests/test-discovery-obshashrange.t	Thu May 18 16:59:25 2017 +0200
@@ -279,6 +279,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete ffffffffffffffffffffffffffffffffffffffff 45f8b879de922f6a6e620ba04205730335b6fc7e exited 0 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push -f (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obsdiscovery, 0/5 mismatch - 1 obshashrange queries in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push -f exited 0 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log -G (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> writing .hg/cache/tags2-visible with 0 tags (glob)
@@ -301,6 +302,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (0r, 1o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobsolete 22222222222222222bbbbbbbbbbbbb2222222222 2dc09a01254db841290af0538aa52f6f52c776e3 exited 0 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obsdiscovery, 2/6 mismatch - 1 obshashrange queries in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push exited 1 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> blackbox (glob)
   $ rm .hg/blackbox.log
@@ -383,6 +385,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' exited 0 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r 6 (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obsdiscovery, 2/6 mismatch - 1 obshashrange queries in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obshashcache reset - new markers affect cached ranges (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (2r, 3o) (glob)
@@ -468,6 +471,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r6)' (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r6)' exited 0 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r f69452c5b1af6cbaaa56ef50cf94fff5bcc6ca23 (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obsdiscovery, 2/7 mismatch - 1 obshashrange queries in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obshashcache reset - new markers affect cached ranges (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (0r, 2o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (0r, 2o) (glob)
@@ -493,6 +497,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> log --hidden --template '{node}\n' --rev 'desc(r4)' exited 0 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull -r bebd167eb94d257ace0e814aeb98e6972ed2970d (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obsdiscovery, 1/5 mismatch - 1 obshashrange queries in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obshashcache reset - new markers affect cached ranges (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (0r, 1o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (0r, 1o) (glob)
@@ -536,6 +541,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' exited 0 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obsdiscovery, 0/8 mismatch - 1 obshashrange queries in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (1r, 1o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (1r, 1o) (glob)
@@ -584,6 +590,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (8r, 12o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' exited 0 after *.?? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> pull (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obsdiscovery, 0/8 mismatch - 1 obshashrange queries in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (1r, 1o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> 1 incoming changes - new heads: 4de32a90b66c (glob)