tags: explicitly log which tags cache file is being written
authorGregory Szorc <gregory.szorc@gmail.com>
Thu, 16 Apr 2015 11:59:36 -0400
changeset 24763 a698e088ad29
parent 24762 1062663808ce
child 24764 4dcd55802237
tags: explicitly log which tags cache file is being written We now have multiple tags cache files. Record exactly which file is being written. This should help aid debugging into performance issues with any single filter.
mercurial/tags.py
tests/test-blackbox.t
tests/test-mq.t
tests/test-obsolete-tag-cache.t
tests/test-tags.t
--- a/mercurial/tags.py	Thu Apr 16 11:54:13 2015 -0400
+++ b/mercurial/tags.py	Thu Apr 16 11:59:36 2015 -0400
@@ -355,13 +355,14 @@
     return (repoheads, cachefnode, valid, None, True)
 
 def _writetagcache(ui, repo, valid, cachetags):
+    filename = _filename(repo)
     try:
-        cachefile = repo.vfs(_filename(repo), 'w', atomictemp=True)
+        cachefile = repo.vfs(filename, 'w', atomictemp=True)
     except (OSError, IOError):
         return
 
-    ui.log('tagscache', 'writing tags cache file with %d tags\n',
-           len(cachetags))
+    ui.log('tagscache', 'writing .hg/%s with %d tags\n',
+           filename, len(cachetags))
 
     if valid[2]:
         cachefile.write('%d %s %s\n' % (valid[0], hex(valid[1]), hex(valid[2])))
--- a/tests/test-blackbox.t	Thu Apr 16 11:54:13 2015 -0400
+++ b/tests/test-blackbox.t	Thu Apr 16 11:59:36 2015 -0400
@@ -123,7 +123,7 @@
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ hg blackbox -l 5
   1970/01/01 00:00:00 bob> update
-  1970/01/01 00:00:00 bob> writing tags cache file with 0 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 0 tags
   1970/01/01 00:00:00 bob> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob)
   1970/01/01 00:00:00 bob> exthook-update: echo hooked finished in * seconds (glob)
   1970/01/01 00:00:00 bob> update exited 0 after * seconds (glob)
--- a/tests/test-mq.t	Thu Apr 16 11:54:13 2015 -0400
+++ b/tests/test-mq.t	Thu Apr 16 11:59:36 2015 -0400
@@ -311,12 +311,12 @@
 qpush with dump of tag cache
 Dump the tag cache to ensure that it has exactly one head after qpush.
 
-  $ rm -f .hg/cache/tags-visible
+  $ rm -f .hg/cache/tags2-visible
   $ hg tags > /dev/null
 
-.hg/cache/tags-visible (pre qpush):
+.hg/cache/tags2-visible (pre qpush):
 
-  $ cat .hg/cache/tags-visible
+  $ cat .hg/cache/tags2-visible
   1 [\da-f]{40} (re)
   $ hg qpush
   applying test.patch
@@ -325,9 +325,9 @@
   2: draft
   $ hg tags > /dev/null
 
-.hg/cache/tags-visible (post qpush):
+.hg/cache/tags2-visible (post qpush):
 
-  $ cat .hg/cache/tags-visible
+  $ cat .hg/cache/tags2-visible
   2 [\da-f]{40} (re)
   $ checkundo qpush
   $ cd ..
--- a/tests/test-obsolete-tag-cache.t	Thu Apr 16 11:54:13 2015 -0400
+++ b/tests/test-obsolete-tag-cache.t	Thu Apr 16 11:59:36 2015 -0400
@@ -70,7 +70,7 @@
   $ hg blackbox -l 4
   1970/01/01 00:00:00 bob> tags
   1970/01/01 00:00:00 bob> 2/2 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 2 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 2 tags
   1970/01/01 00:00:00 bob> tags exited 0 after * seconds (glob)
 
 Hiding another changeset should cause the filtered hash to change
@@ -89,7 +89,7 @@
   $ hg blackbox -l 4
   1970/01/01 00:00:00 bob> tags
   1970/01/01 00:00:00 bob> 1/1 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 1 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 1 tags
   1970/01/01 00:00:00 bob> tags exited 0 after * seconds (glob)
 
 Resolving tags on an unfiltered repo writes a separate tags cache
@@ -109,5 +109,5 @@
   $ hg blackbox -l 4
   1970/01/01 00:00:00 bob> --hidden tags
   1970/01/01 00:00:00 bob> 2/2 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 3 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2 with 3 tags
   1970/01/01 00:00:00 bob> --hidden tags exited 0 after * seconds (glob)
--- a/tests/test-tags.t	Thu Apr 16 11:54:13 2015 -0400
+++ b/tests/test-tags.t	Thu Apr 16 11:59:36 2015 -0400
@@ -133,7 +133,7 @@
   1970/01/01 00:00:00 bob> identify
   1970/01/01 00:00:00 bob> writing 48 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob> 0/1 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 1 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 1 tags
   1970/01/01 00:00:00 bob> identify exited 0 after ?.?? seconds (glob)
 
 Failure to acquire lock results in no write
@@ -146,7 +146,7 @@
   1970/01/01 00:00:00 bob> identify
   1970/01/01 00:00:00 bob> not writing .hg/cache/hgtagsfnodes1 because lock held
   1970/01/01 00:00:00 bob> 0/1 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 1 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 1 tags
   1970/01/01 00:00:00 bob> identify exited 0 after * seconds (glob)
 
   $ fnodescacheexists
@@ -343,7 +343,7 @@
   1970/01/01 00:00:00 bob> tags
   1970/01/01 00:00:00 bob> writing 24 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob> 2/3 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 1 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 1 tags
   1970/01/01 00:00:00 bob> tags exited 0 after * seconds (glob)
 
 #if unix-permissions no-root
@@ -363,7 +363,7 @@
   1970/01/01 00:00:00 bob> tags
   1970/01/01 00:00:00 bob> couldn't write cache/hgtagsfnodes1: [Errno 13] Permission denied: '$TESTTMP/t2/.hg/cache/hgtagsfnodes1'
   1970/01/01 00:00:00 bob> 2/3 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 1 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 1 tags
   1970/01/01 00:00:00 bob> tags exited 0 after * seconds (glob)
 
   $ chmod a+w .hg/cache/hgtagsfnodes1
@@ -378,7 +378,7 @@
   1970/01/01 00:00:00 bob> tags
   1970/01/01 00:00:00 bob> writing 24 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob> 2/3 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 1 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 1 tags
   1970/01/01 00:00:00 bob> tags exited 0 after * seconds (glob)
 
   $ f --size .hg/cache/hgtagsfnodes1
@@ -394,7 +394,7 @@
   $ hg blackbox -l 4
   1970/01/01 00:00:00 bob> tags
   1970/01/01 00:00:00 bob> 3/3 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 1 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 1 tags
   1970/01/01 00:00:00 bob> tags exited 0 after * seconds (glob)
 
   $ f --size .hg/cache/hgtagsfnodes1
@@ -411,7 +411,7 @@
   1970/01/01 00:00:00 bob> tags
   1970/01/01 00:00:00 bob> writing 24 bytes to cache/hgtagsfnodes1
   1970/01/01 00:00:00 bob> 2/3 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00 bob> writing tags cache file with 1 tags
+  1970/01/01 00:00:00 bob> writing .hg/cache/tags2-visible with 1 tags
   1970/01/01 00:00:00 bob> tags exited 0 after * seconds (glob)
   $ f --size .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=144