Message ID | 1353422034-28107-4-git-send-email-lee.jones@linaro.org |
---|---|
State | Rejected |
Delegated to: | Wolfgang Denk |
Headers | show |
Dear Lee Jones, In message <1353422034-28107-4-git-send-email-lee.jones@linaro.org> you wrote: > Boottime is a tool which can be used for full system booting time > measurement. Bootloader boot time is passed to the kernel component > though ATAGS. The kernel-side driver then uses this information to > provide full system boot time diagnostics though debugfs. Aren't we converting more and more systems to use the device treee to pass information to the kenrel, with the result that ATAGS are kind of becoming extinct? And forcing somthing upon a mechanism that was designed for a completely different purpose, where you see right from the first glance that it does not math easily? This makes no sense to me. Why don't you use standard mechaisms, like a shared log buffer, and simply create time-stamped entries into the kernel boot log? The advantages should be obvious: we will need no extra kernel modification, we do not depend on ATAGS, and we are automatically architecture-independent. Sorry, I tend to NAK this. Best regards, Wolfgang Denk
> > Boottime is a tool which can be used for full system booting time > > measurement. Bootloader boot time is passed to the kernel component > > though ATAGS. The kernel-side driver then uses this information to > > provide full system boot time diagnostics though debugfs. > > Aren't we converting more and more systems to use the device treee to > pass information to the kenrel, with the result that ATAGS are kind > of becoming extinct? Yes, I intend to extend this functionality into Device Tree. That way it will be architecture and OS independent. > And forcing something upon a mechanism that was designed for a > completely different purpose, where you see right from the first > glance that it does not math easily? Not entirely sure what you mean here. This mechanism works perfectly with ATAGs. > This makes no sense to me. Why don't you use standard mechanisms, like > a shared log buffer, and simply create time-stamped entries into the > kernel boot log? > > The advantages should be obvious: we will need no extra kernel > modification, we do not depend on ATAGS, and we are automatically > architecture-independent. Wouldn't this clog up the kernel's log buffer? I'm sure no user wants to see reams of otherwise useless logging scrawled throughout their bootlog. We'd also have a write a text parser to obtain the information for processing. It would be easier to either pass in a struct, as we do with the ATAG mechanism, or though Device Tree as previously discussed.
Dear Lee Jones, In message <20121121095045.GI28265@gmail.com> you wrote: > > Yes, I intend to extend this functionality into Device Tree. > That way it will be architecture and OS independent. > > > And forcing something upon a mechanism that was designed for a > > completely different purpose, where you see right from the first > > glance that it does not math easily? > > Not entirely sure what you mean here. This mechanism works > perfectly with ATAGs. Neither ATAGS not the device tree are intended nor designed for passing logfile information. Yes, you can use them like that, and it will actually work. You can also drive a nail in using a microscope as hammer. > > The advantages should be obvious: we will need no extra kernel > > modification, we do not depend on ATAGS, and we are automatically > > architecture-independent. > > Wouldn't this clog up the kernel's log buffer? I'm sure no > user wants to see reams of otherwise useless logging scrawled > throughout their bootlog. We'd also have a write a text parser > to obtain the information for processing. It would be easier > to either pass in a struct, as we do with the ATAG mechanism, > or though Device Tree as previously discussed. I think these are pretty poor arguments. There are standard methods (like log levels) to provide adequate filtering of which messages are passed on to a user. An there exists a plethora of tools for automatic filtering and post-processing of syslog messages. You will need to write _less_ code than with your homebrew implementation. Best regards, Wolfgang Denk
> > Yes, I intend to extend this functionality into Device Tree. > > That way it will be architecture and OS independent. > > > > > And forcing something upon a mechanism that was designed for a > > > completely different purpose, where you see right from the first > > > glance that it does not math easily? > > > > Not entirely sure what you mean here. This mechanism works > > perfectly with ATAGs. > > Neither ATAGS not the device tree are intended nor designed for > passing logfile information. Yes, you can use them like that, and it > will actually work. ATAGs were exactly designed for this type of thing. To pass small data structures though to the kernel. In our case, our trace-points are held in a small data structure. They're not logs. > You can also drive a nail in using a microscope as hammer. Ah good idea. I have to try this. ;) > > > The advantages should be obvious: we will need no extra kernel > > > modification, we do not depend on ATAGS, and we are automatically > > > architecture-independent. > > > > Wouldn't this clog up the kernel's log buffer? I'm sure no > > user wants to see reams of otherwise useless logging scrawled > > throughout their bootlog. We'd also have a write a text parser > > to obtain the information for processing. It would be easier > > to either pass in a struct, as we do with the ATAG mechanism, > > or though Device Tree as previously discussed. > > I think these are pretty poor arguments. There are standard methods > (like log levels) to provide adequate filtering of which messages are > passed on to a user. An there exists a plethora of tools for > automatic filtering and post-processing of syslog messages. You will > need to write _less_ code than with your homebrew implementation. They're not poor augments if the data stored isn't log messages, which these aren't. If anything I would say that ramming them in as textual kernel messages, then parsing the log text using a userspace tool was an abuse of the system. If we create them as data in the bootloader, then pass them to the kernel as data, then process them as data, _that_ would be the correct mechanism.
Dear Lee Jones, In message <20121121150332.GC28899@gmail.com> you wrote: > > > Neither ATAGS not the device tree are intended nor designed for > > passing logfile information. Yes, you can use them like that, and it > > will actually work. > > ATAGs were exactly designed for this type of thing. To pass small > data structures though to the kernel. In our case, our trace-points > are held in a small data structure. They're not logs. You appear to have a specific definition of log data in mind. It must be different to mine. Also, you contradict yourself - here you write "pass small data structures", earlier you wrote about "lots of trace-points", which sounds as if the total amount of data would be not exactly small - actually so big that yu are afraid of annoying users with it. Anyway. This doesn't take us further. > They're not poor augments if the data stored isn't log messages, > which these aren't. If anything I would say that ramming them in as > textual kernel messages, then parsing the log text using a userspace > tool was an abuse of the system. If we create them as data in the > bootloader, then pass them to the kernel as data, then process them > as data, _that_ would be the correct mechanism. Well, I could pooint out here a number of pretty basic design decisions made earlier in a number of pretty important and successful software projects, like the fact that a large number of internet protocols are based on plain text implementations. Or how useful it is if you can just to a post-mortem dump of the log buffer and actually _read_ the entries, without need to special tools. I think I should stop here, though. It appears it makes little sense trying to discuss alternative approaches when you have already fixed your mind about the one and only "correct" way to do this. To summarize: NAK. Best regards, Wolfgang Denk
On Wed, 21 Nov 2012, Wolfgang Denk wrote: > Dear Lee Jones, > > In message <20121121150332.GC28899@gmail.com> you wrote: > > > > > Neither ATAGS not the device tree are intended nor designed for > > > passing logfile information. Yes, you can use them like that, and it > > > will actually work. > > > > ATAGs were exactly designed for this type of thing. To pass small > > data structures though to the kernel. In our case, our trace-points > > are held in a small data structure. They're not logs. > > You appear to have a specific definition of log data in mind. It must > be different to mine. I would say that a log entry would contain useful descriptive information contained. It is _sometimes_ useful to display a related timestamp too. In our case, the most useful part is the timestamp. I just don't see how riddling the kernel log with timestamps would be useful, or nessersary. > Also, you contradict yourself - here you write "pass small data > structures", earlier you wrote about "lots of trace-points", which > sounds as if the total amount of data would be not exactly small - > actually so big that yu are afraid of annoying users with it. Right, perhaps I should have been more descriptive. I don't see the bootloader passing lots of these trace points. The current configuration will allow 10; however, the kernel logs one for every cecal. This would quickly fill the kernel log with lots of unwanted bumph. I also would like to store the data for bootloader and kernel in the same manor. Placing the bootloader's trace points in the kernel log, then putting the kernel's ones somewhere else would add unwanted complexity. Especially if you're wanting the user to write an app for parsing. I would prefer it if all of the processing could be done in the kernel and displayed nicely via debugfs. > Anyway. This doesn't take us further. > > > They're not poor augments if the data stored isn't log messages, > > which these aren't. If anything I would say that ramming them in as > > textual kernel messages, then parsing the log text using a userspace > > tool was an abuse of the system. If we create them as data in the > > bootloader, then pass them to the kernel as data, then process them > > as data, _that_ would be the correct mechanism. > > Well, I could pooint out here a number of pretty basic design > decisions made earlier in a number of pretty important and successful > software projects, like the fact that a large number of internet > protocols are based on plain text implementations. Or how useful it > is if you can just to a post-mortem dump of the log buffer and > actually _read_ the entries, without need to special tools. You can do that in the current implementation though debugfs: $ cat /sys/kernel/debug/boottime/bootgraph [ 0.023024] calling board_init+0x0/0x0 [ 0.177808] initcall board_init+0x0/0x0 returned 0 after 154 msecs. [ 0.177808] calling main_loop+0x0/0x0 [ 0.179632] initcall main_loop+0x0/0x0 returned 0 after 1 msecs. It is your suggestion that would require _extra_ bespoke tools for parsing and actually obtaining the information you require. Where as we can just do this: $ cat /sys/kernel/debug/boottime/summary bootloader: 5484 msecs kernel: 2265 msecs total: 7750 msecs kernel: cpu0 system: 75% idle: 25% iowait: 0% irq: 0% cpu1 system: 2% idle: 97% iowait: 0% irq: 0% bootloader: cpu0 system: 100% idle: 0% iowait: 0% irq: 0% > I think I should stop here, though. It appears it makes little sense > trying to discuss alternative approaches when you have already fixed > your mind about the one and only "correct" way to do this. Not at all. I am open to new and different approaches, so long as they are better. I just don't agree that munging a timestamp and id (usually a function name) into a text string and shoving it into the kernel's log buffer is in any way 'better'. I hope you can at least see my point.
Dear Lee Jones, In message <20121121172604.GB417@gmail.com> you wrote: > > > You appear to have a specific definition of log data in mind. It must > > be different to mine. > > I would say that a log entry would contain useful descriptive > information contained. It is _sometimes_ useful to display a related > timestamp too. In our case, the most useful part is the timestamp. > I just don't see how riddling the kernel log with timestamps would > be useful, or nessersary. Look here: ... [ 85.005969] it87: Found IT8718F chip at 0x290, revision 5 [ 85.041976] it87: VID is disabled (pins used for GPIO) [ 85.081038] it87: Beeping is supported [ 86.283285] r8169 0000:04:00.0: eth0: link down [ 86.283307] r8169 0000:04:00.0: eth0: link down [ 86.348499] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready [ 88.688543] r8169 0000:04:00.0: eth0: link up [ 88.723985] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready [ 89.583337] Bridge firewalling registered [ 89.642103] device virbr0-nic entered promiscuous mode ... You tell me what is the most interesting information here, the "descriptive information", or the "related timestamp"? In many cases, and for many people, it's not one or the other, but _both_. But we're repeating ourselfs. I see no new arguments. Let's stop here. Best regards, Wolfgang Denk
Hi Lee, On Tue, Nov 20, 2012 at 6:33 AM, Lee Jones <lee.jones@linaro.org> wrote: > Boottime is a tool which can be used for full system booting time > measurement. Bootloader boot time is passed to the kernel component > though ATAGS. The kernel-side driver then uses this information to > provide full system boot time diagnostics though debugfs. > > Based heavily on the original driver by Jonas Aaberg. > > Signed-off-by: Lee Jones <lee.jones@linaro.org> Did you take a look at bootstage, which seems at least on the surface to provide a similar mechanism? This passes the information to the kernel through a device tree, or worse case a 'stash area'. Regards, Simon
Hi Simon, > On Tue, Nov 20, 2012 at 6:33 AM, Lee Jones <lee.jones@linaro.org> wrote: > > Boottime is a tool which can be used for full system booting time > > measurement. Bootloader boot time is passed to the kernel component > > though ATAGS. The kernel-side driver then uses this information to > > provide full system boot time diagnostics though debugfs. > > > > Based heavily on the original driver by Jonas Aaberg. > > > > Signed-off-by: Lee Jones <lee.jones@linaro.org> > > Did you take a look at bootstage, which seems at least on the surface > to provide a similar mechanism? This passes the information to the > kernel through a device tree, or worse case a 'stash area'. I didn't see this before. I don't see the kernel counterpart, did it make it upstream? Wolfgang, didn't you know about bootstage? This could have saved us a great deal of time. Kind regards, Lee
Hi Lee, On Mon, Nov 26, 2012 at 1:00 AM, Lee Jones <lee.jones@linaro.org> wrote: > Hi Simon, > >> On Tue, Nov 20, 2012 at 6:33 AM, Lee Jones <lee.jones@linaro.org> wrote: >> > Boottime is a tool which can be used for full system booting time >> > measurement. Bootloader boot time is passed to the kernel component >> > though ATAGS. The kernel-side driver then uses this information to >> > provide full system boot time diagnostics though debugfs. >> > >> > Based heavily on the original driver by Jonas Aaberg. >> > >> > Signed-off-by: Lee Jones <lee.jones@linaro.org> >> >> Did you take a look at bootstage, which seems at least on the surface >> to provide a similar mechanism? This passes the information to the >> kernel through a device tree, or worse case a 'stash area'. > > I didn't see this before. > > I don't see the kernel counterpart, did it make it upstream? It was sent upstream, just for a feeler, but before U-Boot support was mainlined and before we had a way to deal with the non-fdt case. That is now implemented and in mainline, although it has not yet gone out in a release (should be Jan 2013). So I was planning to address that again in the kernel at some point. > > Wolfgang, didn't you know about bootstage? This could have saved > us a great deal of time. > > Kind regards, > Lee > > -- > Lee Jones > Linaro ST-Ericsson Landing Team Lead > Linaro.org │ Open source software for ARM SoCs > Follow Linaro: Facebook | Twitter | Blog Regards, Simon
Hi Simon, > >> On Tue, Nov 20, 2012 at 6:33 AM, Lee Jones <lee.jones@linaro.org> wrote: > >> > Boottime is a tool which can be used for full system booting time > >> > measurement. Bootloader boot time is passed to the kernel component > >> > though ATAGS. The kernel-side driver then uses this information to > >> > provide full system boot time diagnostics though debugfs. > >> > > >> > Based heavily on the original driver by Jonas Aaberg. > >> > > >> > Signed-off-by: Lee Jones <lee.jones@linaro.org> > >> > >> Did you take a look at bootstage, which seems at least on the surface > >> to provide a similar mechanism? This passes the information to the > >> kernel through a device tree, or worse case a 'stash area'. > > > > I didn't see this before. > > > > I don't see the kernel counterpart, did it make it upstream? > > It was sent upstream, just for a feeler, but before U-Boot support was > mainlined and before we had a way to deal with the non-fdt case. That > is now implemented and in mainline, although it has not yet gone out > in a release (should be Jan 2013). So I was planning to address that > again in the kernel at some point. Well if this does the same job as the boottime implementation, I'll scrap my efforts to upstream it. By the way, if Wolfgang didn't want these tracepoints in DT, then how was your implementations upstreamed into u-boot? Kind regards, Lee
Dear Lee Jones, In message <20121127085548.GC7897@gmail.com> you wrote: > > By the way, if Wolfgang didn't want these tracepoints in DT, then > how was your implementations upstreamed into u-boot? Because I don;t manage a 100% review coverage over all submitted patches, i. e. it escaped my attention (and I'm sorry for that). Best regards, Wolfgang Denk
On Tue, 27 Nov 2012, Wolfgang Denk wrote: > Dear Lee Jones, > > In message <20121127085548.GC7897@gmail.com> you wrote: > > > > By the way, if Wolfgang didn't want these tracepoints in DT, then > > how was your implementations upstreamed into u-boot? > > Because I don;t manage a 100% review coverage over all submitted > patches, i. e. it escaped my attention (and I'm sorry for that). Ah, I see. Makes sense. Well I'm pleased someone saw sense in any case. :)
diff --git a/common/Makefile b/common/Makefile index 9e43322..546acbf 100644 --- a/common/Makefile +++ b/common/Makefile @@ -192,6 +192,7 @@ COBJS-$(CONFIG_MODEM_SUPPORT) += modem.o COBJS-$(CONFIG_UPDATE_TFTP) += update.o COBJS-$(CONFIG_USB_KEYBOARD) += usb_kbd.o COBJS-$(CONFIG_CMD_DFU) += cmd_dfu.o +COBJS-$(CONFIG_BOOTTIME) += boottime.o endif ifdef CONFIG_SPL_BUILD diff --git a/common/boottime.c b/common/boottime.c new file mode 100644 index 0000000..87be467 --- /dev/null +++ b/common/boottime.c @@ -0,0 +1,146 @@ +/* + * Copyright (C) ST-Ericsson SA 2009-2010 + * Jonas Aaberg <jonas.aberg@stericsson.com> + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + * + */ + +#include <common.h> +#include <boottime.h> +#include <asm/byteorder.h> +#include <asm/setup.h> + +#ifdef CONFIG_BOOTTIME + +static struct tag_boottime boottime = { + .idle = 0, + .total = 0, +}; + +void boottime_tag(char *name) +{ + if (boottime.num == BOOTTIME_MAX) { + printf("boottime: out of entries!\n"); + return; + } + + strncpy((char *)boottime.entry[boottime.num].name, + name, + BOOTTIME_MAX_NAME_LEN); + boottime.entry[boottime.num].name[BOOTTIME_MAX_NAME_LEN - 1] = '\0'; + boottime.entry[boottime.num].time = get_timer_us(); + + boottime.num++; +} + +struct boottime_entry *boottime_get_entry(unsigned int i) +{ + if (i >= boottime.num) + return NULL; + else + return &boottime.entry[i]; +} + +void boottime_idle_add(unsigned long time) +{ + boottime.idle += time; +} + +unsigned long boottime_idle_done(void) +{ + return get_timer_us(); +} + +unsigned long boottime_idle_get(void) +{ + return boottime.idle; +} + +static int do_boottime(cmd_tbl_t *cmdtp, int flag, int argc, char *argv[]) +{ + unsigned int i; + struct boottime_entry *entry; + + for (i = 0; i < BOOTTIME_MAX; i++) { + entry = boottime_get_entry(i); + if (entry == NULL) + break; + printf("%s: started at %lu ms\n", entry->name, + (unsigned long)entry->time / 1000); + } + printf("idle: %d%% (%d ms)\n", + 100 * (int)boottime_idle_get() / (int)get_timer_us(), + (int)boottime_idle_get() / 1000); + return 0; +} + +static int do_boottime_tag (cmd_tbl_t *cmdtp, int flag, int argc, char *argv[]) +{ + + if (argc < 2) { + cmd_usage(cmdtp); + return 1; + } + boottime_tag(argv[1]); + + return 0; +} + +U_BOOT_CMD( + boottime, 1, 1, do_boottime, + "print boottime info", + "" + " - print boottime tags\n" +); + +U_BOOT_CMD( + boottime_tag, 2, 1, do_boottime_tag, + "boottime tag 'name'", + "" + " - Add a boottime tag at the current time\n" +); + +#else +/* + * Dummy functions when boottime is not enabled. + */ +static int do_boottime_tag (cmd_tbl_t *cmdtp, int flag, int argc, char *argv[]) +{ + return 0; +} + +void boottime_tag(char *name) +{ + +} + +void boottime_idle_add(unsigned long time) +{ + +} + +U_BOOT_CMD( + boottime_tag, 2, 1, do_boottime_tag, + "boottime tag 'name'", + "" + " - NOT ENABLED: Add CONFIG_BOOTIME to your boards configuration" + " file to enable boottime.\n" +); + +#endif + + + diff --git a/include/boottime.h b/include/boottime.h new file mode 100644 index 0000000..58ea314 --- /dev/null +++ b/include/boottime.h @@ -0,0 +1,86 @@ +/* + * Copyright (C) ST-Ericsson SA 2009-2010 + * Jonas Aaberg <jonas.aberg@stericsson.com> + * + * This program is free software; you can redistribute it and/or modify + * it under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 2 of the License, or + * (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, MA 02111-1307 USA + * + */ + +#ifndef BOOTTIME_H +#define BOOTTIME_H + +#define BOOTTIME_MAX_NAME_LEN 64 + +struct boottime_entry { + u32 time; /* in us */ + u8 name[BOOTTIME_MAX_NAME_LEN]; +}; + +#ifdef CONFIG_BOOTTIME + +/** + * boottime_tag() + * Add a sample point with a name now. Shall be called before function "name" + * is executed. + * @name: Sample point name. + */ +void boottime_tag(char *name); + +/** + * boottime_get_entry() + * + * Loads a boottime measure point information. + * @i: boottime measurement point entry. + * + * Returns a boottime entry. NULL, if not existing. + */ +struct boottime_entry *boottime_get_entry(unsigned int i); + +/** + * boottime_idle_get() + * + * Returns the amount of time in us that has been spent idling. + */ +unsigned long boottime_idle_get(void); + +/** + * boottime_idle_done() + * + * Returns the total time since start in us. + */ +unsigned long boottime_idle_done(void); + +/** + * boottime_idle_add() + * + * This function shall be added to all delay() functions. + * The delay time input to delay() shall be provided to this + * function as well. It is used to calculate average load + * during boot. + * @time: time in us. + */ +void boottime_idle_add(unsigned long time); + +#else /* CONFIG_BOOTTIME */ + +static inline void boottime_tag(char *name) { return; } +static inline struct boottime_entry *boottime_get_entry(unsigned int i) { return NULL; } +static inline unsigned long boottime_idle_get(void) { return 0; } +static inline unsigned long boottime_idle_done(void) { return 0; } +static inline void boottime_idle_add(unsigned long time) { return; } + +#endif /* CONFIG_BOOTTIME */ + +#endif /* BOOTTIME_H */
Boottime is a tool which can be used for full system booting time measurement. Bootloader boot time is passed to the kernel component though ATAGS. The kernel-side driver then uses this information to provide full system boot time diagnostics though debugfs. Based heavily on the original driver by Jonas Aaberg. Signed-off-by: Lee Jones <lee.jones@linaro.org> --- common/Makefile | 1 + common/boottime.c | 146 ++++++++++++++++++++++++++++++++++++++++++++++++++++ include/boottime.h | 86 +++++++++++++++++++++++++++++++ 3 files changed, 233 insertions(+) create mode 100644 common/boottime.c create mode 100644 include/boottime.h