Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Mike Frysinger, In message 201105232255.58602.vap...@gentoo.org you wrote: Ultimately, Wolfgang gets final word regardless of anything else. Do I? That's news for me. What prevents you to continue this project as you like if I should decide something that appears to be unacceptable to the community? 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: w...@denx.de No user-servicable parts inside. Refer to qualified service personnel. ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Tuesday, May 24, 2011 03:18:00 Wolfgang Denk wrote: Mike Frysinger wrote: Ultimately, Wolfgang gets final word regardless of anything else. Do I? That's news for me. What prevents you to continue this project as you like if I should decide something that appears to be unacceptable to the community? yours will be Das U-Boot while mine will be an uppity fork doesnt denx also own the trademark on Das U-Boot as applied to low level boot loaders ? -mike signature.asc Description: This is a digitally signed message part. ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Mike Frysinger, In message 201105241422.41948.vap...@gentoo.org you wrote: What prevents you to continue this project as you like if I should decide something that appears to be unacceptable to the community? yours will be Das U-Boot while mine will be an uppity fork If you have the community with you the name alone is in vain doesnt denx also own the trademark on Das U-Boot as applied to low level boot loaders ? No. I've been told that both U-Boot and Das U-Boot are too generic terms to be used for a name mark description. If we had a logo, we could apply for a brand mark (word mark and logo). But so far we don't. 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: w...@denx.de What about WRITING it first and rationalizing it afterwords? :-) - Larry Wall in 8...@jpl-devvax.jpl.nasa.gov ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Hi Simon, [...] I believe I have covered this ground very thoroughly and would like advice please on what to do next. The options I can see are: As Graeme points out, you got enough positive feedback that I encourage you to continue and address the comments. OK, it would be nice to have a note from Wolfgang since without his OK it won't make it in, right? Ultimately we are a democratic community, so when you get enough support the changes will go in. Usually we find a consensus acceptable to all parties before resorting to such formal measures however. Cheers Detlev -- Q: Why did the chicken cross the Moebius strip? A: To get to the other ... er, um ... -- DENX Software Engineering GmbH, MD: Wolfgang Denk Detlev Zundel HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: d...@denx.de ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Monday, May 23, 2011 11:22:18 Detlev Zundel wrote: I believe I have covered this ground very thoroughly and would like advice please on what to do next. The options I can see are: As Graeme points out, you got enough positive feedback that I encourage you to continue and address the comments. OK, it would be nice to have a note from Wolfgang since without his OK it won't make it in, right? Ultimately we are a democratic community, so when you get enough support the changes will go in. Usually we find a consensus acceptable to all parties before resorting to such formal measures however. s/Ultimately/For the most part/ Ultimately, Wolfgang gets final word regardless of anything else. -mike signature.asc Description: This is a digitally signed message part. ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Hi Simon, [...] I believe I have covered this ground very thoroughly and would like advice please on what to do next. The options I can see are: As Graeme points out, you got enough positive feedback that I encourage you to continue and address the comments. - change the code to use a fallback when a microsecond timer is not available Excuse me for not diving into that too deep, but from my top-level overview, it would seem like a good idea that if an architecture _has_ a microsecond timer, it could use generic code to massage that into the HZ=1000 API that we currently use with the addition of offering the extended precision. Your code then would need such a fallback and could work with the best precision offered by the architecture. New architectures with microsecond timers would need to only implement the new microsecond timer infrastructure and be done with it. I know that this probably ignores much of the reality, but it is as much as I can say with the time that I have available. As a side-note, I would always suggest looking at how Linux solves similar problems and follow examples set there. - integrate with boot progress The current boot progress to me seems pretty ugly and could do with a make-over. So if it is possible to merge those two logical functions, we would have a win-win situation. - something else? drop it? No, please don't - I think you created enough interest to carry on. Cheers Detlev -- Perfecting oneself is as much unlearning as it is learning. -- Edsger Dijkstra -- DENX Software Engineering GmbH, MD: Wolfgang Denk Detlev Zundel HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: d...@denx.de ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Thu, May 19, 2011 at 1:36 AM, Detlev Zundel d...@denx.de wrote: Hi Simon, [...] I believe I have covered this ground very thoroughly and would like advice please on what to do next. The options I can see are: As Graeme points out, you got enough positive feedback that I encourage you to continue and address the comments. OK, it would be nice to have a note from Wolfgang since without his OK it won't make it in, right? - change the code to use a fallback when a microsecond timer is not available Excuse me for not diving into that too deep, but from my top-level overview, it would seem like a good idea that if an architecture _has_ a microsecond timer, it could use generic code to massage that into the HZ=1000 API that we currently use with the addition of offering the extended precision. Your code then would need such a fallback and could work with the best precision offered by the architecture. New architectures with microsecond timers would need to only implement the new microsecond timer infrastructure and be done with it. Yes I suggested that a few emails ago but didn't get a response. - integrate with boot progress The current boot progress to me seems pretty ugly and could do with a make-over. So if it is possible to merge those two logical functions, we would have a win-win situation. OK fair enough. I will do this if there is agreement that this type of boot timing is worth having. Wolfgang can you please chime in here? Regards, Simon - something else? drop it? No, please don't - I think you created enough interest to carry on. Cheers Detlev -- Perfecting oneself is as much unlearning as it is learning. -- Edsger Dijkstra -- DENX Software Engineering GmbH, MD: Wolfgang Denk Detlev Zundel HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: d...@denx.de ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Fri, May 20, 2011 at 11:48 AM, Simon Glass s...@chromium.org wrote:
On Thu, May 19, 2011 at 1:36 AM, Detlev Zundel d...@denx.de wrote:
Hi Simon,
[...]
I believe I have covered this ground very thoroughly and would like
advice please on what to do next. The options I can see are:
As Graeme points out, you got enough positive feedback that I encourage
you to continue and address the comments.
OK, it would be nice to have a note from Wolfgang since without his OK
it won't make it in, right?
- change the code to use a fallback when a microsecond timer is not
available
Excuse me for not diving into that too deep, but from my top-level
overview, it would seem like a good idea that if an architecture _has_ a
microsecond timer, it could use generic code to massage that into the
HZ=1000 API that we currently use with the addition of offering the
extended precision. Your code then would need such a fallback and could
work with the best precision offered by the architecture. New
architectures with microsecond timers would need to only implement the
new microsecond timer infrastructure and be done with it.
Yes I suggested that a few emails ago but didn't get a response.
Is it just me or are get_timer(), set_timer() and reset_timer() in U-Boot
a little bit braindead? get_timer() returns microseconds since last
reset_timer() plus an optional offset, set_timer() allows the current
microseconds to an arbitrary value and reset_timer() is essentially
set_timer(0)
A random look at at91 is interesting though:
void set_timer(ulong t)
{
gd-tbl = t;
}
void reset_timer(void)
{
reset_timer_masked();
}
void reset_timer_masked(void)
{
/* reset time */
at91_tc_t *tc = (at91_tc_t *) AT91_TC_BASE;
gd-lastinc = readl(tc-tc[0].cv) 0x;
gd-tbl = 0;
}
So set_timer(0) != reset_timer() in a rather big way!
Now some arches (imx for example) do not implement set_timer() which makes
using it a 'Bad Idea'(tm)
And why do we need reset_timer() - Anything that uses it can just do:
ulong start_time = get_timer(0);
while (get_timer(start_time) SOME_TIMEOUT) {
...do stuff..
}
NOTE: May not be the 'safest' way to do that - I recall there being a LOT
of discussion about this with regards to wrap-around and safe ways of
doing the above
Anyway, my point is, if the timer API wasa fixed, all the boot logging API
needs to do is call get_timer() and your done - instant millisecond
timestamp - No fallbacks - Each arch just needs to implement get_timer()
correctly
- integrate with boot progress
The current boot progress to me seems pretty ugly and could do with a
make-over. So if it is possible to merge those two logical functions,
we would have a win-win situation.
Sounds like a two-patch approach - Fix up boot progress and then slap
logging on top
OK fair enough. I will do this if there is agreement that this type of
boot timing is worth having.
I could have a look at this if you like Simon
Regards,
Graeme
___
U-Boot mailing list
U-Boot@lists.denx.de
http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Anyway, my point is, if the timer API wasa fixed, all the boot logging API needs to do is call get_timer() and your done - instant millisecond make that microsecond ;) timestamp - No fallbacks - Each arch just needs to implement get_timer() correctly ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Hi Simon and Wolfgang, [...] 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. I don't believe this topic to be touchy, it's just that Wolfgang trying to keep the whole code base in shape has a healthy inertia before introducing changes that may be difficult to keep consistent over the multitude of SoCs that we support. To throw in my personal view again, I still would like to see such an infrastructure to get into U-Boot code. I fully agree with Wolfgang that practically the printfs and timing are a method already in place to do measurements. On the other hand my experience has shown that for some reason or other this has never been widely used. So effectively, it wasn't too helpful for the project itself. So I still believe that if we _had_ an infrastructure like you propose, we would get more people interested in _actually_ measuring and improving the code base, which would certainly be a good thing. Of course we have systems that are very limited in their ressources, but this is the reason why many features of U-Boot are opt-in features not forcing any resource usage on such boards. So if some of them are so short on resources that they cannot use such a timing framework, then so be it. But as most of the probably are in the legacy code base, they should not stop us from getting getting positive effects for the currently important boards and architectures. Cheers Detlev -- A change in language can transform our appreciation of the cosmos -- Benjamin Lee Whorf -- DENX Software Engineering GmbH, MD: Wolfgang Denk Detlev Zundel HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: d...@denx.de ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Tue, May 17, 2011 at 1:20 AM, Detlev Zundel d...@denx.de wrote: Hi Simon and Wolfgang, [...] 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. I don't believe this topic to be touchy, it's just that Wolfgang trying to keep the whole code base in shape has a healthy inertia before introducing changes that may be difficult to keep consistent over the multitude of SoCs that we support. To throw in my personal view again, I still would like to see such an infrastructure to get into U-Boot code. I fully agree with Wolfgang that practically the printfs and timing are a method already in place to do measurements. On the other hand my experience has shown that for some reason or other this has never been widely used. So effectively, it wasn't too helpful for the project itself. So I still believe that if we _had_ an infrastructure like you propose, we would get more people interested in _actually_ measuring and improving the code base, which would certainly be a good thing. Of course we have systems that are very limited in their ressources, but this is the reason why many features of U-Boot are opt-in features not forcing any resource usage on such boards. So if some of them are so short on resources that they cannot use such a timing framework, then so be it. But as most of the probably are in the legacy code base, they should not stop us from getting getting positive effects for the currently important boards and architectures. Cheers Detlev Hi Detlev and Wolfgang, Thanks for your comments. I understand a little bit of healthy inertia and do appreciate the constraints. I believe I have covered this ground very thoroughly and would like advice please on what to do next. The options I can see are: - change the code to use a fallback when a microsecond timer is not available - integrate with boot progress - something else? drop it? Regards. Simon -- A change in language can transform our appreciation of the cosmos -- Benjamin Lee Whorf -- DENX Software Engineering GmbH, MD: Wolfgang Denk Detlev Zundel HRB 165235 Munich, Office: Kirchenstr.5, D-82194 Groebenzell, Germany Phone: (+49)-8142-66989-40 Fax: (+49)-8142-66989-80 Email: d...@denx.de ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Hi Simon, Hi Detlev and Wolfgang, Thanks for your comments. I understand a little bit of healthy inertia and do appreciate the constraints. I believe I have covered this ground very thoroughly and would like advice please on what to do next. The options I can see are: - change the code to use a fallback when a microsecond timer is not available - integrate with boot progress - something else? drop it? I suggest you create a V2 of this patch series, integrating the logging into show_boot_progress() - Have a crawl through the existing code and see if you can safely use a bit in the progress number (preferably a fixed bit number across all platforms, or one defined in the config file if this is not possible) to indicate if that progress mark should be logged One day we can perhaps standardise how the parameter to show_boot_progress is treated so the same value is consistent across the entire U-Boot code. Don't worry too much about the 'pre-relocation' case for the time being. You will have to check the relocated flag stored in global data so no attempt to log is made before relocation. If there is enough support for pre-relocation logging, there can always be a V3 patch :) Make sure that the new feature has zero impact if the configuration option is not enabled (CONFIG_LOG_BOOT_PROGRESS for example). Try not to make it too ugly by littering code with #ifdef - If the bulk can be put into a file which can be selectively included in the Makefile that would be good. show_boot_progress() will naturally have some #ifdef's in it Make sure you clearly comment in each patch that it is V2 and the changes made from V1 and that you run it all through checkpatch.pl (from the Linux kernel source) Regards, Graeme ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Mon, May 16, 2011 at 3:56 PM, Wolfgang Denk w...@denx.de wrote:
Dear Graeme Russ,
In message banlktinsypvnpg06uolze65t-fcqdn_...@mail.gmail.com you wrote:
I've thought of a 'better' approach:
- Do no modify the parameters of show_boot_progress()
- Create a new struct:
struct boot_progress_msg {
int boot_progress_id;
const char *message;
{
Where do you store this data _before_ relocation, when we have no
access to RAM yet?
This data is Read-Only so pre/post relocation is not an issue. The boot
stage records however are a problem
Regards,
Graeme
___
U-Boot mailing list
U-Boot@lists.denx.de
http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Mon, May 16, 2011 at 3:55 PM, Wolfgang Denk w...@denx.de wrote: Dear Graeme Russ, In message BANLkTim7=-rza_l-dy0b-+adqv4ngol...@mail.gmail.com you wrote: But at 9600 baud it is over 1ms - 9600 is still considered the lowest common denominator for serial comms for diagnostic output for a lot of devices such as industrial PLCs etc. I think in the last 5 years I have seen but 2 devices using 9600 bps. All others appear to be using 115200 bps these days. And even at 9600 we're still close to millisecond reolution... And in the field, you may be interested more in transient timing anomalies which may result from network issues if the device is obtaining an IP address or loading an image file. In such scenarios, you will need to log the boot timing of every boot, not just when a serial terminal is connected time-stamping console output is not restricted to the serial port. It works as well with tty over USB, or netconsole, or even netconsole over USB. My point is, if the device reboots in the field, you cannot recover the boot timing analysis as once it is streamed out it is gone forever And finally, the lack of a serial port is a biggie - There are devices out there that do not have serial ports If they have a console interface, then the output can be time-stamped. See above Regards, Graeme ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Mon, May 16, 2011 at 3:48 PM, Wolfgang Denk w...@denx.de wrote: Dear Simon Glass, In message BANLkTi=0ijj7dnlsjovo-3eqjmw+rso...@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
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Graeme Russ, In message banlktim55mvfj-fdekea3gsbvqnnaic...@mail.gmail.com you wrote: time-stamping console output is not restricted to the serial port. It works as well with tty over USB, or netconsole, or even netconsole over USB. My point is, if the device reboots in the field, you cannot recover the boot timing analysis as once it is streamed out it is gone forever Agreed. But so far I have never seen a need to perform boot time measurements on devices in the field without access to the console (serial, or usb or netconsole). In all my experience, such behaviour is pretty much deterministic and can be done in the lab, before shipping systems. The only way where I can imagine that the boot ime depends on the actual user environment is when booting from the network, but then again you can also run a network sniffer to measure this impact. I really wonder what the benefit of adding such code to U-Boot is. 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: w...@denx.de Genitiv ins Wasser, weil's Dativ ist! ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Graeme Russ,
In message BANLkTi=u4gj+ci8hpfv95m8nynyedhg...@mail.gmail.com you wrote:
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?
AFAICT tcl is also available under Windoze...
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
We all have seen this, and we all appreciate any tool that is
available then.
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
I don't think so.
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
I smell a bloated implementation which works on one specific system or
two. This doesn't sound attractive to me.
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
What makes you think a call to printf()/puts()/putc() would increase
the code size worse than a call to the trace function? If I don't
care about pretty messages (and use silent console otherwise) my
serial console based messages consist of a plain putc('a') or
similar - certainly not more overhead than the call to the trace
function.
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
It's not about willing or not. If willing or wanting would help, we
had an ideal world. But in reality, we have a world full of
restrictions.
GD is definitely not buffer space for arbitrary amounts of log data.
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: w...@denx.de
A little suffering is good for the soul.
-- Kirk, The Corbomite Maneuver, stardate 1514.0
___
U-Boot mailing list
U-Boot@lists.denx.de
http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
-Original Message- From: u-boot-boun...@lists.denx.de [mailto:u-boot-boun...@lists.denx.de] On Behalf Of Graeme Russ Sent: Monday, May 16, 2011 11:54 AM To: Wolfgang Denk Cc: U-Boot Mailing List; Simon Schwarz Subject: Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement On Mon, May 16, 2011 at 3:48 PM, Wolfgang Denk w...@denx.de wrote: Dear Simon Glass, [snip]...[snip] 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? [sp] I have personally found Realterm quite good specifically for for attaching timing info to the prints received. It is available at: http://realterm.sourceforge.net/ For measurement, I send the output directly to a log file - not displayed on the screen. BTW, Teraterm is my choice for regular use. ~sanjeev [snip]...[snip] ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
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 w...@denx.de wrote:
Dear Simon Glass,
In message BANLkTi=0ijj7dnlsjovo-3eqjmw+rso...@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
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Mon, 16 May 2011 13:40:20 +0200
Wolfgang Denk w...@denx.de wrote:
Dear Graeme Russ,
In message BANLkTi=u4gj+ci8hpfv95m8nynyedhg...@mail.gmail.com you wrote:
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?
AFAICT tcl is also available under Windoze...
What about a board farm with a networked serial port server, adding
unpredictable latency? Even if you have direct access to the host serial
port, there's not just the host FIFO distorting things, but the scheduling
latency of the application. I suspect the useful precision of this
approach is significantly higher than 100 us.
What makes you think a call to printf()/puts()/putc() would increase
the code size worse than a call to the trace function? If I don't
care about pretty messages (and use silent console otherwise) my
serial console based messages consist of a plain putc('a') or
similar - certainly not more overhead than the call to the trace
function.
The size impact minor in either case, but in terms of time overhead (i.e.
the thing being measured), waiting for previous output to go
over the wire and the THR to empty is less overhead than putting a
timestamp in a log? Even if THR is already empty, those I/O accesses tend
to be much more expensive than reading from an CPU-internal time source and
writing to a cached data structure.
It's not about willing or not. If willing or wanting would help, we
had an ideal world. But in reality, we have a world full of
restrictions.
And requiring that debugging infrastructure for such a low-level piece of
software be universally applicable is a pretty big
self-imposed restriction...
How many targets are so short on pre-relocation memory that they can't
spare a couple hundred bytes for debugging, lacking a suitable time
source, etc.? It seems like the concept would be usable on more than just
a handful of boards, even if not necessarily all of them.
GD is definitely not buffer space for arbitrary amounts of log data.
When did limited become arbitrary?
-Scott
___
U-Boot mailing list
U-Boot@lists.denx.de
http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Simon Glass, In message BANLkTi=wdddekljobfroncqzxjn9ugn...@mail.gmail.com you wrote: 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 You can tell many things about me, but this one certainly is not the case. 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. Do you have an explanation how that works? When there is no output on the console, the use of a FIFO in tx direction should not matter at all? 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? We already have that, or better. The problem is that it depends on the architecture. On PPC systems for example you always have the time base, a 64 bit counter which is clocked with something like 1/4 or 1/16 of the CPU clock. And whe have the timer that gettime() is based on - which is in milliseocnd resolution (hence the demand that CONFIG_SYS_HZ must always be defined as 1000). The problem comes with the multitude of different architectures and SoCs we support - there is no concept of timebase registers on ARM, on some systems we need interrupts to implement timer services so these are available only after relocation, etc. 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 Where will you store this pre-reloc table? Yes, there are some systems with plenty of on-chip-memory or huge caches that can beused for this. But there are also systems where we barely can find the room for the most vital global data before relocation. Even worse - if you take this seriously, you will probably also get timing information from early boot stages, like how long it's taking to load the U-Boot image from NAND - but on some systems this loader code has to fit in as little as 2 KiB. 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. Well, the display format is trivial to adapt, as well as the trigger criteria. Keep in mind that this is just an example script that covers the most common use case we've seen so far. 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! I haven't my heart set on it. It is just one example of solutions which cover a large percentage of the potential use cases. I am trying to understand the ration of advanatges versus effort, that's all. 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. Where is the problem? If you are convinced of you idea you should be ready to defend it. If you are not, it's not wort it at all. And if you see a voting result of 2:1 pro this is pretty good, isn't it? But if you really don't want this in U-Boot then please accept my apologies for wasting so much time on the list. I don't consider this discussion a waste of time. I hope you don't do, either. 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: w...@denx.de Life would be so much easier if we could just look at the source code. -- Dave Olson ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Mon, May 16, 2011 at 11:32 AM, Wolfgang Denk w...@denx.de wrote: Dear Simon Glass, ... Yes we do, and in fact they do improve boot performance slightly when the console is muted. Do you have an explanation how that works? When there is no output on the console, the use of a FIFO in tx direction should not matter at all? Hi Wolfgang, That's right, but when output is not muted, the FIFO allows for some characters to be output before stalling the CPU. 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? We already have that, or better. The problem is that it depends on the architecture. The implementation, maybe (not the interface which can be common), but by expressing things in microseconds it is normally possible to convert, and when this isn't available people will understand that some rounding is going on. On PPC systems for example you always have the time base, a 64 bit counter which is clocked with something like 1/4 or 1/16 of the CPU clock. And whe have the timer that gettime() is based on - which is in milliseocnd resolution (hence the demand that CONFIG_SYS_HZ must always be defined as 1000). The problem comes with the multitude of different architectures and SoCs we support - there is no concept of timebase registers on ARM, on some systems we need interrupts to implement timer services so these are available only after relocation, etc. On several ARM SOCs there is a monotonic timer - it's not always a microsecond timer but is typically good enough for this sort of purpose. In some cases this doesn't require interrupts (e.g. Tegra). 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 Where will you store this pre-reloc table? Yes, there are some systems with plenty of on-chip-memory or huge caches that can beused for this. But there are also systems where we barely can find the room for the most vital global data before relocation. I would rather discuss this once we get agreement on the first part of this, which is the concept of using a timer at all! But it is not hard to store data pre-reloc and move it later. This is what happens with the global data at the moment. Even worse - if you take this seriously, you will probably also get timing information from early boot stages, like how long it's taking to load the U-Boot image from NAND - but on some systems this loader code has to fit in as little as 2 KiB. SOC boot ROMs are changing this, but even so I don't see this as a serious limitation. If you don't have room for boot timing in your pre-boot loader, don't add it. 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. Well, the display format is trivial to adapt, as well as the trigger criteria. Keep in mind that this is just an example script that covers the most common use case we've seen so far. OK 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! I haven't my heart set on it. It is just one example of solutions which cover a large percentage of the potential use cases. I am trying to understand the ration of advanatges versus effort, that's all. In that case will you consider the inclusion of this as a different way of doing things? 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. Where is the problem? If you are convinced of you idea you should be ready to defend it. If you are not, it's not wort it at all. And if you see a voting result of 2:1 pro this is pretty good, isn't it? I think I have mounted a robust defense. In fact I haven't written so much on one topic for a week :-) But if you really don't want this in U-Boot then please accept my apologies for wasting so much time on the list. I don't consider this discussion a waste of time. I hope you don't do, either. 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: w...@denx.de Life would be so much
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Mon, May 16, 2011 at 9:40 PM, Wolfgang Denk w...@denx.de wrote:
Dear Graeme Russ,
In message BANLkTi=u4gj+ci8hpfv95m8nynyedhg...@mail.gmail.com you wrote:
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?
AFAICT tcl is also available under Windoze...
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
We all have seen this, and we all appreciate any tool that is
available then.
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
I don't think so.
As I said before, the timing aberation per-boot in pre-relocation code is
going to be pretty minimal. 'In The Lab' you can easily use putc() and
your favourite terminal/script to do the timing analysis when you are
trying to trim micro-seconds (optimising SDRAM init/sizing etc, NAND
loading, NOR wait states)
My particular interest in the boot timing analysis is where it is being
affected by factors such as:
- Device initialisation (peripherals via I2C, FPGAs etc)
- Network (DHCP/TFTP requests)
- Storage device access (HDDs, NAND etc)
- Physical Environment (temperature etc)
These factors are not as reproducible 'In The Lab' and in the field may
be very transient.
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
I smell a bloated implementation which works on one specific system or
two. This doesn't sound attractive to me.
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
What makes you think a call to printf()/puts()/putc() would increase
the code size worse than a call to the trace function? If I don't
care about pretty messages (and use silent console otherwise) my
serial console based messages consist of a plain putc('a') or
similar - certainly not more overhead than the call to the trace
function.
Another 'In The Field' scenario is where you do not have a free console
port available because thay are all used for communicating to other
devices. We have devices with five serial ports and at times we still run
out of ports
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
It's not about willing or not. If willing or wanting would help, we
had an ideal world. But in reality, we have a world full of
restrictions.
Yes, and some of those restrictions limit your ability to use a serial
port to debug boot times
GD is definitely not buffer space for arbitrary amounts of log data.
Agreed, but:
a) Pre-relocation logging may not strictly be needed because boot-times
up to relocation can be fine tuned in the lab using putc()
b) A few dozen bytes in GD in a debug build to isolate some stupid random
issue onyl seen in the field can save hundreds (if not thousands) of
insert you local currency here of engineering time
Regards,
Graeme
___
U-Boot mailing list
U-Boot@lists.denx.de
http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Sun, May 15, 2011 at 3:03 AM, Graeme Russ graeme.r...@gmail.com wrote: Couple of thoughts: - Macro the definition of show_boot_progress() so it accepts a (const char *) argument if CONFIG_BOOTSTAGE is defined - Change BOOTSTAGE_COUNT to CONFIG_MAX_BOOTSTAGE_RECORDS - Any call to show_boot_progress() with a non-null second argument causes it to be logged in the next available bootstage record - After the last bootstage record is filled, no further calls to show_boot_progress() cause logging to the bootstage records - Instead of CONFIG_BOOTSTAGE_REPORT, create a command which dumps the contents of the bootstage records No this is going to result in a big patch (every instance of show_boot_progress() will need to be touched to at least add NULL as the second parameter - Maintainers can add better text later ;) Thanks for your thoughts. It can be done, but my bigger question is this: If there is a strong appetite for that sort of patch I'm happy to do it. If I get some +ve responses then I will do it, otherwise I think I should assume people want this left as is. Regards, Simon Regards, Graeme ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Sun, May 15, 2011 at 4:53 AM, Wolfgang Denk w...@denx.de wrote: Dear Simon Glass, In message 1305319923-9477-1-git-send-email-...@chromium.org you wrote: This defines the basics of a new boot time measurement feature. This allows logging of very accurate time measurements as the boot proceeds, by using an available microsecond counter. Well, as long as we talk about microsecond resolution, I do not see the compelling advantage over the classic method of timing the output on the serial console port. At 115200 bps we have a resolution of better than 0.1 millisecond per character; this should be precise enough for most practical purposes. Hi Wolfgang, 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 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. Logging and timing the serial output has a number of advantages over other solutions: - 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. In our case the console is silent on boot, so this solution does not work. 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 that we track boot time. This means that it has to be done by the device itself. - 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? - 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 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. Can you please explain where your solution is better than this 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. 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 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) 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) 5. It allows timing of things which don't result in serial output. 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. 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. 10. It has higher resolution. 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: w...@denx.de Oh dear, I think you'll find reality's on the blink again. - Marvin The Paranoid Android ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Mon, May 16, 2011 at 7:58 AM, Simon Glass s...@chromium.org wrote: On Sun, May 15, 2011 at 4:53 AM, Wolfgang Denk w...@denx.de wrote: Dear Simon Glass, In message 1305319923-9477-1-git-send-email-...@chromium.org you wrote: This defines the basics of a new boot time measurement feature. This allows logging of very accurate time measurements as the boot proceeds, by using an available microsecond counter. Well, as long as we talk about microsecond resolution, I do not see the compelling advantage over the classic method of timing the output on the serial console port. At 115200 bps we have a resolution of better than 0.1 millisecond per character; this should be precise enough for most practical purposes. But at 9600 baud it is over 1ms - 9600 is still considered the lowest common denominator for serial comms for diagnostic output for a lot of devices such as industrial PLCs etc. Hi Wolfgang, 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 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. Logging and timing the serial output has a number of advantages over other solutions: - 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. In our case the console is silent on boot, so this solution does not work. 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 that we track boot time. This means that it has to be done by the device itself. I concur - Obtaining the timing information requires that the serial console application can generate it - something most default terminal apps (Hyperterminal for example) do not do. Also, timing is skewed by the UART FIFO on the device and the UART FIFO on the host. And in the field, you may be interested more in transient timing anomalies which may result from network issues if the device is obtaining an IP address or loading an image file. In such scenarios, you will need to log the boot timing of every boot, not just when a serial terminal is connected And finally, the lack of a serial port is a biggie - There are devices out there that do not have serial ports - 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? - 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 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. The strcpy can be avoided for the 'bootstage' call (more info in another post later) Can you please explain where your solution is better than this 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. 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 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) 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) 5. It allows timing of things which don't result in serial output. 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. 7. It potentially allows two CPUs to run concurrently and log progress (no I am not working on that yet). Not really a benefit for U-Boot as we don't run multi-cpu (we only initialise additional CPUs) 8. We can log
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Mon, May 16, 2011 at 7:34 AM, Simon Glass s...@chromium.org wrote:
On Sun, May 15, 2011 at 3:03 AM, Graeme Russ graeme.r...@gmail.com wrote:
Couple of thoughts:
- Macro the definition of show_boot_progress() so it accepts a (const
char *) argument if CONFIG_BOOTSTAGE is defined
- Change BOOTSTAGE_COUNT to CONFIG_MAX_BOOTSTAGE_RECORDS
- Any call to show_boot_progress() with a non-null second argument
causes it to be logged in the next available bootstage record
- After the last bootstage record is filled, no further calls to
show_boot_progress() cause logging to the bootstage records
- Instead of CONFIG_BOOTSTAGE_REPORT, create a command which dumps the
contents of the bootstage records
No this is going to result in a big patch (every instance of
show_boot_progress() will need to be touched to at least add NULL as the
second parameter - Maintainers can add better text later ;)
I've thought of a 'better' approach:
- Do no modify the parameters of show_boot_progress()
- Create a new struct:
struct boot_progress_msg {
int boot_progress_id;
const char *message;
{
- Initialise the 'boot profile messages'
struct boot_progress_msg boot_messages[] = {init with any boot progress
id's you want to assign a text message too}
- The 'bootstage record' array is simply an array of int's
- show_boot_progress() logs the argument into the 'bootstage record'
array as described before
- The 'dump boot profile' command dumps the contents in the array,
looking up matches in the 'boot profile messages' array to print out
meaningful messages (or just the raw integer if no message defined)
- Can show_boot_progress() be modified to add a 'flag' to select logging
to the boot profile (do any platforms already use the highest bit for
flagging for example) - Maybe #define CONFIG_BOOTSTAGE_LOG_FLAG in the
config file to select an available bit
- Create another command to compile the boot profile into a memory (for
passing to Linux for example) - This command would need to perform
strcpy() but is not in the time critical path anymore
So the 'time' overhead of profiling is
- A call to show_boot_progress() (already there for a majority of cases)
- A timer read
- An integer test (current record MAX_RECORDS)
- A integer write to boot_messages[]
- An integer increment (current_record++)
The code impact is now negligible - no modification to show_boot_progress()
calls unless the 'profile' flag is added and only minor modifications
to the show_boot_progress() function which can all be contained in an
#ifdef
The memory overhead can be as little as almost zero (have nothing in
boot_progress_msg boot_messages[]) at the expense of you profile log
requiring code or documentation to decode (can even add a #define
CONFIG_BOOTSTAGE_MESSAGES)
Thanks for your thoughts. It can be done, but my bigger question is this:
If there is a strong appetite for that sort of patch I'm happy to do it.
If I get some +ve responses then I will do it, otherwise I think I should
assume people want this left as is.
I hope some more people are interested ;)
Regards,
Graeme
___
U-Boot mailing list
U-Boot@lists.denx.de
http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
serial debug statements might work as a poor mans timing implementation, but i think it makes sense to have a binary framework for this. -mike signature.asc Description: This is a digitally signed message part. ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Simon Glass, In message BANLkTi=0ijj7dnlsjovo-3eqjmw+rso...@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. 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? 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? 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? - 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. 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. 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(). 6. It times when the event actually
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Graeme Russ, In message BANLkTim7=-rza_l-dy0b-+adqv4ngol...@mail.gmail.com you wrote: But at 9600 baud it is over 1ms - 9600 is still considered the lowest common denominator for serial comms for diagnostic output for a lot of devices such as industrial PLCs etc. I think in the last 5 years I have seen but 2 devices using 9600 bps. All others appear to be using 115200 bps these days. And even at 9600 we're still close to millisecond reolution... And in the field, you may be interested more in transient timing anomalies which may result from network issues if the device is obtaining an IP address or loading an image file. In such scenarios, you will need to log the boot timing of every boot, not just when a serial terminal is connected time-stamping console output is not restricted to the serial port. It works as well with tty over USB, or netconsole, or even netconsole over USB. And finally, the lack of a serial port is a biggie - There are devices out there that do not have serial ports If they have a console interface, then the output can be time-stamped. 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: w...@denx.de To know how another being, another creature feels - that is impos- sible. - Terry Pratchett, _The Dark Side of the Sun_ ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Graeme Russ,
In message banlktinsypvnpg06uolze65t-fcqdn_...@mail.gmail.com you wrote:
I've thought of a 'better' approach:
- Do no modify the parameters of show_boot_progress()
- Create a new struct:
struct boot_progress_msg {
int boot_progress_id;
const char *message;
{
Where do you store this data _before_ relocation, when we have no
access to RAM yet?
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: w...@denx.de
The years of peak mental activity are undoubtedly between the ages of
four and eighteen. At four we know all the questions, at eighteen all
the answers.
___
U-Boot mailing list
U-Boot@lists.denx.de
http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On 15/05/11 03:32, Simon Glass wrote: On Sat, May 14, 2011 at 4:34 AM, Mike Frysinger vap...@gentoo.org wrote: On Friday, May 13, 2011 16:51:59 Simon Glass wrote: This defines the basics of a new boot time measurement feature. This allows logging of very accurate time measurements as the boot proceeds, by using an available microsecond counter. To enable the feature, define CONFIG_BOOTSTAGE in your board config file. Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be printed just before handing off to the OS. this seems to overlap the existing show_boot_progress() code. any chance we can look at these being merged ? -mike Hi Mike, Yes I did look at this a few weeks ago. It would be a pretty invasive change. That code just uses a whole lot of numbers which presumably are approximately how far through the boot process we are. Bootstage is intended as a debugging tool for performance tune-up rather than a user display tool. I could imagine adding a table to bootstage with the progess number for each bootstage id, but then people are going to complain that the bootstage report is far to long and includes uninteresting things. I suppose I could fix that by including a flag as to whether to report each item or not...but it any case as you can see it is not a clear win. If there is a strong appetite for that sort of patch I'm happy to do it. Regards, Simon Couple of thoughts: - Macro the definition of show_boot_progress() so it accepts a (const char *) argument if CONFIG_BOOTSTAGE is defined - Change BOOTSTAGE_COUNT to CONFIG_MAX_BOOTSTAGE_RECORDS - Any call to show_boot_progress() with a non-null second argument causes it to be logged in the next available bootstage record - After the last bootstage record is filled, no further calls to show_boot_progress() cause logging to the bootstage records - Instead of CONFIG_BOOTSTAGE_REPORT, create a command which dumps the contents of the bootstage records No this is going to result in a big patch (every instance of show_boot_progress() will need to be touched to at least add NULL as the second parameter - Maintainers can add better text later ;) Regards, Graeme ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
Dear Simon Glass, In message 1305319923-9477-1-git-send-email-...@chromium.org you wrote: This defines the basics of a new boot time measurement feature. This allows logging of very accurate time measurements as the boot proceeds, by using an available microsecond counter. Well, as long as we talk about microsecond resolution, I do not see the compelling advantage over the classic method of timing the output on the serial console port. At 115200 bps we have a resolution of better than 0.1 millisecond per character; this should be precise enough for most practical purposes. Logging and timing the serial output has a number of advantages over other solutions: - 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. - It is completely platform, SoC and board idependent - we do not need to provide any specific timer servcies etc. which are inherently platform-dependent. - 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. Can you please explain where your solution is better than this 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? 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: w...@denx.de Oh dear, I think you'll find reality's on the blink again. - Marvin The Paranoid Android ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Friday, May 13, 2011 16:51:59 Simon Glass wrote: This defines the basics of a new boot time measurement feature. This allows logging of very accurate time measurements as the boot proceeds, by using an available microsecond counter. To enable the feature, define CONFIG_BOOTSTAGE in your board config file. Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be printed just before handing off to the OS. this seems to overlap the existing show_boot_progress() code. any chance we can look at these being merged ? -mike signature.asc Description: This is a digitally signed message part. ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
Re: [U-Boot] [PATCH 0/4] Accurate boot time measurement
On Sat, May 14, 2011 at 4:34 AM, Mike Frysinger vap...@gentoo.org wrote: On Friday, May 13, 2011 16:51:59 Simon Glass wrote: This defines the basics of a new boot time measurement feature. This allows logging of very accurate time measurements as the boot proceeds, by using an available microsecond counter. To enable the feature, define CONFIG_BOOTSTAGE in your board config file. Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be printed just before handing off to the OS. this seems to overlap the existing show_boot_progress() code. any chance we can look at these being merged ? -mike Hi Mike, Yes I did look at this a few weeks ago. It would be a pretty invasive change. That code just uses a whole lot of numbers which presumably are approximately how far through the boot process we are. Bootstage is intended as a debugging tool for performance tune-up rather than a user display tool. I could imagine adding a table to bootstage with the progess number for each bootstage id, but then people are going to complain that the bootstage report is far to long and includes uninteresting things. I suppose I could fix that by including a flag as to whether to report each item or not...but it any case as you can see it is not a clear win. If there is a strong appetite for that sort of patch I'm happy to do it. Regards, Simon ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
[U-Boot] [PATCH 0/4] Accurate boot time measurement
This defines the basics of a new boot time measurement feature. This allows logging of very accurate time measurements as the boot proceeds, by using an available microsecond counter. To enable the feature, define CONFIG_BOOTSTAGE in your board config file. Also available is CONFIG_BOOTSTAGE_REPORT which will cause a report to be printed just before handing off to the OS. Example output is: Timer summary in microseconds: MarkElapsed Stage 0 0 awake 2,181,078 2,181,078 usb_start 11,861,817 9,680,739 bootp_start 11,884,610 22,793 bootp_stop 11,884,689 79 tftp start 15,271,536 3,386,847 tftp done 15,271,568 32 bootm_start 15,406,551134,983 start_kernel Simon Glass (4): Add microsecond boot time measurement Add bootstage progress report Add bootstage calls in places appropriate for network booting Add option to print boot stage report before starting kernel README | 17 + arch/arm/lib/board.c |2 + arch/arm/lib/bootm.c |4 ++ common/Makefile |1 + common/bootstage.c | 97 ++ common/cmd_bootm.c |2 + common/cmd_net.c |7 +++- common/cmd_usb.c |1 + include/bootstage.h | 74 ++ include/common.h |8 net/bootp.c |3 ++ net/net.c|1 + 12 files changed, 216 insertions(+), 1 deletions(-) create mode 100644 common/bootstage.c create mode 100644 include/bootstage.h -- 1.7.3.1 ___ U-Boot mailing list U-Boot@lists.denx.de http://lists.denx.de/mailman/listinfo/u-boot
