Bug 915219 – sys-apps/portage-3.0.52: GPG keepalive failed: "gpg: signing failed: Timeout"

• Product: Portage Development
• Status: RESOLVED CANTFIX

[Description Nowa Ammerlaan 2023-10-05 19:56:04 UTC]

Every now and then portage fails to keep the gpg signing key unlocked. Most of the time it works fine, it feels a bit random when it fails and when it doesn't.

It seems to happen mostly(always?) when building binpkgs for big packages (i.e. when compressing and copying the image directory takes rather long). When keepalive fails the package that is currently being emerged will fail to install. Sometimes I'm prompted for the passphrase again when it is time to sign the built binpkg, however entering it does not prevent portage from failing to sign the binpkg and copy it to the PKGDIR. End result is that this failure prevents the package from being installed at all.

Today it happened when building clang:

>>> Emerging (69 of 96) sys-devel/clang-17.0.2::gentoo
>>> Jobs: 68 of 96 complete, 1 running              Load avg: 16.0, 15.0, 14.3Exception in thread Thread-1 (gpg_keepalive):
Traceback (most recent call last):
File "/usr/lib/python3.11/threading.py", line 1038, in _bootstrap_inner

File "/usr/lib/python3.11/threading.py", line 975, in run
invokes the callable object passed to the object's constructor as the
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/lib/python3.11/site-packages/portage/gpg.py", line 106, in gpg_keepalive
raise GPGException("GPG keepalive failed")
portage.exception.GPGException: GPG keepalive failed
>>> Failed to emerge sys-devel/clang-17.0.2, Log file:
>>>  '/tmp/portage/sys-devel/clang-17.0.2/temp/build.log'
>>> Jobs: 68 of 96 complete, 1 failed               Load avg: 4.9, 12.3, 14.2
*** Resuming merge...
Calculating dependencies... done!
Dependency resolution took 10.38 s.

I'm sorry this is a bit vague. It is a very annoying issue but it is also very difficult to consistently reproduce. Would love to help debug this further, please let me know if there are additional things I can try to maybe reproduce this more consistently.

[Comment 1 Nowa Ammerlaan 2023-10-06 10:13:26 UTC]

I removed the 'stdout=subprocess.DEVNULL' line in gpg.py to better see what happens. Just now it happened again and it shows the problem is a Timeout:

>>> Completed (35 of 51) mail-client/thunderbird-115.3.1::gentoo
>>> Jobs: 43 of 51 complete, 2 running              Load avg: 15.9, 16.6, 17.2gpg: WARNING: unsafe permissionson homedir '/etc/portage/gnupg'
-----BEGIN PGP MESSAGE-----

owEB0QEu/pANAwAKAWXHXw+yi6IFAcsKYgRudWxsZR/Z1YkBswQAAQoAHRYhBIuX
J2MKgYcNprHmMmXHXw+yi6IFBQJlH9nVAAoJEGXHXw+yi6IFtFAL/3CU76OTgpB2
Vl25W1nZW6FGSuQglW3NHmzfC2U2HSLm6yZQ15Belt5lFFnaPaWMCBVazMA4+T77
jTUXAsOEFHaRQcv/W9bPfBhrOm59iLWHVFCjSoyvqjCne/9C3TqStoSED9ggG6ER
ADWdRNf7GApOfiXR8AZ52mTv++bKmacTP9+VWwBHzuuH28Pvh/u/QmqH+zzsJpaG
kG0RMQIjkGPerFMSLBtA0gk/rneSBMa16sykwTejer6q0kUQAqdoFWHOCm7s4Fw2
x7ZSBuyIJYBTX/dczB0tPrNZJH3E7nwvINx7TT0bQ26VIyJAKPxVy6KgI815f1hs
7uolvxygsS62KxI0eLRNBFSnOfpJKWUIhmrfJ0LMycjm8cwtJ5utuo1TXZsnXacO
XAEuIRAAfPiXg7MdRcBVCULjY9tqzD92K1qcfVfi6+Lm8xaUs9VpHIyez37snY5/
UrE2ci+Of1NAPBItAHr6mZ0Cq5y2LxtfhOSHq1R82tJJwHRHLODxRQ==
=d8Nw
-----END PGP MESSAGE-----
>>> Installing (41 of 51) dev-python/pyside2-5.15.10-r2::gentoo
>>> Completed (41 of 51) dev-python/pyside2-5.15.10-r2::gentoo
>>> Jobs: 44 of 51 complete, 1 running              Load avg: 15.8, 16.1, 16.9gpg: WARNING: unsafe permissionson homedir '/etc/portage/gnupg'
>>> Jobs: 44 of 51 complete, 1 running              Load avg: 15.1, 15.8, 16.7gpg: signing failed: Timeout
-----BEGIN PGP MESSAGE-----

gpg: signing failed: Timeout
Exception in thread Thread-1 (gpg_keepalive):
Traceback (most recent call last):
File "/usr/lib/python3.11/threading.py", line 1045, in _bootstrap_inner
self.run()
File "/usr/lib/python3.11/threading.py", line 982, in run
self._target(*self._args, **self._kwargs)
File "/usr/lib/python3.11/site-packages/portage/gpg.py", line 105, in gpg_keepalive
raise GPGException("GPG keepalive failed")
portage.exception.GPGException: GPG keepalive failed
>>> Failed to emerge sci-libs/vtk-9.2.6, Log file:
>>>  '/tmp/portage/sci-libs/vtk-9.2.6/temp/build.log'
>>> Installing (46 of 51) kde-plasma/kscreenlocker-5.27.8-r1::gentoo

[Comment 2 Sam James 2023-10-06 16:19:51 UTC]

Hmm: https://lists.gnupg.org/pipermail/gnupg-users/2021-March/064976.html.

[Comment 3 Nowa Ammerlaan 2023-10-09 09:00:59 UTC]

I think I may have fixed my problem with this gpg-agent.conf:

max-cache-ttl 34560000


From the gpg-agent manual:
--max-cache-ttl n
Set the maximum time a cache entry is valid to n seconds.  After this time a cache entry will be expired even if it has been accessed recently or has been set using gpg-preset-passphrase.  The default is 2 hours (7200 seconds).

With the default of 2 hours this would mean that any emerge session will fail if it lasts longer then 2 hours.

I'll wait a bit until I'm sure it really doesn't happen any more with this config, if this does turn out to be the fix then I'll add it to the wiki page.

[Comment 4 Nowa Ammerlaan 2024-04-14 15:18:31 UTC]

I have not had this problem since I made the above changes to gpg-agent.conf.

I added a note about this to the wiki page, which I think is all we can do here given that this is behaviour controlled by gpg. So I'll close this Bug.