discovery: log information about obshashrange
We augment the blackbox output to help with data gathering.
--- 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
-------------------
--- 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):
--- 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)