Bazaar

LockContention: Could not acquire lock "[Errno 11] Resource temporarily unavailable"

Bug #250121 reported by Edmundo
4
Affects Status Importance Assigned to Milestone
Bazaar
Confirmed
Medium
Unassigned

Bug Description

Yesterday I saw this same kind of problem in two different machines. The only thing they had in common was that they are AMD64 based. One of them is running SLES10 (unpatched, I think). Here's what the log has to say:

0.055 encoding stdout as sys.stdout encoding 'UTF-8'
0.056 bzr arguments: [u'commit']
0.056 looking for plugins in /home/ccanon/.bazaar/plugins
0.056 looking for plugins in /usr/local/lib/python2.5/site-packages/bzrlib/plugins
0.056 Plugin name __init__ already loaded
0.056 Plugin name __init__ already loaded
0.067 encoding stdout as sys.stdout encoding 'UTF-8'
0.102 opening working tree '/home/ccanon/informaw/desarrollo'
0.108 preparing to commit
[18517] 2008-07-18 16:29:02.692 INFO: Committing to: /home/ccanon/informaw/desarrollo/
0.334 Selecting files for commit with filter None
[18517] 2008-07-18 16:29:02.906 INFO: modified web/pactualizam.php
1.281 check paths: None

0.055 encoding stdout as sys.stdout encoding 'UTF-8'
0.056 bzr arguments: [u'commit']
0.056 looking for plugins in /home/ccanon/.bazaar/plugins
0.056 looking for plugins in /usr/local/lib/python2.5/site-packages/bzrlib/plugins
0.056 Plugin name __init__ already loaded
0.056 Plugin name __init__ already loaded
0.067 encoding stdout as sys.stdout encoding 'UTF-8'
0.102 opening working tree '/home/ccanon/informaw/desarrollo'
[18551] 2008-07-18 16:29:36.057 INFO: Unable to obtain lock file:///home/ccanon/informaw/desarrollo/.bzr/branch/lock
held by ccanon@server on host server [process #18517]
locked 34 seconds ago
Will continue to try until 16:34:36

0.057 encoding stdout as sys.stdout encoding 'UTF-8'
0.058 bzr arguments: [u'status']
0.058 looking for plugins in /home/ccanon/.bazaar/plugins
0.058 looking for plugins in /usr/local/lib/python2.5/site-packages/bzrlib/plugins
0.058 Plugin name __init__ already loaded
0.058 Plugin name __init__ already loaded
0.070 encoding stdout as sys.stdout encoding 'UTF-8'
0.106 opening working tree '/home/ccanon/informaw/desarrollo'
0.129 Traceback (most recent call last):
  File "/usr/local/lib/python2.5/site-packages/bzrlib/commands.py", line 846, in run_bzr_catch_errors
    return run_bzr(argv)
  File "/usr/local/lib/python2.5/site-packages/bzrlib/commands.py", line 797, in run_bzr
    ret = run(*run_argv)
  File "/usr/local/lib/python2.5/site-packages/bzrlib/commands.py", line 499, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/usr/local/lib/python2.5/site-packages/bzrlib/commands.py", line 807, in ignore_pipe
    result = func(*args, **kwargs)
  File "/usr/local/lib/python2.5/site-packages/bzrlib/builtins.py", line 178, in run
    show_pending=not no_pending)
  File "/usr/local/lib/python2.5/site-packages/bzrlib/status.py", line 80, in show_tree_status
    wt.lock_read()
  File "/usr/local/lib/python2.5/site-packages/bzrlib/workingtree_4.py", line 585, in lock_read
    state.lock_read()
  File "/usr/local/lib/python2.5/site-packages/bzrlib/dirstate.py", line 2721, in lock_read
    self._lock_token = lock.ReadLock(self._filename)
  File "/usr/local/lib/python2.5/site-packages/bzrlib/lock.py", line 170, in __init__
    raise errors.LockContention(e)
LockContention: Could not acquire lock "[Errno 11] Resource temporarily unavailable"

The other machine was an openSuSE 10.2 (unpatched as well, I think). I'll get the logs from that box on monday.

The problem occurred randomly, I think.

Revision history for this message
Alfonso de la Guarda Reyes (alfonsodg) wrote :

Please provide some steps to recreate the problem, by example commands....

Revision history for this message
Edmundo (eantoranz) wrote : Re: [Bug 250121] Re: LockContention: Could not acquire lock "[Errno 11] Resource temporarily unavailable"

I wish I could. I guess in order to do that we'll have to wait a little
longer till the developers with those boxes notice a "pattern" for the
problem to show up. I promise I'll be getting the logs from the other box on
monday, though.

Revision history for this message
Edmundo (eantoranz) wrote :
Download full text (52.6 KiB)

This is the log with the errors on the other box:

0.116 encoding stdout as sys.stdout encoding 'UTF-8'
0.117 bzr arguments: [u'push']
0.117 looking for plugins in /root/.bazaar/plugins
0.117 looking for plugins in
/usr/local/lib64/python2.5/site-packages/bzrlib/plugins
0.117 Plugin name __init__ already loaded
0.117 Plugin name __init__ already loaded
0.143 looking for plugins in
/usr/lib64/python2.5/site-packages/bzrlib/plugins
0.145 encoding stdout as sys.stdout encoding 'UTF-8'
0.235 ssh implementation is OpenSSH
[ 6860] 2008-07-18 12:33:41.409 WARNING: This transport does not update the
working tree of: bzr+ssh://agarcia@10.0.1.1/home/agarcia/informaw/estable/.
See 'bzr help working-trees' for more information.
16.625 Using fetch logic to copy between
KnitPackRepository('file:///home/agarcia/desarrollo/.bzr/repository/')(<RepositoryFormatKnitPack1>)
and KnitPackRepository('bzr+ssh://
agarcia@10.0.1.1/home/agarcia/informaw/estable/.bzr/repository/')(
<RepositoryFormatKnitPack1>)
16.687 Traceback (most recent call last):
  File "/usr/local/lib64/python2.5/site-packages/bzrlib/commands.py", line
846, in run_bzr_catch_errors
    return run_bzr(argv)
  File "/usr/local/lib64/python2.5/site-packages/bzrlib/commands.py", line
797, in run_bzr
    ret = run(*run_argv)
  File "/usr/local/lib64/python2.5/site-packages/bzrlib/commands.py", line
499, in run_argv_aliases
    return self.run(**all_cmd_args)
  File "/usr/local/lib64/python2.5/site-packages/bzrlib/builtins.py", line
869, in run
    raise errors.BzrCommandError('These branches have diverged.'
BzrCommandError: These branches have diverged. Try using "merge" and then
"push".

16.688 return code 3

0.119 encoding stdout as sys.stdout encoding 'UTF-8'
0.120 bzr arguments: [u'merge']
0.120 looking for plugins in /root/.bazaar/plugins
0.120 looking for plugins in
/usr/local/lib64/python2.5/site-packages/bzrlib/plugins
0.121 Plugin name __init__ already loaded
0.121 Plugin name __init__ already loaded
0.146 looking for plugins in
/usr/lib64/python2.5/site-packages/bzrlib/plugins
0.221 opening working tree '/home/agarcia/desarrollo'
0.234 bzr+ssh://agarcia@10.0.1.1/home/desarrollo/informaw/estable/
[ 6865] 2008-07-18 12:33:53.515 INFO: Merging from remembered location
bzr+ssh://agarcia@10.0.1.1/home/desarrollo/informaw/estable/
0.270 ssh implementation is OpenSSH

0.113 encoding stdout as sys.stdout encoding 'UTF-8'
0.114 bzr arguments: [u'status']
0.114 looking for plugins in /root/.bazaar/plugins
0.114 looking for plugins in
/usr/local/lib64/python2.5/site-packages/bzrlib/plugins
0.115 Plugin name __init__ already loaded
0.115 Plugin name __init__ already loaded
0.139 looking for plugins in
/usr/lib64/python2.5/site-packages/bzrlib/plugins
0.142 encoding stdout as sys.stdout encoding 'UTF-8'
0.210 opening working tree '/home/agarcia/desarrollo'
0.254 Traceback (most recent call last):
  File "/usr/local/lib64/python2.5/site-packages/bzrlib/commands.py", line
846, in run_bzr_catch_errors
    return run_bzr(argv)
  File "/usr/local/lib64/python2.5/site-packages/bzrlib/commands.py", line
797, in run_bzr
    ret = run(*run_argv)
  File "/usr/local/lib64/python2.5/si...

Revision history for this message
Edmundo (eantoranz) wrote :
Download full text (12.0 KiB)

I don't know if this helps at all, but I have noticed that before the
problems I reported from the second box, the user was allowed to merge twice
without a commit, and then the brown thing hit the fan:

0.118 encoding stdout as sys.stdout encoding 'UTF-8'
0.118 bzr arguments: [u'merge']
0.119 looking for plugins in /root/.bazaar/plugins
0.119 looking for plugins in
/usr/local/lib64/python2.5/site-packages/bzrlib/plugins
0.119 Plugin name __init__ already loaded
0.119 Plugin name __init__ already loaded
0.145 looking for plugins in
/usr/lib64/python2.5/site-packages/bzrlib/plugins
0.218 opening working tree '/home/agarcia/desarrollo'
0.231 bzr+ssh://agarcia@10.0.1.1/home/desarrollo/informaw/estable/
[ 6848] 2008-07-18 12:32:07.400 INFO: Merging from remembered location
bzr+ssh://agarcia@10.0.1.1/home/desarrollo/informaw/estable/
0.268 ssh implementation is OpenSSH
20.155 Using fetch logic to copy between RemoteRepository(bzr+ssh://
agarcia@10.0.1.1/home/desarrollo/informaw/estable/.bzr/)(remote) and
KnitPackRepository('file:///home/agarcia/desarrollo/.bzr/repository/')(<RepositoryFormatKnitPack1>)
20.157 fetch up to rev
{<email address hidden>}
[ 6848] 2008-07-18 12:32:31.902 INFO: +N web/2.jpg
[ 6848] 2008-07-18 12:32:31.903 INFO: +N web/acceso.inc
[ 6848] 2008-07-18 12:32:31.903 INFO: +N web/ajax-tooltip-demo.css
[ 6848] 2008-07-18 12:32:31.904 INFO: +N web/ajax-tooltip.css
[ 6848] 2008-07-18 12:32:31.904 INFO: +N web/angenilta_border_left.gif
[ 6848] 2008-07-18 12:32:31.904 INFO: +N web/angenilta_border_right.gif
[ 6848] 2008-07-18 12:32:31.905 INFO: +N web/angenilta_bottom_left.gif
[ 6848] 2008-07-18 12:32:31.905 INFO: +N web/angenilta_bottom_right.gif
[ 6848] 2008-07-18 12:32:31.906 INFO: +N web/angenilta_bullet.gif
[ 6848] 2008-07-18 12:32:31.906 INFO: +N web/angenilta_footer_bg.gif
[ 6848] 2008-07-18 12:32:31.907 INFO: +N web/angenilta_hnavbar.gif
[ 6848] 2008-07-18 12:32:31.907 INFO: +N web/angenilta_hnavbar.js
[ 6848] 2008-07-18 12:32:31.908 INFO: +N web/angenilta_hnavbar_b1.gif
[ 6848] 2008-07-18 12:32:31.908 INFO: +N web/angenilta_hnavbar_b1_over.gif
[ 6848] 2008-07-18 12:32:31.908 INFO: +N web/angenilta_hnavbar_b2.gif
[ 6848] 2008-07-18 12:32:31.909 INFO: +N web/angenilta_hnavbar_b2_over.gif
[ 6848] 2008-07-18 12:32:31.909 INFO: +N web/angenilta_hnavbar_b3.gif
[ 6848] 2008-07-18 12:32:31.910 INFO: +N web/angenilta_hnavbar_b3_over.gif
[ 6848] 2008-07-18 12:32:31.910 INFO: +N web/angenilta_hnavbar_b4.gif
[ 6848] 2008-07-18 12:32:31.910 INFO: +N web/angenilta_hnavbar_b4_over.gif
[ 6848] 2008-07-18 12:32:31.911 INFO: +N web/angenilta_hnavbar_b5.gif
[ 6848] 2008-07-18 12:32:31.911 INFO: +N web/angenilta_hnavbar_b5_over.gif
[ 6848] 2008-07-18 12:32:31.912 INFO: +N web/angenilta_hnavbar_b6.gif
[ 6848] 2008-07-18 12:32:31.912 INFO: +N web/angenilta_hnavbar_b6_over.gif
[ 6848] 2008-07-18 12:32:31.912 INFO: +N web/angenilta_hnavbar_b7.gif
[ 6848] 2008-07-18 12:32:31.913 INFO: +N web/angenilta_hnavbar_b7_over.gif
[ 6848] 2008-07-18 12:32:31.913 INFO: +N web/angenilta_hnavbar_bg.gif
[ 6848] 2008-07-18 12:32:31.914 INFO: +N web/angenilta_logo2.gif
[ 6848] 2008-07-18 12:32:3...

Revision history for this message
James Westby (james-w) wrote :

Hi,

What filesystem are these trees on? Is NFS involved?

Thanks,

James

Revision history for this message
James Westby (james-w) wrote :

Hi,

bug 122001 has the same things.

Thanks,

James

Revision history for this message
Andrew Bennetts (spiv) wrote :

I believe one way to produce this error is to have another process running that holds the dirstate lock, for example I can cause this with the bzr-gtk plugin:

andrew@steerpike:~/code/bzr$ bzr gannotate README &
[1] 11025
andrew@steerpike:~/code/bzr$ bzr merge
bzr: ERROR: Could not acquire lock "[Errno 11] Resource temporarily unavailable"

Edmundo: do you have any other bzr processes running? What plugins do you use? (The output of "bzr plugins" will summarise them for you.)

Revision history for this message
Edmundo (eantoranz) wrote :

I think there's no concurrency involved. And there's no NFS involved either.

And this guys have no plugins (but the default ones.... I'll tell you in a
while).

Revision history for this message
Martin Pool (mbp) wrote :

If we're getting that error from the OS then *something* must be holding the lock.

If you hit this again, please run 'lsof >/tmp/lsof.out' to record all open filehandles for your userid; trim it down to include just stuff relevant to bzr, and attach it to this bug.

Changed in bzr:
importance: Undecided → Medium
status: New → Incomplete
Martin Pool (mbp)
Changed in bzr:
status: Incomplete → Confirmed
tags: added: lockdir
Revision history for this message
Grant Walters (grunter) wrote :

I just started getting this error from within synaptic Package Manager. I have etckeeper installed and it is this that is complaining. I sort of followed Martins lsof instructions with an fuser on the dirstate file. I found the file was considered open by Nautilus. I have the Olive? extension loaded. The nautilus process was running but did not appear on any of my desktops. I killed it and the file is no longer locked. An install with synaptic and etckeeper is working again. Hopes this helps.

Jelmer Vernooij (jelmer)
tags: added: check-for-breezy
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.
Subscribing...

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.