Since upgrading to portage 2.3.92, retrieveal of binpkgs from my bin server fail: ``` $ sudo emerge -DuvaN @world These are the packages that would be merged, in order: Calculating dependencies .. ..... done! [binary U ] dev-libs/nss-3.50-r1-1::gentoo [3.50::gentoo] USE="-cacert (-nss-pem%) -utils" 1,693 KiB [binary U ] dev-libs/libinput-1.15.3-1:0/10::gentoo [1.15.2:0/10::gentoo] USE="-doc" INPUT_DEVICES="-wacom" 293 KiB [binary R ] gnome-base/gnome-shell-3.34.4-7::gentoo USE="bluetooth browser-extension -elogind -gtk-doc -ibus networkmanager systemd -telepathy -test" PYTHON_SINGLE_TARGET="python3_6 -python3_7 -python3_8" 1,696 KiB Total: 3 packages (2 upgrades, 1 reinstall, 3 binaries), Size of downloads: 3,681 KiB Would you like to merge these packages? [Yes/No] >>> Emerging binary (1 of 3) dev-libs/nss-3.50-r1::gentoo >>> Emerging binary (2 of 3) dev-libs/libinput-1.15.3::gentoo >>> Jobs: 0 of 3 complete, 2 running Load avg: 0.80, 0.50, 0.24Exception in callback AsynchronousTask.wait() handle: <Handle AsynchronousTask.wait()> 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 107, in wait self._wait_hook() File "/usr/lib64/python3.6/site-packages/_emerge/AsynchronousTask.py", line 224, in _wait_hook self._exit_listener_stack.pop()(self) File "/usr/lib64/python3.6/site-packages/_emerge/BinpkgFetcher.py", line 63, in _fetcher_exit fetcher.sync_timestamp() File "/usr/lib64/python3.6/site-packages/_emerge/BinpkgFetcher.py", line 190, in sync_timestamp self.pkg.cpv)].get("_mtime_") KeyError: ('dev-libs/nss-3.50-r1', 1, 1733003, 1583506556, 1583506560) Terminated ``` The problem goes away when I downgrade to portage-2.3.89-r1.
$ emerge --info =sys-apps/portage-2.3.92 Portage 2.3.92 (python 3.6.10-final-0, default/linux/amd64/17.1/no-multilib, gcc-9.2.0, glibc-2.30-r4, 5.6.0-rc4 x86_64) ================================================================= System Settings ================================================================= System uname: Linux-5.6.0-rc4-x86_64-Intel-R-_Core-TM-_i7-8665U_CPU_@_1.90GHz-with-gentoo-2.7 KiB Mem: 16042656 total, 8071936 free KiB Swap: 23488508 total, 23488508 free Timestamp of repository gentoo: Fri, 06 Mar 2020 14:44:07 +0000 Timestamp of repository marduk: Fri, 14 Feb 2020 01:02:14 +0000 sh bash 5.0_p16 ld GNU ld (Gentoo 2.34 p1) 2.34.0 app-shells/bash: 5.0_p16::gentoo dev-lang/perl: 5.30.1::gentoo dev-lang/python: 3.6.10::gentoo dev-util/pkgconfig: 0.29.2::gentoo sys-apps/baselayout: 2.7::gentoo sys-apps/sandbox: 2.18::gentoo sys-devel/binutils: 2.34::gentoo sys-devel/gcc: 9.2.0-r4::gentoo sys-devel/gcc-config: 2.2.1::gentoo sys-devel/make: 4.3::gentoo sys-kernel/linux-headers: 5.5::gentoo (virtual/os-headers) sys-libs/glibc: 2.30-r4::gentoo Repositories: gentoo location: /var/db/repos/gentoo sync-type: rsync sync-uri: rsync://blackwidow/portage priority: -1000 sync-rsync-verify-metamanifest: False sync-rsync-verify-jobs: 1 sync-rsync-verify-max-age: 24 sync-rsync-extra-opts: --exclude .rsync-filter --info=progress2 marduk location: /var/db/repos/marduk sync-type: rsync sync-uri: rsync://blackwidow/local-portage masters: gentoo priority: 50 sync-rsync-verify-metamanifest: False sync-rsync-extra-opts: --exclude .rsync-filter --info=progress2 ACCEPT_KEYWORDS="amd64 ~amd64" ACCEPT_LICENSE="@FREE @BINARY-REDISTRIBUTABLE Google-TOS google-chrome google-talkplugin" CBUILD="x86_64-pc-linux-gnu" CFLAGS="-O2 -march=skylake -pipe" CHOST="x86_64-pc-linux-gnu" CONFIG_PROTECT="/etc /usr/share/gnupg/qualified.txt" CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/dconf /etc/env.d /etc/fonts/fonts.conf /etc/gconf /etc/gentoo-release /etc/revdep-rebuild /etc/sandbox.d /etc/terminfo" CXXFLAGS="-O2 -march=skylake -pipe" DISTDIR="/var/cache/distfiles" EMERGE_DEFAULT_OPTS=" --alphabetical --autounmask=n --buildpkg-exclude=sys-kernel/gentoo-sources --changed-deps=y --color=n --jobs=5 --nospinner --unordered-display --verbose-conflicts --with-bdeps=y --binpkg-changed-deps --binpkg-respect-use --buildpkg --color=y --getbinpkg --jobs=3 --keep-going --oneshot --quiet-build --quiet-unmerge-warn --rebuilt-binaries=y --with-bdeps=n " ENV_UNSET="DBUS_SESSION_BUS_ADDRESS DISPLAY GOBIN PERL5LIB PERL5OPT PERLPREFIX PERL_CORE PERL_MB_OPT PERL_MM_OPT XAUTHORITY XDG_CACHE_HOME XDG_CONFIG_HOME XDG_DATA_HOME XDG_RUNTIME_DIR" FCFLAGS="-O2 -pipe" FEATURES="assume-digests binpkg-docompress binpkg-dostrip binpkg-logs binpkg-multi-instance buildpkg cgroup config-protect-if-modified distlocks fixlafiles ipc-sandbox multilib-strict network-sandbox news noinfo notitles parallel-fetch pid-sandbox preserve-libs protect-owned qa-unresolved-soname-deps sandbox sfperms skiprocheck strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync xattr" FFLAGS="-O2 -pipe" GENTOO_MIRRORS="http://distfiles.gentoo.org" INSTALL_MASK="/usr/share/doc" LANG="en_US.utf8" LDFLAGS="-Wl,-O1 -Wl,--as-needed" LINGUAS="en" MAKEOPTS="-j8 -l8" PKGDIR="/var/cache/binpkgs" PORTAGE_BINHOST="http://blackwidow/packages/lighthouse/" PORTAGE_COMPRESS="" PORTAGE_COMPRESS_FLAGS="" PORTAGE_CONFIGROOT="/" PORTAGE_RSYNC_EXTRA_OPTS=" --exclude .rsync-filter --info=progress2 " PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --omit-dir-times --compress --force --whole-file --delete --stats --human-readable --timeout=180 --exclude=/distfiles --exclude=/local --exclude=/packages --exclude=/.git" PORTAGE_TMPDIR="/var/tmp" USE="acl aes amd64 asm avx avx2 f16c fma3 glamor introspection ipv6 jpeg2k mmx mmxext nls nptl opentype pam pclmul popcnt seccomp split-usr sse sse2 sse3 sse4_1 sse4_2 ssse3 systemd udev unicode urandom utf8 wayland xattr" ABI_X86="64" APACHE2_MODULES="auth_digest authn_core authn_file authz authz_core authz_groupfile authz_host authz_user dav dav_fs dir group_file mime socache_shmcb unixd" APACHE2_MPMS="prefork" CAMERAS="*" CPU_FLAGS_X86="aes avx avx2 f16c fma3 mmx mmxext pclmul popcnt sse sse2 sse3 sse4_1 sse4_2 ssse3" CURL_SSL="openssl" ELIBC="glibc" FFTOOLS="*" INPUT_DEVICES="libinput" KERNEL="linux" L10N="en" LLVM_TARGETS="X86" NGINX_MODULES_HTTP="auth_basic gzip proxy rewrite uwsgi" PYTHON_SINGLE_TARGET="python3_6" PYTHON_TARGETS="python3_6" QEMU_SOFTMMU_TARGETS="i386 x86_64" QEMU_USER_TARGETS="i386 x86_64" RUBY_TARGETS="ruby27" USERLAND="GNU" VIDEO_CARDS="intel i965" Unset: CC, CPPFLAGS, CTARGET, CXX, LC_ALL, PORTAGE_BUNZIP2_COMMAND ================================================================= Package Settings ================================================================= sys-apps/portage-2.3.92::gentoo was built with the following: USE="-apidoc -build -doc -gentoo-dev (ipc) native-extensions -rsync-verify (-selinux) xattr" PYTHON_TARGETS="-pypy3 -python2_7 python3_6 -python3_7 -python3_8" CFLAGS="-O2 -march=native -mtune=skylake -pipe" CXXFLAGS="-O2 -march=native -mtune=skylake -pipe"
It looks like it may have downloaded the file twice, once for parallel-fetch and then again even though it should have recognized that it was being fetched already. Can you confirm that two copies of the file exist after the error occurs? For example, for the dev-libs/nss-3.50-r1 package shown in comment #0, you would have these two files if it download the file twice: /var/cache/binpkgs/dev-libs/nss/nss-3.50-r1-1.xpak /var/cache/binpkgs/dev-libs/nss/nss-3.50-r1-1.xpak.partial If only one of these files exists immediately after the error occurs, then that would suggest that the bug occurs earlier, during parallel-fetch.
(In reply to Zac Medico from comment #2) > It looks like it may have downloaded the file twice, once for parallel-fetch > and then again even though it should have recognized that it was being > fetched already. > > Can you confirm that two copies of the file exist after the error occurs? > For example, for the dev-libs/nss-3.50-r1 package shown in comment #0, you > would have these two files if it download the file twice: > > /var/cache/binpkgs/dev-libs/nss/nss-3.50-r1-1.xpak > /var/cache/binpkgs/dev-libs/nss/nss-3.50-r1-1.xpak.partial That doesn't appear to be the case: ``` >>> Emerging binary (1 of 6) dev-libs/wayland-protocols-1.20::gentoo >>> Jobs: 0 of 6 complete, 1 running Load avg: 0.78, 0.35, 0.35Exception in callback AsynchronousTask.wait() handle: <Handle AsynchronousTask.wait()> 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 107, in wait self._wait_hook() File "/usr/lib64/python3.6/site-packages/_emerge/AsynchronousTask.py", line 224, in _wait_hook self._exit_listener_stack.pop()(self) File "/usr/lib64/python3.6/site-packages/_emerge/BinpkgFetcher.py", line 63, in _fetcher_exit fetcher.sync_timestamp() File "/usr/lib64/python3.6/site-packages/_emerge/BinpkgFetcher.py", line 190, in sync_timestamp self.pkg.cpv)].get("_mtime_") KeyError: ('dev-libs/wayland-protocols-1.20', 1, 71571, 1583570721, 1583570725) Error updating @world [● admin∙lighthouse /] ls /var/cache/binpkgs/dev-libs/wayland-protocols/ wayland-protocols-1.19-1.xpak wayland-protocols-1.20-1.xpak ```
The strange thing is that I can always downgrade portage from the binhost. I guess that's a good thing.
I'm pretty sure that the issue started with this commit related to bug 709746, since it causes the CompositeTask isAlive method (which is used to check if the BinpkgPrefetcher is still running) to inappropriately return False: https://gitweb.gentoo.org/proj/portage.git/commit/?id=d66e9ec0b10522528d62e18b83e012c1ec121787
The bug has been referenced in the following commit(s): https://gitweb.gentoo.org/proj/portage.git/commit/?id=50da2e16599202b9ecb3d4494f214a0d30b073d7 commit 50da2e16599202b9ecb3d4494f214a0d30b073d7 Author: Zac Medico <zmedico@gentoo.org> AuthorDate: 2020-03-07 19:41:49 +0000 Commit: Zac Medico <zmedico@gentoo.org> CommitDate: 2020-03-07 19:54:06 +0000 AsynchronousTask: simplify isAlive (bug 711688) Simplify all AsynchronousTask subclasses to use the default isAlive implementation, which returns True if self.returncode is not None. This fixes cases where the method would erroneously return False, leading to issues like bug 711688, where the CompositeTask isAlive implementation returned False for a BinpkgPrefetcher instance that was still in the process of starting via its async_start method. Fixes: d66e9ec0b105 ("AsynchronousTask: add coroutine async_start method") Bug: https://bugs.gentoo.org/711688 Signed-off-by: Zac Medico <zmedico@gentoo.org> lib/_emerge/AbstractPollTask.py | 3 --- lib/_emerge/CompositeTask.py | 3 --- lib/_emerge/FifoIpcDaemon.py | 3 --- lib/_emerge/SubProcess.py | 6 +----- 4 files changed, 1 insertion(+), 14 deletions(-)
The bug has been closed via the following commit(s): https://gitweb.gentoo.org/repo/gentoo.git/commit/?id=3330b6df6278675073b2f25cb1a743005ad7cc98 commit 3330b6df6278675073b2f25cb1a743005ad7cc98 Author: Zac Medico <zmedico@gentoo.org> AuthorDate: 2020-03-07 22:55:37 +0000 Commit: Zac Medico <zmedico@gentoo.org> CommitDate: 2020-03-07 22:59:57 +0000 sys-apps/portage: Bump to version 2.3.93 #711322 schedule exit listeners via call_soon #711688 BinpkgFetcher sync_timestamp KeyError regression Bug: https://bugs.gentoo.org/711148 Bug: https://bugs.gentoo.org/711322 Closes: https://bugs.gentoo.org/711688 Package-Manager: Portage-2.3.93, Repoman-2.3.20 Signed-off-by: Zac Medico <zmedico@gentoo.org> sys-apps/portage/Manifest | 1 + sys-apps/portage/portage-2.3.93.ebuild | 271 +++++++++++++++++++++++++++++++++ 2 files changed, 272 insertions(+)
Please re-open if the problem is not fixed in portage-2.3.93.
