20sec more boot time with current master branch

Volumio Version: 3.631
Hardware: Raspberry Pi 5

Debug Log

Mar 12 22:07:18 volumio-p volumio[710]: info: CoreCommandRouter::volumioGetState
Mar 12 22:07:18 volumio-p volumio[710]: info: CorePlayQueue::getTrack 0
Mar 12 22:07:18 volumio-p ntpd[850]: Listen normally on 3 eth0 192.168.2.136:123
Mar 12 22:07:18 volumio-p ntpd[850]: new interface(s) found: waking up resolver
Mar 12 22:07:39 volumio-p systemd[1]: systemd-fsckd.service: Succeeded.
Mar 12 22:07:40 volumio-p systemd[1]: systemd-hostnamed.service: Succeeded.
Mar 12 22:07:42 volumio-p volumio[710]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion
Mar 12 22:07:42 volumio-p volumio[710]: info: Preparing to generate the ALSA configuration file

Steps to Reproduce

Please look to the time stamp.
The boot procedure needs 20 seconds more then for previous versions
I find out the system plugin in system_controller needs this time for

self.getUSBBootCapable()

This procedure check entries in file

/volumio/app/plugins/system_controller/system/usbbootcapable.json

per default this file contains only one sample entry. But this entry is checked for bootable.

This needs 20 sec of boot time.

The workaround for a fast solution is: rename usbbootcapable.json, if you wonā€™t boot from USB. Then the section to greb the file is skipped.

I think itā€™s need to change the function or remark the sample entry per default.

Best regards
2aCD

1 Like

The 21 seconds is spent on the NTP time resolver queries before before moving to checking filesystem. At this point, the USB BOOT eligibility is not being examined yet.

To help you further, without any changes to any code - can you create your device debug log and post URL in this thread please?

The ntp entry is only random here. Also the filesystem check. The next entry created from system plugin is important. Please try to rename the json file and compare the boot time.

Technically speaking function:

is dormant until you open System from main menu. This is where the eligibility is triggered for ā€œInstal to Diskā€ checks. This is part of the upcoming change and tested in this thread: [ALPHA] Raspberry Pi boot from USB/NVMe

As a note - tested 3.631 on three Raspberry Pi 5 in a row and all finishing boot in 57sec flat from MicroSD with or without alleged culprit. Something else is going on.
Question - do you observe interface drop in debug logs?

In ā€šonVolumioStartā€˜ this function is the second return value and therefore active.
And this return command needs 20 sec.

Hi 2aCD,

Does this apply only with USB boot or also with NVMe as well?

Andy

Function runs simple comparator and returns boolean true/false onVolumioStart. And this is what you observe in volumio livelog.

I do encourage you to post complete debug log URL for further examination.

Hi Andy, I noticed it with nvme.
But I think it is not depend of this specific boot method

maybe as a hint. This is particularly noticeable when the touch-screen plugin is installed.
Chromium is 20sec earlier ready.

3.631 is from official release channels. Now, we are reaching to NVMe which is from Alpha release channel.
@2aCD - Which exact Volumio OS version are you testing on?

It is the latest branch compiled from GitHub

Is it from master or some other branch?

From master ca 14 days ago

From internal quick check you seem to be caught up behind official release. It is hard to determine your build inline with the continuously changing landscape. There are four options here:

  1. Wait for master branch to reach release level - limited support for custom build.
  2. Use mpd-0.23.15-3 branch - testing - limited support for custom build.
  3. Install official 3.631 release and enable test OTA and update - recommended and supported.
  4. Use NVMe ALPHA testing release - should you decide to use this branch, be aware that this is temporary only until all tests are concluded.

Regarding proposed self.getUSBBootCapable() consumed in the ALPHA build, we will take it under revision and run further impact and regression tests. The last thing we need is to introduce to the ecosystem unknown factors.

Ok, I assumed that the master branch always corresponds to the last published version and does not contain any intermediate versions. Then see this thread as a hint to take a closer look at this function.

Iā€™m renaming the thread because the official release is obviously not affected.

As a rule of thumb, master branch is the release channel. However, the devil lives in the detail - time when you executed built from master was where there were new release changes committed. Right now it reflects 3.631 however test OTA is around a corner to be merged. Hence suggestion to wait for the release.

UPDATE: Our regression test confirmed that there is a promise delay of 20862ms from a new storage eligibility discovery function.
Facts:

  1. file usbbootcapable.json is not a problem here.
  2. your report lead me to squash the bug and PR will be raised shortly.

Thank you for reporting.

@2aCD

FYI - master is fully aligned with the upcoming release. Can you kindly run a build and confirm whether a delay is still observed?

Oh that sounds very interesting. Yes, Iā€˜ll compile again from master branch in the evening today and give you a response :+1: