# HG changeset patch
# User Gregory Szorc <gregory.szorc@gmail.com>
# Date 1397501405 25200
# Node ID 9ea132aee96ca0817d55e72013b9cfc644dc0088
# Parent  76f68595ff8e5616a79dd79e962a97cc9ba58713
tags: log events related to tags cache

We now log when .hg/cache/tags data is built from scratch by reading
manifests and when the file is written.

diff -r 76f68595ff8e -r 9ea132aee96c mercurial/tags.py
--- a/mercurial/tags.py	Mon Apr 14 15:14:02 2014 -0400
+++ b/mercurial/tags.py	Mon Apr 14 11:50:05 2014 -0700
@@ -15,6 +15,7 @@
 import encoding
 import error
 import errno
+import time
 
 def findglobaltags(ui, repo, alltags, tagtypes):
     '''Find global tags in repo by reading .hgtags from every head that
@@ -234,6 +235,8 @@
         # potentially expensive search.
         return (repoheads, cachefnode, None, True)
 
+    starttime = time.time()
+
     newheads = [head
                 for head in repoheads
                 if head not in set(cacheheads)]
@@ -251,6 +254,12 @@
             # no .hgtags file on this head
             pass
 
+    duration = time.time() - starttime
+    ui.log('tagscache',
+           'resolved %d tags cache entries from %d manifests in %0.4f '
+           'seconds\n',
+           len(cachefnode), len(newheads), duration)
+
     # Caller has to iterate over all heads, but can use the filenodes in
     # cachefnode to get to each .hgtags revision quickly.
     return (repoheads, cachefnode, None, True)
@@ -262,6 +271,9 @@
     except (OSError, IOError):
         return
 
+    ui.log('tagscache', 'writing tags cache file with %d heads and %d tags\n',
+            len(heads), len(cachetags))
+
     realheads = repo.heads()            # for sanity checks below
     for head in heads:
         # temporary sanity checks; these can probably be removed
diff -r 76f68595ff8e -r 9ea132aee96c tests/test-blackbox.t
--- a/tests/test-blackbox.t	Mon Apr 14 15:14:02 2014 -0400
+++ b/tests/test-blackbox.t	Mon Apr 14 11:50:05 2014 -0700
@@ -120,6 +120,18 @@
   1970/01/01 00:00:00 bob> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob)
   1970/01/01 00:00:00 bob> strip tip exited 0 after * seconds (glob)
 
+tags cache gets logged
+  $ hg up tip
+  1 files updated, 0 files merged, 0 files removed, 0 files unresolved
+  $ hg tag -m 'create test tag' test-tag
+  $ hg tags
+  tip                                3:5b5562c08298
+  test-tag                           2:d02f48003e62
+  $ hg blackbox -l 3
+  1970/01/01 00:00:00 bob> resolved 1 tags cache entries from 1 manifests in ?.???? seconds (glob)
+  1970/01/01 00:00:00 bob> writing tags cache file with 2 heads and 1 tags
+  1970/01/01 00:00:00 bob> tags exited 0 after ?.?? seconds (glob)
+
 extension and python hooks - use the eol extension for a pythonhook
 
   $ echo '[extensions]' >> .hg/hgrc
@@ -128,7 +140,7 @@
   $ echo 'update = echo hooked' >> .hg/hgrc
   $ hg update
   hooked
-  1 files updated, 0 files merged, 0 files removed, 0 files unresolved
+  0 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ hg blackbox -l 4
   1970/01/01 00:00:00 bob> update
   1970/01/01 00:00:00 bob> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob)
@@ -144,7 +156,7 @@
   $ hg status
   $ hg status
   $ hg tip -q
-  2:d02f48003e62
+  3:5b5562c08298
   $ ls .hg/blackbox.log*
   .hg/blackbox.log
   .hg/blackbox.log.1