Bug 1803070 - Tests failed in copr for the latest srpm from rawhide
Summary: Tests failed in copr for the latest srpm from rawhide
Keywords:
Status: CLOSED ERRATA
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: 33
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks: 1880842
TreeView+ depends on / blocked
 
Reported: 2020-02-14 12:27 UTC by Lukas Slebodnik
Modified: 2020-10-05 18:34 UTC (History)
9 users (show)

Fixed In Version: systemd-245.8-2.fc32 systemd-243.9-1.fc31
Doc Type: If docs needed, set a value
Doc Text:
Clone Of:
: 1880842 (view as bug list)
Environment:
Last Closed: 2020-09-23 17:12:41 UTC
Type: Bug
Embargoed:


Attachments (Terms of Use)

Description Lukas Slebodnik 2020-02-14 12:27:09 UTC
Description of problem:
I tried to debug something (probably unrelated) and I wanted to do some changes in systemd scriptlets. But i was not able to rebuilds srpm in copr

Version-Release number of selected component (if applicable):
systemd-245~rc1-2.fc33.src.rpm

How reproducible:
Deterministic

Steps to Reproduce:
1. dnf install -y fedpkg
2. fedpkg clone --anonymous systemd
3. cd systemd/
4. git log -1
5. # create project in copr copr.fedorainfracloud.org
6. # rebuild systemd-245~rc1-2.fc33.src.rpm created in the current directory

Actual results:
sh-5.0$ fedpkg clone --anonymous systemd
Cloning into 'systemd'...
remote: Counting objects: 9867, done.
remote: Compressing objects: 100% (7026/7026), done.
remote: Total 9867 (delta 4766), reused 7225 (delta 2824)
Receiving objects: 100% (9867/9867), 7.04 MiB | 823.00 KiB/s, done.
Resolving deltas: 100% (4766/4766), done.
sh-5.0$ cd systemd/
sh-5.0$ git log -1
commit 3666983037e56865f622c2bc1aa30399b75bd725 (HEAD -> master, origin/master, origin/f32, origin/HEAD)
Author: Zbigniew Jędrzejewski-Szmek <zbyszek.pl>
Date:   Tue Feb 11 14:16:34 2020 +0100

    Run tests with a timeout multiplier
    
    Tests fail to pass on s390x, and this seems to be just a timeout.
sh-5.0$ fedpkg srpm
Downloading systemd-245-rc1.tar.gz
######################################################################## 100.0%


setting SOURCE_DATE_EPOCH=1581033600
Wrote: /tmp/data/systemd/systemd-245~rc1-2.fc33.src.rpm

### check build log

sh-5.0$  curl https://download.copr.fedorainfracloud.org/results/lslebodn/test_rawhide/fedora-rawhide-x86_64/01239669-systemd/build.log.gz | zgrep FAIL
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  109k  100  109k    0     0  1079k      0 --:--:-- --:--:-- --:--:-- 1090k
Installing man/SD_BUS_ERROR_AUTH_FAILED.3 to /builddir/build/BUILDROOT/systemd-245~rc1-2.fc32.x86_64/usr/share/man/man3
Installing man/SD_BUS_ERROR_FAILED.3 to /builddir/build/BUILDROOT/systemd-245~rc1-2.fc32.x86_64/usr/share/man/man3
285/490 test-mountpoint-util                    FAIL     0.47 s (killed by signal 6 SIGABRT)

Expected results:

No failure or SIGABRT in build.log


Additional info:
sample build
https://copr.fedorainfracloud.org/coprs/lslebodn/test_rawhide/build/1239669/
https://download.copr.fedorainfracloud.org/results/lslebodn/test_rawhide/fedora-rawhide-x86_64/01239669-systemd/build.log.gz

You can from copr https://download.copr.fedorainfracloud.org/results/lslebodn/test_rawhide/fedora-rawhide-x86_64/01239669-systemd/systemd-245~rc1-2.fc32.src.rpm

Comment 1 Lukas Slebodnik 2020-02-14 12:29:35 UTC
Actually it is simpler to rebuild srpm from koji.
https://kojipkgs.fedoraproject.org//packages/systemd/245~rc1/2.fc32/src/systemd-245~rc1-2.fc32.src.rpm

e.g. https://copr.fedorainfracloud.org/coprs/lslebodn/test_rawhide/build/1239672/

But it does not contain commit 3666983037e56865f622c2bc1aa30399b75bd725

Comment 2 Zbigniew Jędrzejewski-Szmek 2020-02-28 12:49:19 UTC
Yeah, it fails this way on one of my machines too. I think it's a kernel bug that
has long been fixed (I haven't seen it since F30, but it reproduced reliably with
linux-5.2.11-100.fc29.x86_64.

Unfortunately that build log gives 404 now. Do you know what kernel version was/is
running in copr?

Comment 3 Zbigniew Jędrzejewski-Szmek 2020-02-28 13:54:13 UTC
https://github.com/systemd/systemd/pull/14970

Comment 4 Zbigniew Jędrzejewski-Szmek 2020-02-28 13:54:39 UTC
Sorry, wrong bug.

Comment 5 Lukas Slebodnik 2020-02-28 16:30:37 UTC
(In reply to Zbigniew Jędrzejewski-Szmek from comment #2)
> Yeah, it fails this way on one of my machines too. I think it's a kernel bug
> that
> has long been fixed (I haven't seen it since F30, but it reproduced reliably
> with
> linux-5.2.11-100.fc29.x86_64.
> 
> Unfortunately that build log gives 404 now. Do you know what kernel version
> was/is
> running in copr?

Here is a fresh rebuild
https://download.copr.fedorainfracloud.org/results/lslebodn/test_rawhide/fedora-rawhide-x86_64/01259489-systemd/

I briefly checked and I was not able to find anything about version of kernel in logs.
copr devs might know more details.

Comment 6 Lukas Slebodnik 2020-02-28 16:32:48 UTC
(In reply to Zbigniew Jędrzejewski-Szmek from comment #2)
> Yeah, it fails this way on one of my machines too. I think it's a kernel bug
> that
> has long been fixed (I haven't seen it since F30, but it reproduced reliably
> with
> linux-5.2.11-100.fc29.x86_64.
> 

BTW, feel free to close it if it is a kernel bug. I hit this issue as part of debugging BZ1803240

Comment 7 Pavel Raiskup 2020-03-06 08:52:09 UTC
There's kernel 5.0.16, we did not have to update the cloud images
for builders for some time already.

Comment 8 Zbigniew Jędrzejewski-Szmek 2020-03-11 09:16:41 UTC
The issue appears to occur when name_to_handle_at is not available. It is possible that our fallback code
is buggy. Let's leave this open for now.

Comment 9 Pavel Raiskup 2020-04-16 07:41:34 UTC
I was able to reproduce this on F32 with the latest kernel few days back.

Comment 10 Pavel Raiskup 2020-04-16 07:54:40 UTC
$ fedpkg srpm  # fedora master branch
Downloading systemd-245.4.tar.gz
######################################################################## 100.0%
setting SOURCE_DATE_EPOCH=1585699200
Wrote: /tmp/systemd/systemd-245.4-1.fc33.src.rpm
$ mock -r fedora-rawhide-x86_64 /tmp/systemd/systemd-245.4-1.fc33.src.rpm
...
283/490 test-libmount                           OK      0.016834259033203125 s 
284/490 test-mount-util                         OK      0.014326333999633789 s 
285/490 test-mountpoint-util                    FAIL    0.637660026550293 s (killed by signal 6 SIGABRT)
286/490 test-exec-util                          OK      1.1383476257324219 s 
287/490 test-hexdecoct                          OK      0.014191627502441406 s 
...

$ cat ~/.config/mock.cfg
config_opts['plugin_conf']['tmpfs_enable'] = True
config_opts['plugin_conf']['tmpfs_opts']['keep_mounted'] = True
config_opts['nosync'] = True

$ cat /proc/cmdline 
BOOT_IMAGE=(hd0,msdos1)/vmlinuz-5.6.3-300.fc32.x86_64  ...

Comment 11 James Cassell 2020-05-05 13:20:02 UTC
Apparently I'm already CC'ed, but wanted to report that this happens also with the RHEL 8.2 systemd, as well as the latest rawhide (fc33) systemd.

Rawhide output:
https://copr.fedorainfracloud.org/coprs/cyberpear/systemd/build/1367589/

285/491 test-mountpoint-util                    FAIL    0.4175901412963867 s (killed by signal 6 SIGABRT)


Output for EPEL 8, RHEL 8.2 systemd:
https://copr.fedorainfracloud.org/coprs/cyberpear/systemd/build/1367207/

133/314 test-mount-util                         FAIL     0.42 s (killed by signal 6 SIGABRT)

--- command ---
SYSTEMD_KBD_MODEL_MAP='/builddir/build/BUILD/systemd-239/src/locale/kbd-model-map' PATH='/builddir/build/BUILD/systemd-239/x86_64-redhat-linux-gnu:/builddir/.local/bin:/builddir/bin:/usr/bin:/bin:/usr/sbin:/sbin:/usr/local/sbin' SYSTEMD_LANGUAGE_FALLBACK_MAP='/builddir/build/BUILD/systemd-239/src/locale/language-fallback-map' /builddir/build/BUILD/systemd-239/x86_64-redhat-linux-gnu/test-mount-util
--- stderr ---
mnt id of /proc/keys is 423
mnt id of /dev/loop9 is 518
mnt id of /proc/sys/kernel/random/boot_id is 433
mnt id of /proc/acpi is 426
mnt id of /proc is 524
mnt id of /dev/loop10 is 509
mnt id of /proc/kcore is 422
mnt id of /run/systemd/nspawn/incoming is 520
mnt id of /proc/timer_list is 425
mnt id of /proc/fs is 428
mnt id of /run is 519
mnt id of /dev is 503
mnt id of /sys/fs/cgroup is 432
mnt id of /dev/pts is 505
mnt id of /dev/loop6 is 515
mnt id of /dev/loop2 is 511
mnt id of /var/cache/yum is 498
mnt id of /dev/loop5 is 514
mnt id of /sys is 501
mnt id of /proc/sys is 420
mnt id of /dev/loop1 is 508
mnt id of /etc/resolv.conf is 521
mnt id of /dev/loop-control is 506
mnt id of /dev/loop7 is 516
mnt id of /var/cache/dnf is 499
mnt id of /proc/sysrq-trigger is 424
mnt id of /dev/loop8 is 517
mnt id of /proc/filesystems is 524
Assertion 'path_equal_ptr(hashmap_get(h, INT_TO_PTR(mnt_id2)), p)' failed at ../src/test/test-mount-util.c:77, function test_mnt_id(). Aborting.
-------

Comment 12 Ben Cotton 2020-08-11 13:08:14 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 33 development cycle.
Changing version to 33.

Comment 13 Zbigniew Jędrzejewski-Szmek 2020-09-13 11:59:09 UTC
I managed to find a reliable reproducer on one of the fedora test machines. AFAICT, it's a kernel bug.

(gdb) !uname -r
5.6.19-200.fc31.ppc64le

(gdb) !cat /proc/self/mountinfo
697 664 253:0 /var/lib/mock/fedora-31-ppc64le/root / rw,relatime shared:298 master:1 - xfs /dev/mapper/fedora_rh--power--vm14-root rw,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota
698 697 253:0 /var/cache/mock/fedora-31-ppc64le/yum_cache /var/cache/yum rw,relatime shared:299 master:1 - xfs /dev/mapper/fedora_rh--power--vm14-root rw,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota
699 697 253:0 /var/cache/mock/fedora-31-ppc64le/dnf_cache /var/cache/dnf rw,relatime shared:300 master:1 - xfs /dev/mapper/fedora_rh--power--vm14-root rw,seclabel,attr2,inode64,logbufs=8,logbsize=32k,noquota
700 697 0:32 /mock-selinux-plugin.7me9bfpi /proc/filesystems rw,nosuid,nodev shared:301 master:18 - tmpfs tmpfs rw,seclabel <==========================================================
701 697 0:41 / /sys ro,nosuid,nodev,noexec,relatime shared:302 - sysfs sysfs ro,seclabel
702 701 0:21 / /sys/fs/selinux ro,nosuid,nodev,noexec,relatime shared:306 master:8 - selinuxfs selinuxfs rw
703 697 0:42 / /dev rw,nosuid shared:303 - tmpfs tmpfs rw,seclabel,mode=755
704 703 0:43 / /dev/shm rw,nosuid,nodev shared:304 - tmpfs tmpfs rw,seclabel
705 703 0:45 / /dev/pts rw,nosuid,noexec,relatime shared:307 - devpts devpts rw,seclabel,gid=5,mode=620,ptmxmode=666
706 703 0:6 /btrfs-control /dev/btrfs-control rw,nosuid shared:308 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
707 703 0:6 /loop-control /dev/loop-control rw,nosuid shared:309 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
708 703 0:6 /loop0 /dev/loop0 rw,nosuid shared:310 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
709 703 0:6 /loop1 /dev/loop1 rw,nosuid shared:311 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
710 703 0:6 /loop10 /dev/loop10 rw,nosuid shared:312 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
711 703 0:6 /loop11 /dev/loop11 rw,nosuid shared:313 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
712 703 0:6 /loop2 /dev/loop2 rw,nosuid shared:314 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
713 703 0:6 /loop3 /dev/loop3 rw,nosuid shared:315 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
714 703 0:6 /loop4 /dev/loop4 rw,nosuid shared:316 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
715 703 0:6 /loop5 /dev/loop5 rw,nosuid shared:317 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
716 703 0:6 /loop6 /dev/loop6 rw,nosuid shared:318 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
717 703 0:6 /loop7 /dev/loop7 rw,nosuid shared:319 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
718 703 0:6 /loop8 /dev/loop8 rw,nosuid shared:320 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
719 703 0:6 /loop9 /dev/loop9 rw,nosuid shared:321 master:9 - devtmpfs devtmpfs rw,seclabel,size=4107840k,nr_inodes=64185,mode=755
720 697 0:44 / /run rw,nosuid,nodev shared:305 - tmpfs tmpfs rw,seclabel,mode=755
721 720 0:25 /systemd/nspawn/propagate/9cc8a155d0244558b273f773d2b92142 /run/systemd/nspawn/incoming ro master:12 - tmpfs tmpfs rw,seclabel,mode=755
722 697 0:32 /mock-resolv.dvml91hp /etc/resolv.conf rw,nosuid,nodev shared:322 master:18 - tmpfs tmpfs rw,seclabel
725 697 0:47 / /proc rw,nosuid,nodev,noexec,relatime shared:323 - proc proc rw
603 725 0:47 /sys /proc/sys ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw
604 725 0:44 /systemd/inaccessible/reg /proc/kallsyms ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755
605 725 0:44 /systemd/inaccessible/reg /proc/kcore ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755
606 725 0:44 /systemd/inaccessible/reg /proc/keys ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755
607 725 0:44 /systemd/inaccessible/reg /proc/sysrq-trigger ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755
608 725 0:44 /systemd/inaccessible/reg /proc/timer_list ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755
609 725 0:47 /bus /proc/bus ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw
610 725 0:47 /fs /proc/fs ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw
611 725 0:47 /irq /proc/irq ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw
612 725 0:47 /scsi /proc/scsi ro,nosuid,nodev,noexec,relatime shared:323 - proc proc rw
613 703 0:46 / /dev/mqueue rw,nosuid,nodev,noexec,relatime shared:324 - mqueue mqueue rw,seclabel
614 701 0:26 / /sys/fs/cgroup rw,nosuid,nodev,noexec,relatime shared:325 - cgroup2 cgroup rw,seclabel,nsdelegate
615 603 0:44 /.#proc-sys-kernel-random-boot-id4fbdce67af46d1c2//deleted /proc/sys/kernel/random/boot_id ro,nosuid,nodev,noexec shared:305 - tmpfs tmpfs rw,seclabel,mode=755
616 725 0:44 /.#proc-sys-kernel-random-boot-id4fbdce67af46d1c2//deleted /proc/sys/kernel/random/boot_id rw,nosuid,nodev shared:305 - tmpfs tmpfs rw,seclabel,mode=755
617 725 0:44 /.#proc-kmsg5b7a8bcfe6717139//deleted /proc/kmsg rw,nosuid,nodev shared:305 - tmpfs tmpfs rw,seclabel,mode=755

The test process does
name_to_handle_at("/proc/filesystems") which returns -EOPNOTSUPP, and then
openat(AT_FDCWD, "/proc/filesystems") which returns 4, and then
read(4, ...) which gives
"pos:\t0\nflags:\t012100000\nmnt_id:\t725\n"

which is clearly inconsistent with "700" in /proc/self/mountinfo.

We could either drop the fallback path (and fail name_to_handle_at() is not avaiable) or ignore the error in the test.
Not sure what is better.

Comment 14 Zbigniew Jędrzejewski-Szmek 2020-09-14 16:07:28 UTC
https://github.com/systemd/systemd/pull/17050

Comment 15 Fedora Update System 2020-09-20 13:20:23 UTC
FEDORA-2020-0d29e88946 has been submitted as an update to Fedora 32. https://bodhi.fedoraproject.org/updates/FEDORA-2020-0d29e88946

Comment 16 Fedora Update System 2020-09-20 13:22:33 UTC
FEDORA-2020-dc4f0fb907 has been submitted as an update to Fedora 31. https://bodhi.fedoraproject.org/updates/FEDORA-2020-dc4f0fb907

Comment 17 Fedora Update System 2020-09-20 23:55:19 UTC
FEDORA-2020-0d29e88946 has been pushed to the Fedora 32 testing repository.
In short time you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2020-0d29e88946`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2020-0d29e88946

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 18 Fedora Update System 2020-09-21 00:39:14 UTC
FEDORA-2020-dc4f0fb907 has been pushed to the Fedora 31 testing repository.
In short time you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2020-dc4f0fb907`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2020-dc4f0fb907

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 19 Fedora Update System 2020-09-21 08:01:19 UTC
FEDORA-2020-0d29e88946 has been submitted as an update to Fedora 32. https://bodhi.fedoraproject.org/updates/FEDORA-2020-0d29e88946

Comment 20 Fedora Update System 2020-09-21 14:28:24 UTC
FEDORA-2020-0d29e88946 has been pushed to the Fedora 32 testing repository.
In short time you'll be able to install the update with the following command:
`sudo dnf upgrade --enablerepo=updates-testing --advisory=FEDORA-2020-0d29e88946`
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2020-0d29e88946

See also https://fedoraproject.org/wiki/QA:Updates_Testing for more information on how to test updates.

Comment 21 Fedora Update System 2020-09-23 17:12:41 UTC
FEDORA-2020-0d29e88946 has been pushed to the Fedora 32 stable repository.
If problem still persists, please make note of it in this bug report.

Comment 22 Fedora Update System 2020-10-05 18:34:46 UTC
FEDORA-2020-dc4f0fb907 has been pushed to the Fedora 31 stable repository.
If problem still persists, please make note of it in this bug report.


Note You need to log in before you can comment on or make changes to this bug.