blackbox: change year in logs to ISO 8601 format

AFAIK, year/month/day is not a format than anyone uses. It seems more
sensible to me to use ISO 8601, as that's standard and unambiguously
year-month-day.

Compatibility-wise, I think it's acceptable to change the default
format. It's most for human consumption. It's plausible that a few
tools parse this format, but it has already changed in the past (for
instance to add the current revision).

Differential Revision: https://phab.mercurial-scm.org/D12006

hgext/blackbox.py

@@ -1,237 +1,241 b''
 # blackbox.py - log repository events to a file for post-mortem debugging
 #
 # Copyright 2010 Nicolas Dumazet
 # Copyright 2013 Facebook, Inc.
 #
 # This software may be used and distributed according to the terms of the
 # GNU General Public License version 2 or any later version.
 
 """log repository events to a blackbox for debugging
 
 Logs event information to .hg/blackbox.log to help debug and diagnose problems.
 The events that get logged can be configured via the blackbox.track and
 blackbox.ignore config keys.
 
 Examples::
 
   [blackbox]
   track = *
   ignore = pythonhook
   # dirty is *EXPENSIVE* (slow);
   # each log entry indicates `+` if the repository is dirty, like :hg:`id`.
   dirty = True
   # record the source of log messages
   logsource = True
 
   [blackbox]
   track = command, commandfinish, commandexception, exthook, pythonhook
 
   [blackbox]
   track = incoming
 
   [blackbox]
   # limit the size of a log file
   maxsize = 1.5 MB
   # rotate up to N log files when the current one gets too big
   maxfiles = 3
 
   [blackbox]
   # Include microseconds in log entries with %f (see Python function
   # datetime.datetime.strftime)
   date-format = %Y-%m-%d @ %H:%M:%S.%f
 
 """
 
 from __future__ import absolute_import
 
 import re
 
 from mercurial.i18n import _
 from mercurial.node import hex
 
 from mercurial import (
     encoding,
     loggingutil,
     registrar,
 )
 from mercurial.utils import (
     dateutil,
     procutil,
 )
 
 # Note for extension authors: ONLY specify testedwith = 'ships-with-hg-core' for
 # extensions which SHIP WITH MERCURIAL. Non-mainline extensions should
 # be specifying the version(s) of Mercurial they are tested with, or
 # leave the attribute unspecified.
 testedwith = b'ships-with-hg-core'
 
 cmdtable = {}
 command = registrar.command(cmdtable)
 
 configtable = {}
 configitem = registrar.configitem(configtable)
 
 configitem(
     b'blackbox',
     b'dirty',
     default=False,
 )
 configitem(
     b'blackbox',
     b'maxsize',
     default=b'1 MB',
 )
 configitem(
     b'blackbox',
     b'logsource',
     default=False,
 )
 configitem(
     b'blackbox',
     b'maxfiles',
     default=7,
 )
 configitem(
     b'blackbox',
     b'track',
     default=lambda: [b'*'],
 )
 configitem(
     b'blackbox',
     b'ignore',
     default=lambda: [b'chgserver', b'cmdserver', b'extension'],
 )
 configitem(b'blackbox', b'date-format', default=b'')
 
 _lastlogger = loggingutil.proxylogger()
 
 
 class blackboxlogger(object):
     def __init__(self, ui, repo):
         self._repo = repo
         self._trackedevents = set(ui.configlist(b'blackbox', b'track'))
         self._ignoredevents = set(ui.configlist(b'blackbox', b'ignore'))
         self._maxfiles = ui.configint(b'blackbox', b'maxfiles')
         self._maxsize = ui.configbytes(b'blackbox', b'maxsize')
         self._inlog = False
 
     def tracked(self, event):
         return (
             b'*' in self._trackedevents and event not in self._ignoredevents
         ) or event in self._trackedevents
 
     def log(self, ui, event, msg, opts):
         # self._log() -> ctx.dirty() may create new subrepo instance, which
         # ui is derived from baseui. So the recursion guard in ui.log()
         # doesn't work as it's local to the ui instance.
         if self._inlog:
             return
         self._inlog = True
         try:
             self._log(ui, event, msg, opts)
         finally:
             self._inlog = False
 
     def _log(self, ui, event, msg, opts):
         default = ui.configdate(b'devel', b'default-date')
         dateformat = ui.config(b'blackbox', b'date-format')
         if dateformat:
             date = dateutil.datestr(default, dateformat)
         else:
             # We want to display milliseconds (more precision seems
             # unnecessary).  Since %.3f is not supported, use %f and truncate
             # microseconds.
-            date = dateutil.datestr(default, b'%Y/%m/%d %H:%M:%S.%f')[:-3]
+            date = dateutil.datestr(default, b'%Y-%m-%d %H:%M:%S.%f')[:-3]
         user = procutil.getuser()
         pid = b'%d' % procutil.getpid()
         changed = b''
         ctx = self._repo[None]
         parents = ctx.parents()
         rev = b'+'.join([hex(p.node()) for p in parents])
         if ui.configbool(b'blackbox', b'dirty') and ctx.dirty(
             missing=True, merge=False, branch=False
         ):
             changed = b'+'
         if ui.configbool(b'blackbox', b'logsource'):
             src = b' [%s]' % event
         else:
             src = b''
         try:
             fmt = b'%s %s @%s%s (%s)%s> %s'
             args = (date, user, rev, changed, pid, src, msg)
             with loggingutil.openlogfile(
                 ui,
                 self._repo.vfs,
                 name=b'blackbox.log',
                 maxfiles=self._maxfiles,
                 maxsize=self._maxsize,
             ) as fp:
                 fp.write(fmt % args)
         except (IOError, OSError) as err:
             # deactivate this to avoid failed logging again
             self._trackedevents.clear()
             ui.debug(
                 b'warning: cannot write to blackbox.log: %s\n'
                 % encoding.strtolocal(err.strerror)
             )
             return
         _lastlogger.logger = self
 
 
 def uipopulate(ui):
     ui.setlogger(b'blackbox', _lastlogger)
 
 
 def reposetup(ui, repo):
     # During 'hg pull' a httppeer repo is created to represent the remote repo.
     # It doesn't have a .hg directory to put a blackbox in, so we don't do
     # the blackbox setup for it.
     if not repo.local():
         return
 
     # Since blackbox.log is stored in the repo directory, the logger should be
     # instantiated per repository.
     logger = blackboxlogger(ui, repo)
     ui.setlogger(b'blackbox', logger)
 
     # Set _lastlogger even if ui.log is not called. This gives blackbox a
     # fallback place to log
     if _lastlogger.logger is None:
         _lastlogger.logger = logger
 
     repo._wlockfreeprefix.add(b'blackbox.log')
 
 
 @command(
     b'blackbox',
     [
         (b'l', b'limit', 10, _(b'the number of events to show')),
     ],
     _(b'hg blackbox [OPTION]...'),
     helpcategory=command.CATEGORY_MAINTENANCE,
     helpbasic=True,
 )
 def blackbox(ui, repo, *revs, **opts):
     """view the recent repository events"""
 
     if not repo.vfs.exists(b'blackbox.log'):
         return
 
     limit = opts.get('limit')
     fp = repo.vfs(b'blackbox.log', b'r')
     lines = fp.read().split(b'\n')
 
     count = 0
     output = []
     for line in reversed(lines):
         if count >= limit:
             break
 
-        # count the commands by matching lines like: 2013/01/23 19:13:36 root>
+        # count the commands by matching lines like:
+        # 2013/01/23 19:13:36 root>
+        # 2013/01/23 19:13:36 root (1234)>
+        # 2013/01/23 19:13:36 root @0000000000000000000000000000000000000000 (1234)>
+        # 2013-01-23 19:13:36.000 root @0000000000000000000000000000000000000000 (1234)>
         if re.match(
-            br'^\d{4}/\d{2}/\d{2} \d{2}:\d{2}:\d{2}(.\d*)? .*> .*', line
+            br'^\d{4}[-/]\d{2}[-/]\d{2} \d{2}:\d{2}:\d{2}(.\d*)? .*> .*', line
         ):
             count += 1
         output.append(line)
 
     ui.status(b'\n'.join(reversed(output)))

rust/rhg/src/blackbox.rs

@@ -1,163 +1,163 b''
 //! Logging for repository events, including commands run in the repository.
 
 use crate::CliInvocation;
 use format_bytes::format_bytes;
 use hg::errors::HgError;
 use hg::repo::Repo;
 use hg::utils::{files::get_bytes_from_os_str, shell_quote};
 
 const ONE_MEBIBYTE: u64 = 1 << 20;
 
 // TODO: somehow keep defaults in sync with `configitem` in `hgext/blackbox.py`
 const DEFAULT_MAX_SIZE: u64 = ONE_MEBIBYTE;
 const DEFAULT_MAX_FILES: u32 = 7;
 
 // Python does not support %.3f, only %f
-const DEFAULT_DATE_FORMAT: &str = "%Y/%m/%d %H:%M:%S%.3f";
+const DEFAULT_DATE_FORMAT: &str = "%Y-%m-%d %H:%M:%S%.3f";
 
 type DateTime = chrono::DateTime<chrono::Local>;
 
 pub struct ProcessStartTime {
     /// For measuring duration
     monotonic_clock: std::time::Instant,
     /// For formatting with year, month, day, etc.
     calendar_based: DateTime,
 }
 
 impl ProcessStartTime {
     pub fn now() -> Self {
         Self {
             monotonic_clock: std::time::Instant::now(),
             calendar_based: chrono::Local::now(),
         }
     }
 }
 
 pub struct Blackbox<'a> {
     process_start_time: &'a ProcessStartTime,
     /// Do nothing if this is `None`
     configured: Option<ConfiguredBlackbox<'a>>,
 }
 
 struct ConfiguredBlackbox<'a> {
     repo: &'a Repo,
     max_size: u64,
     max_files: u32,
     date_format: &'a str,
 }
 
 impl<'a> Blackbox<'a> {
     pub fn new(
         invocation: &'a CliInvocation<'a>,
         process_start_time: &'a ProcessStartTime,
     ) -> Result<Self, HgError> {
         let configured = if let Ok(repo) = invocation.repo {
             if invocation.config.get(b"extensions", b"blackbox").is_none() {
                 // The extension is not enabled
                 None
             } else {
                 Some(ConfiguredBlackbox {
                     repo,
                     max_size: invocation
                         .config
                         .get_byte_size(b"blackbox", b"maxsize")?
                         .unwrap_or(DEFAULT_MAX_SIZE),
                     max_files: invocation
                         .config
                         .get_u32(b"blackbox", b"maxfiles")?
                         .unwrap_or(DEFAULT_MAX_FILES),
                     date_format: invocation
                         .config
                         .get_str(b"blackbox", b"date-format")?
                         .unwrap_or(DEFAULT_DATE_FORMAT),
                 })
             }
         } else {
             // Without a local repository there’s no `.hg/blackbox.log` to
             // write to.
             None
         };
         Ok(Self {
             process_start_time,
             configured,
         })
     }
 
     pub fn log_command_start(&self) {
         if let Some(configured) = &self.configured {
             let message = format_bytes!(b"(rust) {}", format_cli_args());
             configured.log(&self.process_start_time.calendar_based, &message);
         }
     }
 
     pub fn log_command_end(&self, exit_code: i32) {
         if let Some(configured) = &self.configured {
             let now = chrono::Local::now();
             let duration = self
                 .process_start_time
                 .monotonic_clock
                 .elapsed()
                 .as_secs_f64();
             let message = format_bytes!(
                 b"(rust) {} exited {} after {} seconds",
                 format_cli_args(),
                 exit_code,
                 format_bytes::Utf8(format_args!("{:.03}", duration))
             );
             configured.log(&now, &message);
         }
     }
 }
 
 impl ConfiguredBlackbox<'_> {
     fn log(&self, date_time: &DateTime, message: &[u8]) {
         let date = format_bytes::Utf8(date_time.format(self.date_format));
         let user = users::get_current_username().map(get_bytes_from_os_str);
         let user = user.as_deref().unwrap_or(b"???");
         let rev = format_bytes::Utf8(match self.repo.dirstate_parents() {
             Ok(parents) if parents.p2 == hg::revlog::node::NULL_NODE => {
                 format!("{:x}", parents.p1)
             }
             Ok(parents) => format!("{:x}+{:x}", parents.p1, parents.p2),
             Err(_dirstate_corruption_error) => {
                 // TODO: log a non-fatal warning to stderr
                 "???".to_owned()
             }
         });
         let pid = std::process::id();
         let line = format_bytes!(
             b"{} {} @{} ({})> {}\n",
             date,
             user,
             rev,
             pid,
             message
         );
         let result =
             hg::logging::LogFile::new(self.repo.hg_vfs(), "blackbox.log")
                 .max_size(Some(self.max_size))
                 .max_files(self.max_files)
                 .write(&line);
         match result {
             Ok(()) => {}
             Err(_io_error) => {
                 // TODO: log a non-fatal warning to stderr
             }
         }
     }
 }
 
 fn format_cli_args() -> Vec<u8> {
     let mut args = std::env::args_os();
     let _ = args.next(); // Skip the first (or zeroth) arg, the name of the `rhg` executable
     let mut args = args.map(|arg| shell_quote(&get_bytes_from_os_str(arg)));
     let mut formatted = Vec::new();
     if let Some(arg) = args.next() {
         formatted.extend(arg)
     }
     for arg in args {
         formatted.push(b' ');
         formatted.extend(arg)
     }
     formatted
 }

tests/test-blackbox.t

@@ -1,499 +1,499 b''
 setup
 
   $ cat > myextension.py <<EOF
   > from mercurial import error, registrar
   > cmdtable = {}
   > command = registrar.command(cmdtable)
   > @command(b'crash', [], b'hg crash')
   > def crash(ui, *args, **kwargs):
   >     raise Exception("oops")
   > @command(b'abortcmd', [], b'hg abortcmd')
   > def abort(ui, *args, **kwargs):
   >     raise error.Abort(b"oops")
   > EOF
   $ abspath=`pwd`/myextension.py
 
   $ cat >> $HGRCPATH <<EOF
   > [extensions]
   > blackbox=
   > mock=$TESTDIR/mockblackbox.py
   > mq=
   > myextension=$TESTTMP/myextension.py
   > [alias]
   > confuse = log --limit 3
   > so-confusing = confuse --style compact
   > EOF
 
   $ hg init blackboxtest
   $ cd blackboxtest
 
 command, exit codes, and duration
 
   $ echo a > a
   $ hg add a
   $ hg blackbox --config blackbox.dirty=True
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> init blackboxtest exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> add a
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> add a exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000+ (5000)> blackbox --config *blackbox.dirty=True* (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> init blackboxtest exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> add a
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> add a exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000+ (5000)> blackbox --config *blackbox.dirty=True* (glob)
 
 failure exit code
   $ rm ./.hg/blackbox.log
   $ hg add non-existent
   non-existent: $ENOENT$
   [1]
   $ hg blackbox
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> add non-existent
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> add non-existent exited 1 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> add non-existent
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> add non-existent exited 1 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
 
 abort exit code
   $ rm ./.hg/blackbox.log
   $ hg abortcmd 2> /dev/null
   [255]
   $ hg blackbox -l 2
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> abortcmd exited 255 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox -l 2
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> abortcmd exited 255 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox -l 2
 
 unhandled exception
   $ rm ./.hg/blackbox.log
 #if chg
  (chg exits 255 because it fails to receive an exit code)
   $ hg crash 2>/dev/null
   [255]
 #else
  (hg exits 1 because Python default exit code for uncaught exception is 1)
   $ hg crash 2>/dev/null
   [1]
 #endif
   $ hg blackbox -l 2
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> crash exited 1 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox -l 2
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> crash exited 1 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox -l 2
 
 alias expansion is logged
   $ rm ./.hg/blackbox.log
   $ hg confuse
   $ hg blackbox
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> confuse
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> alias 'confuse' expands to 'log --limit 3'
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> confuse exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> confuse
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> alias 'confuse' expands to 'log --limit 3'
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> confuse exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
 
 recursive aliases work correctly
   $ rm ./.hg/blackbox.log
   $ hg so-confusing
   $ hg blackbox
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> so-confusing
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> alias 'so-confusing' expands to 'confuse --style compact'
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> alias 'confuse' expands to 'log --limit 3'
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> so-confusing exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> so-confusing
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> alias 'so-confusing' expands to 'confuse --style compact'
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> alias 'confuse' expands to 'log --limit 3'
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> so-confusing exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
 
 custom date format
   $ rm ./.hg/blackbox.log
   $ hg --config blackbox.date-format='%Y-%m-%d @ %H:%M:%S' \
   >    --config devel.default-date='1334347993 0' --traceback status
   A a
   $ hg blackbox
   2012-04-13 @ 20:13:13 bob @0000000000000000000000000000000000000000 (5000)> --config *blackbox.date-format=%Y-%m-%d @ %H:%M:%S* --config *devel.default-date=1334347993 0* --traceback status (glob)
   2012-04-13 @ 20:13:13 bob @0000000000000000000000000000000000000000 (5000)> --config *blackbox.date-format=%Y-%m-%d @ %H:%M:%S* --config *devel.default-date=1334347993 0* --traceback status exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
 
 incoming change tracking
 
 create two heads to verify that we only see one change in the log later
   $ hg commit -ma
   $ hg up null
   0 files updated, 0 files merged, 1 files removed, 0 files unresolved
   $ echo b > b
   $ hg commit -Amb
   adding b
   created new head
 
 clone, commit, pull
   $ hg clone . ../blackboxtest2
   updating to branch default
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ echo c > c
   $ hg commit -Amc
   adding c
   $ cd ../blackboxtest2
   $ hg pull
   pulling from $TESTTMP/blackboxtest
   searching for changes
   adding changesets
   adding manifests
   adding file changes
   added 1 changesets with 1 changes to 1 files
   new changesets d02f48003e62
   (run 'hg update' to get a working copy)
   $ hg blackbox -l 6
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (served) with 1 labels and 2 nodes
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> updated branch cache (served.hidden) in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (served.hidden) with 1 labels and 2 nodes
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> 1 incoming changes - new heads: d02f48003e62
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pull exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> blackbox -l 6
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (served) with 1 labels and 2 nodes
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> updated branch cache (served.hidden) in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (served.hidden) with 1 labels and 2 nodes
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> 1 incoming changes - new heads: d02f48003e62
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pull exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> blackbox -l 6
 
 we must not cause a failure if we cannot write to the log
 
   $ hg rollback
   repository tip rolled back to revision 1 (undo pull)
 
   $ mv .hg/blackbox.log .hg/blackbox.log-
   $ mkdir .hg/blackbox.log
   $ hg --debug incoming
   warning: cannot write to blackbox.log: * (glob)
   comparing with $TESTTMP/blackboxtest
   query 1; heads
   searching for changes
   all local changesets known remotely
   changeset:   2:d02f48003e62c24e2659d97d30f2a83abe5d5d51
   tag:         tip
   phase:       draft
   parent:      1:6563da9dcf87b1949716e38ff3e3dfaa3198eb06
   parent:      -1:0000000000000000000000000000000000000000
   manifest:    2:ab9d46b053ebf45b7996f2922b9893ff4b63d892
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   files+:      c
   extra:       branch=default
   description:
   c
   
   
   $ hg pull
   pulling from $TESTTMP/blackboxtest
   searching for changes
   adding changesets
   adding manifests
   adding file changes
   added 1 changesets with 1 changes to 1 files
   new changesets d02f48003e62
   (run 'hg update' to get a working copy)
 
 a failure reading from the log is fatal
 
   $ hg blackbox -l 3
   abort: *$TESTTMP/blackboxtest2/.hg/blackbox.log* (glob)
   [255]
 
   $ rmdir .hg/blackbox.log
   $ mv .hg/blackbox.log- .hg/blackbox.log
 
 backup bundles get logged
 
   $ touch d
   $ hg commit -Amd
   adding d
   created new head
   $ hg strip tip
   0 files updated, 0 files merged, 1 files removed, 0 files unresolved
   saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/*-backup.hg (glob)
   $ hg blackbox -l 6
-  1970/01/01 00:00:00.000 bob @73f6ee326b27d820b0472f1a825e3a50f3dc489b (5000)> strip tip
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/73f6ee326b27-7612e004-backup.hg
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> updated branch cache (immutable) in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (immutable) with 1 labels and 2 nodes
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> strip tip exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> blackbox -l 6
+  1970-01-01 00:00:00.000 bob @73f6ee326b27d820b0472f1a825e3a50f3dc489b (5000)> strip tip
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> saved backup bundle to $TESTTMP/blackboxtest2/.hg/strip-backup/73f6ee326b27-7612e004-backup.hg
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> updated branch cache (immutable) in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> wrote branch cache (immutable) with 1 labels and 2 nodes
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> strip tip exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> blackbox -l 6
 
 extension and python hooks - use the eol extension for a pythonhook
 
   $ echo '[extensions]' >> .hg/hgrc
   $ echo 'eol=' >> .hg/hgrc
   $ echo '[hooks]' >> .hg/hgrc
   $ echo 'update = echo hooked' >> .hg/hgrc
   $ hg update
   The fsmonitor extension is incompatible with the eol extension and has been disabled. (fsmonitor !)
   hooked
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   updated to "d02f48003e62: c"
   1 other heads for branch "default"
   $ cat >> .hg/hgrc <<EOF
   > [extensions]
   > # disable eol, because it is not needed for subsequent tests
   > # (in addition, keeping it requires extra care for fsmonitor)
   > eol=!
   > EOF
   $ hg blackbox -l 5
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> update (no-chg !)
-  1970/01/01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> exthook-update: echo hooked finished in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> update exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> serve --no-profile --cmdserver chgunix --address $TESTTMP.chgsock/server.* --daemon-postexec 'chdir:/' (glob) (chg !)
-  1970/01/01 00:00:00.000 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> blackbox -l 5
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> update (no-chg !)
+  1970-01-01 00:00:00.000 bob @6563da9dcf87b1949716e38ff3e3dfaa3198eb06 (5000)> pythonhook-preupdate: hgext.eol.preupdate finished in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> exthook-update: echo hooked finished in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> update exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> serve --no-profile --cmdserver chgunix --address $TESTTMP.chgsock/server.* --daemon-postexec 'chdir:/' (glob) (chg !)
+  1970-01-01 00:00:00.000 bob @d02f48003e62c24e2659d97d30f2a83abe5d5d51 (5000)> blackbox -l 5
 
 log rotation
 
   $ echo '[blackbox]' >> .hg/hgrc
   $ echo 'maxsize = 20 b' >> .hg/hgrc
   $ echo 'maxfiles = 3' >> .hg/hgrc
   $ hg status
   $ hg status
   $ hg status
   $ hg tip -q
   2:d02f48003e62
   $ ls .hg/blackbox.log*
   .hg/blackbox.log
   .hg/blackbox.log.1
   .hg/blackbox.log.2
   $ cd ..
 
   $ hg init blackboxtest3
   $ cd blackboxtest3
   $ hg blackbox
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> init blackboxtest3 exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> init blackboxtest3 exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> blackbox
   $ mv .hg/blackbox.log .hg/blackbox.log-
   $ mkdir .hg/blackbox.log
   $ sed -e 's/\(.*test1.*\)/#\1/; s#\(.*commit2.*\)#os.rmdir(".hg/blackbox.log")\
   > os.rename(".hg/blackbox.log-", ".hg/blackbox.log")\
   > \1#' $TESTDIR/test-dispatch.py > ../test-dispatch.py
   $ "$PYTHON" $TESTDIR/blackbox-readonly-dispatch.py
   running: --debug add foo
   warning: cannot write to blackbox.log: Is a directory (no-windows !)
   warning: cannot write to blackbox.log: $TESTTMP/blackboxtest3/.hg/blackbox.log: Access is denied (windows !)
   adding foo
   result: 0
   running: --debug commit -m commit1 -d 2000-01-01 foo
   warning: cannot write to blackbox.log: Is a directory (no-windows !)
   warning: cannot write to blackbox.log: $TESTTMP/blackboxtest3/.hg/blackbox.log: Access is denied (windows !)
   committing files:
   foo
   committing manifest
   committing changelog
   updating the branch cache
   committed changeset 0:0e46349438790c460c5c9f7546bfcd39b267bbd2
   result: 0
   running: --debug commit -m commit2 -d 2000-01-02 foo
   committing files:
   foo
   committing manifest
   committing changelog
   updating the branch cache
   committed changeset 1:45589e459b2edfbf3dbde7e01f611d2c1e7453d7
   result: 0
   running: --debug log -r 0
   changeset:   0:0e46349438790c460c5c9f7546bfcd39b267bbd2
   phase:       draft
   parent:      -1:0000000000000000000000000000000000000000
   parent:      -1:0000000000000000000000000000000000000000
   manifest:    0:9091aa5df980aea60860a2e39c95182e68d1ddec
   user:        test
   date:        Sat Jan 01 00:00:00 2000 +0000
   files+:      foo
   extra:       branch=default
   description:
   commit1
   
   
   result: 0
   running: --debug log -r tip
   changeset:   1:45589e459b2edfbf3dbde7e01f611d2c1e7453d7
   tag:         tip
   phase:       draft
   parent:      0:0e46349438790c460c5c9f7546bfcd39b267bbd2
   parent:      -1:0000000000000000000000000000000000000000
   manifest:    1:895aa9b7886f89dd017a6d62524e1f9180b04df9
   user:        test
   date:        Sun Jan 02 00:00:00 2000 +0000
   files:       foo
   extra:       branch=default
   description:
   commit2
   
   
   result: 0
   $ hg blackbox
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> updating the branch cache
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> updated branch cache (served) in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> wrote branch cache (served) with 1 labels and 1 nodes
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug commit -m commit2 -d 2000-01-02 foo exited 0 after *.?? seconds (glob)
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r 0
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> writing .hg/cache/tags2-visible with 0 tags
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r 0 exited 0 after *.?? seconds (glob)
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r tip
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r tip exited 0 after *.?? seconds (glob)
-  1970/01/01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> blackbox
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> updating the branch cache
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> updated branch cache (served) in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> wrote branch cache (served) with 1 labels and 1 nodes
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug commit -m commit2 -d 2000-01-02 foo exited 0 after *.?? seconds (glob)
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r 0
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> writing .hg/cache/tags2-visible with 0 tags
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r 0 exited 0 after *.?? seconds (glob)
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r tip
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> --debug log -r tip exited 0 after *.?? seconds (glob)
+  1970-01-01 00:00:00.000 bob @45589e459b2edfbf3dbde7e01f611d2c1e7453d7 (5000)> blackbox
 
 Skip rotation if the .hg is read-only
 
 #if unix-permissions
   $ chmod -w .hg
   $ hg log -r. -T '{rev}\n' --config blackbox.maxsize=1 --debug
   warning: cannot rename '$TESTTMP/blackboxtest3/.hg/blackbox.log.1' to '$TESTTMP/blackboxtest3/.hg/blackbox.log': Permission denied
   warning: cannot write to blackbox.log: Permission denied
   1
   $ chmod +w .hg
 #endif
 
 Test log recursion from dirty status check
 
   $ cat > ../r.py <<EOF
   > from mercurial import context, error, extensions
   > x=[False]
   > def status(orig, *args, **opts):
   >     args[0].repo().ui.log(b"broken", b"recursion?")
   >     return orig(*args, **opts)
   > def reposetup(ui, repo):
   >     extensions.wrapfunction(context.basectx, 'status', status)
   > EOF
   $ hg id --config extensions.x=../r.py --config blackbox.dirty=True
   45589e459b2e tip
 
 cleanup
   $ cd ..
 
 Test missing log directory, which shouldn't be created automatically
 
   $ cat <<'EOF' > closeremove.py
   > def reposetup(ui, repo):
   >     class rmrepo(repo.__class__):
   >         def close(self):
   >             super(rmrepo, self).close()
   >             self.ui.debug(b'removing %s\n' % self.vfs.base)
   >             self.vfs.rmtree()
   >     repo.__class__ = rmrepo
   > EOF
 
   $ hg init gone
   $ cd gone
   $ cat <<'EOF' > .hg/hgrc
   > [extensions]
   > closeremove = ../closeremove.py
   > EOF
   $ hg log --debug
   removing $TESTTMP/gone/.hg
   warning: cannot write to blackbox.log: $ENOENT$ (no-windows !)
   warning: cannot write to blackbox.log: $TESTTMP/gone/.hg/blackbox.log: $ENOTDIR$ (windows !)
   $ cd ..
 
 blackbox should disable itself if track is empty
 
   $ hg --config blackbox.track= init nothing_tracked
   $ cd nothing_tracked
   $ cat >> .hg/hgrc << EOF
   > [blackbox]
   > track =
   > EOF
   $ hg blackbox
   $ cd $TESTTMP
 
 a '*' entry in blackbox.track is interpreted as log everything
 
   $ hg --config blackbox.track='*' \
   >    --config blackbox.logsource=True \
   >    init track_star
   $ cd track_star
   $ cat >> .hg/hgrc << EOF
   > [blackbox]
   > logsource = True
   > track = *
   > EOF
 (only look for entries with specific logged sources, otherwise this test is
 pretty brittle)
   $ hg blackbox | egrep '\[command(finish)?\]'
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000) [commandfinish]> --config *blackbox.track=* --config *blackbox.logsource=True* init track_star exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000) [command]> blackbox
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000) [commandfinish]> --config *blackbox.track=* --config *blackbox.logsource=True* init track_star exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000) [command]> blackbox
   $ cd $TESTTMP
 
 #if chg
 
 when using chg, blackbox.log should get rotated correctly
 
   $ cat > $TESTTMP/noop.py << EOF
   > from __future__ import absolute_import
   > import time
   > from mercurial import registrar, scmutil
   > cmdtable = {}
   > command = registrar.command(cmdtable)
   > @command(b'noop')
   > def noop(ui, repo):
   >     pass
   > EOF
 
   $ hg init blackbox-chg
   $ cd blackbox-chg
 
   $ cat > .hg/hgrc << EOF
   > [blackbox]
   > maxsize = 500B
   > [extensions]
   > # extension change forces chg to restart
   > noop=$TESTTMP/noop.py
   > EOF
 
   $ "$PYTHON" -c 'print("a" * 400)' > .hg/blackbox.log
   $ chg noop
   $ chg noop
   $ chg noop
   $ chg noop
   $ chg noop
 
   $ cat > showsize.py << 'EOF'
   > import os
   > import sys
   > limit = 500
   > for p in sys.argv[1:]:
   >     size = os.stat(p).st_size
   >     if size >= limit:
   >         desc = '>='
   >     else:
   >         desc = '<'
   >     print('%s: %s %d' % (p, desc, limit))
   > EOF
 
   $ "$PYTHON" showsize.py .hg/blackbox*
   .hg/blackbox.log: < 500
   .hg/blackbox.log.1: >= 500
   .hg/blackbox.log.2: >= 500
 
   $ cd ..
 
 With chg, blackbox should not create the log file if the repo is gone
 
   $ hg init repo1
   $ hg --config extensions.a=! -R repo1 log
   $ rm -rf $TESTTMP/repo1
   $ hg --config extensions.a=! init repo1
 
 #endif
 
 blackbox should work if repo.ui.log is not called (issue5518)
 
   $ cat > $TESTTMP/raise.py << EOF
   > from __future__ import absolute_import
   > from mercurial import registrar, scmutil
   > cmdtable = {}
   > command = registrar.command(cmdtable)
   > @command(b'raise')
   > def raisecmd(*args):
   >     raise RuntimeError('raise')
   > EOF
 
   $ cat >> $HGRCPATH << EOF
   > [blackbox]
   > track = commandexception
   > [extensions]
   > raise=$TESTTMP/raise.py
   > EOF
 
   $ hg init $TESTTMP/blackbox-exception-only
   $ cd $TESTTMP/blackbox-exception-only
 
 #if chg
  (chg exits 255 because it fails to receive an exit code)
   $ hg raise 2>/dev/null
   [255]
 #else
  (hg exits 1 because Python default exit code for uncaught exception is 1)
   $ hg raise 2>/dev/null
   [1]
 #endif
 
   $ head -1 .hg/blackbox.log
-  1970/01/01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> ** Unknown exception encountered with possibly-broken third-party extension "mock" (version N/A)
+  1970-01-01 00:00:00.000 bob @0000000000000000000000000000000000000000 (5000)> ** Unknown exception encountered with possibly-broken third-party extension "mock" (version N/A)
   $ tail -2 .hg/blackbox.log
   RuntimeError: raise
   

tests/test-devel-warnings.t

@@ -1,470 +1,470 b''
 
   $ cat << EOF > buggylocking.py
   > """A small extension that tests our developer warnings
   > """
   > 
   > from mercurial import error, registrar, repair, util
   > 
   > cmdtable = {}
   > command = registrar.command(cmdtable)
   > 
   > @command(b'buggylocking', [], '')
   > def buggylocking(ui, repo):
   >     lo = repo.lock()
   >     wl = repo.wlock()
   >     wl.release()
   >     lo.release()
   > 
   > @command(b'buggytransaction', [], '')
   > def buggylocking(ui, repo):
   >     tr = repo.transaction(b'buggy')
   >     # make sure we rollback the transaction as we don't want to rely on the__del__
   >     tr.release()
   > 
   > @command(b'properlocking', [], '')
   > def properlocking(ui, repo):
   >     """check that reentrance is fine"""
   >     wl = repo.wlock()
   >     lo = repo.lock()
   >     tr = repo.transaction(b'proper')
   >     tr2 = repo.transaction(b'proper')
   >     lo2 = repo.lock()
   >     wl2 = repo.wlock()
   >     wl2.release()
   >     lo2.release()
   >     tr2.close()
   >     tr.close()
   >     lo.release()
   >     wl.release()
   > 
   > @command(b'nowaitlocking', [], '')
   > def nowaitlocking(ui, repo):
   >     lo = repo.lock()
   >     wl = repo.wlock(wait=False)
   >     wl.release()
   >     lo.release()
   > 
   > @command(b'no-wlock-write', [], '')
   > def nowlockwrite(ui, repo):
   >     with repo.vfs(b'branch', b'a'):
   >         pass
   > 
   > @command(b'no-lock-write', [], '')
   > def nolockwrite(ui, repo):
   >     with repo.svfs(b'fncache', b'a'):
   >         pass
   > 
   > @command(b'stripintr', [], '')
   > def stripintr(ui, repo):
   >     lo = repo.lock()
   >     tr = repo.transaction(b'foobar')
   >     try:
   >         repair.strip(repo.ui, repo, [repo[b'.'].node()])
   >     finally:
   >         lo.release()
   > @command(b'oldanddeprecated', [], '')
   > def oldanddeprecated(ui, repo):
   >     """test deprecation warning API"""
   >     def foobar(ui):
   >         ui.deprecwarn(b'foorbar is deprecated, go shopping', b'42.1337')
   >     foobar(ui)
   > @command(b'nouiwarning', [], '')
   > def nouiwarning(ui, repo):
   >     util.nouideprecwarn(b'this is a test', b'13.37')
   > @command(b'programmingerror', [], '')
   > def programmingerror(ui, repo):
   >     raise error.ProgrammingError(b'something went wrong', hint=b'try again')
   > EOF
 
   $ cat << EOF >> $HGRCPATH
   > [extensions]
   > buggylocking=$TESTTMP/buggylocking.py
   > mock=$TESTDIR/mockblackbox.py
   > blackbox=
   > [devel]
   > all-warnings=1
   > [blackbox]
   > track = command, commandexception, commandfinish, develwarn
   > EOF
 
   $ hg init lock-checker
   $ cd lock-checker
   $ hg buggylocking
   devel-warn: "wlock" acquired after "lock" at: $TESTTMP/buggylocking.py:* (buggylocking) (glob)
   $ cat << EOF >> $HGRCPATH
   > [devel]
   > all=0
   > check-locks=1
   > EOF
   $ hg buggylocking
   devel-warn: "wlock" acquired after "lock" at: $TESTTMP/buggylocking.py:* (buggylocking) (glob)
 #if no-chg no-pyoxidizer
   $ hg buggylocking --traceback
   devel-warn: "wlock" acquired after "lock" at:
    */hg:* in <module> (glob) (?)
    */mercurial/dispatch.py:* in run (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    $TESTTMP/buggylocking.py:* in buggylocking (glob)
 #endif
 #if chg no-pyoxidizer
   $ hg buggylocking --traceback
   devel-warn: "wlock" acquired after "lock" at:
    */hg:* in <module> (glob) (?)
    */mercurial/dispatch.py:* in run (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py:* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    */mercurial/commands.py:* in serve (glob)
    */mercurial/server.py:* in runservice (glob)
    */mercurial/commandserver.py:* in run (glob)
    */mercurial/commandserver.py:* in _mainloop (glob)
    */mercurial/commandserver.py:* in _acceptnewconnection (glob)
    */mercurial/commandserver.py:* in _runworker (glob)
    */mercurial/commandserver.py:* in _serverequest (glob)
    */mercurial/commandserver.py:* in serve (glob)
    */mercurial/commandserver.py:* in serveone (glob)
    */mercurial/chgserver.py:* in runcommand (glob)
    */mercurial/commandserver.py:* in runcommand (glob)
    */mercurial/commandserver.py:* in _dispatchcommand (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py:* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    $TESTTMP/buggylocking.py:* in buggylocking (glob)
 #endif
 #if pyoxidizer
   $ hg buggylocking --traceback
   devel-warn: "wlock" acquired after "lock" at:
    <string>:* (glob)
    mercurial.dispatch:* in run (glob)
    mercurial.dispatch:* in dispatch (glob)
    mercurial.dispatch:* in _rundispatch (glob)
    mercurial.dispatch:* in _runcatch (glob)
    mercurial.dispatch:* in _callcatch (glob)
    mercurial.scmutil:* in callcatch (glob)
    mercurial.dispatch:* in _runcatchfunc (glob)
    mercurial.dispatch:* in _dispatch (glob)
    mercurial.dispatch:* in runcommand (glob)
    mercurial.dispatch:* in _runcommand (glob)
    mercurial.dispatch:* in <lambda> (glob)
    mercurial.util:* in check (glob)
    $TESTTMP/buggylocking.py:* in buggylocking (glob)
 #endif
   $ hg properlocking
   $ hg nowaitlocking
 
 Writing without lock
 
   $ hg no-wlock-write
   devel-warn: write with no wlock: "branch" at: $TESTTMP/buggylocking.py:* (nowlockwrite) (glob)
 
   $ hg no-lock-write
   devel-warn: write with no lock: "fncache" at: $TESTTMP/buggylocking.py:* (nolockwrite) (glob)
 
 Stripping from a transaction
 
   $ echo a > a
   $ hg add a
   $ hg commit -m a
   $ hg stripintr 2>&1 | egrep -v '^(\*\*|  )'
   Traceback (most recent call last):
   *ProgrammingError: cannot strip from inside a transaction (glob)
 
   $ hg oldanddeprecated
   devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at: $TESTTMP/buggylocking.py:* (oldanddeprecated) (glob)
 
 #if no-chg no-pyoxidizer
   $ hg oldanddeprecated --traceback
   devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at:
    */hg:* in <module> (glob) (?)
    */mercurial/dispatch.py:* in run (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    $TESTTMP/buggylocking.py:* in oldanddeprecated (glob)
 #endif
 #if chg no-pyoxidizer
   $ hg oldanddeprecated --traceback
   devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at:
    */hg:* in <module> (glob)
    */mercurial/dispatch.py:* in run (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py:* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    */mercurial/commands.py:* in serve (glob)
    */mercurial/server.py:* in runservice (glob)
    */mercurial/commandserver.py:* in run (glob)
    */mercurial/commandserver.py:* in _mainloop (glob)
    */mercurial/commandserver.py:* in _acceptnewconnection (glob)
    */mercurial/commandserver.py:* in _runworker (glob)
    */mercurial/commandserver.py:* in _serverequest (glob)
    */mercurial/commandserver.py:* in serve (glob)
    */mercurial/commandserver.py:* in serveone (glob)
    */mercurial/chgserver.py:* in runcommand (glob)
    */mercurial/commandserver.py:* in runcommand (glob)
    */mercurial/commandserver.py:* in _dispatchcommand (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py:* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    $TESTTMP/buggylocking.py:* in oldanddeprecated (glob)
 #endif
 #if pyoxidizer
   $ hg oldanddeprecated --traceback
   devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at:
    <string>:* (glob)
    mercurial.dispatch:* in run (glob)
    mercurial.dispatch:* in dispatch (glob)
    mercurial.dispatch:* in _rundispatch (glob)
    mercurial.dispatch:* in _runcatch (glob)
    mercurial.dispatch:* in _callcatch (glob)
    mercurial.scmutil:* in callcatch (glob)
    mercurial.dispatch:* in _runcatchfunc (glob)
    mercurial.dispatch:* in _dispatch (glob)
    mercurial.dispatch:* in runcommand (glob)
    mercurial.dispatch:* in _runcommand (glob)
    mercurial.dispatch:* in <lambda> (glob)
    mercurial.util:* in check (glob)
    $TESTTMP/buggylocking.py:* in oldanddeprecated (glob)
 #endif
 
 #if no-chg no-pyoxidizer
   $ hg blackbox -l 7
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at: $TESTTMP/buggylocking.py:* (oldanddeprecated) (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at:
    */hg:* in <module> (glob) (?)
    */mercurial/dispatch.py:* in run (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    $TESTTMP/buggylocking.py:* in oldanddeprecated (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> blackbox -l 7
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> blackbox -l 7
 #endif
 #if chg no-pyoxidizer
   $ hg blackbox -l 7
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at: $TESTTMP/buggylocking.py:* (oldanddeprecated) (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at:
    */hg:* in <module> (glob)
    */mercurial/dispatch.py:* in run (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py:* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    */mercurial/commands.py:* in serve (glob)
    */mercurial/server.py:* in runservice (glob)
    */mercurial/commandserver.py:* in run (glob)
    */mercurial/commandserver.py:* in _mainloop (glob)
    */mercurial/commandserver.py:* in _acceptnewconnection (glob)
    */mercurial/commandserver.py:* in _runworker (glob)
    */mercurial/commandserver.py:* in _serverequest (glob)
    */mercurial/commandserver.py:* in serve (glob)
    */mercurial/commandserver.py:* in serveone (glob)
    */mercurial/chgserver.py:* in runcommand (glob)
    */mercurial/commandserver.py:* in runcommand (glob)
    */mercurial/commandserver.py:* in _dispatchcommand (glob)
    */mercurial/dispatch.py:* in dispatch (glob)
    */mercurial/dispatch.py:* in _rundispatch (glob)
    */mercurial/dispatch.py:* in _runcatch (glob)
    */mercurial/dispatch.py:* in _callcatch (glob)
    */mercurial/scmutil.py:* in callcatch (glob)
    */mercurial/dispatch.py:* in _runcatchfunc (glob)
    */mercurial/dispatch.py:* in _dispatch (glob)
    */mercurial/dispatch.py:* in runcommand (glob)
    */mercurial/dispatch.py:* in _runcommand (glob)
    */mercurial/dispatch.py:* in <lambda> (glob)
    */mercurial/util.py:* in check (glob)
    $TESTTMP/buggylocking.py:* in oldanddeprecated (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> blackbox -l 7
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> blackbox -l 7
 #endif
 #if pyoxidizer
   $ hg blackbox -l 7
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at: $TESTTMP/buggylocking.py:* (oldanddeprecated) (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> devel-warn: foorbar is deprecated, go shopping
   (compatibility will be dropped after Mercurial-42.1337, update your code.) at:
    <string>:* in <module> (glob)
    mercurial.dispatch:* in run (glob)
    mercurial.dispatch:* in dispatch (glob)
    mercurial.dispatch:* in _rundispatch (glob)
    mercurial.dispatch:* in _runcatch (glob)
    mercurial.dispatch:* in _callcatch (glob)
    mercurial.scmutil* in callcatch (glob)
    mercurial.dispatch:* in _runcatchfunc (glob)
    mercurial.dispatch:* in _dispatch (glob)
    mercurial.dispatch:* in runcommand (glob)
    mercurial.dispatch:* in _runcommand (glob)
    mercurial.dispatch:* in <lambda> (glob)
    mercurial.util:* in check (glob)
    $TESTTMP/buggylocking.py:* in oldanddeprecated (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> blackbox -l 7
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> oldanddeprecated --traceback exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @cb9a9f314b8b07ba71012fcdbc544b5a4d82ff5b (5000)> blackbox -l 7
 #endif
 
 Test programming error failure:
 
   $ hg buggytransaction 2>&1 | egrep -v '^  '
   ** Unknown exception encountered with possibly-broken third-party extension "buggylocking" (version N/A)
   ** which supports versions unknown of Mercurial.
   ** Please disable "buggylocking" and try your action again.
   ** If that fixes the bug please report it to the extension author.
   ** Python * (glob)
   ** Mercurial Distributed SCM (*) (glob)
   ** Extensions loaded: * (glob)
   ** ProgrammingError: transaction requires locking
   Traceback (most recent call last):
   *ProgrammingError: transaction requires locking (glob)
 
   $ hg programmingerror 2>&1 | egrep -v '^  '
   ** Unknown exception encountered with possibly-broken third-party extension "buggylocking" (version N/A)
   ** which supports versions unknown of Mercurial.
   ** Please disable "buggylocking" and try your action again.
   ** If that fixes the bug please report it to the extension author.
   ** Python * (glob)
   ** Mercurial Distributed SCM (*) (glob)
   ** Extensions loaded: * (glob)
   ** ProgrammingError: something went wrong
   ** (try again)
   Traceback (most recent call last):
   *ProgrammingError: something went wrong (glob)
 
 Old style deprecation warning
 
   $ hg nouiwarning
   $TESTTMP/buggylocking.py:*: DeprecationWarning: this is a test (glob)
   (compatibility will be dropped after Mercurial-13.37, update your code.)
     util.nouideprecwarn(b'this is a test', b'13.37')
 
 (disabled outside of test run)
 
   $ HGEMITWARNINGS= hg nouiwarning
 
 Test warning on config option access and registration
 
   $ cat << EOF > ${TESTTMP}/buggyconfig.py
   > """A small extension that tests our developer warnings for config"""
   > 
   > from mercurial import configitems, registrar
   > 
   > cmdtable = {}
   > command = registrar.command(cmdtable)
   > 
   > configtable = {}
   > configitem = registrar.configitem(configtable)
   > 
   > configitem(b'test', b'some', default=b'foo')
   > configitem(b'test', b'dynamic', default=configitems.dynamicdefault)
   > configitem(b'test', b'callable', default=list)
   > # overwrite a core config
   > configitem(b'ui', b'quiet', default=False)
   > configitem(b'ui', b'interactive', default=None)
   > 
   > @command(b'buggyconfig')
   > def cmdbuggyconfig(ui, repo):
   >     repo.ui.config(b'ui', b'quiet', True)
   >     repo.ui.config(b'ui', b'interactive', False)
   >     repo.ui.config(b'test', b'some', b'bar')
   >     repo.ui.config(b'test', b'some', b'foo')
   >     repo.ui.config(b'test', b'dynamic', b'some-required-default')
   >     repo.ui.config(b'test', b'dynamic')
   >     repo.ui.config(b'test', b'callable', [])
   >     repo.ui.config(b'test', b'callable', b'foo')
   >     repo.ui.config(b'test', b'unregistered')
   >     repo.ui.config(b'unregistered', b'unregistered')
   > EOF
 
   $ hg --config "extensions.buggyconfig=${TESTTMP}/buggyconfig.py" buggyconfig
   devel-warn: extension 'buggyconfig' overwrite config item 'ui.interactive' at: */mercurial/extensions.py:* (_loadextra) (glob) (no-pyoxidizer !)
   devel-warn: extension 'buggyconfig' overwrite config item 'ui.quiet' at: */mercurial/extensions.py:* (_loadextra) (glob) (no-pyoxidizer !)
   devel-warn: extension 'buggyconfig' overwrite config item 'ui.interactive' at: mercurial.extensions:* (_loadextra) (glob) (pyoxidizer !)
   devel-warn: extension 'buggyconfig' overwrite config item 'ui.quiet' at: mercurial.extensions:* (_loadextra) (glob) (pyoxidizer !)
   devel-warn: specifying a mismatched default value for a registered config item: 'ui.quiet' 'True' at: $TESTTMP/buggyconfig.py:* (cmdbuggyconfig) (glob)
   devel-warn: specifying a mismatched default value for a registered config item: 'ui.interactive' 'False' at: $TESTTMP/buggyconfig.py:* (cmdbuggyconfig) (glob)
   devel-warn: specifying a mismatched default value for a registered config item: 'test.some' 'bar' at: $TESTTMP/buggyconfig.py:* (cmdbuggyconfig) (glob)
   devel-warn: config item requires an explicit default value: 'test.dynamic' at: $TESTTMP/buggyconfig.py:* (cmdbuggyconfig) (glob)
   devel-warn: specifying a mismatched default value for a registered config item: 'test.callable' 'foo' at: $TESTTMP/buggyconfig.py:* (cmdbuggyconfig) (glob)
   devel-warn: accessing unregistered config item: 'test.unregistered' at: $TESTTMP/buggyconfig.py:* (cmdbuggyconfig) (glob)
   devel-warn: accessing unregistered config item: 'unregistered.unregistered' at: $TESTTMP/buggyconfig.py:* (cmdbuggyconfig) (glob)
 
   $ cd ..

tests/test-obsolete-tag-cache.t

@@ -1,125 +1,125 b''
   $ cat >> $HGRCPATH << EOF
   > [extensions]
   > blackbox=
   > rebase=
   > mock=$TESTDIR/mockblackbox.py
   > 
   > [blackbox]
   > track = command, commandfinish, tagscache
   > 
   > [experimental]
   > evolution.createmarkers=True
   > EOF
 
 Create a repo with some tags
 
   $ hg init repo
   $ cd repo
   $ echo initial > foo
   $ hg -q commit -A -m initial
   $ hg tag -m 'test tag' test1
   $ echo first > first
   $ hg -q commit -A -m first
   $ hg tag -m 'test2 tag' test2
   $ hg -q up -r 0
   $ echo newhead > newhead
   $ hg commit -A -m newhead
   adding newhead
   created new head
   $ hg tag -m 'test head 2 tag' head2
 
   $ hg log -G -T '{rev}:{node|short} {tags} {desc}\n'
   @  5:2942a772f72a tip test head 2 tag
   |
   o  4:042eb6bfcc49 head2 newhead
   |
   | o  3:c3cb30f2d2cd  test2 tag
   | |
   | o  2:d75775ffbc6b test2 first
   | |
   | o  1:5f97d42da03f  test tag
   |/
   o  0:55482a6fb4b1 test1 initial
   
 
 Trigger tags cache population by doing something that accesses tags info
 
   $ hg tags
   tip                                5:2942a772f72a
   head2                              4:042eb6bfcc49
   test2                              2:d75775ffbc6b
   test1                              0:55482a6fb4b1
 
   $ cat .hg/cache/tags2-visible
   5 2942a772f72a444bef4bef13874d515f50fa27b6
   042eb6bfcc4909bad84a1cbf6eb1ddf0ab587d41 head2
   55482a6fb4b1881fa8f746fd52cf6f096bb21c89 test1
   d75775ffbc6bca1794d300f5571272879bd280da test2
 
 Hiding a non-tip changeset should change filtered hash and cause tags recompute
 
   $ hg debugobsolete -d '0 0' c3cb30f2d2cd0aae008cc91a07876e3c5131fd22 -u dummyuser
   1 new obsolescence markers
   obsoleted 1 changesets
 
   $ hg tags
   tip                                5:2942a772f72a
   head2                              4:042eb6bfcc49
   test1                              0:55482a6fb4b1
 
   $ cat .hg/cache/tags2-visible
   5 2942a772f72a444bef4bef13874d515f50fa27b6 f34fbc9a9769ba9eff5aff3d008a6b49f85c08b1
   042eb6bfcc4909bad84a1cbf6eb1ddf0ab587d41 head2
   55482a6fb4b1881fa8f746fd52cf6f096bb21c89 test1
 
   $ hg blackbox -l 5
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 2/2 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2-visible with 2 tags
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 2/2 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2-visible with 2 tags
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5
 
 Hiding another changeset should cause the filtered hash to change
 
   $ hg debugobsolete -d '0 0' d75775ffbc6bca1794d300f5571272879bd280da -u dummyuser
   1 new obsolescence markers
   obsoleted 1 changesets
   $ hg debugobsolete -d '0 0' 5f97d42da03fd56f3b228b03dfe48af5c0adf75b -u dummyuser
   1 new obsolescence markers
   obsoleted 1 changesets
 
   $ hg tags
   tip                                5:2942a772f72a
   head2                              4:042eb6bfcc49
 
   $ cat .hg/cache/tags2-visible
   5 2942a772f72a444bef4bef13874d515f50fa27b6 2fce1eec33263d08a4d04293960fc73a555230e4
   042eb6bfcc4909bad84a1cbf6eb1ddf0ab587d41 head2
 
   $ hg blackbox -l 5
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 1/1 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 1/1 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2-visible with 1 tags
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> tags exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5
 
 Resolving tags on an unfiltered repo writes a separate tags cache
 
   $ hg --hidden tags
   tip                                5:2942a772f72a
   head2                              4:042eb6bfcc49
   test2                              2:d75775ffbc6b
   test1                              0:55482a6fb4b1
 
   $ cat .hg/cache/tags2
   5 2942a772f72a444bef4bef13874d515f50fa27b6
   042eb6bfcc4909bad84a1cbf6eb1ddf0ab587d41 head2
   55482a6fb4b1881fa8f746fd52cf6f096bb21c89 test1
   d75775ffbc6bca1794d300f5571272879bd280da test2
 
   $ hg blackbox -l 5
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> --hidden tags
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 2/2 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2 with 3 tags
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> --hidden tags exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> --hidden tags
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> 2/2 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> writing .hg/cache/tags2 with 3 tags
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> --hidden tags exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @2942a772f72a444bef4bef13874d515f50fa27b6 (5000)> blackbox -l 5

tests/test-rhg.t

@@ -1,392 +1,392 b''
 #require rhg
 
   $ NO_FALLBACK="env RHG_ON_UNSUPPORTED=abort"
 
 Unimplemented command
   $ $NO_FALLBACK rhg unimplemented-command
   unsupported feature: error: Found argument 'unimplemented-command' which wasn't expected, or isn't valid in this context
   
   USAGE:
       rhg [OPTIONS] <SUBCOMMAND>
   
   For more information try --help
   
   [252]
   $ rhg unimplemented-command --config rhg.on-unsupported=abort-silent
   [252]
 
 Finding root
   $ $NO_FALLBACK rhg root
   abort: no repository found in '$TESTTMP' (.hg not found)!
   [255]
 
   $ hg init repository
   $ cd repository
   $ $NO_FALLBACK rhg root
   $TESTTMP/repository
 
 Reading and setting configuration
   $ echo "[ui]" >> $HGRCPATH
   $ echo "username = user1" >> $HGRCPATH
   $ $NO_FALLBACK rhg config ui.username
   user1
   $ echo "[ui]" >> .hg/hgrc
   $ echo "username = user2" >> .hg/hgrc
   $ $NO_FALLBACK rhg config ui.username
   user2
   $ $NO_FALLBACK rhg --config ui.username=user3 config ui.username
   user3
 
 Unwritable file descriptor
   $ $NO_FALLBACK rhg root > /dev/full
   abort: No space left on device (os error 28)
   [255]
 
 Deleted repository
   $ rm -rf `pwd`
   $ $NO_FALLBACK rhg root
   abort: error getting current working directory: $ENOENT$
   [255]
 
 Listing tracked files
   $ cd $TESTTMP
   $ hg init repository
   $ cd repository
   $ for i in 1 2 3; do
   >   echo $i >> file$i
   >   hg add file$i
   > done
   > hg commit -m "commit $i" -q
 
 Listing tracked files from root
   $ $NO_FALLBACK rhg files
   file1
   file2
   file3
 
 Listing tracked files from subdirectory
   $ mkdir -p path/to/directory
   $ cd path/to/directory
   $ $NO_FALLBACK rhg files
   ../../../file1
   ../../../file2
   ../../../file3
 
 Listing tracked files through broken pipe
   $ $NO_FALLBACK rhg files | head -n 1
   ../../../file1
 
 Debuging data in inline index
   $ cd $TESTTMP
   $ rm -rf repository
   $ hg init repository
   $ cd repository
   $ for i in 1 2 3 4 5 6; do
   >   echo $i >> file-$i
   >   hg add file-$i
   >   hg commit -m "Commit $i" -q
   > done
   $ $NO_FALLBACK rhg debugdata -c 2
   8d0267cb034247ebfa5ee58ce59e22e57a492297
   test
   0 0
   file-3
   
   Commit 3 (no-eol)
   $ $NO_FALLBACK rhg debugdata -m 2
   file-1\x00b8e02f6433738021a065f94175c7cd23db5f05be (esc)
   file-2\x005d9299349fc01ddd25d0070d149b124d8f10411e (esc)
   file-3\x002661d26c649684b482d10f91960cc3db683c38b4 (esc)
 
 Debuging with full node id
   $ $NO_FALLBACK rhg debugdata -c `hg log -r 0 -T '{node}'`
   d1d1c679d3053e8926061b6f45ca52009f011e3f
   test
   0 0
   file-1
   
   Commit 1 (no-eol)
 
 Specifying revisions by changeset ID
   $ hg log -T '{node}\n'
   c6ad58c44207b6ff8a4fbbca7045a5edaa7e908b
   d654274993d0149eecc3cc03214f598320211900
   f646af7e96481d3a5470b695cf30ad8e3ab6c575
   cf8b83f14ead62b374b6e91a0e9303b85dfd9ed7
   91c6f6e73e39318534dc415ea4e8a09c99cd74d6
   6ae9681c6d30389694d8701faf24b583cf3ccafe
   $ $NO_FALLBACK rhg files -r cf8b83
   file-1
   file-2
   file-3
   $ $NO_FALLBACK rhg cat -r cf8b83 file-2
   2
   $ $NO_FALLBACK rhg cat --rev cf8b83 file-2
   2
   $ $NO_FALLBACK rhg cat -r c file-2
   abort: ambiguous revision identifier: c
   [255]
   $ $NO_FALLBACK rhg cat -r d file-2
   2
   $ $NO_FALLBACK rhg cat -r 0000 file-2
   file-2: no such file in rev 000000000000
   [1]
 
 Cat files
   $ cd $TESTTMP
   $ rm -rf repository
   $ hg init repository
   $ cd repository
   $ echo "original content" > original
   $ hg add original
   $ hg commit -m "add original" original
 Without `--rev`
   $ $NO_FALLBACK rhg cat original
   original content
 With `--rev`
   $ $NO_FALLBACK rhg cat -r 0 original
   original content
 Cat copied file should not display copy metadata
   $ hg copy original copy_of_original
   $ hg commit -m "add copy of original"
   $ $NO_FALLBACK rhg cat original
   original content
   $ $NO_FALLBACK rhg cat -r 1 copy_of_original
   original content
 
 
 Fallback to Python
   $ $NO_FALLBACK rhg cat original --exclude="*.rs"
   unsupported feature: error: Found argument '--exclude' which wasn't expected, or isn't valid in this context
   
   USAGE:
       rhg cat [OPTIONS] <FILE>...
   
   For more information try --help
   
   [252]
   $ rhg cat original --exclude="*.rs"
   original content
 
   $ (unset RHG_FALLBACK_EXECUTABLE; rhg cat original --exclude="*.rs")
   abort: 'rhg.on-unsupported=fallback' without 'rhg.fallback-executable' set.
   [255]
 
   $ (unset RHG_FALLBACK_EXECUTABLE; rhg cat original)
   original content
 
   $ rhg cat original --exclude="*.rs" --config rhg.fallback-executable=false
   [1]
 
   $ rhg cat original --exclude="*.rs" --config rhg.fallback-executable=hg-non-existent
   tried to fall back to a 'hg-non-existent' sub-process but got error $ENOENT$
   unsupported feature: error: Found argument '--exclude' which wasn't expected, or isn't valid in this context
   
   USAGE:
       rhg cat [OPTIONS] <FILE>...
   
   For more information try --help
   
   [252]
 
   $ rhg cat original --exclude="*.rs" --config rhg.fallback-executable=rhg
   Blocking recursive fallback. The 'rhg.fallback-executable = rhg' config points to `rhg` itself.
   unsupported feature: error: Found argument '--exclude' which wasn't expected, or isn't valid in this context
   
   USAGE:
       rhg cat [OPTIONS] <FILE>...
   
   For more information try --help
   
   [252]
 
 Fallback with shell path segments
   $ $NO_FALLBACK rhg cat .
   unsupported feature: `..` or `.` path segment
   [252]
   $ $NO_FALLBACK rhg cat ..
   unsupported feature: `..` or `.` path segment
   [252]
   $ $NO_FALLBACK rhg cat ../..
   unsupported feature: `..` or `.` path segment
   [252]
 
 Fallback with filesets
   $ $NO_FALLBACK rhg cat "set:c or b"
   unsupported feature: fileset
   [252]
 
 Fallback with generic hooks
   $ $NO_FALLBACK rhg cat original --config hooks.pre-cat=something
   unsupported feature: pre-cat hook defined
   [252]
 
   $ $NO_FALLBACK rhg cat original --config hooks.post-cat=something
   unsupported feature: post-cat hook defined
   [252]
 
   $ $NO_FALLBACK rhg cat original --config hooks.fail-cat=something
   unsupported feature: fail-cat hook defined
   [252]
 
 Fallback with [defaults]
   $ $NO_FALLBACK rhg cat original --config "defaults.cat=-r null"
   unsupported feature: `defaults` config set
   [252]
 
 
 Requirements
   $ $NO_FALLBACK rhg debugrequirements
   dotencode
   fncache
   generaldelta
   persistent-nodemap
   revlog-compression-zstd (zstd !)
   revlogv1
   sparserevlog
   store
 
   $ echo indoor-pool >> .hg/requires
   $ $NO_FALLBACK rhg files
   unsupported feature: repository requires feature unknown to this Mercurial: indoor-pool
   [252]
 
   $ $NO_FALLBACK rhg cat -r 1 copy_of_original
   unsupported feature: repository requires feature unknown to this Mercurial: indoor-pool
   [252]
 
   $ $NO_FALLBACK rhg debugrequirements
   unsupported feature: repository requires feature unknown to this Mercurial: indoor-pool
   [252]
 
   $ echo -e '\xFF' >> .hg/requires
   $ $NO_FALLBACK rhg debugrequirements
   abort: parse error in 'requires' file
   [255]
 
 Persistent nodemap
   $ cd $TESTTMP
   $ rm -rf repository
   $ hg --config format.use-persistent-nodemap=no init repository
   $ cd repository
   $ $NO_FALLBACK rhg debugrequirements | grep nodemap
   [1]
   $ hg debugbuilddag .+5000 --overwritten-file --config "storage.revlog.nodemap.mode=warn"
   $ hg id -r tip
   c3ae8dec9fad tip
   $ ls .hg/store/00changelog*
   .hg/store/00changelog.d
   .hg/store/00changelog.i
   $ $NO_FALLBACK rhg files -r c3ae8dec9fad
   of
 
   $ cd $TESTTMP
   $ rm -rf repository
   $ hg --config format.use-persistent-nodemap=True init repository
   $ cd repository
   $ $NO_FALLBACK rhg debugrequirements | grep nodemap
   persistent-nodemap
   $ hg debugbuilddag .+5000 --overwritten-file --config "storage.revlog.nodemap.mode=warn"
   $ hg id -r tip
   c3ae8dec9fad tip
   $ ls .hg/store/00changelog*
   .hg/store/00changelog-*.nd (glob)
   .hg/store/00changelog.d
   .hg/store/00changelog.i
   .hg/store/00changelog.n
 
 Specifying revisions by changeset ID
   $ $NO_FALLBACK rhg files -r c3ae8dec9fad
   of
   $ $NO_FALLBACK rhg cat -r c3ae8dec9fad of
   r5000
 
 Crate a shared repository
 
   $ echo "[extensions]"      >> $HGRCPATH
   $ echo "share = "          >> $HGRCPATH
 
   $ cd $TESTTMP
   $ hg init repo1
   $ echo a > repo1/a
   $ hg -R repo1 commit -A -m'init'
   adding a
 
   $ hg share repo1 repo2
   updating working directory
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
 
 And check that basic rhg commands work with sharing
 
   $ $NO_FALLBACK rhg files -R repo2
   repo2/a
   $ $NO_FALLBACK rhg -R repo2 cat -r 0 repo2/a
   a
 
 Same with relative sharing
 
   $ hg share repo2 repo3 --relative
   updating working directory
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
 
   $ $NO_FALLBACK rhg files -R repo3
   repo3/a
   $ $NO_FALLBACK rhg -R repo3 cat -r 0 repo3/a
   a
 
 Same with share-safe
 
   $ echo "[format]"         >> $HGRCPATH
   $ echo "use-share-safe = True" >> $HGRCPATH
 
   $ cd $TESTTMP
   $ hg init repo4
   $ cd repo4
   $ echo a > a
   $ hg commit -A -m'init'
   adding a
 
   $ cd ..
   $ hg share repo4 repo5
   updating working directory
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
 
 And check that basic rhg commands work with sharing
 
   $ cd repo5
   $ $NO_FALLBACK rhg files
   a
   $ $NO_FALLBACK rhg cat -r 0 a
   a
 
 The blackbox extension is supported
 
   $ echo "[extensions]" >> $HGRCPATH
   $ echo "blackbox =" >> $HGRCPATH
   $ echo "[blackbox]" >> $HGRCPATH
   $ echo "maxsize = 1" >> $HGRCPATH
   $ $NO_FALLBACK rhg files > /dev/null
   $ cat .hg/blackbox.log
-  ????/??/?? ??:??:??.??? * @d3873e73d99ef67873dac33fbcc66268d5d2b6f4 (*)> (rust) files exited 0 after 0.??? seconds (glob)
+  ????-??-?? ??:??:??.??? * @d3873e73d99ef67873dac33fbcc66268d5d2b6f4 (*)> (rust) files exited 0 after 0.??? seconds (glob)
   $ cat .hg/blackbox.log.1
-  ????/??/?? ??:??:??.??? * @d3873e73d99ef67873dac33fbcc66268d5d2b6f4 (*)> (rust) files (glob)
+  ????-??-?? ??:??:??.??? * @d3873e73d99ef67873dac33fbcc66268d5d2b6f4 (*)> (rust) files (glob)
 
 Subrepos are not supported
 
   $ touch .hgsub
   $ $NO_FALLBACK rhg files
   unsupported feature: subrepos (.hgsub is present)
   [252]
   $ rhg files
   a
   $ rm .hgsub
 
 The `:required` extension suboptions are correctly ignored
 
   $ echo "[extensions]" >> $HGRCPATH
   $ echo "blackbox:required = yes" >> $HGRCPATH
   $ rhg files
   a
   $ echo "*:required = yes" >> $HGRCPATH
   $ rhg files
   a

tests/test-tags.t

@@ -1,935 +1,935 b''
 setup
 
   $ cat >> $HGRCPATH << EOF
   > [extensions]
   > blackbox=
   > mock=$TESTDIR/mockblackbox.py
   > [blackbox]
   > track = command, commandfinish, tagscache
   > EOF
 
 Helper functions:
 
   $ cacheexists() {
   >   [ -f .hg/cache/tags2-visible ] && echo "tag cache exists" || echo "no tag cache"
   > }
 
   $ fnodescacheexists() {
   >   [ -f .hg/cache/hgtagsfnodes1 ] && echo "fnodes cache exists" || echo "no fnodes cache"
   > }
 
   $ dumptags() {
   >     rev=$1
   >     echo "rev $rev: .hgtags:"
   >     hg cat -r$rev .hgtags
   > }
 
 # XXX need to test that the tag cache works when we strip an old head
 # and add a new one rooted off non-tip: i.e. node and rev of tip are the
 # same, but stuff has changed behind tip.
 
 Setup:
 
   $ hg init t
   $ cd t
   $ cacheexists
   no tag cache
   $ fnodescacheexists
   no fnodes cache
   $ hg id
   000000000000 tip
   $ cacheexists
   no tag cache
   $ fnodescacheexists
   no fnodes cache
   $ echo a > a
   $ hg add a
   $ hg commit -m "test"
   $ hg co
   0 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ hg identify
   acb14030fe0a tip
   $ hg identify -r 'wdir()'
   acb14030fe0a tip
   $ cacheexists
   tag cache exists
 No fnodes cache because .hgtags file doesn't exist
 (this is an implementation detail)
   $ fnodescacheexists
   no fnodes cache
 
 Try corrupting the cache
 
   $ printf 'a b' > .hg/cache/tags2-visible
   $ hg identify
   acb14030fe0a tip
   $ cacheexists
   tag cache exists
   $ fnodescacheexists
   no fnodes cache
   $ hg identify
   acb14030fe0a tip
 
 Create local tag with long name:
 
   $ T=`hg identify --debug --id`
   $ hg tag -l "This is a local tag with a really long name!"
   $ hg tags
   tip                                0:acb14030fe0a
   This is a local tag with a really long name!     0:acb14030fe0a
   $ rm .hg/localtags
 
 Create a tag behind hg's back:
 
   $ echo "$T first" > .hgtags
   $ cat .hgtags
   acb14030fe0a21b60322c440ad2d20cf7685a376 first
   $ hg add .hgtags
   $ hg commit -m "add tags"
   $ hg tags
   tip                                1:b9154636be93
   first                              0:acb14030fe0a
   $ hg identify
   b9154636be93 tip
 
 We should have a fnodes cache now that we have a real tag
 The cache should have an empty entry for rev 0 and a valid entry for rev 1.
 
 
   $ fnodescacheexists
   fnodes cache exists
   $ f --size --hexdump .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=48
   0000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0010: ff ff ff ff ff ff ff ff b9 15 46 36 26 b7 b4 a7 |..........F6&...|
   0020: 73 e0 9e e3 c5 2f 51 0e 19 e0 5e 1f f9 66 d8 59 |s..../Q...^..f.Y|
   $ hg debugtagscache
   0 acb14030fe0a21b60322c440ad2d20cf7685a376 missing
   1 b9154636be938d3d431e75a7c906504a079bfe07 26b7b4a773e09ee3c52f510e19e05e1ff966d859
 
 Repeat with cold tag cache:
 
   $ rm -f .hg/cache/tags2-visible .hg/cache/hgtagsfnodes1
   $ hg identify
   b9154636be93 tip
 
   $ fnodescacheexists
   fnodes cache exists
   $ f --size --hexdump .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=48
   0000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0010: ff ff ff ff ff ff ff ff b9 15 46 36 26 b7 b4 a7 |..........F6&...|
   0020: 73 e0 9e e3 c5 2f 51 0e 19 e0 5e 1f f9 66 d8 59 |s..../Q...^..f.Y|
 
 And again, but now unable to write tag cache or lock file:
 
 #if unix-permissions no-fsmonitor
 
   $ rm -f .hg/cache/tags2-visible .hg/cache/hgtagsfnodes1
   $ chmod 555 .hg/cache
   $ hg identify
   b9154636be93 tip
   $ chmod 755 .hg/cache
 
 (this block should be protected by no-fsmonitor, because "chmod 555 .hg"
 makes watchman fail at accessing to files under .hg)
 
   $ chmod 555 .hg
   $ hg identify
   b9154636be93 tip
   $ chmod 755 .hg
 #endif
 
 Tag cache debug info written to blackbox log
 
   $ rm -f .hg/cache/tags2-visible .hg/cache/hgtagsfnodes1
   $ hg identify
   b9154636be93 tip
   $ hg blackbox -l 6
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing 48 bytes to cache/hgtagsfnodes1
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> 0/2 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l 6
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing 48 bytes to cache/hgtagsfnodes1
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> 0/2 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing .hg/cache/tags2-visible with 1 tags
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l 6
 
 Failure to acquire lock results in no write
 
   $ rm -f .hg/cache/tags2-visible .hg/cache/hgtagsfnodes1
   $ echo 'foo:1' > .hg/store/lock
   $ hg identify
   b9154636be93 tip
   $ hg blackbox -l 6
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> not writing .hg/cache/hgtagsfnodes1 because lock cannot be acquired
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> 0/2 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l 6
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> not writing .hg/cache/hgtagsfnodes1 because lock cannot be acquired
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> 0/2 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> writing .hg/cache/tags2-visible with 1 tags
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> identify exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l 6
 
   $ fnodescacheexists
   no fnodes cache
 
   $ rm .hg/store/lock
 
   $ rm -f .hg/cache/tags2-visible .hg/cache/hgtagsfnodes1
   $ hg identify
   b9154636be93 tip
 
 Create a branch:
 
   $ echo bb > a
   $ hg status
   M a
   $ hg identify
   b9154636be93+ tip
   $ hg co first
   0 files updated, 0 files merged, 1 files removed, 0 files unresolved
   $ hg id
   acb14030fe0a+ first
   $ hg id -r 'wdir()'
   acb14030fe0a+ first
   $ hg -v id
   acb14030fe0a+ first
   $ hg status
   M a
   $ echo 1 > b
   $ hg add b
   $ hg commit -m "branch"
   created new head
 
 Creating a new commit shouldn't append the .hgtags fnodes cache until
 tags info is accessed
 
   $ f --size --hexdump .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=48
   0000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0010: ff ff ff ff ff ff ff ff b9 15 46 36 26 b7 b4 a7 |..........F6&...|
   0020: 73 e0 9e e3 c5 2f 51 0e 19 e0 5e 1f f9 66 d8 59 |s..../Q...^..f.Y|
 
   $ hg id
   c8edf04160c7 tip
 
 First 4 bytes of record 3 are changeset fragment
 
   $ f --size --hexdump .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=72
   0000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0010: ff ff ff ff ff ff ff ff b9 15 46 36 26 b7 b4 a7 |..........F6&...|
   0020: 73 e0 9e e3 c5 2f 51 0e 19 e0 5e 1f f9 66 d8 59 |s..../Q...^..f.Y|
   0030: c8 ed f0 41 00 00 00 00 00 00 00 00 00 00 00 00 |...A............|
   0040: 00 00 00 00 00 00 00 00                         |........|
 
 Merge the two heads:
 
   $ hg merge 1
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   (branch merge, don't forget to commit)
   $ hg blackbox -l3
-  1970/01/01 00:00:00.000 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28 (5000)> merge 1
-  1970/01/01 00:00:00.000 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28+b9154636be938d3d431e75a7c906504a079bfe07 (5000)> merge 1 exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28+b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l3
+  1970-01-01 00:00:00.000 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28 (5000)> merge 1
+  1970-01-01 00:00:00.000 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28+b9154636be938d3d431e75a7c906504a079bfe07 (5000)> merge 1 exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @c8edf04160c7f731e4589d66ab3ab3486a64ac28+b9154636be938d3d431e75a7c906504a079bfe07 (5000)> blackbox -l3
   $ hg id
   c8edf04160c7+b9154636be93+ tip
   $ hg status
   M .hgtags
   $ hg commit -m "merge"
 
 Create a fake head, make sure tag not visible afterwards:
 
   $ cp .hgtags tags
   $ hg tag last
   $ hg rm .hgtags
   $ hg commit -m "remove"
 
   $ mv tags .hgtags
   $ hg add .hgtags
   $ hg commit -m "readd"
   $ 
   $ hg tags
   tip                                6:35ff301afafe
   first                              0:acb14030fe0a
 
 Add invalid tags:
 
   $ echo "spam" >> .hgtags
   $ echo >> .hgtags
   $ echo "foo bar" >> .hgtags
   $ echo "a5a5 invalid" >> .hg/localtags
   $ cat .hgtags
   acb14030fe0a21b60322c440ad2d20cf7685a376 first
   spam
   
   foo bar
   $ hg commit -m "tags"
 
 Report tag parse error on other head:
 
   $ hg up 3
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ echo 'x y' >> .hgtags
   $ hg commit -m "head"
   created new head
 
   $ hg tags --debug
   .hgtags@75d9f02dfe28, line 2: cannot parse entry
   .hgtags@75d9f02dfe28, line 4: node 'foo' is not well formed
   .hgtags@c4be69a18c11, line 2: node 'x' is not well formed
   tip                                8:c4be69a18c11e8bc3a5fdbb576017c25f7d84663
   first                              0:acb14030fe0a21b60322c440ad2d20cf7685a376
   $ hg tip
   changeset:   8:c4be69a18c11
   tag:         tip
   parent:      3:ac5e980c4dc0
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     head
   
 
 Test tag precedence rules:
 
   $ cd ..
   $ hg init t2
   $ cd t2
   $ echo foo > foo
   $ hg add foo
   $ hg ci -m 'add foo'      # rev 0
   $ hg tag bar              # rev 1
   $ echo >> foo
   $ hg ci -m 'change foo 1' # rev 2
   $ hg up -C 1
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ hg tag -r 1 -f bar      # rev 3
   $ hg up -C 1
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ echo >> foo
   $ hg ci -m 'change foo 2' # rev 4
   created new head
   $ hg tags
   tip                                4:0c192d7d5e6b
   bar                                1:78391a272241
 
 Repeat in case of cache effects:
 
   $ hg tags
   tip                                4:0c192d7d5e6b
   bar                                1:78391a272241
 
 Detailed dump of tag info:
 
   $ hg heads -q             # expect 4, 3, 2
   4:0c192d7d5e6b
   3:6fa450212aeb
   2:7a94127795a3
   $ dumptags 2
   rev 2: .hgtags:
   bbd179dfa0a71671c253b3ae0aa1513b60d199fa bar
   $ dumptags 3
   rev 3: .hgtags:
   bbd179dfa0a71671c253b3ae0aa1513b60d199fa bar
   bbd179dfa0a71671c253b3ae0aa1513b60d199fa bar
   78391a272241d70354aa14c874552cad6b51bb42 bar
   $ dumptags 4
   rev 4: .hgtags:
   bbd179dfa0a71671c253b3ae0aa1513b60d199fa bar
 
 Dump cache:
 
   $ cat .hg/cache/tags2-visible
   4 0c192d7d5e6b78a714de54a2e9627952a877e25a
   bbd179dfa0a71671c253b3ae0aa1513b60d199fa bar
   bbd179dfa0a71671c253b3ae0aa1513b60d199fa bar
   78391a272241d70354aa14c874552cad6b51bb42 bar
 
   $ f --size --hexdump .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=120
   0000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0010: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0020: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0030: 7a 94 12 77 0c 04 f2 a8 af 31 de 17 fa b7 42 28 |z..w.....1....B(|
   0040: 78 ee 5a 2d ad bc 94 3d 6f a4 50 21 7d 3b 71 8c |x.Z-...=o.P!};q.|
   0050: 96 4e f3 7b 89 e5 50 eb da fd 57 89 e7 6c e1 b0 |.N.{..P...W..l..|
   0060: 0c 19 2d 7d 0c 04 f2 a8 af 31 de 17 fa b7 42 28 |..-}.....1....B(|
   0070: 78 ee 5a 2d ad bc 94 3d                         |x.Z-...=|
 
 Corrupt the .hgtags fnodes cache
 Extra junk data at the end should get overwritten on next cache update
 
   $ echo extra >> .hg/cache/hgtagsfnodes1
   $ echo dummy1 > foo
   $ hg commit -m throwaway1
 
   $ hg tags
   tip                                5:8dbfe60eff30
   bar                                1:78391a272241
 
   $ hg blackbox -l 6
-  1970/01/01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> tags
-  1970/01/01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> writing 24 bytes to cache/hgtagsfnodes1
-  1970/01/01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> 3/4 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> tags exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> blackbox -l 6
+  1970-01-01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> tags
+  1970-01-01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> writing 24 bytes to cache/hgtagsfnodes1
+  1970-01-01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> 3/4 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> writing .hg/cache/tags2-visible with 1 tags
+  1970-01-01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> tags exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @8dbfe60eff306a54259cfe007db9e330e7ecf866 (5000)> blackbox -l 6
 
 On junk data + missing cache entries, hg also overwrites the junk.
 
   $ rm -f .hg/cache/tags2-visible
   >>> import os
   >>> with open(".hg/cache/hgtagsfnodes1", "ab+") as fp:
   ...     fp.seek(-10, os.SEEK_END) and None
   ...     fp.truncate() and None
 
   $ hg debugtagscache | tail -2
   4 0c192d7d5e6b78a714de54a2e9627952a877e25a 0c04f2a8af31de17fab7422878ee5a2dadbc943d
   5 8dbfe60eff306a54259cfe007db9e330e7ecf866 missing
   $ hg tags
   tip                                5:8dbfe60eff30
   bar                                1:78391a272241
   $ hg debugtagscache | tail -2
   4 0c192d7d5e6b78a714de54a2e9627952a877e25a 0c04f2a8af31de17fab7422878ee5a2dadbc943d
   5 8dbfe60eff306a54259cfe007db9e330e7ecf866 0c04f2a8af31de17fab7422878ee5a2dadbc943d
 
 If the 4 bytes of node hash for a record don't match an existing node, the entry
 is flagged as invalid.
 
   >>> import os
   >>> with open(".hg/cache/hgtagsfnodes1", "rb+") as fp:
   ...     fp.seek(-24, os.SEEK_END) and None
   ...     fp.write(b'\xde\xad') and None
 
   $ f --size --hexdump .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=144
   0000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0010: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0020: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0030: 7a 94 12 77 0c 04 f2 a8 af 31 de 17 fa b7 42 28 |z..w.....1....B(|
   0040: 78 ee 5a 2d ad bc 94 3d 6f a4 50 21 7d 3b 71 8c |x.Z-...=o.P!};q.|
   0050: 96 4e f3 7b 89 e5 50 eb da fd 57 89 e7 6c e1 b0 |.N.{..P...W..l..|
   0060: 0c 19 2d 7d 0c 04 f2 a8 af 31 de 17 fa b7 42 28 |..-}.....1....B(|
   0070: 78 ee 5a 2d ad bc 94 3d de ad e6 0e 0c 04 f2 a8 |x.Z-...=........|
   0080: af 31 de 17 fa b7 42 28 78 ee 5a 2d ad bc 94 3d |.1....B(x.Z-...=|
 
   $ hg debugtagscache | tail -2
   4 0c192d7d5e6b78a714de54a2e9627952a877e25a 0c04f2a8af31de17fab7422878ee5a2dadbc943d
   5 8dbfe60eff306a54259cfe007db9e330e7ecf866 invalid
 
   $ hg tags
   tip                                5:8dbfe60eff30
   bar                                1:78391a272241
 
 BUG: If the filenode part of an entry in hgtagsfnodes is corrupt and
 tags2-visible is missing, `hg tags` aborts.  Corrupting the leading 4 bytes of
 node hash (as above) doesn't seem to trigger the issue.  Also note that the
 debug command hides the corruption, both with and without tags2-visible.
 
   $ mv .hg/cache/hgtagsfnodes1 .hg/cache/hgtagsfnodes1.bak
   $ hg debugupdatecaches
 
   >>> import os
   >>> with open(".hg/cache/hgtagsfnodes1", "rb+") as fp:
   ...     fp.seek(-16, os.SEEK_END) and None
   ...     fp.write(b'\xde\xad') and None
 
   $ f --size --hexdump .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=144
   0000: bb d1 79 df 00 00 00 00 00 00 00 00 00 00 00 00 |..y.............|
   0010: 00 00 00 00 00 00 00 00 78 39 1a 27 0c 04 f2 a8 |........x9.'....|
   0020: af 31 de 17 fa b7 42 28 78 ee 5a 2d ad bc 94 3d |.1....B(x.Z-...=|
   0030: 7a 94 12 77 0c 04 f2 a8 af 31 de 17 fa b7 42 28 |z..w.....1....B(|
   0040: 78 ee 5a 2d ad bc 94 3d 6f a4 50 21 7d 3b 71 8c |x.Z-...=o.P!};q.|
   0050: 96 4e f3 7b 89 e5 50 eb da fd 57 89 e7 6c e1 b0 |.N.{..P...W..l..|
   0060: 0c 19 2d 7d 0c 04 f2 a8 af 31 de 17 fa b7 42 28 |..-}.....1....B(|
   0070: 78 ee 5a 2d ad bc 94 3d 8d bf e6 0e 0c 04 f2 a8 |x.Z-...=........|
   0080: de ad de 17 fa b7 42 28 78 ee 5a 2d ad bc 94 3d |......B(x.Z-...=|
 
   $ hg debugtagscache | tail -2
   4 0c192d7d5e6b78a714de54a2e9627952a877e25a 0c04f2a8af31de17fab7422878ee5a2dadbc943d
   5 8dbfe60eff306a54259cfe007db9e330e7ecf866 0c04f2a8deadde17fab7422878ee5a2dadbc943d (unknown node)
 
   $ rm -f .hg/cache/tags2-visible
   $ hg debugtagscache | tail -2
   4 0c192d7d5e6b78a714de54a2e9627952a877e25a 0c04f2a8af31de17fab7422878ee5a2dadbc943d
   5 8dbfe60eff306a54259cfe007db9e330e7ecf866 0c04f2a8deadde17fab7422878ee5a2dadbc943d (unknown node)
 
   $ hg tags
   tip                                5:8dbfe60eff30
   bar                                1:78391a272241
 
 BUG: Unless this file is restored, the `hg tags` in the next unix-permissions
 conditional will fail: "abort: data/.hgtags.i@0c04f2a8dead: no match found"
 
   $ mv .hg/cache/hgtagsfnodes1.bak .hg/cache/hgtagsfnodes1
 
 #if unix-permissions no-root
 Errors writing to .hgtags fnodes cache are silently ignored
 
   $ echo dummy2 > foo
   $ hg commit -m throwaway2
 
   $ chmod a-w .hg/cache/hgtagsfnodes1
   $ rm -f .hg/cache/tags2-visible
 
   $ hg tags
   tip                                6:b968051b5cf3
   bar                                1:78391a272241
 
   $ hg blackbox -l 6
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> couldn't write cache/hgtagsfnodes1: [Errno *] * (glob)
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> 2/4 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> blackbox -l 6
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> couldn't write cache/hgtagsfnodes1: [Errno *] * (glob)
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> 2/4 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing .hg/cache/tags2-visible with 1 tags
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> blackbox -l 6
 
   $ chmod a+w .hg/cache/hgtagsfnodes1
 
   $ rm -f .hg/cache/tags2-visible
   $ hg tags
   tip                                6:b968051b5cf3
   bar                                1:78391a272241
 
   $ hg blackbox -l 6
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing 24 bytes to cache/hgtagsfnodes1
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> 2/4 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> blackbox -l 6
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing 24 bytes to cache/hgtagsfnodes1
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> 2/4 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> writing .hg/cache/tags2-visible with 1 tags
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> tags exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @b968051b5cf3f624b771779c6d5f84f1d4c3fb5d (5000)> blackbox -l 6
 
   $ f --size .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=168
 
   $ hg -q --config extensions.strip= strip -r 6 --no-backup
 #endif
 
 Stripping doesn't truncate the tags cache until new data is available
 
   $ rm -f .hg/cache/hgtagsfnodes1 .hg/cache/tags2-visible
   $ hg tags
   tip                                5:8dbfe60eff30
   bar                                1:78391a272241
 
   $ f --size .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=144
 
   $ hg -q --config extensions.strip= strip -r 5 --no-backup
   $ hg tags
   tip                                4:0c192d7d5e6b
   bar                                1:78391a272241
 
   $ hg blackbox -l 5
-  1970/01/01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> writing 24 bytes to cache/hgtagsfnodes1
-  1970/01/01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> 2/4 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> tags exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> blackbox -l 5
+  1970-01-01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> writing 24 bytes to cache/hgtagsfnodes1
+  1970-01-01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> 2/4 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> writing .hg/cache/tags2-visible with 1 tags
+  1970-01-01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> tags exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @0c192d7d5e6b78a714de54a2e9627952a877e25a (5000)> blackbox -l 5
 
   $ f --size .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=120
 
   $ echo dummy > foo
   $ hg commit -m throwaway3
 
   $ hg tags
   tip                                5:035f65efb448
   bar                                1:78391a272241
 
   $ hg blackbox -l 6
-  1970/01/01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> tags
-  1970/01/01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> writing 24 bytes to cache/hgtagsfnodes1
-  1970/01/01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> 3/4 cache hits/lookups in * seconds (glob)
-  1970/01/01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> writing .hg/cache/tags2-visible with 1 tags
-  1970/01/01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> tags exited 0 after * seconds (glob)
-  1970/01/01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> blackbox -l 6
+  1970-01-01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> tags
+  1970-01-01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> writing 24 bytes to cache/hgtagsfnodes1
+  1970-01-01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> 3/4 cache hits/lookups in * seconds (glob)
+  1970-01-01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> writing .hg/cache/tags2-visible with 1 tags
+  1970-01-01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> tags exited 0 after * seconds (glob)
+  1970-01-01 00:00:00.000 bob @035f65efb448350f4772141702a81ab1df48c465 (5000)> blackbox -l 6
   $ f --size .hg/cache/hgtagsfnodes1
   .hg/cache/hgtagsfnodes1: size=144
 
   $ hg -q --config extensions.strip= strip -r 5 --no-backup
 
 Test tag removal:
 
   $ hg tag --remove bar     # rev 5
   $ hg tip -vp
   changeset:   5:5f6e8655b1c7
   tag:         tip
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   files:       .hgtags
   description:
   Removed tag bar
   
   
   diff -r 0c192d7d5e6b -r 5f6e8655b1c7 .hgtags
   --- a/.hgtags	Thu Jan 01 00:00:00 1970 +0000
   +++ b/.hgtags	Thu Jan 01 00:00:00 1970 +0000
   @@ -1,1 +1,3 @@
    bbd179dfa0a71671c253b3ae0aa1513b60d199fa bar
   +78391a272241d70354aa14c874552cad6b51bb42 bar
   +0000000000000000000000000000000000000000 bar
   
   $ hg tags
   tip                                5:5f6e8655b1c7
   $ hg tags                 # again, try to expose cache bugs
   tip                                5:5f6e8655b1c7
 
 Remove nonexistent tag:
 
   $ hg tag --remove foobar
   abort: tag 'foobar' does not exist
   [10]
   $ hg tip
   changeset:   5:5f6e8655b1c7
   tag:         tip
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     Removed tag bar
   
 
 Undo a tag with rollback:
 
   $ hg rollback             # destroy rev 5 (restore bar)
   repository tip rolled back to revision 4 (undo commit)
   working directory now based on revision 4
   $ hg tags
   tip                                4:0c192d7d5e6b
   bar                                1:78391a272241
   $ hg tags
   tip                                4:0c192d7d5e6b
   bar                                1:78391a272241
 
 Test tag rank:
 
   $ cd ..
   $ hg init t3
   $ cd t3
   $ echo foo > foo
   $ hg add foo
   $ hg ci -m 'add foo'       # rev 0
   $ hg tag -f bar            # rev 1 bar -> 0
   $ hg tag -f bar            # rev 2 bar -> 1
   $ hg tag -fr 0 bar         # rev 3 bar -> 0
   $ hg tag -fr 1 bar         # rev 4 bar -> 1
   $ hg tag -fr 0 bar         # rev 5 bar -> 0
   $ hg tags
   tip                                5:85f05169d91d
   bar                                0:bbd179dfa0a7
   $ hg co 3
   1 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ echo barbar > foo
   $ hg ci -m 'change foo'    # rev 6
   created new head
   $ hg tags
   tip                                6:735c3ca72986
   bar                                0:bbd179dfa0a7
 
 Don't allow moving tag without -f:
 
   $ hg tag -r 3 bar
   abort: tag 'bar' already exists (use -f to force)
   [10]
   $ hg tags
   tip                                6:735c3ca72986
   bar                                0:bbd179dfa0a7
 
 Strip 1: expose an old head:
 
   $ hg --config extensions.mq= strip 5
   saved backup bundle to $TESTTMP/t3/.hg/strip-backup/*-backup.hg (glob)
   $ hg tags                  # partly stale cache
   tip                                5:735c3ca72986
   bar                                1:78391a272241
   $ hg tags                  # up-to-date cache
   tip                                5:735c3ca72986
   bar                                1:78391a272241
 
 Strip 2: destroy whole branch, no old head exposed
 
   $ hg --config extensions.mq= strip 4
   saved backup bundle to $TESTTMP/t3/.hg/strip-backup/*-backup.hg (glob)
   $ hg tags                  # partly stale
   tip                                4:735c3ca72986
   bar                                0:bbd179dfa0a7
   $ rm -f .hg/cache/tags2-visible
   $ hg tags                  # cold cache
   tip                                4:735c3ca72986
   bar                                0:bbd179dfa0a7
 
 Test tag rank with 3 heads:
 
   $ cd ..
   $ hg init t4
   $ cd t4
   $ echo foo > foo
   $ hg add
   adding foo
   $ hg ci -m 'add foo'                 # rev 0
   $ hg tag bar                         # rev 1 bar -> 0
   $ hg tag -f bar                      # rev 2 bar -> 1
   $ hg up -qC 0
   $ hg tag -fr 2 bar                   # rev 3 bar -> 2
   $ hg tags
   tip                                3:197c21bbbf2c
   bar                                2:6fa450212aeb
   $ hg up -qC 0
   $ hg tag -m 'retag rev 0' -fr 0 bar  # rev 4 bar -> 0, but bar stays at 2
 
 Bar should still point to rev 2:
 
   $ hg tags
   tip                                4:3b4b14ed0202
   bar                                2:6fa450212aeb
 
 Test that removing global/local tags does not get confused when trying
 to remove a tag of type X which actually only exists as a type Y:
 
   $ cd ..
   $ hg init t5
   $ cd t5
   $ echo foo > foo
   $ hg add
   adding foo
   $ hg ci -m 'add foo'                 # rev 0
 
   $ hg tag -r 0 -l localtag
   $ hg tag --remove localtag
   abort: tag 'localtag' is not a global tag
   [10]
   $ 
   $ hg tag -r 0 globaltag
   $ hg tag --remove -l globaltag
   abort: tag 'globaltag' is not a local tag
   [10]
   $ hg tags -v
   tip                                1:a0b6fe111088
   localtag                           0:bbd179dfa0a7 local
   globaltag                          0:bbd179dfa0a7
 
 Templated output:
 
  (immediate values)
 
   $ hg tags -T '{pad(tag, 9)} {rev}:{node} ({type})\n'
   tip       1:a0b6fe111088c8c29567d3876cc466aa02927cae ()
   localtag  0:bbd179dfa0a71671c253b3ae0aa1513b60d199fa (local)
   globaltag 0:bbd179dfa0a71671c253b3ae0aa1513b60d199fa ()
 
  (ctx/revcache dependent)
 
   $ hg tags -T '{pad(tag, 9)} {rev} {file_adds}\n'
   tip       1 .hgtags
   localtag  0 foo
   globaltag 0 foo
 
   $ hg tags -T '{pad(tag, 9)} {rev}:{node|shortest}\n'
   tip       1:a0b6
   localtag  0:bbd1
   globaltag 0:bbd1
 
 Test for issue3911
 
   $ hg tag -r 0 -l localtag2
   $ hg tag -l --remove localtag2
   $ hg tags -v
   tip                                1:a0b6fe111088
   localtag                           0:bbd179dfa0a7 local
   globaltag                          0:bbd179dfa0a7
 
   $ hg tag -r 1 -f localtag
   $ hg tags -v
   tip                                2:5c70a037bb37
   localtag                           1:a0b6fe111088
   globaltag                          0:bbd179dfa0a7
 
   $ hg tags -v
   tip                                2:5c70a037bb37
   localtag                           1:a0b6fe111088
   globaltag                          0:bbd179dfa0a7
 
   $ hg tag -r 1 localtag2
   $ hg tags -v
   tip                                3:bbfb8cd42be2
   localtag2                          1:a0b6fe111088
   localtag                           1:a0b6fe111088
   globaltag                          0:bbd179dfa0a7
 
   $ hg tags -v
   tip                                3:bbfb8cd42be2
   localtag2                          1:a0b6fe111088
   localtag                           1:a0b6fe111088
   globaltag                          0:bbd179dfa0a7
 
   $ cd ..
 
 Create a repository with tags data to test .hgtags fnodes transfer
 
   $ hg init tagsserver
   $ cd tagsserver
   $ touch foo
   $ hg -q commit -A -m initial
   $ hg tag -m 'tag 0.1' 0.1
   $ echo second > foo
   $ hg commit -m second
   $ hg tag -m 'tag 0.2' 0.2
   $ hg tags
   tip                                3:40f0358cb314
   0.2                                2:f63cc8fe54e4
   0.1                                0:96ee1d7354c4
   $ cd ..
 
 Cloning should pull down hgtags fnodes mappings and write the cache file
 
   $ hg clone --pull tagsserver tagsclient
   requesting all changes
   adding changesets
   adding manifests
   adding file changes
   added 4 changesets with 4 changes to 2 files
   new changesets 96ee1d7354c4:40f0358cb314
   updating to branch default
   2 files updated, 0 files merged, 0 files removed, 0 files unresolved
 
 Missing tags2* files means the cache wasn't written through the normal mechanism.
 
   $ ls tagsclient/.hg/cache
   branch2-base
   branch2-immutable
   branch2-served
   branch2-served.hidden
   branch2-visible
   branch2-visible-hidden
   hgtagsfnodes1
   rbc-names-v1
   rbc-revs-v1
   tags2
   tags2-served
 
 Cache should contain the head only, even though other nodes have tags data
 
   $ f --size --hexdump tagsclient/.hg/cache/hgtagsfnodes1
   tagsclient/.hg/cache/hgtagsfnodes1: size=96
   0000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0010: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0020: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0030: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0040: ff ff ff ff ff ff ff ff 40 f0 35 8c 19 e0 a7 d3 |........@.5.....|
   0050: 8a 5c 6a 82 4d cf fb a5 87 d0 2f a3 1e 4f 2f 8a |.\j.M...../..O/.|
 
 Running hg tags should produce tags2* file and not change cache
 
   $ hg -R tagsclient tags
   tip                                3:40f0358cb314
   0.2                                2:f63cc8fe54e4
   0.1                                0:96ee1d7354c4
 
   $ ls tagsclient/.hg/cache
   branch2-base
   branch2-immutable
   branch2-served
   branch2-served.hidden
   branch2-visible
   branch2-visible-hidden
   hgtagsfnodes1
   rbc-names-v1
   rbc-revs-v1
   tags2
   tags2-served
   tags2-visible
 
   $ f --size --hexdump tagsclient/.hg/cache/hgtagsfnodes1
   tagsclient/.hg/cache/hgtagsfnodes1: size=96
   0000: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0010: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0020: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0030: ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff ff |................|
   0040: ff ff ff ff ff ff ff ff 40 f0 35 8c 19 e0 a7 d3 |........@.5.....|
   0050: 8a 5c 6a 82 4d cf fb a5 87 d0 2f a3 1e 4f 2f 8a |.\j.M...../..O/.|
 
 Check that the bundle includes cache data
 
   $ hg -R tagsclient bundle --all ./test-cache-in-bundle-all-rev.hg
   4 changesets found
   $ hg debugbundle ./test-cache-in-bundle-all-rev.hg
   Stream params: {Compression: BZ}
   changegroup -- {nbchanges: 4, version: 02} (mandatory: True)
       96ee1d7354c4ad7372047672c36a1f561e3a6a4c
       c4dab0c2fd337eb9191f80c3024830a4889a8f34
       f63cc8fe54e4d326f8d692805d70e092f851ddb1
       40f0358cb314c824a5929ee527308d90e023bc10
   hgtagsfnodes -- {} (mandatory: True)
   cache:rev-branch-cache -- {} (mandatory: False)
 
 Check that local clone includes cache data
 
   $ hg clone tagsclient tags-local-clone
   updating to branch default
   2 files updated, 0 files merged, 0 files removed, 0 files unresolved
   $ (cd tags-local-clone/.hg/cache/; ls -1 tag*)
   tags2
   tags2-served
   tags2-visible
 
 Avoid writing logs on trying to delete an already deleted tag
   $ hg init issue5752
   $ cd issue5752
   $ echo > a
   $ hg commit -Am 'add a'
   adding a
   $ hg tag a
   $ hg tags
   tip                                1:bd7ee4f3939b
   a                                  0:a8a82d372bb3
   $ hg log
   changeset:   1:bd7ee4f3939b
   tag:         tip
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     Added tag a for changeset a8a82d372bb3
   
   changeset:   0:a8a82d372bb3
   tag:         a
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     add a
   
   $ hg tag --remove a
   $ hg log
   changeset:   2:e7feacc7ec9e
   tag:         tip
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     Removed tag a
   
   changeset:   1:bd7ee4f3939b
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     Added tag a for changeset a8a82d372bb3
   
   changeset:   0:a8a82d372bb3
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     add a
   
   $ hg tag --remove a
   abort: tag 'a' is already removed
   [10]
   $ hg log
   changeset:   2:e7feacc7ec9e
   tag:         tip
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     Removed tag a
   
   changeset:   1:bd7ee4f3939b
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     Added tag a for changeset a8a82d372bb3
   
   changeset:   0:a8a82d372bb3
   user:        test
   date:        Thu Jan 01 00:00:00 1970 +0000
   summary:     add a
   
   $ cat .hgtags
   a8a82d372bb35b42ff736e74f07c23bcd99c371f a
   a8a82d372bb35b42ff736e74f07c23bcd99c371f a
   0000000000000000000000000000000000000000 a