Bug 714480 – sys-apps/portage: portage.exception.DirectoryNotFound: /var/tmp/portage/category-directory

• Product: Portage Development
• Status: RESOLVED FIXED

[Description Rick Farina (Zero_Chaos) 2020-03-24 18:51:58 UTC]

I know nothing, other than sometimes it stalls forever, and sometimes it seems to explode for no reason.... kinda like my 6 year old.

Reproducible: Always

[Comment 1 Rick Farina (Zero_Chaos) 2020-03-24 18:52:57 UTC]

Created attachment 625352 [details]
emerge --info

This is emerge --info pulled out of catalyst using "run_merge --info" so it executes just like catalyst executes every other emerge command.

[Comment 2 Rick Farina (Zero_Chaos) 2020-03-24 18:53:55 UTC]

>>> Jobs: 188 of 927 complete, 35 running           Load avg: 11.3, 7.0, 5.7Exception in callback AsynchronousTask._exit_listener_cb(<bound method...7ed2a5ed6eb8>>)
handle: <Handle AsynchronousTask._exit_listener_cb(<bound method...7ed2a5ed6eb8>>)>
Traceback (most recent call last):
  File "/usr/lib64/python3.6/asyncio/events.py", line 145, in _run
    self._callback(*self._args)
  File "/usr/lib64/python3.6/site-packages/_emerge/AsynchronousTask.py", line 224, in _exit_listener_cb
    listener(self)
  File "/usr/lib64/python3.6/site-packages/_emerge/Binpkg.py", line 129, in _start_fetcher
    lock_task.future.result()
  File "/usr/lib64/python3.6/site-packages/portage/util/futures/compat_coroutine.py", line 121, in _next
    future = self._generator.throw(previous.exception())
  File "/usr/lib64/python3.6/site-packages/_emerge/EbuildBuildDir.py", line 88, in async_lock
    yield builddir_lock.async_start()
  File "/usr/lib64/python3.6/site-packages/portage/util/futures/compat_coroutine.py", line 121, in _next
    future = self._generator.throw(previous.exception())
  File "/usr/lib64/python3.6/site-packages/_emerge/AsynchronousTask.py", line 31, in async_start
    yield self._async_start()
  File "/usr/lib64/python3.6/site-packages/portage/util/futures/compat_coroutine.py", line 115, in _next
    future = next(self._generator)
  File "/usr/lib64/python3.6/site-packages/_emerge/AsynchronousLock.py", line 55, in _async_start
    wantnewlockfile=True, flags=os.O_NONBLOCK)
  File "/usr/lib64/python3.6/site-packages/portage/locks.py", line 113, in lockfile
    unlinkfile=unlinkfile, waiting_msg=waiting_msg, flags=flags)
  File "/usr/lib64/python3.6/site-packages/portage/locks.py", line 175, in _lockfile_iteration
    raise DirectoryNotFound(os.path.dirname(mypath))
portage.exception.DirectoryNotFound: /var/tmp/portage/dev-libs
Terminated

[Comment 3 Rick Farina (Zero_Chaos) 2020-03-24 19:14:46 UTC]

>>> Jobs: 247 of 1389 complete, 37 running          Load avg: 6.53, 5.77, 3.82Exception in callback AsynchronousTask._exit_listener_cb(<bound method...74f4b06af780>>)
handle: <Handle AsynchronousTask._exit_listener_cb(<bound method...74f4b06af780>>)>
Traceback (most recent call last):
  File "/usr/lib64/python3.6/asyncio/events.py", line 145, in _run
    self._callback(*self._args)
  File "/usr/lib64/python3.6/site-packages/_emerge/AsynchronousTask.py", line 224, in _exit_listener_cb
    listener(self)
  File "/usr/lib64/python3.6/site-packages/_emerge/Binpkg.py", line 129, in _start_fetcher
    lock_task.future.result()
  File "/usr/lib64/python3.6/site-packages/portage/util/futures/compat_coroutine.py", line 121, in _next
    future = self._generator.throw(previous.exception())
  File "/usr/lib64/python3.6/site-packages/_emerge/EbuildBuildDir.py", line 88, in async_lock
    yield builddir_lock.async_start()
  File "/usr/lib64/python3.6/site-packages/portage/util/futures/compat_coroutine.py", line 121, in _next
    future = self._generator.throw(previous.exception())
  File "/usr/lib64/python3.6/site-packages/_emerge/AsynchronousTask.py", line 31, in async_start
    yield self._async_start()
  File "/usr/lib64/python3.6/site-packages/portage/util/futures/compat_coroutine.py", line 115, in _next
    future = next(self._generator)
  File "/usr/lib64/python3.6/site-packages/_emerge/AsynchronousLock.py", line 55, in _async_start
    wantnewlockfile=True, flags=os.O_NONBLOCK)
  File "/usr/lib64/python3.6/site-packages/portage/locks.py", line 113, in lockfile
    unlinkfile=unlinkfile, waiting_msg=waiting_msg, flags=flags)
  File "/usr/lib64/python3.6/site-packages/portage/locks.py", line 175, in _lockfile_iteration
    raise DirectoryNotFound(os.path.dirname(mypath))
portage.exception.DirectoryNotFound: /var/tmp/portage/net-misc
Terminated

[Comment 4 Zac Medico 2020-03-24 21:56:21 UTC]

Both comment #2 and comment #3 show that a category directory under /var/tmp/portage/ was removed even though a (cooperative) lock was held on it. If something else is removing the directory without acquiring the lock, then that will trigger it. However, I think the problem is actually that portages default locking function is fcntl.lockf, which doesn't work properly when we try do lock the same path more than once from within the same process.

[Comment 5 Zac Medico 2020-03-24 22:12:14 UTC]

My plan is to fix the lockfile function to raise a TryAgain exception when we attempt to lock a file that is already locked by the same process with the fcntl.lockf function. This will cause the AsynchronousLock class to launch an asynchronous _LockProcess which will behave appropriately.

[Comment 6 Larry the Git Cow 2020-03-25 07:57:09 UTC]

The bug has been referenced in the following commit(s):

https://gitweb.gentoo.org/repo/gentoo.git/commit/?id=935570dbd797db4f0818a5c377ab056c8e0bb272

commit 935570dbd797db4f0818a5c377ab056c8e0bb272
Author:     Zac Medico <[e-mail]>
AuthorDate: 2020-03-25 07:49:50 +0000
Commit:     Zac Medico <[e-mail]>
CommitDate: 2020-03-25 07:56:58 +0000

    sys-apps/portage: Bump to version 2.3.96
    
     #714480 DirectoryNotFound: /var/tmp/portage/category-directory
    
    Bug: https://bugs.gentoo.org/711148
    Bug: https://bugs.gentoo.org/714480
    Package-Manager: Portage-2.3.96, Repoman-2.3.21
    Signed-off-by: Zac Medico <[e-mail]>

 sys-apps/portage/Manifest              |   1 +
 sys-apps/portage/portage-2.3.96.ebuild | 267 +++++++++++++++++++++++++++++++++
 2 files changed, 268 insertions(+)

[Comment 7 Larry the Git Cow 2020-03-25 07:57:32 UTC]

The bug has been referenced in the following commit(s):

https://gitweb.gentoo.org/proj/portage.git/commit/?id=d87fa22e70513915cebe79a1923b65ea0a6fc55e

commit d87fa22e70513915cebe79a1923b65ea0a6fc55e
Author:     Zac Medico <[e-mail]>
AuthorDate: 2020-03-25 05:35:17 +0000
Commit:     Zac Medico <[e-mail]>
CommitDate: 2020-03-25 07:39:33 +0000

    lockfile: raise TryAgain if inode is already locked (bug 714480)
    
    Raise TryAgain if the current inode is already locked by the current
    process, since in this case the lock will not behave as intended with
    the default fcntl.lockf function. With the alternative fcntl.flock
    function, TryAgain is raised earlier.
    
    Bug: https://bugs.gentoo.org/714480
    Signed-off-by: Zac Medico <[e-mail]>

 lib/portage/locks.py                          | 12 ++++++++++--
 lib/portage/tests/locks/test_lock_nonblock.py | 16 +++++++++++++++-
 2 files changed, 25 insertions(+), 3 deletions(-)

https://gitweb.gentoo.org/proj/portage.git/commit/?id=895a7417f41c4f6617e22dc0ebf001de526fc666

commit 895a7417f41c4f6617e22dc0ebf001de526fc666
Author:     Zac Medico <[e-mail]>
AuthorDate: 2020-03-25 05:13:43 +0000
Commit:     Zac Medico <[e-mail]>
CommitDate: 2020-03-25 07:25:00 +0000

    _lockfile_iteration: index locked files by inode (bug 714480)
    
    Index each locked file by inode so that it's possible to detect when
    there's an attempt to lock the same inode twice, since in that case
    the lock will not behave as intended with the default fcntl.lockf
    function.
    
    Bug: https://bugs.gentoo.org/714480
    Signed-off-by: Zac Medico <[e-mail]>

 lib/portage/locks.py | 35 +++++++++++++++++++++++------------
 1 file changed, 23 insertions(+), 12 deletions(-)

https://gitweb.gentoo.org/proj/portage.git/commit/?id=59e9452fda79f69e9b5ab7e44ef918f6fb4d6161

commit 59e9452fda79f69e9b5ab7e44ef918f6fb4d6161
Author:     Zac Medico <[e-mail]>
AuthorDate: 2020-03-25 05:11:06 +0000
Commit:     Zac Medico <[e-mail]>
CommitDate: 2020-03-25 07:24:52 +0000

    _lockfile_was_removed: return fstat result (bug 714480)
    
    Return a tuple that includes the fstat result, which can be used to
    detect when there's an attempt to lock the same inode more than once
    by the same process, since in that case the lock will not behave as
    intended with the default fcntl.lockf function.
    
    Bug: https://bugs.gentoo.org/714480
    Signed-off-by: Zac Medico <[e-mail]>

 lib/portage/locks.py | 16 ++++++++--------
 1 file changed, 8 insertions(+), 8 deletions(-)

[Comment 8 Larry the Git Cow 2020-03-25 19:26:32 UTC]

The bug has been referenced in the following commit(s):

https://gitweb.gentoo.org/repo/gentoo.git/commit/?id=ab3a65311eaae2242a5b04d06daec7daea90e5da

commit ab3a65311eaae2242a5b04d06daec7daea90e5da
Author:     Zac Medico <[e-mail]>
AuthorDate: 2020-03-25 19:23:25 +0000
Commit:     Zac Medico <[e-mail]>
CommitDate: 2020-03-25 19:24:13 +0000

    sys-apps/portage: Revbump to 2.3.96-r1
    
    This applies a small fixup to the changes for bug 714480.
    
    Bug: https://bugs.gentoo.org/711148
    Bug: https://bugs.gentoo.org/714480
    See: https://gitweb.gentoo.org/proj/portage.git/commit/?id=2b3fc2be07ad897b7df6b77f79616c143a353275
    Package-Manager: Portage-2.3.96, Repoman-2.3.21
    Signed-off-by: Zac Medico <[e-mail]>

 sys-apps/portage/{portage-2.3.96.ebuild => portage-2.3.96-r1.ebuild} | 3 +++
 1 file changed, 3 insertions(+)

[Comment 9 Rick Farina (Zero_Chaos) 2020-03-30 20:09:16 UTC]

I have built a few thousand packages with and without ebuild-locks and can no longer replicate this issue.  Thanks!