[PATCH 3 of 3] lock: allow to configure when the lock messages are displayed

Boris Feld boris.feld at octobus.net
Mon Nov 27 18:18:11 EST 2017


# HG changeset patch
# User Boris Feld <boris.feld at octobus.net>
# Date 1511801811 18000
#      Mon Nov 27 11:56:51 2017 -0500
# Node ID 15b8fcffac40607710816a75217219b5668baba5
# Parent  f40e9671a53992359c622dd9c46050b4ff09c374
# EXP-Topic lock-message
# Available At https://bitbucket.org/octobus/mercurial-devel/
#              hg pull https://bitbucket.org/octobus/mercurial-devel/ -r 15b8fcffac40
lock: allow to configure when the lock messages are displayed

We add a new 'ui.timeout.warn' config to set a grace period before we display
lock related warning:

    waiting for lock on PATH held by PROCESS

The config is based on 'ui.timeout' and expresses a number of seconds before
the warning is displayed. Negative values disable the warning altogether.

The messages go to the debug output to help people trouble-shooting deadlocks.

diff --git a/mercurial/configitems.py b/mercurial/configitems.py
--- a/mercurial/configitems.py
+++ b/mercurial/configitems.py
@@ -985,6 +985,9 @@ coreconfigitem('ui', 'textwidth',
 coreconfigitem('ui', 'timeout',
     default='600',
 )
+coreconfigitem('ui', 'timeout.warn',
+    default=0,
+)
 coreconfigitem('ui', 'traceback',
     default=False,
 )
diff --git a/mercurial/help/config.txt b/mercurial/help/config.txt
--- a/mercurial/help/config.txt
+++ b/mercurial/help/config.txt
@@ -2215,6 +2215,10 @@ User interface controls.
     The timeout used when a lock is held (in seconds), a negative value
     means no timeout. (default: 600)
 
+``timeout.warn``
+    Time (in seconds) before a warning is printed about held lock. A negative
+    value means no warning. (default: 0)
+
 ``traceback``
     Mercurial always prints a traceback when an unknown exception
     occurs. Setting this to True will make Mercurial print a traceback
diff --git a/mercurial/localrepo.py b/mercurial/localrepo.py
--- a/mercurial/localrepo.py
+++ b/mercurial/localrepo.py
@@ -1609,16 +1609,38 @@ class localrepository(object):
                 msg = _("waiting for lock on %s held by %r\n") % (desc, locker)
             printer(msg)
 
+        delaywarning = self.ui.configint("ui", "timeout.warn")
+        dowarn = True
+        if delaywarning < 0:
+            dowarn = False
+            delaywarning = 0
+        else:
+            delaywarning = delaywarning if wait else 0
         try:
-            l = trylock(0)
+            try:
+                l = trylock(0)
+            except error.LockHeld as inst:
+                if not wait:
+                    raise
+                printwarning(self.ui.debug, inst.locker)
+                if not delaywarning:
+                    raise
+                l = trylock(delaywarning)
+                # We got the lock while warning were silent, inform debug output
+                msg = _("got lock after %s seconds\n") % (l.delay)
+                self.ui.debug(msg)
         except error.LockHeld as inst:
             if not wait:
                 raise
-            printwarning(self.ui.warn, inst.locker)
+            if dowarn:
+                printwarning(self.ui.warn, inst.locker)
             # default to 600 seconds timeout
             l = trylock(int(self.ui.config("ui", "timeout")))
-            msg = _("got lock after %s seconds\n") % l.delay
-            self.ui.warn(msg)
+            msg = _("got lock after %s seconds\n") % (l.delay + delaywarning)
+            if dowarn:
+                self.ui.warn(msg)
+            else:
+                self.ui.debug(msg)
         return l
 
     def _afterlock(self, callback):
diff --git a/tests/test-lock-badness.t b/tests/test-lock-badness.t
--- a/tests/test-lock-badness.t
+++ b/tests/test-lock-badness.t
@@ -57,14 +57,77 @@ One process waiting for another
   $ echo b > b/b
   $ hg -R b ci -A -m b --config hooks.precommit="python:`pwd`/hooks.py:sleepone" > stdout &
   $ hg -R b up -q --config hooks.pre-update="python:`pwd`/hooks.py:sleephalf" \
-  > > preup 2>&1
+  > > preup-stdout 2>preup-stderr
   $ wait
-  $ cat preup
+  $ cat preup-stdout
+  $ cat preup-stderr
   waiting for lock on working directory of b held by process '*' on host '*' (glob)
   got lock after * seconds (glob)
   $ cat stdout
   adding b
 
+On processs waiting on another, warning after a long time.
+
+  $ echo b > b/c
+  $ hg -R b ci -A -m b --config hooks.precommit="python:`pwd`/hooks.py:sleepone" > stdout &
+  $ hg -R b up -q --config hooks.pre-update="python:`pwd`/hooks.py:sleephalf" \
+  > --config ui.timeout.warn=250 \
+  > > preup-stdout 2>preup-stderr
+  $ wait
+  $ cat preup-stdout
+  $ cat preup-stderr
+  $ cat stdout
+  adding c
+
+On processs waiting on another, warning disabled.
+
+  $ echo b > b/d
+  $ hg -R b ci -A -m b --config hooks.precommit="python:`pwd`/hooks.py:sleepone" > stdout &
+  $ hg -R b up -q --config hooks.pre-update="python:`pwd`/hooks.py:sleephalf" \
+  > --config ui.timeout.warn=-1 \
+  > > preup-stdout 2>preup-stderr
+  $ wait
+  $ cat preup-stdout
+  $ cat preup-stderr
+  $ cat stdout
+  adding d
+
+check we still print debug output
+
+On processs waiting on another, warning after a long time (debug output on)
+
+  $ echo b > b/e
+  $ hg -R b ci -A -m b --config hooks.precommit="python:`pwd`/hooks.py:sleepone" > stdout &
+  $ hg -R b up --config hooks.pre-update="python:`pwd`/hooks.py:sleephalf" \
+  > --config ui.timeout.warn=250 --debug\
+  > > preup-stdout 2>preup-stderr
+  $ wait
+  $ cat preup-stdout
+  calling hook pre-update: hghook_pre-update.sleephalf
+  waiting for lock on working directory of b held by process '*' on host '*' (glob)
+  got lock after * seconds (glob)
+  0 files updated, 0 files merged, 0 files removed, 0 files unresolved
+  $ cat preup-stderr
+  $ cat stdout
+  adding e
+
+On processs waiting on another, warning disabled, (debug output on)
+
+  $ echo b > b/f
+  $ hg -R b ci -A -m b --config hooks.precommit="python:`pwd`/hooks.py:sleepone" > stdout &
+  $ hg -R b up --config hooks.pre-update="python:`pwd`/hooks.py:sleephalf" \
+  > --config ui.timeout.warn=-1 --debug\
+  > > preup-stdout 2>preup-stderr
+  $ wait
+  $ cat preup-stdout
+  calling hook pre-update: hghook_pre-update.sleephalf
+  waiting for lock on working directory of b held by process '*' on host '*' (glob)
+  got lock after * seconds (glob)
+  0 files updated, 0 files merged, 0 files removed, 0 files unresolved
+  $ cat preup-stderr
+  $ cat stdout
+  adding f
+
 Pushing to a local read-only repo that can't be locked
 
   $ chmod 100 a/.hg/store


More information about the Mercurial-devel mailing list