Need help with slow boot on NESPi4 build

raymonte

I hate to make a long post like this but I'd like to include as much information as possible to aid in troubleshooting my problem. The issue is the boot time, it takes about 1 minute 15 seconds to go from power on (with the NESP1 4 case button) to useable on the Retropie emulator selection menu. I'll point out that my custom splashcreen video is 38 seconds long, but my startup time is the same with or without it. Even using the static Retropie screen the boot time is about 1:15.

I've made lots of customizations including the theme, splash screen video, bezel project and other custom overlays, scraped media, and runncommand splash screens. There are A LOT of ROMs on here. I have "Parse Gameslist Only" set to "Off" and "Save Metadata" set to "On Exit".

I've edited boot/cmdline.txt to eliminate some of the startup texts and images too. Here's the file:

console=serial0,115200 console=tty3 root=PARTUUID=c719d1a1-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait loglevel=3 consoleblank=0 plymouth.enable=0 splash quiet plymouth.ignore-serial-consoles logo.nologo vt.global_cursor_default=0 disable_splash=1

I ran systemd to find out where the hangup is and, oddly, it says it took only 23.867s. Here are the outputs for analyze, blame, and critical chain.

pi@retropie:~ $ sudo systemd-analyze
Startup finished in 1.969s (kernel) + 21.897s (userspace) = 23.867s
multi-user.target reached after 21.849s in userspace

pi@retropie:~ $ sudo systemd-analyze blame
16.027s dhcpcd.service
6.969s hciuart.service
5.380s usbmount@dev-sda1.service
1.809s dev-mmcblk0p2.device
1.636s apt-daily.service
903ms apt-daily-upgrade.service
728ms networking.service
696ms rpi-eeprom-update.service
564ms systemd-udev-trigger.service
501ms keyboard-setup.service
416ms nmbd.service
412ms avahi-daemon.service
406ms usbmount@dev-sda.service
391ms dphys-swapfile.service
367ms rng-tools.service
366ms systemd-fsck-root.service
359ms smbd.service
348ms systemd-logind.service
331ms systemd-journald.service
311ms raspi-config.service
290ms rsyslog.service
241ms boot.mount
227ms systemd-remount-fs.service

pi@retropie:~ $ sudo systemd-analyze critical-chain
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

multi-user.target @21.849s
└─smbd.service @21.488s +359ms
└─nmbd.service @21.069s +416ms
└─network-online.target @21.054s
└─network.target @21.049s
└─dhcpcd.service @5.020s +16.027s
└─basic.target @4.973s
└─sockets.target @4.972s
└─dbus.socket @4.972s
└─sysinit.target @4.967s
└─systemd-timesyncd.service @4.752s +213ms
└─systemd-tmpfiles-setup.service @4.616s +124ms
└─local-fs.target @4.586s
└─home-pi-RetroPie.mount @10.390s
└─dev-sda1.device @4.141s

Here's some info on my build:
Raspberry Pi 4 Model B - 4GB DDR4
Retropie Buster 4.7.1
OS on Micro Center 128GB microSDXC Card Class 10 UHS-I C10 U1
ROMs on Samsung 860 EVO 2TB SSD connected via USB 3.0 on NESPi NES cart
Retroflag NESPi4 case with included power supply and cooling fan
Retropie theme scv720
Overclocked:
over_voltage=4
arm_freq=2100
gpu_freq=750

Thanks for reading, any help will be much appreciated.

quicksilver

@raymonte did you try disabling wait for wifi on startup? I believe the setting is in raspi-config menu.

raymonte

@quicksilver No, but I’ll give it a try later this evening and let you know. Thanks for the reply.

raymonte

@quicksilver I don’t see anything specific to WiFi but I set “Select wait for network connection on boot” to “No” and the boot time clocked in at 1:09. That’s me timing it with the clock app on my phone so accounting for human error that really didn’t change anything. Thanks for the suggestion though.

raymonte

@raymonte This is partly solved. I set “Parse Gameslists Only” to “On” and now my boot time is much improved. With a static image splash screen it boots in under 30 seconds and with my long video it’s around a minute. There is still a long pause with a black screen before the splash screen but maybe that can’t be helped.

There are two, new, minor issues though.

Sometimes it doesn’t play my custom splash screen startup video.
Sometimes I get this text about 20 seconds or so into the startup process:

I’ve been holding off on this post while experimenting with it and I don’t seem to be seeing those new issues anymore. The only thing that would make it perfect is if the splash screen startup video would start sooner but if this is how it has to be then it’s much better anyway.

mitu

@raymonte said in Need help with slow boot on NESPi4 build:

Sometimes it doesn’t play my custom splash screen startup video.

If the splashscreen is on your external drive, it might not be available (i.e. the disk is not mounted) when the splashscreen service starts. You can work around by modifying the asplashscreen service and make it depend on dev-sda1.device , but if you have a static splashscreen it's better to keep the file on the sdcard (somewhere in /home/pi) and configure the splashscreen to use it.

See if solving this will solve 2.

raymonte

@mitu said in Need help with slow boot on NESPi4 build:

dev-sda1.device

Thanks for your help on this.

It's interesting because now that you mention it, the splashscreen video played every time I rebooted and now that I think of it I don't think it played on a fresh startup. So it makes sense that it's because the external disk is not yet mounted and it was already mounted when I was rebooting.

I had asplashscreen.sh open in Notepad++ but I couldn't figure out how to edit it to depend on dev-sda1.device so I moved my video to /opt/retropie/supplementary/splashscreen . That's the directory where the stock Retropie splashscreens are stored and it resides on my sd card so it should solve the disk mounting issue. Only difference is, when choosing my video from the Retropie splashscreen menu I have to look in "RetroPie splashscreens" not "Own/Extra splashscreens".

I don't seem to be seeing the text message at startup now either.

Only thing now is it takes 20 seconds before the splashscreen video starts, but it's been doing that all along. Is there a way to make it launch earlier so it runs during all the startup scripts? That was why I made it so long in the first place.

mitu

@raymonte said in Need help with slow boot on NESPi4 build:

I had asplashscreen.sh open in Notepad++ but I couldn't figure out how to edit it to depend on dev-sda1.device...

That's not how it's done, asplashscreen.sh is the script run by the service, the service itself is configured with a systemd unit file. You can edit the unit file with

sudo systemctl edit asplashscreen.service

which opens up and editor. You can then add

After=local-fs.target

and save the file, instructing systemd to start the splashscreen service after all filesystems have been mounted.

But the other method is easier and I'd recommend to use it.

Only thing now is it takes 20 seconds before the splashscreen video starts, but it's been doing that all along

Use systemd-analyze critical-chain asplashscreen.service to see which services are needed and starting before the splashscreen. The only hard dependency is on console-setup, but it will wait for dbus to start because omxplayer needs it.
Looking at the critical-chain output you posted, I think the mounting of the disk is the biggest contender.

raymonte

@mitu Here's the output:

pi@retropie:~ $ systemd-analyze critical-chain asplashscreen.service
The time after the unit is active or started is printed after the "@" character.
The time the unit takes to start is printed after the "+" character.

asplashscreen.service +16ms
└─console-setup.service @4.397s +35ms
  └─local-fs.target @4.377s
    └─run-user-1000.mount @10.536s
      └─local-fs-pre.target @1.884s
        └─systemd-tmpfiles-setup-dev.service @1.805s +70ms
          └─systemd-sysusers.service @1.705s +84ms
            └─systemd-remount-fs.service @1.498s +200ms
              └─systemd-fsck-root.service @1.116s +374ms
                └─fake-hwclock.service @974ms +127ms
                  └─systemd-journald.socket @938ms
                    └─-.mount @919ms
                      └─systemd-journald.socket @938ms
                        └─...

Sorry, I don't know how to post like the cool kids :(

raymonte

@raymonte lol, thanks @mitu

mitu

Looking at the dependency chain startup, mounting of the media is taking the most, delaying the console-setup start.
You can try to disable the auto-mounting of the external disc and manually add the mount command in /opt/retropie/configs/all/autostart.sh, before ES starts. This way the splashscreen service will start sooner.