[U-Boot] [PATCH 0/4] Accurate boot time measurement

[Graeme Russ]

On Mon, May 16, 2011 at 3:48 PM, Wolfgang Denk <wd at denx.de> wrote:
> Dear Simon Glass,
>
> In message <BANLkTi=0ijj7DnLsjovO-3eQjMw+RSOQwg at mail.gmail.com> you wrote:
>>
>> This is 100us which is pretty good although you are assuming that there is
>> no FIFO holding things. Also on modern ARM CPUs the 'processing' part of
>
> I don't see that we use any FIFOs in the output direction.
>
>> U-Boot (where it is not just waiting on a device) can be over in under
>> 100ms, and if you are wanting to reduce this, a little more resolution
>> doesn't hurt.
>
> Sorry, I cannot parse the "over in under 100 millisecond" part.
>
>> > - It requires zero code changes.  You can run the production code and
>> >  time it.  You can use it without rebuilding / reinstalling the
>> >  software, yes even without access to the source code.
>> >
>>
>> Are you not ignoring the timing parser on the serial port which must be
>> written and changed to cope with the different output of U-Boot (net boot,
>> USB boot, MMC boot, SD boot, etc.)? We have a lot of boot paths, different
>> architectures, etc. We want a simple solution.
>
> Well, the "timing parser", as you callit, can be written in 10 lines
> or less of your scripting language of choice.  See for example here
> for a solution in expect/tcl: ftp://ftp.denx.de/pub/tools/time_log
> We've been using this for about 10 years by now (see for example this
> 7 year old boot time analysis:
> http://www.denx.de/wiki/DULG/AN2004_11_BootTimeOptimization).
>
> As we can trivially use regular expressions, the effort to implement a
> "timing parser" can be ignored. And it is independet of what sort of
> boot device we are using.
>

Fine if your running Linux - What if the only tool tyou have is
Hyperterminal?

>
> You write: "We want a simple solution."  I agree 100%.
>
> Isn;t a 10 line script code solution that does not require ANY changes
> to the U-Boot code _much_ simpler than your approach?
>
> This is why I was asking if your solution had any significant
> advantages.
>
>> In our case the console is silent on boot, so this solution does not work.
>
> Point taken. But, you need to output the timing information, don't you?

If it can be compiled by U-Boot and passed to the OS then the OS can do
the ou

>> Secondly it requires a listener on the serial port which we often don't
>> have. Thirdly we want to log this information and record it in the field so
>
> You must have one to rea the time logs, right?

Maybe it can be retrieved over a network connection

>> that we track boot time. This means that it has to be done by the device
>> itself.
>
> Did you see cases where the boot time in the field differs from that
> in your lab?  Can you please explain what is causing such differecnes?

I've seen many instances where everything works well 'in the lab' and as
soon as you put it in the field, things go pear shaped. Often you need to
resort to network sniffing but if the problem is intermittent, this is
very hit and miss. If you have several devices on a network and you can
see the breakdown of the bootstage on each individual device, traking
down the problem is much easier - Is it a associated with a common network
function (DHCP/TFTP)? A common network segment, a particular file being
TFTP'd?

>
>> > - It is completely platform, SoC and board idependent - we do not need
>> >  to provide any specific timer servcies etc. which are inherently
>> >  platform-dependent.
>>
>> Is this really an advantage?
>
> Don't you think so?
>
> Will you provide the code to implement your solution for all currently
> supported BlackFin, ColdFire, MicroBlaze, MIPS, NIOS, PPC, SH, SPARC
> or x86 CPUs?  Or even for all currently supported ARMN SoCs?
>
>> > - It does not cause execution overhead on the running system - it
>> >  affects neither the execution speed not the memory footprint of the
>> >  target under test.
>>
>> Write to the serial port costs about 30ms on our platform at minimum. I
>> have't looked at why, but the serial FIFO is only so big so I assume that is
>
> I think this can (and should) be fixed. It makes little sense to use a
> FIFO in the transmit direction in U-Boot.
>
>> what is happening. The overhead of bootstage is a function call, a readl(),
>> a a few memory accesses and an optional strcpy. It is much cheaper than
>> outputting a serial character.
>
> But you need storage for the timing events, and you don't have this
> before relocation. So you miss some really interesting parts of the
> boot procedure.

Maybe a limited amount can be stored in global data by testing the
relocated flag

>> > approach, i. e. which problems can be addressed with your code where
>> > the output timing method cannot be used, or where it is less
>> > efficient?
>>
>> With a little bit of cheating I can think of 10:
>>
>> 1. It doesn't need a serial watcher to be connected, which is not available
>> in the field, and is something that anyway would only be attached when the
>> engineer is not using the console for actually typing commands.
>
> OK, not needing a console port during boot is indeed an advantage.  It
> comes at the cost of needing log space, which is not available before
> relocation, so we miss some interesting parts of the boot procedure.

Can use global data for a limited number of pre-relocation records. And I
don't think pre-location is where a lot of problems will occur anyway
unless you have flaky/misconfigured  hardware

>> 2. It is internal to the code, so as different code paths are taken it still
>> has working timing, and doesn't rely on separate serial traffic parsing code
>> to work out what happened
>
> I don't consider this an advantage.  On contrary.
>
>> 3. It still works with a silent console (we can either unmute the console
>> and print the info, or pass it on to Linux for logging)
>
> OK.
>
>> 4. It is simpler to write and extend (just add a new bootstage call around
>> any interesting section even if there is no serial output there)
>
> This is plain wrong.  Compare your implementation against the 10 lines
> of TCL code referenced above.
>
>> 5. It allows timing of things which don't result in serial output.
>
> But to do so, you need to insert trace points.  With the same effort
> we can insert a printf().

Which increase code/data size - If you don't care about having pretty
messages in you boot profile (you can always look up source or
documentation) the size impact per 'mark' is less

>> 6. It times when the event actually happens rather than when a character
>> makes its way through a UART FIFO. At worst the character might take a few
>> ms to get through the FIFO which will skew timings.
>
> Serial drivers are not supposed to use FIFOs in the tx direction.

Moot point and counterpoint when considering 3) above

>> 7. It potentially allows two CPUs to run concurrently and log progress (no I
>> am not working on that yet).
>>
>> 8. We can log the information in the field, perhaps by passing it to Linux
>>
>> 9. There is only one code base to be changed when a boot path is adjusted.
>
> ...which is a disadvantage, because with the externat tool nothing
> needs to be changed at all.
>
>> 10. It has higher resolution.
>
> OK.
>
> I understand your position, and I too see some advantages of your
> implementation.  But I see also disadvantages, especially it being a
> pretty much intrusive change to large areas of the code, and being
> available for a single platform only.  Also, I see it as a
> disadvantage that you lose pre-relocation information.

I think my refined suggestion has a far smaller impact than first thought
and you can get pre-relocation information if you are willing to use
some global data storage

>
> So far, I am not convinced that the result is worth the effort.
>

We live in hope ;)

Regards,

Graeme