Hello, I'm currently investigating a long boot delay on our embedded Linux system (systemd 255.4-1ubuntu8.4, custom embedded board) as a sporadic issue. We noticed that `systemd-binfmt.service` takes almost 90 seconds to start.
Here’s the serial port log: [2025-04-24 01:53:29.060676] [ [0;32m OK [0m] Set up automount [0;1;39mproc-sys-fs-binfm… [0mormats File System Automount Point. [2025-04-24 01:53:29.668827] Starting [0;1;39msystemd-binfmt.service [0m - Set Up Additional Binary Formats... // Here is the issue，delay almost 90s [2025-04-24 01:54:59.508873] Mounting [0;1;39mproc-sys-fs-binfmt_misc.m… [0mcutable File Formats File System... [2025-04-24 01:54:59.524553] [ [0;32m OK [0m] Mounted [0;1;39mproc-sys-fs-binfmt_misc.mo… [0mxecutable File Formats File System. [2025-04-24 01:54:59.525037] [ [0;32m OK [0m] Finished [0;1;39msystemd-binfmt.service [0m - Set Up Additional Binary Formats. more logs for reference. [2025-04-24 01:53:28.980704] oem-config setup has already been successfully completed [2025-04-24 01:53:28.996653] [ [0;32m OK [0m] Created slice [0;1;39msystem-getty.slice [0m - Slice /system/getty. [2025-04-24 01:53:28.996996] [ [0;32m OK [0m] Created slice [0;1;39msystem-modprobe.slice [0m - Slice /system/modprobe. [2025-04-24 01:53:29.013292] [ [0;32m OK [0m] Created slice [0;1;39msystem-serial\x2dget…slice [0m - Slice /system/serial-getty. [2025-04-24 01:53:29.029010] [ [0;32m OK [0m] Created slice [0;1;39muser.slice [0m - User and Session Slice. [2025-04-24 01:53:29.029335] [ [0;32m OK [0m] Started [0;1;39msystemd-ask-password-conso… [0mequests to Console Directory Watch. [2025-04-24 01:53:29.045009] [ [0;32m OK [0m] Started [0;1;39msystemd-ask-password-wall.… [0md Requests to Wall Directory Watch. [2025-04-24 01:53:29.060676] [ [0;32m OK [0m] Set up automount [0;1;39mproc-sys-fs-binfm… [0mormats File System Automount Point. [2025-04-24 01:53:29.061114] Expecting device [0;1;39mdev-tegra_hv_pm_ctl.device [0m - /dev/tegra_hv_pm_ctl... [2025-04-24 01:53:29.076787] Expecting device [0;1;39mdev-ttyUTC0.device [0m - /dev/ttyUTC0... [2025-04-24 01:53:29.077151] [ [0;32m OK [0m] Reached target [0;1;39mcryptsetup.target [0m - Local Encrypted Volumes. [2025-04-24 01:53:29.092718] [ [0;32m OK [0m] Reached target [0;1;39mintegritysetup.targ… [0m Local Integrity Protected Volumes. [2025-04-24 01:53:29.108861] [ [0;32m OK [0m] Reached target [0;1;39mpaths.target [0m - Path Units. [2025-04-24 01:53:29.109174] [ [0;32m OK [0m] Reached target [0;1;39mslices.target [0m - Slice Units. [2025-04-24 01:53:29.124789] [ [0;32m OK [0m] Reached target [0;1;39mswap.target [0m - Swaps. [2025-04-24 01:53:29.125073] [ [0;32m OK [0m] Reached target [0;1;39mtime-set.target [0m - System Time Set. [2025-04-24 01:53:29.140611] [ [0;32m OK [0m] Reached target [0;1;39mveritysetup.target [0m - Local Verity Protected Volumes. [2025-04-24 01:53:29.140972] [ [0;32m OK [0m] Listening on [0;1;39mrpcbind.socket [0m - RPCbind Server Activation Socket. [2025-04-24 01:53:29.156787] [ [0;32m OK [0m] Listening on [0;1;39msyslog.socket [0m - Syslog Socket. [2025-04-24 01:53:29.157101] [ [0;32m OK [0m] Listening on [0;1;39msystemd-initctl.socke… [0m- initctl Compatibility Named Pipe. [2025-04-24 01:53:29.172789] [ [0;32m OK [0m] Listening on [0;1;39msystemd-journald-dev-…socket [0m - Journal Socket (/dev/log). [2025-04-24 01:53:29.173191] [ [0;32m OK [0m] Listening on [0;1;39msystemd-journald.socket [0m - Journal Socket. [2025-04-24 01:53:29.188785] [ [0;32m OK [0m] Listening on [0;1;39msystemd-networkd.socket [0m - Network Service Netlink Socket. [2025-04-24 01:53:29.189284] [ [0;32m OK [0m] Listening on [0;1;39msystemd-udevd-control.socket [0m - udev Control Socket. [2025-04-24 01:53:29.204783] [ [0;32m OK [0m] Listening on [0;1;39msystemd-udevd-kernel.socket [0m - udev Kernel Socket. [2025-04-24 01:53:29.205172] Starting [0;1;39mkmod-static-nodes.service [0m…eate List of Static Device Nodes... [2025-04-24 01:53:29.220823] Starting [0;1;39mmodprobe@configfs.service [0m - Load Kernel Module configfs... [2025-04-24 01:53:29.221197] Starting [0;1;39mmodprobe@dm_mod.service [0m - Load Kernel Module dm_mod... [2025-04-24 01:53:29.236923] Starting [0;1;39mmodprobe@drm.service [0m - Load Kernel Module drm... [2025-04-24 01:53:29.237252] Starting [0;1;39mmodprobe@efi_pstore.servi… [0m - Load Kernel Module efi_pstore... [2025-04-24 01:53:29.252938] Starting [0;1;39mmodprobe@fuse.service [0m - Load Kernel Module fuse... [2025-04-24 01:53:29.253289] Starting [0;1;39mmodprobe@loop.service [0m - Load Kernel Module loop... [2025-04-24 01:53:29.268933] Starting [0;1;39msystemd-modules-load.service [0m - Load Kernel Modules... [2025-04-24 01:53:29.269312] Starting [0;1;39msystemd-remount-fs.servic… [0munt Root and Kernel File Systems... [2025-04-24 01:53:29.284929] Starting [0;1;39msystemd-udev-trigger.service [0m - Coldplug All udev Devices... [2025-04-24 01:53:29.285280] [ [0;32m OK [0m] Finished [0;1;39mkmod-static-nodes.service [0m…Create List of Static Device Nodes. [2025-04-24 01:53:29.300869] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@configfs.service [0m - Load Kernel Module configfs. [2025-04-24 01:53:29.301244] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@dm_mod.service [0m - Load Kernel Module dm_mod. [2025-04-24 01:53:29.316933] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@efi_pstore.service [0m - Load Kernel Module efi_pstore. [2025-04-24 01:53:29.332694] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@fuse.service [0m - Load Kernel Module fuse. [2025-04-24 01:53:29.332998] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@drm.service [0m - Load Kernel Module drm. [2025-04-24 01:53:29.348741] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@loop.service [0m - Load Kernel Module loop. [2025-04-24 01:53:29.349115] [ [0;32m OK [0m] Finished [0;1;39msystemd-remount-fs.servic… [0mmount Root and Kernel File Systems. [2025-04-24 01:53:29.364728] Starting [0;1;39msystemd-random-seed.service [0m - Load/Save OS Random Seed... [2025-04-24 01:53:29.365135] Starting [0;1;39msystemd-tmpfiles-setup-de… [0m Device Nodes in /dev gracefully... [2025-04-24 01:53:29.380772] Mounting [0;1;39mdev-hugepages.mount [0m - Huge Pages File System... [2025-04-24 01:53:29.381102] Mounting [0;1;39mdev-mqueue.mount [0m - POSIX Message Queue File System... [2025-04-24 01:53:29.396625] Mounting [0;1;39msys-fs-fuse-connections.mount [0m - FUSE Control File System... [2025-04-24 01:53:29.396982] Mounting [0;1;39msys-kernel-config.mount [0m - Kernel Configuration File System... [2025-04-24 01:53:29.412690] Mounting [0;1;39msys-kernel-debug.mount [0m - Kernel Debug File System... [2025-04-24 01:53:29.413019] Mounting [0;1;39msys-kernel-tracing.mount [0m - Kernel Trace File System... [2025-04-24 01:53:29.428650] [ [0;32m OK [0m] Finished [0;1;39msystemd-random-seed.service [0m - Load/Save OS Random Seed. [2025-04-24 01:53:29.429055] [ [0;32m OK [0m] Mounted [0;1;39mdev-hugepages.mount [0m - Huge Pages File System. [2025-04-24 01:53:29.444625] [ [0;32m OK [0m] Mounted [0;1;39mdev-mqueue.mount [0m - POSIX Message Queue File System. [2025-04-24 01:53:29.445005] [ [0;32m OK [0m] Finished [0;1;39msystemd-udev-trigger.service [0m - Coldplug All udev Devices. [2025-04-24 01:53:29.460976] [ [0;32m OK [0m] Finished [0;1;39msystemd-tmpfiles-setup-de… [0mic Device Nodes in /dev gracefully. [2025-04-24 01:53:29.476754] [ [0;32m OK [0m] Mounted [0;1;39msys-fs-fuse-connections.mount [0m - FUSE Control File System. [2025-04-24 01:53:29.477153] [ [0;32m OK [0m] Mounted [0;1;39msys-kernel-config.mount [0m - Kernel Configuration File System. [2025-04-24 01:53:29.492930] [ [0;32m OK [0m] Mounted [0;1;39msys-kernel-debug.mount [0m - Kernel Debug File System. [2025-04-24 01:53:29.493329] [ [0;32m OK [0m] Mounted [0;1;39msys-kernel-tracing.mount [0m - Kernel Trace File System. [2025-04-24 01:53:29.509264] Starting [0;1;39msystemd-tmpfiles-setup-de… [0meate Static Device Nodes in /dev... [2025-04-24 01:53:29.524940] Starting [0;1;39mmodprobe@dm_mod.service [0m - Load Kernel Module dm_mod... [2025-04-24 01:53:29.525286] Starting [0;1;39mmodprobe@efi_pstore.servi… [0m - Load Kernel Module efi_pstore... [2025-04-24 01:53:29.540888] Starting [0;1;39mmodprobe@loop.service [0m - Load Kernel Module loop... [2025-04-24 01:53:29.556908] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@dm_mod.service [0m - Load Kernel Module dm_mod. [2025-04-24 01:53:29.557293] [ [0;32m OK [0m] Reached target [0;1;39mtime-sync.target [0m - System Time Synchronized. [2025-04-24 01:53:29.572971] Starting [0;1;39msystemd-journald.service [0m - Journal Service... [2025-04-24 01:53:29.573274] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@efi_pstore.service [0m - Load Kernel Module efi_pstore. [2025-04-24 01:53:29.588991] [ [0;32m OK [0m] Finished [0;1;39mmodprobe@loop.service [0m - Load Kernel Module loop. [2025-04-24 01:53:29.589369] [ [0;32m OK [0m] Started [0;1;39msystemd-journald.service [0m - Journal Service. [2025-04-24 01:53:29.604937] [ [0;32m OK [0m] Finished [0;1;39msystemd-modules-load.service [0m - Load Kernel Modules. [2025-04-24 01:53:29.605309] Starting [0;1;39msystemd-journal-flush.ser… [0msh Journal to Persistent Storage... [2025-04-24 01:53:29.620963] Starting [0;1;39msystemd-sysctl.service [0m - Apply Kernel Variables... [2025-04-24 01:53:29.621290] [ [0;32m OK [0m] Finished [0;1;39msystemd-tmpfiles-setup-de… [0mCreate Static Device Nodes in /dev. [2025-04-24 01:53:29.636998] [ [0;32m OK [0m] Reached target [0;1;39mlocal-fs-pre.target [0m…Preparation for Local File Systems. [2025-04-24 01:53:29.652735] [ [0;32m OK [0m] Reached target [0;1;39mlocal-fs.target [0m - Local File Systems. [2025-04-24 01:53:29.653078] [ [0;32m OK [0m] Listening on [0;1;39msystemd-sysext.socket [0m…tension Image Management (Varlink). [2025-04-24 01:53:29.668827] Starting [0;1;39msystemd-binfmt.service [0m - Set Up Additional Binary Formats... [2025-04-24 01:53:29.669215] Starting [0;1;39msystemd-udevd.service [0m - R…ager for Device Events and Files... [2025-04-24 01:53:29.684895] [ [0;32m OK [0m] Finished [0;1;39msystemd-journal-flush.ser… [0mlush Journal to Persistent Storage. [2025-04-24 01:53:29.685319] Starting [0;1;39msystemd-tmpfiles-setup.se… [0me Volatile Files and Directories... [2025-04-24 01:53:29.700893] [ [0;32m OK [0m] Started [0;1;39msystemd-udevd.service [0m - Ru…anager for Device Events and Files. [2025-04-24 01:53:29.716677] [ [0;32m OK [0m] Finished [0;1;39msystemd-sysctl.service [0m - Apply Kernel Variables. [2025-04-24 01:53:29.908669] [ [0;32m OK [0m] Finished [0;1;39msystemd-tmpfiles-setup.se… [0mate Volatile Files and Directories. [2025-04-24 01:53:29.940602] Starting [0;1;39mrpcbind.service [0m - RPC bind portmap service... [2025-04-24 01:53:29.956710] Starting [0;1;39msystemd-resolved.service [0m - Network Name Resolution... [2025-04-24 01:53:29.957067] Starting [0;1;39msystemd-update-utmp.servi… [0mord System Boot/Shutdown in UTMP... [2025-04-24 01:53:29.972733] [ [0;32m OK [0m] Started [0;1;39mrpcbind.service [0m - RPC bind portmap service. [2025-04-24 01:53:29.973106] [ [0;32m OK [0m] Found device [0;1;39mdev-ttyUTC0.device [0m - /dev/ttyUTC0. [2025-04-24 01:53:29.988662] [ [0;32m OK [0m] Reached target [0;1;39mrpcbind.target [0m - RPC Port Mapper. [2025-04-24 01:53:29.988963] [ [0;32m OK [0m] Finished [0;1;39msystemd-update-utmp.servi… [0mecord System Boot/Shutdown in UTMP. [2025-04-24 01:53:30.052644] [ [0;32m OK [0m] Found device [0;1;39mdev-tegra_hv_pm_ctl.device [0m - /dev/tegra_hv_pm_ctl. // Here is the issue [2025-04-24 01:54:59.508873] Mounting [0;1;39mproc-sys-fs-binfmt_misc.m… [0mcutable File Formats File System... [2025-04-24 01:54:59.509871] Mounting [0;1;39mrun-rpc_pipefs.mount [0m - RPC Pipe File System... [2025-04-24 01:54:59.524553] [ [0;32m OK [0m] Mounted [0;1;39mproc-sys-fs-binfmt_misc.mo… [0mxecutable File Formats File System. [2025-04-24 01:54:59.525037] [ [0;32m OK [0m] Finished [0;1;39msystemd-binfmt.service [0m - Set Up Additional Binary Formats. [2025-04-24 01:54:59.540745] [ [0;32m OK [0m] Mounted [0;1;39mrun-rpc_pipefs.mount [0m - RPC Pipe File System. [2025-04-24 01:54:59.541148] [ [0;32m OK [0m] Reached target [0;1;39mrpc_pipefs.target [0m. [2025-04-24 01:54:59.556593] [ [0;32m OK [0m] Reached target [0;1;39mnfs-client.target [0m - NFS client services. [2025-04-24 01:54:59.557016] [ [0;32m OK [0m] Reached target [0;1;39mremote-fs-pre.targe… [0mreparation for Remote File Systems. [2025-04-24 01:54:59.572662] [ [0;32m OK [0m] Reached target [0;1;39mremote-fs.target [0m - Remote File Systems. [2025-04-24 01:54:59.684360] [ [0;32m OK [0m] Started [0;1;39msystemd-resolved.service [0m - Network Name Resolution. [2025-04-24 01:54:59.700487] [ [0;32m OK [0m] Reached target [0;1;39mnss-lookup.target [0m - Host and Network Name Lookups. [2025-04-24 01:54:59.700918] [ [0;32m OK [0m] Reached target [0;1;39msysinit.target [0m - System Initialization. [2025-04-24 01:54:59.716451] [ [0;32m OK [0m] Started [0;1;39mdpkg-db-backup.timer [0m - Daily dpkg database backup timer. [2025-04-24 01:54:59.716877] [ [0;32m OK [0m] Started [0;1;39me2scrub_all.timer [0m - Period…Metadata Check for All Filesystems. [2025-04-24 01:54:59.732503] [ [0;32m OK [0m] Started [0;1;39mfstrim.timer [0m - Discard unused filesystem blocks once a week. [2025-04-24 01:54:59.732921] [ [0;32m OK [0m] Started [0;1;39mlogrotate.timer [0m - Daily rotation of log files. [2025-04-24 01:54:59.748556] [ [0;32m OK [0m] Started [0;1;39mmotd-news.timer [0m - Message of the Day. [2025-04-24 01:54:59.748928] [ [0;32m OK [0m] Started [0;1;39msystemd-tmpfiles-clean.tim… [0my Cleanup of Temporary Directories. [2025-04-24 01:54:59.764676] [ [0;32m OK [0m] Started [0;1;39mxm_logrotate.timer [0m - Periodically execute logrotate tasks. [2025-04-24 01:54:59.765127] [ [0;32m OK [0m] Reached target [0;1;39mtimers.target [0m - [ 93.015236] bash[956]: net.ipv4.ping_group_range = 0 2147483647 [2025-04-24 01:54:59.796540] [ [0;32m OK [0m] Started [0;1;39mrng-tools-debian.service [0m - LSB: rng-tools (Debian variant). [2025-04-24 01:54:59.844697] [ 93.097184] bash[971]: vm.min_free_kbytes = 65535 Unit informaiton: 1. /usr/lib/systemd/system/proc-sys-fs-binfmt_misc.automount [Unit] Description=Arbitrary Executable File Formats File System Automount Point Documentation=https://docs.kernel.org/admin-guide/binfmt-misc.html Documentation= https://www.freedesktop.org/wiki/Software/systemd/APIFileSystems ConditionPathExists=/proc/sys/fs/binfmt_misc/ ConditionPathIsReadWrite=/proc/sys/ DefaultDependencies=no Before=sysinit.target Conflicts=shutdown.target Before=shutdown.target [Automount] Where=/proc/sys/fs/binfmt_misc 2. /usr/lib/systemd/system/proc-sys-fs-binfmt_misc.mount [Unit] Description=Arbitrary Executable File Formats File System Documentation=https://docs.kernel.org/admin-guide/binfmt-misc.html Documentation= https://www.freedesktop.org/wiki/Software/systemd/APIFileSystems DefaultDependencies=no [Mount] What=binfmt_misc Where=/proc/sys/fs/binfmt_misc Type=binfmt_misc Options=nosuid,nodev,noexec [Install] WantedBy=sysinit.target 3. /usr/lib/systemd/system/systemd-binfmt.service [Unit] Description=Set Up Additional Binary Formats Documentation=man:systemd-binfmt.service(8) man:binfmt.d(5) Documentation=https://docs.kernel.org/admin-guide/binfmt-misc.html Documentation= https://www.freedesktop.org/wiki/Software/systemd/APIFileSystems DefaultDependencies=no Conflicts=shutdown.target After=proc-sys-fs-binfmt_misc.automount After=proc-sys-fs-binfmt_misc.mount After=local-fs.target Before=sysinit.target shutdown.target ConditionPathIsMountPoint=/proc/sys/fs/binfmt_misc ConditionDirectoryNotEmpty=|/lib/binfmt.d ConditionDirectoryNotEmpty=|/usr/lib/binfmt.d ConditionDirectoryNotEmpty=|/usr/local/lib/binfmt.d ConditionDirectoryNotEmpty=|/etc/binfmt.d ConditionDirectoryNotEmpty=|/run/binfmt.d [Service] Type=oneshot RemainAfterExit=yes ExecStart=/usr/lib/systemd/systemd-binfmt ExecStop=/usr/lib/systemd/systemd-binfmt --unregister TimeoutSec=90s Any insight would be appreciated.Thanks~ Best regards, Alien Kong
