# HG changeset patch
# User Pierre-Yves David <pierre-yves.david@octobus.net>
# Date 1494947014 -7200
# Node ID 07725f25296bb4c4ed401257a4d913d14be108d2
# Parent  694494619795a81d9df548d8af221586a1b98823
stablerange: log time spent updating the stable range

diff --git a/hgext3rd/evolve/stablerange.py b/hgext3rd/evolve/stablerange.py
--- a/hgext3rd/evolve/stablerange.py
+++ b/hgext3rd/evolve/stablerange.py
@@ -263,6 +263,7 @@
         #
         # we use the revnumber as an approximation for depth
         ui = repo.ui
+        starttime = util.timer()
 
         if upto is None:
             upto = len(cl) - 1
@@ -308,6 +309,10 @@
         self._tiprev = upto
         self._tipnode = cl.node(upto)
 
+        duration = util.timer() - starttime
+        repo.ui.log('evoext-cache', 'updated stablerange cache in %.4f seconds\n',
+                    duration)
+
     def depthrev(self, repo, rev):
         repo = repo.unfiltered()
         cl = repo.changelog
diff --git a/tests/test-discovery-obshashrange.t b/tests/test-discovery-obshashrange.t
--- a/tests/test-discovery-obshashrange.t
+++ b/tests/test-discovery-obshashrange.t
@@ -168,6 +168,7 @@
   $ hg -R ../server blackbox
   * @0000000000000000000000000000000000000000 (*)> debugobshashrange --subranges --rev tip (glob)
   * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated stablerange cache in *.???? seconds (glob)
   * @0000000000000000000000000000000000000000 (*)> obscache is out of date, falling back to slower obsstore version (glob)
   * @0000000000000000000000000000000000000000 (*)> updated evo-ext-obshashrange in *.???? seconds (8r, 5o) (glob)
   * @0000000000000000000000000000000000000000 (*)> debugobshashrange --subranges --rev tip exited 0 after *.?? seconds (glob)
@@ -185,6 +186,7 @@
   * @0000000000000000000000000000000000000000 (*)> pull --rev 4 (glob)
   * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
   * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 1 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated stablerange cache in *.???? seconds (glob)
   * @0000000000000000000000000000000000000000 (*)> updated evo-ext-obshashrange in *.???? seconds (5r, 3o) (glob)
   * @0000000000000000000000000000000000000000 (*)> updated evo-ext-obscache in *.???? seconds (5r, 3o) (glob)
   * @0000000000000000000000000000000000000000 (*)> 5 incoming changes - new heads: bebd167eb94d (glob)
@@ -226,6 +228,7 @@
   * @0000000000000000000000000000000000000000 (*)> updated evo-ext-obscache in *.???? seconds (9r, 5o) (glob)
   * @0000000000000000000000000000000000000000 (*)> updated served branch cache in *.???? seconds (glob)
   * @0000000000000000000000000000000000000000 (*)> wrote served branch cache with 1 labels and 2 nodes (glob)
+  * @0000000000000000000000000000000000000000 (*)> updated stablerange cache in *.???? seconds (glob)
   * @0000000000000000000000000000000000000000 (*)> updated evo-ext-obshashrange in *.???? seconds (9r, 6o) (glob)
   * @0000000000000000000000000000000000000000 (*)> updated evo-ext-obscache in *.???? seconds (0r, 1o) (glob)
   * @0000000000000000000000000000000000000000 (*)> 1 incoming changes - new heads: 45f8b879de92 (glob)
@@ -303,6 +306,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push -f (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obscache is out of date, falling back to slower obsstore version (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> obscache is out of date, falling back to slower obsstore version (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (6r, 4o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (6r, 4o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> push -f exited 0 after *.?? seconds (glob)
@@ -412,6 +416,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (2r, 0o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated served branch cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> wrote served branch cache with 1 labels and 2 nodes (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (8r, 9o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (0r, 3o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> 2 incoming changes - new heads: f69452c5b1af (glob)
@@ -568,6 +573,7 @@
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (9r, 12o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated served branch cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> wrote served branch cache with 1 labels and 2 nodes (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (9r, 13o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (0r, 1o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> 1 incoming changes - new heads: 4de32a90b66c (glob)
@@ -608,11 +614,13 @@
   (run 'hg update' to get a working copy)
   $ hg blackbox
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> debugobshashrange --subranges --rev 'heads(all())' (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
   * @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 (*)> updated evo-ext-obshashrange in *.???? seconds (8r, 12o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (9r, 12o) (glob)
+  * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated stablerange cache in *.???? seconds (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obshashrange in *.???? seconds (9r, 13o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> updated evo-ext-obscache in *.???? seconds (0r, 1o) (glob)
   * @45f8b879de922f6a6e620ba04205730335b6fc7e (*)> 1 incoming changes - new heads: 4de32a90b66c (glob)