Show some on-screen activity at boot during the rocket stage

[haikupr]

Contrary to BeOS which was lightning fast to boot, Haiku can spend during the rocket stage a fair amount of time mounting package filesystems. Sometimes I'm even under the (false) impression that the boot process has halted. At that moment I wish there was some sort of on-screen indicator showing activity or, even better, progression. For this purpose I suggest that the rocket should be animated.

For an activity indication, the rocket could be shown spinning around its vertical axis, the animation would step by one frame for every mounted package---or two or three of them. For a progression indicator, the rocket could be shown through its voyage from the ground launch pad (before the first package gets mounted) to orbit (when the last package is mounted), traveling an ever thinner atmosphere, crossing the path of clouds, meteorites, lightning, sprites, aurora borealis, the space station and artificial satellites.

The first option is light as it require the storage of very few frames (4 or 5 should be enough). The second is heavy because it require the work of an artist and will need a significantly larger amount of storage for 80+ frames.

[waddlesplash]

The major premise of this ticket is false, as packagefs is mounted at the "disks" icon, long before the "rocket" icon. The "rocket" icon is reserved for actually launching userspace (app_server, etc.) and is normally very fast. I don't know that I've ever seen it linger for more than a second or two.

How long does it exactly spend for you? Generally anything more than 5 seconds on the rocket is indicative of some major problem.

A syslog might indicate what's happening at this stage. I would recommend trying booting with "fail-safe graphics" enabled, and (separately) with "Disable ACPI" enabled, from the bootloader options, to see if either makes any difference with how long the rocket lingers.

[madmax]

Replying to waddlesplash:

Generally anything more than 5 seconds on the rocket is indicative of some major problem.

Unless you have slow storage, I guess. While my desktop with an SSD takes about 3 seconds there and a VM booting from a drive in the host's RAM even less, my older laptop with an HD is 12 seconds in the rocket and about the same in the disks icon.

[bipolar]

Adding to madmax data... On the same Phenom II X4 (bare-metal) I get:

• Slightly outdated beta4 on SSD: 3 seconds on the Rocket icon before Desktop.
• Up-to-date beta4 on HDD: 22 seconds on the Rocket icon before Desktop.

(I remember the later not being so slow on fresh install, I should try to see where the big slow down comes from).

[pulkomandy]

On my very fast laptop (11 gen core i7 with nvme), it also takes what looks like a long time to me recently. Maybe in the 2 to 5 seconds range, but compared to what I'm used to in Haiku, this is an eternity already.

But rather than adding on-screen animations, we should fix the problem and make it boot faster, of course. Why does it take so long?

[KitsunePrefecture]

Against that animation .. can we rahter get short text about achieved progress like as in case it was in LiLo ?

As I've seen - in a Youtube video - a Debian Linux still does something similar - enlist a status message about boot progress and launched stuff with OK or not OK. It would be more detailed than icons which are enlighting or not.

Of course with a toggle on / off for them who does not need such text messages or annoying.

I know that syslog can be switched to be printed while booting, but that requires knowledge to interpret, I think something more simple and straight statements that despite it can give a glue about the failure - if any - where it happened and if possible : what ?

At least who reports something in a ticket or on the forum ask for help - can give a better hint what arised at them as an error / problem during boot.

Of course the investigation and resolution of reason of slowness also welcomed, but maybe some details about progress.

[pulkomandy]

I made a test on my machine.

Haiku currently boots in 11 seconds (from selecting it in refind to showing the desktop) which I think isn't that bad.

I enabled syslog timestamps in kernel settings and had to increase the syslog buffer size. I only have about 5 seconds of logs, I guess not everything in the boot process is logging to syslog and maybe we should add logs when we light up icons and also when launch_daemon starts differernt things?

Anyway, on my machine this breaks out to, roughly:

• 1 second for early init of kernel, identifying CPUs, start loading drivers
• 3 seconds of logs from the intel_extreme driver, which is scanning all video outputs sequentially over I2C (a somewhat slow protocol and also most of this is timing out since there are 6 or 7 ports, but only one connected to a display
• 1 second of logs from HDA audio and PS2 drivers

This is all in the "PCI card" stage of the boot screen (hardware init) as far as I can tell. Indeed I think this is where my machine spends the most time now.

[pulkomandy]

syslog with bootsplash tracing and launch daemon debug enabled

[pulkomandy]

I have attached a syslog with timestamps enabled, as well as trace messages from both the bootsplash and the launch daemon.

I can see that we get to stage 6 (rocket) very quickly, apparently in less than 1 second. But after that, it takes several seconds for everything else to complete.

The main reason for this appears to be the new driver model: since the drivers are loaded lazily, it doesn't happen early for most drivers, and so, few initializations are done early on. For example, the soundcard is only initialized when media_server is started, likewise for the graphics card and app_server.

One option would be to redistribute the icons a bit better over the boot process duration, however, it seems some work would be needed, because the rocket icon marks the startup of userspace, at that point, some part of the boot argument memory is freed, and that includes the boot icons (there is a TODO about it in the bootsplash code).

And, one way to make the boot faster is indeed to optimize the drivers initialization.

[nephele]

waddlesplash: does this need to be in beta5 still?

[waddlesplash]

Probably not, I suppose. There's a few things we could optimize here, but it's not important.

[waddlesplash]

I can see that we get to stage 6 (rocket) very quickly, apparently in less than 1 second.

I think that's wrong, the timestamps look like they come from when syslog_daemon started up.

[waddlesplash]

Has the time spent on the rocket improved for anyone after recent optimizations (especially the one to have application startup not need to go through the device_manager lock for stack protector initialization?)

[waddlesplash]

When upgrading the package builders just now, the 32-bit one failed to come back initially. It was apparently stuck on the rocket icon; a Ctrl+Alt+Del apparently got it unstuck. The x86_64 came back OK, but a few more reboots demonstrated that it occasionally stuck for a few seconds longer than usual on the rocket icon.

It sounds like 32-bit now takes 8-10 seconds on the rocket and 64-bit around 5 seconds even when they don't get "stuck" temporarily or permanently. That sounds like we have some regression since beta4 in particular here.

[diver]

64 bit here in vmware. It takes about 15 seconds on the rocket.

[KitsunePrefecture]

Rocket icon lasts about 51 secs - 64 bit Haiku Nightly - hrev57943 -, otherwise Beta4 is similar.

Now finally I have both 64 bit Haiku (Beta and Nightly) are installed on such a 256 GB Samsung USB 3.0 thumbdrive where I do not experience performance issue - except at boot time.

As I socialied in computing that times whena "Drink a cup of coffee ..." like messages used to be appeared I am patience regarding to this - I let the machine do the boot alone ... meanwhile I do anything else.

I experienced this Rocket part of boot process lasts longer ... ... after I installed more and more applications and their dependency. The fresh install, as I remember, it took some secs, now I have an installer that pimped to store my favourite settings, so I do not know this.

As for HW reference - in a nutshell :

~> uname -a
Haiku HiQ_R1Nitely_256GO.szabadpart.n 1 hrev57943 Aug  9 2024 06:02:38 x86_64 x86_64 Haiku
~> neofetch
          :dc'                      user@HiQ_R1Nitely_256GO.szabadpart.net 
       'l:;','ck.    .;dc:.         -------------------------------------- 
       co    ..k.  .;;   ':o.       OS: Haiku x86_64 
       co    ..k. ol      .0.       Kernel: hrev57943 Aug 9 2024 06:02:38 
       co    ..k. oc     ..0.       Uptime: 15 mins 
       co    ..k. oc     ..0.       Packages: 1034 (pkgman) 
.Ol,.  co ...''Oc;kkodxOdddOoc,.    Shell: bash 5.2.26 
 ';lxxlxOdxkxk0kdooolldlccc:clxd;   Resolution: 1920x1080 
     ..oOolllllccccccc:::::od;      Theme: Adwaita [GTK3] 
       cx:ooc:::::::;cooolcX.       Icons: haiku [GTK3] 
       cd.''cloxdoollc' ...0.       CPU: Intel i7-3940XM (8) @ 3.189GHz 
       cd......k;.xl....  .0.       Memory: 1630MiB / 32669MiB 
       .::c;..cx;.xo..... .0.
          '::c'...do..... .K,                               
                  cd,.....:O,                               
                    ':clod:'
                        

~> 

Syslogs would be provided as well.

[waddlesplash]

How many packages are installed on beta4, and how long does the rocket icon last there? If you have the same number of packages, is it faster on beta4 vs. nightly?

[KitsunePrefecture]

syslogs of 64 bit Nightly - hrev57943 - I have not got a switched on special debugging/tracing/counting on it

[KitsunePrefecture]

Sorry, I have got some token issue in Falkon,as Trac reported to me, I had to close the tab and reopen a Trac session to finish addition of my attachment of syslogs of Nitely.

Then i saw your questions

As I wrote it lasts similar long. Let me check by shutting down Nightly and switch the thumbdrive.

R1Nitely --> Packages: 1034 (pkgman) from neofetch

[KitsunePrefecture]

(Ok, so I could not acces Trac in Webpositive in Beta4 as I switched back.

I keep on getting

Blocked by scanlock or Locked by scanblock

message I got on Falkon on R1Nitely as as well.

Anyway I gave up on it and used Falkon to login here on Beta4 as well now. Later I retry to login in Webpositive.).

So, I rebooted with R1Beta4 thumbdrive ...

~> uname -a
Haiku HiQ_R1B4_256GO.szabadpart.net 1 hrev56578+97 Jul 31 2024 06:22: x86_64 x86_64 Haiku

Rocket icon lasted 58 secs - 64 bit Haiku R1Beta4

R1B4 --> Packages: 1058 (pkgman)

Summarized :

----------------------------------------------------------
                        R1 Beta4         R1 Nightly
----------------------------------------------------------
Rocket icon lasts      58  secs          51  secs
----------------------------------------------------------
Number of packages
by neofetch             1058               1034     
----------------------------------------------------------

[KitsunePrefecture]

syslogs of 64 bit Beta4 - hrev56578+97 - I haven't got a switched on special debugging/tracing/counting on it

[pulkomandy]

Please stop spamming trac tickets. This is not the place to comment about web browser problems and post neofetch screenshots. Here, even more than in the forums, it is extremely important to keep the discussion extremely focused and the messages as short as possible.

[haikupr]

I get back to this ticket since booting is still quite slow.

What messages should I look for in /var/log/syslog as barriers for the the rocket stage?

On hrev58436, I see some timing gaps but I don't know to which stage they relate to:

2024-12-20 06:43:17 KERN: register_domain(1, internet)
2024-12-20 06:43:18 KERN: unregister_domain(0xffffffff89cc8c80, 1, internet)
2024-12-20 06:43:18 KERN: publish device: node 0xffffffff8a853a08, path net/virtio/0, module drivers/network/virtio_net/device_v1
2024-12-20 06:43:19 KERN: loaded driver /boot/system/add-ons/kernel/drivers/dev/net/usb_rndis
...
2024-12-20 06:43:19 KERN: register_domain(5, internet6)
2024-12-20 06:43:19 AUTH 'sshd'[111]: error: setsockopt IPV6_V6ONLY: Operation not supported
2024-12-20 06:43:19 AUTH 'sshd'[111]: Server listening on :: port 22.
2024-12-20 06:43:19 AUTH 'sshd'[111]: Server listening on 0.0.0.0 port 22.
2024-12-20 06:43:21 KERN: radeon_hd: init_hardware
...
2024-12-20 06:43:21 KERN: framebuffer: framebuffer_init() completed successfully!
2024-12-20 06:43:21 KERN: framebuffer: acc: framebuffer.accelerant
2024-12-20 06:43:23 KERN: package_daemon: [12222059:    61] The latest volume state is also the currently active one
...
2024-12-20 06:43:23 KERN: package_daemon: [12315565:    61] Volume::InitialVerify(): volume at "/boot/home/config" is consistent
2024-12-20 06:43:54 KERN: slab memory manager: created area 0xffffffff86801000 (9408)
2024-12-20 06:44:13 KERN: loaded driver /boot/system/add-ons/kernel/drivers/dev/input/wacom
...
2024-12-20 06:44:14 KERN: auich: init_hardware()
2024-12-20 06:44:16 KERN: virtio_net: ioctl: unknown message 22e1
2024-12-20 06:44:17 KERN: ps2: probe_mouse Standard PS/2 mouse found

Could stage transition messages be explicitly logged?

[waddlesplash]

All of those happen after the rocket is lit. However, none of them should block on the rocket. The real problem here is probably just #18979, which doesn't print any log messages at all.