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

[Simon Glass]

Hi Wolfgang,

Such a lot of text about such a small patch. It is clear to me that you are
used to doing things one way, and this is a different approach. As I said
there is more than one way to skin this cat and I think there are advantages
to having internal self-contained timing. I will try to address some of your
comments below.

On Sun, May 15, 2011 at 10: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.
>

Yes we do, and in fact they do improve boot performance slightly when the
console is muted.


>
> > 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.
>

finished in under 100ms, the point being that if the time taken to load the
kernel is fixed, and you want to work on the other stuff, the total run-time
of it is under 100ms on some platforms.


> > > - 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.
>

It looks great, I wish we could use it on our platform, but for the reasons
I have given it is not suitable.


>
>
> 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.
>

OK fair enough, of course we want the simplest solution that covers the
requirements.


>
> > 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?
>

We need to record it - generally this is done by Linux later (along with all
the boot performance stats from Linux).


>
> > 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?
>

See above - there is no serial port listener.


>
> > 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?
>

We have a verified boot which can taken different paths when it sees an
update image, or corruption, for example. These paths can substantially
change the boot time. Changing boot times have often led us to bugs in the
past. Also the device itself can change. For example the performance of an
eMMC device changes over time and we want to track that.


> > > - 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?
>

Here is the entire extent of the platform-specific code for Tegra2:

unsigned long timer_get_us(void)
{
struct timerus *timer_base = (struct timerus *)NV_PA_TMRUS_BASE;

return readl(&timer_base->cntr_1us);
}

I agree it is unfortunate to have features which require platform-specific
features. Perhaps we should define a microsecond timer as a requirement of a
U-Boot port? Or perhaps an option which opens up new features?


>
> > 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.
>

It does save time.

>
> > 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.
>

It is easy enough to get storage if we want it - you can maintain a
pre-reloc table which is copied over afterwards. I notice that some
functions do different things before and after reloc. I imagine that
reducing what is done before reloc is a good thing, so this window is likely
to shrink. We can always make bootstage more complex and feature-full as
time goes by, if there is some interest in having it in in the first place.

>
> > > 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.
>

See above.


>
> > 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.
>

OK, not sure why, but 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.
>

I believe it compares favourably. It has a more friendly display, doesn't
require a serial port, is more accurate, can run self-hosted, etc. With the
TCL script you need to add a new line before you will get a new time.


> > 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().
>

Fair enough. If you have your heart set on the TCL script I'm really not
going to get very far!


>
> > 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.
>

I don't see why not. That means they are busy waiting when they could be
carrying on with the boot.


>
> > 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.
>

Yes, you must add a printf(), right? Otherwise you won't know it has taken a
different path

>
>
> 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'm happy to post a patch for collecting pre-relocation information later if
that is of general interest. We can also have an automatic fallback call to
the ticks timer if microsecond resolution is not available. That would
support all platforms.

Instrumentation is always going to involve putting something in there. We
could run U-Boot in an emulator and do it that way I suppose. We could
require our users to connect a serial logging device. There are lots of
things we could do.


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

In terms of all this discussion I can see your point :-) I did have
expressions of interest from two people including one I thought was at your
company, which I why I went to the effort to clean up and submit this. At
that time I didn't realise it would be such a touchy subject.

In summary I believe this patch is a clean, simple and functional solution
to a real problem that we have, and that I believe others have also.

But if you really don't want this in U-Boot then please accept my apologies
for wasting so much time on the list.

Regards,
Simon


>
> Best regards,
>
> Wolfgang Denk
>
> --
> DENX Software Engineering GmbH,     MD: Wolfgang Denk & Detlev Zundel
> HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany
> Phone: (+49)-8142-66989-10 Fax: (+49)-8142-66989-80 Email: wd at denx.de
> Syntactic sugar causes cancer of the semicolon.
>                - Epigrams in Programming, ACM SIGPLAN Sept. 1982
>