Hi Gene
Thanks for your reply.I'm trying to breakdown overall system boot time and
to understand each component duration.
My linux image is a ~10 MB bzImage file with the rootfs cpio'ed inside.
I also have 2 BIOS images:- some general purpose BIOS
- a custom BIOS which loads real quick
I'm using TSC to measure time. I'm not sure it's the best way
(I've read about CPU's synchronization problems with it) but I'm not
sure how to do it otherwise.
I've added the following TSC reads at:1) the begining of a custom c32 module
which later calls "syslinux_run_command"2)?the begining?of
"start_kernel" function3) end of kernel load
As far as I understand the duration between 1 to 2 is bootloader time (am I
wrong?).
Using the custom BIOS:- it takes ~1.1 seconds for bootloader to finish- it takes
~0.9 seconds for Linux to finish
Using the general purpose BIOS:- it takes ~0.45 seconds for bootloader to
finish- it takes ~0.9 seconds for Linux to finish
Of course that the overall boot time with the general purpose BIOS is much
longer than with the custom BIOS (the custom BIOS is intended to cut down boot
time).
So I'm trying to understand:- Where does the extra bootloader time go when
using the custom BIOS?- Is there a mechanisem built into syslinux code which can
help solve this mystery?
Thanks again,Tal
From: Gene Cumm <gene.cumm at gmail.com>
To: Tal Lubko <tallubko at yahoo.com>
Cc: "syslinux at zytor.com" <syslinux at zytor.com>
Sent: Wednesday, July 8, 2015 4:45 AM
Subject: Re: [syslinux] Measuring boot time
On Mon, Jul 6, 2015 at 1:01 PM, Tal Lubko via Syslinux
<syslinux at zytor.com> wrote:> Hello Everyone
> I'd like to know what's the best way to measure syslinux functions
duration.I know how to measure overall time (from syslinux start), but is there
an easy way to break it down?
What do you mean?? How long it takes to load individual files along
the way from initial start to the kernel handoff?? cptime.c32 might
offer a way to get some answers there.
Do you mean how long individual function calls take?? That sounds like
a non-trivial question if this is the case.
--
-Gene
On Wed, Jul 8, 2015 at 12:47 AM, Tal Lubko <tallubko at yahoo.com> wrote:> Hi Gene > > Thanks for your reply. > I'm trying to breakdown overall system boot time and to understand each > component duration. > My linux image is a ~10 MB bzImage file with the rootfs cpio'ed inside. > > I also have 2 BIOS images: > - some general purpose BIOS > - a custom BIOS which loads real quick > > I'm using TSC to measure time. I'm not sure it's the best way (I've read > about CPU's synchronization problems with it) but I'm not sure how to do it > otherwise.Syslinux is essentially a single-core single-thread application. Unless your BIOS uses other cores for some BIOS function calls, they shouldn't matter.> I've added the following TSC reads at: > 1) the begining of a custom c32 module which later calls > "syslinux_run_command" > 2) the begining of "start_kernel" function > 3) end of kernel load > > As far as I understand the duration between 1 to 2 is bootloader time (am I > wrong?).That sounds reasonable. Time to fetch kernel and iniitrd payload(s) plus set it all up.> Using the custom BIOS: > - it takes ~1.1 seconds for bootloader to finish > - it takes ~0.9 seconds for Linux to finish > > Using the general purpose BIOS: > - it takes ~0.45 seconds for bootloader to finish > - it takes ~0.9 seconds for Linux to finish > > Of course that the overall boot time with the general purpose BIOS is much > longer than with the custom BIOS (the custom BIOS is intended to cut down > boot time). > > So I'm trying to understand: > - Where does the extra bootloader time go when using the custom BIOS?Any of various sources though most likely your custom BIOS is just slower at its disk access.> - Is there a mechanisem built into syslinux code which can help solve this > mystery?There's not any mechanism that I know of aside from using cptime.c32 to time how long it takes for the files to be loaded or enabling some of the debug functionality (with debug.c32 to the screen or a recompile to output to a serial port at IO port 3F8h at 115200 8n1). There are some obvious questions that are yet unanswered: 1) What version? Where did it come from? 2) Where is it installed? SYSLINUX on a hard drive or perhaps installed to a USB drive of some sort? Some USB BIOSs are horribly slow. Perhaps ISOLINUX on a CD or hybridized to a hard drive or USB drive? 3) If SYSLINUX, what 3-character mode does the version/copyright banner display, CHS or EDD? -- -Gene> ________________________________ > From: Gene Cumm <gene.cumm at gmail.com> > To: Tal Lubko <tallubko at yahoo.com> > Cc: "syslinux at zytor.com" <syslinux at zytor.com> > Sent: Wednesday, July 8, 2015 4:45 AM > Subject: Re: [syslinux] Measuring boot time > > On Mon, Jul 6, 2015 at 1:01 PM, Tal Lubko via Syslinux > > > > <syslinux at zytor.com> wrote: >> Hello Everyone >> I'd like to know what's the best way to measure syslinux functions >> duration.I know how to measure overall time (from syslinux start), but is >> there an easy way to break it down? > > > What do you mean? How long it takes to load individual files along > the way from initial start to the kernel handoff? cptime.c32 might > offer a way to get some answers there. > > Do you mean how long individual function calls take? That sounds like > a non-trivial question if this is the case.
Hi Gene Thanks again for your help. I'm using SYSLINUX 4.05 distributed by Ubuntu. For debugging I'm using SYSLINUX 6.03 because for some reason if I build SYSLINUX 4.05 from sources I get many compilation errors. SYSLINUX is installed on eMMC storage (along with Linux). I don't see the 3-character mode banner display. How can I check it? So I've added some timing prints to SYSLINUX 6.03 and got the following results: bootloader start 1179.140 ms before loadfile 1180.320 ms after loadfile 1454.250 ms before bios_do_shuffle_and_boot 1465.795 ms kernl_start (main.c) 2298.054 ms The Linux image size is around 10 MByte. You can see that the time that it takes to read it is around 280 ms. It is slow compared to reading it from Linux but it doesn't what take the vast boot time. You can see that the vast boot time part is between bios_do_shuffle_and_boot and kernel start. As far as I could see, from this stage on SYSLINUX code is assembly which I'm less familiar with so it is harder for me to debug. Can you describe what SYSLINUX does from this stage on? Do you have any assumption what can take so much time? I'd like to remind you that if I use slower BIOS "bios_do_shuffle_and_boot" is called later BUT the duration from it to kernel_start is shorter. Thanks, Tal ________________________________ From: Gene Cumm <gene.cumm at gmail.com> To: Tal Lubko <tallubko at yahoo.com> Cc: "syslinux at zytor.com" <syslinux at zytor.com> Sent: Wednesday, July 8, 2015 4:54 PM Subject: Re: [syslinux] Measuring boot time On Wed, Jul 8, 2015 at 12:47 AM, Tal Lubko <tallubko at yahoo.com> wrote:> Hi Gene > > Thanks for your reply. > I'm trying to breakdown overall system boot time and to understand each > component duration. > My linux image is a ~10 MB bzImage file with the rootfs cpio'ed inside. > > I also have 2 BIOS images: > - some general purpose BIOS > - a custom BIOS which loads real quick > > I'm using TSC to measure time. I'm not sure it's the best way (I've read > about CPU's synchronization problems with it) but I'm not sure how to do it > otherwise.Syslinux is essentially a single-core single-thread application. Unless your BIOS uses other cores for some BIOS function calls, they shouldn't matter.> I've added the following TSC reads at: > 1) the begining of a custom c32 module which later calls > "syslinux_run_command" > 2) the begining of "start_kernel" function > 3) end of kernel load > > As far as I understand the duration between 1 to 2 is bootloader time (am I > wrong?).That sounds reasonable. Time to fetch kernel and iniitrd payload(s) plus set it all up.> Using the custom BIOS: > - it takes ~1.1 seconds for bootloader to finish > - it takes ~0.9 seconds for Linux to finish > > Using the general purpose BIOS: > - it takes ~0.45 seconds for bootloader to finish > - it takes ~0.9 seconds for Linux to finish > > Of course that the overall boot time with the general purpose BIOS is much > longer than with the custom BIOS (the custom BIOS is intended to cut down > boot time). > > So I'm trying to understand: > - Where does the extra bootloader time go when using the custom BIOS?Any of various sources though most likely your custom BIOS is just slower at its disk access.> - Is there a mechanisem built into syslinux code which can help solve this > mystery?There's not any mechanism that I know of aside from using cptime.c32 to time how long it takes for the files to be loaded or enabling some of the debug functionality (with debug.c32 to the screen or a recompile to output to a serial port at IO port 3F8h at 115200 8n1). There are some obvious questions that are yet unanswered: 1) What version? Where did it come from? 2) Where is it installed? SYSLINUX on a hard drive or perhaps installed to a USB drive of some sort? Some USB BIOSs are horribly slow. Perhaps ISOLINUX on a CD or hybridized to a hard drive or USB drive? 3) If SYSLINUX, what 3-character mode does the version/copyright banner display, CHS or EDD? -- -Gene> ________________________________ > From: Gene Cumm <gene.cumm at gmail.com> > To: Tal Lubko <tallubko at yahoo.com> > Cc: "syslinux at zytor.com" <syslinux at zytor.com> > Sent: Wednesday, July 8, 2015 4:45 AM > Subject: Re: [syslinux] Measuring boot time > > On Mon, Jul 6, 2015 at 1:01 PM, Tal Lubko via Syslinux > > > > <syslinux at zytor.com> wrote: >> Hello Everyone >> I'd like to know what's the best way to measure syslinux functions >> duration.I know how to measure overall time (from syslinux start), but is >> there an easy way to break it down? > > > What do you mean? How long it takes to load individual files along > the way from initial start to the kernel handoff? cptime.c32 might > offer a way to get some answers there. > > Do you mean how long individual function calls take? That sounds like > a non-trivial question if this is the case.