Am 08.01.25 um 22:19 schrieb Bird, Tim:
-----Original Message-----
From: Marko Hoyer <mhoyer.oss-devel@xxxxxxxxxx>
Am 08.01.25 um 19:33 schrieb Bird, Tim:
-----Original Message-----
From: Shankari <beingcap11@xxxxxxxxx>
Hi
I wanted to provide an update on my recent contributions to the boot-time reduction project. I have recently started contributing
and
am working with the beagleplay. I have been analyzing the boot time of the init process. Below is the output from the system log:
debian@BeaglePlay:~$ dmesg | grep "init process"
[ 1.480490] Run /init as init process
Moving forward, I plan to explore ways to modify the command line and further investigate the data used for SIG analysis. This will
help me gain a deeper understanding of the boot process and its performance characteristics.
Please let me know if you have any suggestions or areas where I could focus my efforts.
Hi Shankari,
It sounds like you are off to a good start. I have something that needs to be done, that I think
you can help with, and that matches where I believe you are in your status with being able
to evaluate the kernel.
In general, there's a lot of information on the elinux wiki which is stale, which needs to be
updated or archived, or maybe even just removed.
This section of the Boot Time page has a lot of material in this category:
https://elinux.org/Boot_Time#kernel_speedups
Can you validate the information on these 2 pages:
* https://elinux.org/Disable_Console
* https://elinux.org/Preset_LPJ
This would consist of reading through the material, and testing the
described techniques on your machine. This will involve booting the
machine 2 ways, with a particular kernel command line option and without
it, and then reporting back the final boot time for both. You can use
the timestamp for the "init process" string as your final boot time, for the
purposes of this exercise.
Helping me to update the elinux wiki material on boot time would be
an immense help, and is one of my main goals for the boot time SIG in 2025.
Don't hesitate to ask questions if you have any.
BTW - you can just report your findings to me and linux-embedded list, but
alternatively (and even better) would be if you could also update the wiki
pages themselves with your information based on recent kernels and hardware.
To do this, you will need an elinux wiki account, which you can make online on
elinux wiki.org by going to this page: https://elinux.org/Special:CreateAccount
Anyone else reading this who wants to also participate in this project to
update the elinux wiki boot time information, please contact me.
Thanks.
-- Tim
Hi Tim, all,
first time I'm posting here so hopefully everything is fine w/ my mail
format / attachment and so on ... If not, please give me some feedback
and guidance.
Marko,
Thanks for this great data!
In general, I don't see a lot of attachments on kernel mailing lists.
They don't bother me, and we aren't CC'ing LKML (that's a separate
issue we should discuss - developers outside of embedded might
want to see this data). I'll check later and see what lore does with this,
but if no one complains, I don't see a problem with it. If someone
does complain, I can provide file hosting either on the elinux wiki
or the boot-time wiki, and we can link attachments like you've
provided on this message from one of those places (to avoid
putting attachments on kernel mailing lists).
Ok sounds good. I don't have really a place to publish data, so would
be good if you can find a way ...
To the "disable console" topic: I have some numbers in place for an RPI
Zero W, find dmesg dumps and systemd-analyze plots attached.
Environment:
- RPi Zero W, kernel 5.15.24, systemd 247.3, customized debian
- onboard UART used
Cases:
- #1 quiet: cmdline w/ quiet, no kernel or userspace output up to the
serial login console
- #2 normal: cmdline w/o quiet, serial console @115200 baud
- #3 normal_baud9600: cmdline w/o quiet, serial console @9600 baud
Main outcomes:
- kernel timestamps "Run /sbin/init as init process"
#1: "1.714458", #2: "3.011701", #3: "16.108101"
Wow from 1.7 seconds to 16.1 seconds. That's a pretty huge
difference. I guess this particular technique is still
very relevant!
Interpretation:
* enabled serial console has significant impact in kernel boot time
* reducing baud to 9600 induced some side effect, not sure what it is ...
Did you see any other weird behavior besides the huge slowdown?
I'll take a look at the amount of characters in your dmesg output and
see if it can be linearly correlated to the baud rate, or if it seems something
else is going on.
Take a look into the kmesg logs. Looks like there is a 8s delay at a
certain point:
[ 5.897018] input: C-Media Electronics Inc. USB Audio Device as
/devices/platform/soc/20980000.usb/usb1/1-1/1-1:1.3/0003:0D8C:0014.0001/input/input1
[ 6.016086] hid-generic 0003:0D8C:0014.0001: input,hidraw0: USB HID
v1.00 Device [C-Media Electronics Inc. USB Audio Device] on
usb-20980000.usb-1/input3[ 14.012174] printk: console [ttyS0] enabled
[ 14.064965] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[ 14.142795] bcm2835-power bcm2835-power: Broadcom BCM2835 power
domains driver
[ 14.232013] mmc-bcm2835 20300000.mmcnr: mmc_debug:0 mmc_debug2:0
Not sure if it really makes sense to dig further into this issue. Might
be something in the serial driver of the RPI. I don't see really a valid
use case, 9600 baud is nothing you really need and in anyway pushing
serial logs out via serial is nothing really needed in productive use
cases, just for development (correct me if I'm wrong).
- systemd startup
* systemd drops 2 log lines per started unit to the console
* seems serial output is not implemented asynchronously (see steps of
units in sd plot, ~10ms per unit w/ baud 115200, ~80ms per unit w/ baud9600
I'm not sure what you're referring to here. Is the 'unit' you are talking about
the graphing grid size, or are you referring to systemd units? The grid size
seems to be 10ms per minor grid line in each plot.
unit -> systemd unit
* grid size per minor grid line is 100ms to me (1s per main grid line ->
see top of plot)
* take two units "user.slice" and "remote-fs.target"
* they should have basically no delay between each other -> you can see
it in quiet case
* w/ serial on, you see delays (10ms, 80ms) which in fact are caused
just by dropping the log lines to serial kernel log
* overall delay in user space startup sums up significantly
Side notes:
* I remember similar behavior w/ imx.6 SoCs
* Maybe this issues is not seen on other SoCs (maybe w/ another hw
implementation of the UART)
* Maybe this issues is only seen in single core machines (I can double
check w/ a PI3 or orange pi zero once)
Hope this helps.
It helps a lot. Thanks for this data!
I think the 'Disable Console' technique will continue to stay as one of the first
things we recommend for developers working on their board's boot time.
Yes I agree. Let me check out other boards and especially multi-core
systems if the issues is happening there as well ...
To others developers - I'd like to see more data like this on other systems
as well. So please keep submitting your data to this list.
Thanks,
-- Tim
Regards,
Marko
