Bug 1731772

Summary: Can't get systemd-binfmt to work: 1) binfmt_misc module isn't loaded automatically 2) binfmt_misc fs isn't automatically mounted to /proc/sys/fs/binfmt_misc
Product: [Fedora] Fedora Reporter: Artem S. Tashkinov <aros>
Component: systemdAssignee: systemd-maint
Status: CLOSED ERRATA QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 31CC: lnykryn, msekleta, ssahani, s, systemd-maint, zbyszek
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: systemd-241-12.git323cdf4.fc30 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-09-18 10:00:09 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Artem S. Tashkinov 2019-07-21 23:09:57 UTC
Description of problem:

Here's my /etc/binfmt.d/wine.conf:

# Pre-PE Windows Executables
:windows:M::MZ::/usr/bin/wine:

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

Version-Release number of selected component (if applicable): systemd-241-8.git9ef65cb.fc30.x86_64


How reproducible: always


Steps to Reproduce:
1. systemctl start systemd-binfmt
2.
3.

Actual results:

● systemd-binfmt.service - Set Up Additional Binary Formats
   Loaded: loaded (/usr/lib/systemd/system/systemd-binfmt.service; static; vendor preset: disabled)
   Active: failed (Result: exit-code) since ; 7min ago
     Docs: man:systemd-binfmt.service(8)
           man:binfmt.d(5)
           https://www.kernel.org/doc/html/latest/admin-guide/binfmt-misc.html
           https://www.freedesktop.org/wiki/Software/systemd/APIFileSystems
  Process: 14255 ExecStart=/usr/lib/systemd/systemd-binfmt (code=exited, status=1/FAILURE)
 Main PID: 14255 (code=exited, status=1/FAILURE)

systemd[1]: Starting Set Up Additional Binary Formats...
systemd-binfmt[14255]: Failed to add binary format: No such file or directory
systemd-binfmt[14255]: Failed to add binary format: No such file or directory
systemd[1]: systemd-binfmt.service: Main process exited, code=exited, status=1/FAILURE
systemd[1]: systemd-binfmt.service: Failed with result 'exit-code'.
systemd[1]: Failed to start Set Up Additional Binary Formats.


Additional info:

# ls -la /usr/bin/wine
lrwxrwxrwx. 1 root root 18 Jun 15 18:38 /usr/bin/wine -> /opt/wine/bin/wine


I use a custom kernel compiled from sources.

binfmt_misc is compiled as a module.

Comment 1 Artem S. Tashkinov 2019-07-21 23:11:58 UTC
# lsmod | grep binfmt
binfmt_misc            20480  0

# strace /usr/lib/systemd/systemd-binfmt 
execve("/usr/lib/systemd/systemd-binfmt", ["/usr/lib/systemd/systemd-binfmt"], 0x7ffceb6697c0 /* 25 vars */) = 0
brk(NULL)                               = 0x5573cbc01000
arch_prctl(0x3001 /* ARCH_??? */, 0x7ffd09d38c30) = -1 EINVAL (Invalid argument)
access("/etc/ld.so.preload", R_OK)      = -1 ENOENT (No such file or directory)
... skipped ...
getrandom("\x45\x7d\x70\x70\x10\x1b\x1e\x0e\x3a\xb8\x45\x6b\x49\x22\xa9\x39", 16, GRND_NONBLOCK) = 16
openat(AT_FDCWD, "/etc/binfmt.d", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3
fstat(3, {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
getdents64(3, /* 3 entries */, 32768)   = 80
getdents64(3, /* 0 entries */, 32768)   = 0
close(3)                                = 0
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
getdents64(3, /* 2 entries */, 32768)   = 48
getdents64(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, "/etc/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
read(3, "", 4096)                       = 0
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
close(3)                                = 0
exit_group(1)                           = ?
+++ exited with 1 +++

Comment 2 Artem S. Tashkinov 2019-07-21 23:14:43 UTC
Looks like systemd doesn't mount the necessary FS:

# grep binfmt /proc/mounts
<empty>

# mount binfmt_misc -t binfmt_misc /proc/sys/fs/binfmt_misc
# grep binfmt /proc/mounts
binfmt_misc /proc/sys/fs/binfmt_misc binfmt_misc rw,relatime 0 0

Now I wonder why all of this has to be done manually.

# systemctl start systemd-binfmt
# systemctl status systemd-binfmt
● systemd-binfmt.service - Set Up Additional Binary Formats
   Loaded: loaded (/usr/lib/systemd/system/systemd-binfmt.service; static; vendor preset: disabled)
   Active: active (exited) since ; 14s ago
     Docs: man:systemd-binfmt.service(8)
           man:binfmt.d(5)
           https://www.kernel.org/doc/html/latest/admin-guide/binfmt-misc.html
           https://www.freedesktop.org/wiki/Software/systemd/APIFileSystems
  Process: 15855 ExecStart=/usr/lib/systemd/systemd-binfmt (code=exited, status=0/SUCCESS)
 Main PID: 15855 (code=exited, status=0/SUCCESS)

Comment 3 Artem S. Tashkinov 2019-07-21 23:21:10 UTC
I don't have the autofs module enabled in the kernel:

# journalctl -b | grep -i auto
localhost systemd[1]: Failed to find module 'autofs4'
localhost systemd[1]: Starting of Arbitrary Executable File Formats File System Automount Point not supported.

Comment 4 Ben Cotton 2019-08-13 16:50:27 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 31 development cycle.
Changing version to '31'.

Comment 5 Ben Cotton 2019-08-13 18:58:45 UTC
This bug appears to have been reported against 'rawhide' during the Fedora 31 development cycle.
Changing version to 31.

Comment 6 Artem S. Tashkinov 2019-09-17 09:10:51 UTC
So many comments, so much attention, WTF??

This is how I "solved" this bug seeing that no one gives a f:

1) sudo systemctl mask proc-sys-fs-binfmt_misc.automount
2) sudo cp -a /usr/lib/systemd/system/systemd-binfmt.service /etc/systemd/system
3)

--- /usr/lib/systemd/system/systemd-binfmt.service	2019-09-03 12:59:59.000000000 +0000
+++ /etc/systemd/system/systemd-binfmt.service	2019-09-17 08:56:18.357965085 +0000
@@ -14,7 +14,6 @@
 Documentation=https://www.freedesktop.org/wiki/Software/systemd/APIFileSystems
 DefaultDependencies=no
 Conflicts=shutdown.target
-After=proc-sys-fs-binfmt_misc.automount
 Before=sysinit.target shutdown.target
 ConditionPathIsReadWrite=/proc/sys/
 ConditionDirectoryNotEmpty=|/lib/binfmt.d
@@ -28,3 +27,7 @@
 RemainAfterExit=yes
 ExecStart=/usr/lib/systemd/systemd-binfmt
 TimeoutSec=90s
+
+ExecStartPre=/usr/sbin/modprobe binfmt_misc
+ExecStartPre=-/usr/bin/mount -t binfmt_misc binfmt_misc /proc/sys/fs/binfmt_misc

Comment 7 Zbigniew Jędrzejewski-Szmek 2019-09-18 10:00:09 UTC
Normally, the way that this works is that:
1. proc-sys-fs-binfmt_misc.automount is pulled in by sysinit.target (it is statically enabled)
2. systemd-binfmt.service only runs if it has something to do, potentially triggering the next point
3. when /proc/sys/fs/binfmt_misc/ is accessed, proc-sys-fs-binfmt_misc.mount is started
4. proc-sys-fs-binfmt_misc.mount mounts the filesystem which also causes binfmt_misc to be loaded

Since you disabled autofs, step 1 doesn't happen, so steps 3-4 don't happen and nothing loads
the module. You can make things work by adding proc-sys-fs-binfmt_misc.mount as a dependency:
# /etc/systemd/system/systemd-binfmt.service.d/dep.conf
[Unit]
Requires=proc-sys-fs-binfmt_misc.mount
After=proc-sys-fs-binfmt_misc.mount

If you customize a kernel like that, you have to take the necessary steps to adjust certain
units. Sorry, but when you do this in Fedora, you're on your own.

I'll file a patch to add After=proc-sys-fs-binfmt_misc.mount to systemd-binfmt.service upstream.
This will not fix your issue, but it'll make it slightly nicer to handle, because then it will
be enough to enable proc-sys-fs-binfmt_misc.mount in any way, and systemd-binfmt.service will
be ordered appropriately after it.

Comment 8 Fedora Update System 2019-10-10 20:49:11 UTC
FEDORA-2019-66b24a298e has been submitted as an update to Fedora 30. https://bodhi.fedoraproject.org/updates/FEDORA-2019-66b24a298e

Comment 9 Fedora Update System 2019-10-12 02:02:14 UTC
systemd-241-12.git323cdf4.fc30 has been pushed to the Fedora 30 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-2019-66b24a298e

Comment 10 Fedora Update System 2019-10-14 16:40:56 UTC
systemd-241-12.git323cdf4.fc30 has been pushed to the Fedora 30 stable repository. If problems still persist, please make note of it in this bug report.