Gentoo Websites Logo
Go to: Gentoo Home Documentation Forums Lists Bugs Planet Store Wiki Get Gentoo!
Bug 710476 - sys-apps/portage-2.3.84 file_copy failure (gawk emerge doins failed) ** WORK AROUND **
Summary: sys-apps/portage-2.3.84 file_copy failure (gawk emerge doins failed) ** WORK ...
Status: RESOLVED OBSOLETE
Alias: None
Product: Portage Development
Classification: Unclassified
Component: Core (show other bugs)
Hardware: All Linux
: Normal normal (vote)
Assignee: Portage team
URL:
Whiteboard:
Keywords:
Depends on:
Blocks: 635020
  Show dependency tree
 
Reported: 2020-02-22 11:37 UTC by Michael South
Modified: 2023-01-17 02:40 UTC (History)
3 users (show)

See Also:
Package list:
Runtime testing required: ---


Attachments
Build log (gawk-4.2.1-r1-build.log.txt,52.67 KB, text/plain)
2020-02-22 11:37 UTC, Michael South
Details
Fragment of **successful** emerge strace. (portage-2.3.89-emerge-ok-strace_frag.txt,25.85 KB, text/plain)
2020-02-22 13:37 UTC, Michael South
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Michael South 2020-02-22 11:37:51 UTC
Created attachment 615088 [details]
Build log

More file_copy weirdness, for one particular ebuild. Emerge of gawk is consistently failing for one particular file; reports "file not found", but file exists and is actually being created as a zero-byte destination file. Sounds similar to file_copy bugs in the past (https://forums.gentoo.org/viewtopic-t-1075756-postdays-0-postorder-asc-start-0.html https://forums.gentoo.org/viewtopic-t-1073760-start-0.html)

Many, many other emerges working without problems.

Note that I modified file_copy/__init__.py to display source and destination names and filenos before every call to _file_copy, and doins.py to display cwd:

/var is on root:

~ # df -h
Filesystem      Size  Used Avail Use% Mounted on
/dev/root       217G   74G  132G  36% /
devtmpfs         10M     0   10M   0% /dev
tmpfs           1.6G  760K  1.6G   1% /run
cgroup_root      10M     0   10M   0% /sys/fs/cgroup
shm             7.9G   52M  7.8G   1% /dev/shm
none            7.9G   16K  7.9G   1% /run/user/500
none            7.9G     0  7.9G   0% /run/user/0

~ # mount
/dev/sda4 on / type ext4 (rw,noatime)
devtmpfs on /dev type devtmpfs (rw,nosuid,relatime,size=10240k,nr_inodes=2044577,mode=755)
proc on /proc type proc (rw,nosuid,nodev,noexec,relatime)
tmpfs on /run type tmpfs (rw,nodev,relatime,size=1642816k,mode=755)
sysfs on /sys type sysfs (rw,nosuid,nodev,noexec,relatime)
securityfs on /sys/kernel/security type securityfs (rw,nosuid,nodev,noexec,relatime)
debugfs on /sys/kernel/debug type debugfs (rw,nosuid,nodev,noexec,relatime)
configfs on /sys/kernel/config type configfs (rw,nosuid,nodev,noexec,relatime)
fusectl on /sys/fs/fuse/connections type fusectl (rw,nosuid,nodev,noexec,relatime)
pstore on /sys/fs/pstore type pstore (rw,nosuid,nodev,noexec,relatime)
efivarfs on /sys/firmware/efi/efivars type efivarfs (rw,nosuid,nodev,noexec,relatime)
cgroup_root on /sys/fs/cgroup type tmpfs (rw,nosuid,nodev,noexec,relatime,size=10240k,mode=755)
openrc on /sys/fs/cgroup/openrc type cgroup (rw,nosuid,nodev,noexec,relatime,release_agent=/lib/rc/sh/cgroup-release-agent.sh,name=openrc)
none on /sys/fs/cgroup/unified type cgroup2 (rw,nosuid,nodev,noexec,relatime,nsdelegate)
cpu on /sys/fs/cgroup/cpu type cgroup (rw,nosuid,nodev,noexec,relatime,cpu)
cpuacct on /sys/fs/cgroup/cpuacct type cgroup (rw,nosuid,nodev,noexec,relatime,cpuacct)
blkio on /sys/fs/cgroup/blkio type cgroup (rw,nosuid,nodev,noexec,relatime,blkio)
memory on /sys/fs/cgroup/memory type cgroup (rw,nosuid,nodev,noexec,relatime,memory)
freezer on /sys/fs/cgroup/freezer type cgroup (rw,nosuid,nodev,noexec,relatime,freezer)
net_cls on /sys/fs/cgroup/net_cls type cgroup (rw,nosuid,nodev,noexec,relatime,net_cls)
net_prio on /sys/fs/cgroup/net_prio type cgroup (rw,nosuid,nodev,noexec,relatime,net_prio)
hugetlb on /sys/fs/cgroup/hugetlb type cgroup (rw,nosuid,nodev,noexec,relatime,hugetlb)
pids on /sys/fs/cgroup/pids type cgroup (rw,nosuid,nodev,noexec,relatime,pids)
mqueue on /dev/mqueue type mqueue (rw,nosuid,nodev,noexec,relatime)
devpts on /dev/pts type devpts (rw,nosuid,noexec,relatime,gid=5,mode=620,ptmxmode=000)
shm on /dev/shm type tmpfs (rw,nosuid,nodev,noexec,relatime)
none on /run/user/500 type tmpfs (rw,relatime,mode=700,uid=500)
none on /run/user/0 type tmpfs (rw,relatime,mode=700)

~ # dumpe2fs -h /dev/root
dumpe2fs 1.45.5 (07-Jan-2020)
Filesystem volume name:   rootfs
Last mounted on:          /
Filesystem UUID:          6b071641-ebde-440f-bac5-d317e46c6c83
Filesystem magic number:  0xEF53
Filesystem revision #:    1 (dynamic)
Filesystem features:      has_journal ext_attr resize_inode dir_index sparse_super2 filetype needs_recovery extent 64bit flex_bg inline_data sparse_super large_file huge_file uninit_bg dir_nlink extra_isize
Filesystem flags:         signed_directory_hash
Default mount options:    user_xattr acl
Filesystem state:         clean
Errors behavior:          Continue
Filesystem OS type:       Linux
Inode count:              1013824
Block count:              56855086
Reserved block count:     2842754
Free blocks:              25908918
Free inodes:              297412
First block:              0
Block size:               4096
Fragment size:            4096
Group descriptor size:    64
Reserved GDT blocks:      354
Blocks per group:         32768
Fragments per group:      32768
Inodes per group:         584
Inode blocks per group:   73
Flex block group size:    8
Filesystem created:       Thu Jul 19 12:37:29 2018
Last mount time:          Mon Oct  7 20:09:43 2019
Last write time:          Fri Jul 20 11:57:15 2018
Mount count:              39
Maximum mount count:      -1
Last checked:             Thu Jul 19 12:37:29 2018
Check interval:           0 (<none>)
Lifetime writes:          2637 GB
Reserved blocks uid:      0 (user root)
Reserved blocks gid:      0 (group root)
First inode:              11
Inode size:	          512
Required extra isize:     32
Desired extra isize:      32
Journal inode:            8
First orphan inode:       24505
Default directory hash:   half_md4
Directory Hash Seed:      9383622c-fedd-4ade-9923-7521ff4a4598
Journal backup:           inode blocks
Backup block groups:      1 1735
Journal features:         journal_incompat_revoke journal_64bit
Journal size:             64M
Journal length:           16384
Journal sequence:         0x003051cf
Journal start:            7127


--------

src b'cmd.h', src_file.fileno 3, dst b'/var/tmp/portage/sys-apps/gawk-4.2.1-r1/image/usr/include/awk/cmd.h', dst_file.fileno 4
src b'config.h', src_file.fileno 3, dst b'/var/tmp/portage/sys-apps/gawk-4.2.1-r1/image/usr/include/awk/config.h', dst_file.fileno 4
ERROR:root:Failed to copy file: _parsed_options=Namespace(group=-1, mode=420, owner=-1, preserve_timestamps=False), cwd='/var/tmp/portage/sys-apps/gawk-4.2.1-r1/work/gawk-4.2.1', source=b'config.h', dest_dir=b'/var/tmp/portage/sys-apps/gawk-4.2.1-r1/image/usr/include/awk'
Traceback (most recent call last):
  File "/usr/lib/portage/python3.6/doins.py", line 209, in run
    copyfile(source, dest)
  File "/usr/lib64/python3.6/site-packages/portage/util/file_copy/__init__.py", line 31, in _optimized_copyfile
    _file_copy(src_file.fileno(), dst_file.fileno())
FileNotFoundError: [Errno 2] No such file or directory
src b'custom.h', src_file.fileno 3, dst b'/var/tmp/portage/sys-apps/gawk-4.2.1-r1/image/usr/include/awk/custom.h', dst_file.fileno 4
src b'floatmagic.h', src_file.fileno 3, dst b'/var/tmp/portage/sys-apps/gawk-4.2.1-r1/image/usr/include/awk/floatmagic.h', dst_file.fileno 4

~ # ls -l /var/tmp/portage/sys-apps/gawk-4.2.1-r1/work/gawk-4.2.1/
...
-rw-r--r-- 1 portage portage  59511 Feb 25  2018 awk.h
...
-rw-r--r-- 1 portage portage   5589 Dec 14  2017 cmd.h
...
-rw-r--r-- 1 portage portage  14516 Feb 22 01:57 config.h
...

~ # ls -l /var/tmp/portage/sys-apps/gawk-4.2.1-r1/image/usr/include/awk/
total 180
-rw-r--r-- 1 root root 59511 Feb 22 01:57 awk.h
-rw-r--r-- 1 root root  5589 Feb 22 01:57 cmd.h
-rw-r--r-- 1 root root     0 Feb 22 01:57 config.h
-rw-r--r-- 1 root root  2137 Feb 22 01:57 custom.h
-rw-r--r-- 1 root root  1873 Feb 22 01:57 floatmagic.h
-rw-r--r-- 1 root root 40228 Feb 22 01:57 gawkapi.h
-rw-r--r-- 1 root root 10536 Feb 22 01:57 gettext.h
-rw-r--r-- 1 root root 35565 Feb 22 01:57 interpret.h
-rw-r--r-- 1 root root  1678 Feb 22 01:57 mbsupport.h
-rw-r--r-- 1 root root  2747 Feb 22 01:57 nonposix.h
-rw-r--r-- 1 root root  4322 Feb 22 01:57 protos.h

However, of the files in image/usr/include/awk, only config.h appears to have been created as part of the build process; the others come from files with older creation dates.

--------

emerge --info '=sys-apps/gawk-4.2.1-r1::gentoo'
Portage 2.3.84 (python 3.6.9-final-0, default/linux/amd64/17.1, gcc-9.2.0, glibc-2.29-r7, 4.17.0-speedy-180720b x86_64)
=================================================================
                         System Settings
=================================================================
System uname: Linux-4.17.0-speedy-180720b-x86_64-Intel-R-_Core-TM-_i5-3570_CPU_@_3.40GHz-with-gentoo-2.6
KiB Mem:    16428132 total,   5980976 free
KiB Swap:   16643068 total,  16642544 free
Timestamp of repository gentoo: Sat, 22 Feb 2020 00:45:01 +0000
Timestamp of repository bitcoin: Fri, 21 Feb 2020 19:41:59 +0000
Head commit of repository bitcoin: 153726c83400f5d7f7d278b633101ef8e3a1c361

Timestamp of repository lisp: Wed, 12 Feb 2020 17:43:05 +0000
Head commit of repository lisp: 70e0c0aa3d9fd16d1b091b88695eac3ac4a8ba29

sh bash 4.4_p23-r1
ld GNU ld (Gentoo 2.32 p2) 2.32.0
app-shells/bash:          4.4_p23-r1::gentoo
dev-lang/perl:            5.30.1::gentoo
dev-lang/python:          2.7.17::gentoo, 3.6.9::gentoo, 3.7.5-r1::gentoo
dev-util/cmake:           3.14.6::gentoo
dev-util/pkgconfig:       0.29.2::gentoo
sys-apps/baselayout:      2.6-r1::gentoo
sys-apps/openrc:          0.41.2::gentoo
sys-apps/sandbox:         2.13::gentoo
sys-devel/autoconf:       2.13-r1::gentoo, 2.69-r4::gentoo
sys-devel/automake:       1.16.1-r1::gentoo
sys-devel/binutils:       2.32-r1::gentoo
sys-devel/gcc:            9.2.0-r2::gentoo
sys-devel/gcc-config:     2.2::gentoo
sys-devel/libtool:        2.4.6-r6::gentoo
sys-devel/make:           4.2.1-r4::gentoo
sys-kernel/linux-headers: 4.19::gentoo (virtual/os-headers)
sys-libs/glibc:           2.29-r7::gentoo
Repositories:

gentoo
    location: /usr/portage
    sync-type: webrsync
    sync-uri: rsync://rsync.gentoo.org/gentoo-portage
    priority: -1000
    sync-webrsync-verify-signature: true

bitcoin
    location: /var/db/repos/bitcoin
    sync-type: git
    sync-uri: https://github.com/gentoo-mirror/bitcoin.git
    masters: gentoo

lisp
    location: /var/db/repos/lisp
    sync-type: git
    sync-uri: https://github.com/gentoo-mirror/lisp.git
    masters: gentoo

localrepo
    location: /usr/local/portage
    masters: gentoo

ACCEPT_KEYWORDS="amd64"
ACCEPT_LICENSE="* -@EULA"
CBUILD="x86_64-pc-linux-gnu"
CFLAGS="-O2 -pipe"
CHOST="x86_64-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/share/config /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 -pipe"
DISTDIR="/usr/portage/distfiles"
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 config-protect-if-modified distlocks ebuild-locks fixlafiles ipc-sandbox merge-sync multilib-strict network-sandbox news nodoc parallel-fetch pid-sandbox preserve-libs protect-owned sandbox sfperms strict unknown-features-warn unmerge-logs unmerge-orphans userfetch userpriv usersandbox usersync xattr"
FFLAGS="-O2 -pipe"
GENTOO_MIRRORS="http://mirror.usu.edu/mirrors/gentoo/ http://gentoo.osuosl.org/"
LANG="en_US.utf8"
LDFLAGS="-Wl,-O1 -Wl,--as-needed"
MAKEOPTS="-j5"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
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="X acl aio alsa amd64 berkdb bzip2 cairo caps cli consolekit crypt cups cxx dbus dri egl evdev expat gdbm gif gssapi gtk iconv idn ipv6 jpeg kde kerberos libev libsamplerate libsndfile libtirpc lm_sensors multilib ncurses nfsidmap nfsv3 nfsv4 nfsv41 nptl ocaml ocamlopt opengl openmp pam pcre pdf png pulseaudio qalculate qt5 readline seccomp speex split-usr ssl svg tiff udev unicode wayland xattr xcb xinerama xrandr zlib" ABI_X86="64" ADA_TARGET="gnat_2018" ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m maestro3 trident usb-audio via82xx via82xx-modem ymfpci" APACHE2_MODULES="authn_core authz_core socache_shmcb unixd actions alias auth_basic authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter file_cache filter headers include info log_config logio mem_cache mime mime_magic negotiation rewrite setenvif speling status unique_id userdir usertrack vhost_alias" CALLIGRA_FEATURES="karbon sheets words" COLLECTD_PLUGINS="df interface irq load memory rrdtool swap syslog" CPU_FLAGS_X86="mmx mmxext sse sse2 aes avx f16c pclmul popcnt sse3 sse4_1 sse4_2 ssse3" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm earthmate evermore fv18 garmin garmintxt gpsclock greis isync itrax mtk3301 nmea ntrip navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf skytraq superstar2 timing tsip tripmate tnt ublox ubx" INPUT_DEVICES="libinput" KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001 mtxorb ncurses text" LIBREOFFICE_EXTENSIONS="presenter-console presenter-minimizer" OFFICE_IMPLEMENTATION="libreoffice" PHP_TARGETS="php7-2" POSTGRES_TARGETS="postgres10 postgres11" PYTHON_SINGLE_TARGET="python3_6" PYTHON_TARGETS="python2_7 python3_6" RUBY_TARGETS="ruby24 ruby25" USERLAND="GNU" VIDEO_CARDS="r600 radeon intel i915 i965" XTABLES_ADDONS="quota2 psd pknock lscan length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq steal rawnat logmark ipmark dhcpmac delude chaos account"
Unset:  CC, CPPFLAGS, CTARGET, CXX, EMERGE_DEFAULT_OPTS, INSTALL_MASK, LC_ALL, LINGUAS, PORTAGE_BINHOST, PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS, PORTAGE_RSYNC_EXTRA_OPTS

=================================================================
                        Package Settings
=================================================================

sys-apps/gawk-4.2.1-r1::gentoo was built with the following:
USE="readline -forced-sandbox -mpfr -nls" ABI_X86="(64)"

-----

emerge -pqv '=sys-apps/gawk-4.2.1-r1::gentoo'
[ebuild   R   ] sys-apps/gawk-4.2.1-r1  USE="readline -mpfr -nls (-forced-sandbox%)"
Comment 1 Michael South 2020-02-22 13:11:27 UTC
Wonderful, wonderful news. (deep sarcasm...) Heisenbug...

Same behavior with Portage 2.3.79 and 2.3.89. So, still in Portage 2.3.89, I emerged strace (which worked) and did

~ # strace -o portage-2.3.89-emerge-gawk-strace.txt -f emerge -1 gawk

...and it worked without problems.

Race condition? BTW, I previously tried and failed with -j1 (both in command line and in make.conf).

Tried `emerge -1 gawk' again (still Portage 2.3.89), and it failed.

Tried this in file_copy/__init__.py:

        with open(src, 'rb', buffering=0) as src_file, \
                open(dst, 'wb', buffering=0) as dst_file:
+               time.sleep(1)
                _file_copy(src_file.fileno(), dst_file.fileno())

and

+       time.sleep(1)
        with open(src, 'rb', buffering=0) as src_file, \
                open(dst, 'wb', buffering=0) as dst_file:

                _file_copy(src_file.fileno(), dst_file.fileno())

Slower in install, but still failed.

This failed, too:

+       with open(src, 'rb', buffering=0) as src_file, \
+               open(dst, 'wb', buffering=0) as dst_file:
+               pass
+       os.remove(dst)
        with open(src, 'rb', buffering=0) as src_file, \
                open(dst, 'wb', buffering=0) as dst_file:
                _file_copy(src_file.fileno(), dst_file.fileno())


I'll go ahead an upload the (successful) strace.
Comment 2 Michael South 2020-02-22 13:37:57 UTC
Created attachment 615090 [details]
Fragment of **successful** emerge strace.

The important part of an strace from a *successful* emerge of gawk. There doesn't appear to be any difference in behavior for config.h (which has been troublesome) and cmd.h (which isn't).
Comment 3 Zac Medico gentoo-dev 2020-02-22 19:37:06 UTC
This could be due to a bug in your kernel's ext4 driver. Note that 4.17.0 is a relatively old linux kernel version. You should try upgrading to a newer kernel version in order to see if that corrects the problem.
Comment 4 Alexandra Parker 2020-06-15 18:24:00 UTC
I'm seeing this behavior on Linux 5.7.2 and Portage 2.3.101.
Comment 5 Michael South 2020-06-15 18:46:01 UTC
Still seeing w/ kernel 5.4.0, Portage 2.3.99-r2.

** WORK AROUND **

Works if I disable native extensions:

sys-apps/portage -native-extensions
Comment 6 Michael South 2020-06-15 18:56:41 UTC
Also, latest failure and successful work-round were using same version of Python, either 3.6 or 3.7.
Comment 7 Alexandra Parker 2020-06-15 18:58:08 UTC
I guess this is some problem using reflinks (which I'm not familiar with), but why for this particular file?
Comment 8 Alexandra Parker 2020-06-15 19:23:05 UTC
I'm trying to make a minimal reproduction of the error, but having no luck. I ran this Python code and it worked:

from portage.util.file_copy.reflink_linux import file_copy
fin = open(b'config.h', 'rb')
fout = open(b'/var/tmp/portage/sys-apps/gawk-5.1.0/image/usr/include/awk/config.h', 'wb')
file_copy(fin.fileno(), fout.fileno())
Comment 9 Alexandra Parker 2020-06-15 19:44:34 UTC
A similar doins failure occurs for me with qtgui. The same workaround works.
Comment 10 Michael South 2020-06-16 00:01:07 UTC
Sure looks like a lseek() bug...

I verified its still happening to me. Re-enabled native extensions, tried with Python 3.6 and 3.7. emerge gawk still fails.

I put some printfs into portage_util_file_copy_reflink_linux.c. The important bits are:

    /* Locate the next hole, so that we know when to
     * stop copying. There is an implicit hole at the
     * end of the file. This should never result in ENXIO
     * after SEEK_DATA has succeeded above.
     */
    printf("{seeking... pre errno=%d, offset_data=%ld}", errno, offset_data);
    {
        struct stat s;
        if (!fstat(fd_in, &s)) {
            printf("{fstat %d .mode=%d, .nlink=%ld, .size=%ld}", fd_in, s.st_mode, s.st_nlink, s.st_size);
        } else {
            printf("{fstat %d failed! errno %d}", fd_in, errno);
        }
    }
    offset_hole = lseek(fd_in, offset_data, SEEK_HOLE);
    if (offset_hole < 0) {
        printf("{err ret 4: errno=%d, offset_data=%ld, offset_hole=%ld}", errno, offset_data, offset_hole);
        return -1;
    }

'emerge gawk' results in:

<try><a>{do_lseek_data}{b offset_data=0}{seeking... pre errno=25, offset_data=0}{fstat 3 .mode=33188, .nlink=1, .size=5589}{ok errno=25}<a ok1>{do_lseek_data}<ok>

<try><a>{do_lseek_data}{b offset_data=0}{seeking... pre errno=25, offset_data=0}{fstat 3 .mode=33188, .nlink=1, .size=14348}{err ret 4: errno=2, offset_data=0, offset_hole=-1}<a len -1, err 2><some err 2>
ERROR:root:Failed to copy file: _parsed_options=Namespace(group=-1, mode=420, owner=-1, preserve_timestamps=False), source=b'config.h', dest_dir=b'/var/tmp/portage/sys-apps/gawk-5.0.1/image/usr/include/awk'
Traceback (most recent call last):
  File "/usr/lib/portage/python3.7/doins.py", line 209, in run
    copyfile(source, dest)
  File "/usr/lib/python3.7/site-packages/portage/util/file_copy/__init__.py", line 30, in _optimized_copyfile
    _file_copy(src_file.fileno(), dst_file.fileno())
FileNotFoundError: [Errno 2] No such file or directory

<try><a>{do_lseek_data}{b offset_data=0}{seeking... pre errno=25, offset_data=0}{fstat 3 .mode=33188, .nlink=1, .size=2355}{ok errno=25}<a ok1>{do_lseek_data}<ok>

Each "<try>" line is an attempt to copy one file. The files before and after config.h work. For config.h, the fstat(3, ...) works, but lseek(3, ...) is returning -1 and forcing errno to ENOENT.
Comment 11 Michael South 2020-06-16 04:12:36 UTC
Found a fix... Adding `fsync(fd_in);` before the `lseek(fd_in, offset_data, SEEK_HOLE);` eliminates the error.

I think there's a bug in the kernel where seeking holes on unflushed mmapped pages is causing lseek() to return ENOENT rather than the documented behavior of returning the end-of-file offset.

Looking at the kernel sources, in fs/iomap/seek.c, there is a function page_cache_seek_hole_data() which says "within unwritten extents, the page cache determines which parts are holes". If it doesn't find a hole it's returning -ENOENT; I suspect this is what's leaking out through lseek(). Hence the guess at fsync(), which appears to work.

As noted in a previous comment, the troublesome config.h file is the only in this directory install which is created during the build process, and so may have unwritten extents.

Probably don't want to actually fsync(); a better hack-patch would be to check for ENOENT being returned, and force offset_hole to fstat() st_size.
Comment 12 Zac Medico gentoo-dev 2020-06-16 04:21:28 UTC
(In reply to Michael South from comment #11)
> Probably don't want to actually fsync(); a better hack-patch would be to
> check for ENOENT being returned, and force offset_hole to fstat() st_size.

This needs to get fixed in the kernel. Please open a bug report at https://bugzilla.kernel.org/ and give us a link to it.
Comment 13 Michael South 2020-06-18 03:58:35 UTC
I'm having trouble creating a simplified test case. Will try to get a strace of the process which is creating the troublesome config.h file so that I can reproduce the same steps. Also, it's possible there's some kind of race condition in what Portage is doing. So it might be a while before I submit any kernel bugs.
Comment 14 Zac Medico gentoo-dev 2020-06-18 04:23:40 UTC
You might be able to reproduce it with a shell script that runs in a loop creating a temporary directory, unpacking the tarball, and copying the files to another temporary directory with a command like cp -a --reflink=always --sparse=always.

It's really helpful if the script uses a trap to clean up after itself so that you never have to clean up after it manually. For example see the script that I attached in bug 641262 comment 36.
Comment 15 Michael South 2020-06-18 05:07:49 UTC
It's having trouble with config.h, which is created by the build process, and not the files which are from the tarball. Also, I'm using ext4, which I don't think supports reflinks. Nice suggestion, though.
Comment 16 and 2021-10-21 21:52:43 UTC
Over time I hit this issue again and again.
Tracking misfeature down to ext4 when inline_data feature is in place.

-- Testcase (using zram for free space playground):

# zramctl -a lzo /dev/zram3 -s 1G
# zramctl /dev/zram3
NAME       ALGORITHM DISKSIZE DATA COMPR TOTAL STREAMS MOUNTPOINT
/dev/zram3 lzo             1G   0B    0B    0B      16

# mkfs.ext4 -O inline_data,^metadata_csum,^has_journal,^resize_inode,^dir_nlink,^huge_file -m 0 /dev/zram3
# mkdir /tmpzram
# mount /dev/zram3 /tmpzram
# mount | grep /tmpzra
/dev/zram3 on /tmpzram type ext4 (rw,relatime)

# chmod 1777 /tmpzram
# while true; do PORTAGE_TMPDIR=/tmpzram emerge --oneshot --ask=n gawk; done
...
ERROR:root:Failed to copy file: _parsed_options=Namespace(group=-1, owner=-1, mode=420, preserve_timestamps=False), source=b'config.h', dest_dir=b'/tmpzram/portage/sys-apps/gawk-5.1.0/image/usr/include/awk'
Traceback (most recent call last):
...

-- Workaround without disabling native-extensions and/or inline_data feature is mounting ext4 with nodelalloc

# umount /tmpzram
# mount -o nodelalloc /dev/zram3 /tmpzram
# mount | grep /tmpzra
/dev/zram3 on /tmpzram type ext4 (rw,relatime,nodelalloc)

# while true; do PORTAGE_TMPDIR=/tmpzram emerge --oneshot --ask=n gawk; done
no more strange doins.py failures
Comment 17 and 2021-10-21 21:54:48 UTC
used kernel version is 5.14.14
Comment 18 Sam James archtester Gentoo Infrastructure gentoo-dev Security 2023-01-17 02:40:03 UTC
These native-extension bugs tend to get reused by people hitting completely new issues. Please report this bug to the kernel folks if it's still happening.