Bug 1565425

Created attachment 1419631 [details]
journalctl

Error extract:
anaconda[1886]: packaging: Configuring (running scriptlet for): systemd-238-7.fc28.x86_64 1522220916 cf77ea519bf5cb426ee112ad6820e6149bc1ce5eeb821742f6b9ed21e6d1b253
anaconda[1886]: packaging: Configuring (running scriptlet for): systemd-238-7.fc28.x86_64 1522220916 cf77ea519bf5cb426ee112ad6820e6149bc1ce5eeb821742f6b9ed21e6d1b253
anaconda[1886]: packaging: Configuring (running scriptlet for): systemd-238-7.fc28.x86_64 1522220916 cf77ea519bf5cb426ee112ad6820e6149bc1ce5eeb821742f6b9ed21e6d1b253
systemd-binfmt[9335]: Failed to add binary format: No such file or directory
systemd-binfmt[9335]: Failed to add binary format: No such file or directory
anaconda[3146]: dnf: Non-fatal <unknown> scriptlet failure in rpm package systemd

*** Bug 1566773 has been marked as a duplicate of this bug. ***

Created attachment 1425201 [details]
small kickstart file to localize the problem

I could reduce the problem to a small kickstart file. See attached example kickstart file.

If %package section contains only @core, kickstart installation will finish as expected.
If package wine is added to this section, then kickstart installation stops with the error described in this bug report.

wine forces the installation of a lot of other packages as dependencies, so the problem may be in one of these packages, not in wine itself.

Created attachment 1425202 [details]
List of packages that was installed on"dnf install wine" after kickstart installtion

After successful kickstart installation using the kickstart file of the previous attachment, I installed wine by "dnf install wine". This had installed other packages as dependencies, you find the list of packages in this attachment.

One of these packages may be the reason for the error described in this bug report.

Installing wine this way after kickstart installation (without wine) doesn't show an error.

I could further isolate the problem to package wine-systemd.
Only @core works, but @core and wine-systemd crashes.

wine-systemd is a dependency of wine-desktop, which is required by wine.

wine-systemd contains only the file /usr/lib/binfmt.d/wine.conf .

I also tried Fedora 28 Branched 20180421.n.1 nightly compose.
The results are the same.

Maybe this bug should be a blocker bug, because it crashes all Fedora installation which include wine-systemd directly or as a dependency (for example, all packages and package groups that require or contain wine).

At least it should be in common bugs, with the workaround, that the kickstart file must not contain wine, wine-desktop, wine-systemd, and any other package or package group that include these packages directly or indirectly.

Can confirm that removing wine from %packages & adding "dnf install -y wine" on %post makes the install succeed.

i get, however, some warnings on update (after installing wine, and also on %post) "warning: %triggerin(systemd-238-7.fc28.1.x86_64) scriptlet failed, exit status 1" and "Non-fatal <unknown> scriptlet failure in rpm package systemd"

reinstalling systemd after the system is installed & rebooted shows no warning

The problem still exists in Fedora 28 release.

At least wine-systemd such have a dep on /usr/bin/wine, now it possible to
add wine-systemd and 

$ cat /usr/lib/binfmt.d/wine.conf
# Pre-PE Windows Executables
:windows:M::MZ::/usr/bin/wine:

# PE Windows Executables
:windowsPE:M::PE::/usr/bin/wine:

without having /usr/bin/wine available, this seems wrong.

Maybe this error is enough to cause:

systemd-binfmt[9335]: Failed to add binary format: No such file or directory
systemd-binfmt[9335]: Failed to add binary format: No such file or directory

from comment #1

Doing some debugging (by ssh into VM after install has stopped due to systemd scriptlet failure):

$ strace /usr/lib/systemd/systemd-binfmt 

gives:

openat(AT_FDCWD, "/run/binfmt.d", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/local/lib/binfmt.d", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/binfmt.d", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
fstat(3, {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
getdents(3, /* 3 entries */, 32768)     = 80
getdents(3, /* 0 entries */, 32768)     = 0
close(3)                                = 0
openat(AT_FDCWD, "/proc/sys/fs/binfmt_misc/status", O_WRONLY|O_NOCTTY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/usr/lib/binfmt.d/wine.conf", O_RDONLY|O_CLOEXEC) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=119, ...}) = 0
read(3, "# Pre-PE Windows Executables\n:wi"..., 4096) = 119
openat(AT_FDCWD, "/proc/sys/fs/binfmt_misc/windows", O_WRONLY|O_NOCTTY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/fs/binfmt_misc/register", O_WRONLY|O_NOCTTY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
writev(2, [{iov_base="Failed to add binary format: No "..., iov_len=54}, {iov_base="\n", iov_len=1}], 2Failed to add binary format: No such file or directory
) = 55
openat(AT_FDCWD, "/proc/sys/fs/binfmt_misc/windowsPE", O_WRONLY|O_NOCTTY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
openat(AT_FDCWD, "/proc/sys/fs/binfmt_misc/register", O_WRONLY|O_NOCTTY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
writev(2, [{iov_base="Failed to add binary format: No "..., iov_len=54}, {iov_base="\n", iov_len=1}], 2Failed to add binary format: No such file or directory
) = 55
read(3, "", 4096)                       = 0
close(3)                                = 0
exit_group(1)                           = ?
+++ exited with 1 +++


There are in fact no files in that directory:

$ find /proc/sys/fs/binfmt_misc/
/proc/sys/fs/binfmt_misc/

Infrastructure to run systemd-binfmt  with success is simply not available during install?

The /usr/lib/systemd/systemd-binfmt run is trigged by file trigger in systemd:


$ rpm -q --filetriggers systemd |tail -5
# This script will automatically apply binfmt rules if files have been
# installed or updated in /usr/lib/binfmt.d.
if test -d /run/systemd/system; then
  /usr/lib/systemd/systemd-binfmt
fi


which gives:

$ /usr/lib/systemd/systemd-binfmt  ; echo $?
Failed to add binary format: No such file or directory
Failed to add binary format: No such file or directory
1

Maybe adding 

 /usr/lib/systemd/systemd-binfmt || :

is enough to make install work, however root might be that kernel module binfmt_misc is not loaded at this point?

Created attachment 1436730 [details]
Patch to safeguard call to systemd-binfmt in triggers

With attached patch installing via kickstart and wine-systemd included in %packages complete install is a successful.

Please apply to master and f28 branch and create update, thanks.

PR created: 
  https://src.fedoraproject.org/rpms/systemd/pull-request/5

Ping?

systemd-238-9.git0e0aa59.fc28 has been submitted as an update to Fedora 28. https://bodhi.fedoraproject.org/updates/FEDORA-2018-3d06321edf

systemd-238-9.git0e0aa59.fc28 has been pushed to the Fedora 28 testing repository. If problems still persist, please make note of it in this bug report.
See https://fedoraproject.org/wiki/QA:Updates_Testing for
instructions on how to install test updates.
You can provide feedback for this update here: https://bodhi.fedoraproject.org/updates/FEDORA-2018-3d06321edf

systemd-238-9.git0e0aa59.fc28 has been pushed to the Fedora 28 stable repository. If problems still persist, please make note of it in this bug report.