Mercurial > hg
changeset 35209:9153871d50e0
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.
| author | Boris Feld <boris.feld@octobus.net> |
|---|---|
| date | Wed, 29 Nov 2017 20:39:59 -0500 |
| parents | 1b758105b5c7 |
| children | 15d38e8fcb1e |
| files | mercurial/configitems.py mercurial/help/config.txt mercurial/localrepo.py mercurial/lock.py tests/test-lock-badness.t |
| diffstat | 5 files changed, 87 insertions(+), 7 deletions(-) [+] |
line wrap: on
line diff
--- a/mercurial/configitems.py Wed Nov 29 20:36:29 2017 -0500 +++ b/mercurial/configitems.py Wed Nov 29 20:39:59 2017 -0500 @@ -1081,6 +1081,9 @@ coreconfigitem('ui', 'timeout', default='600', ) +coreconfigitem('ui', 'timeout.warn', + default=0, +) coreconfigitem('ui', 'traceback', default=False, )
--- a/mercurial/help/config.txt Wed Nov 29 20:36:29 2017 -0500 +++ b/mercurial/help/config.txt Wed Nov 29 20:39:59 2017 -0500 @@ -2215,6 +2215,10 @@ 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
--- a/mercurial/localrepo.py Wed Nov 29 20:36:29 2017 -0500 +++ b/mercurial/localrepo.py Wed Nov 29 20:39:59 2017 -0500 @@ -1594,10 +1594,12 @@ parentlock = encoding.environ.get(parentenvvar) timeout = 0 + warntimeout = 0 if wait: timeout = self.ui.configint("ui", "timeout") + warntimeout = self.ui.configint("ui", "timeout.warn") - l = lockmod.trylock(self.ui, vfs, lockname, timeout, + l = lockmod.trylock(self.ui, vfs, lockname, timeout, warntimeout, releasefn=releasefn, acquirefn=acquirefn, desc=desc, inheritchecker=inheritchecker,
--- a/mercurial/lock.py Wed Nov 29 20:36:29 2017 -0500 +++ b/mercurial/lock.py Wed Nov 29 20:39:59 2017 -0500 @@ -41,11 +41,11 @@ raise return result -def trylock(ui, vfs, lockname, timeout, *args, **kwargs): +def trylock(ui, vfs, lockname, timeout, warntimeout, *args, **kwargs): """return an acquired lock or raise an a LockHeld exception - This function is responsible to issue warnings about the held lock while - trying to acquires it.""" + This function is responsible to issue warnings and or debug messages about + the held lock while trying to acquires it.""" def printwarning(printer, locker): """issue the usual "waiting on lock" message through any channel""" @@ -60,9 +60,12 @@ l = lock(vfs, lockname, 0, *args, dolock=False, **kwargs) + debugidx = 0 if (warntimeout and timeout) else -1 warningidx = 0 if not timeout: warningidx = -1 + elif warntimeout: + warningidx = warntimeout delay = 0 while True: @@ -70,6 +73,8 @@ l._trylock() break except error.LockHeld as inst: + if delay == debugidx: + printwarning(ui.debug, inst.locker) if delay == warningidx: printwarning(ui.warn, inst.locker) if timeout <= delay: @@ -80,7 +85,10 @@ l.delay = delay if l.delay: - ui.warn(_("got lock after %s seconds\n") % l.delay) + if 0 <= warningidx <= l.delay: + ui.warn(_("got lock after %s seconds\n") % l.delay) + else: + ui.debug("got lock after %s seconds\n" % l.delay) if l.acquirefn: l.acquirefn() return l
--- a/tests/test-lock-badness.t Wed Nov 29 20:36:29 2017 -0500 +++ b/tests/test-lock-badness.t Wed Nov 29 20:39:59 2017 -0500 @@ -57,14 +57,77 @@ $ 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