Skip to contentSkip to conversation

add a counter in grub_dprintf

PATCH In review Robert Millan 7 participants 17 messages Jun 19, 2008 – Jul 3, 2008

lore
Share & tools
lore
#0 lore raw

PATCH 1/1 add a counter in grub_dprintf

How about adding a counter to grub_dprintf to make it easy to instrument GRUB and find which are the bottlenecks in boot time?

Sidenote: perhaps it'd be a good idea to conditionalize all grub_dprintf calls with #ifdef DEBUG to obtain a smaller core.img. It's not hard to ask a user to rebuild if dprintf is needed, and we can find non-ugly ways to do this without massive #ifdefs all over the code.

Signature · 5 lines
Robert Millan

<GPLv2> I know my rights; I want my phone call!
<DRM> What good is a phone call… if you are unable to speak?
(as seen on /.)
include/grub/time.h renamed from grub2/include/grub/time.h +2 -0
diff -x ChangeLog -x configure -x config.h.in -x CVS -x '*~' -x '*.mk' -urp ../grub2/include/grub/time.h ./include/grub/time.h
@@ -23,6 +23,8 @@
 #include <grub/machine/time.h>
 #include <grub/cpu/time.h>
 
+extern grub_uint32_t grub_start_time;
+
 void EXPORT_FUNC(grub_millisleep) (grub_uint32_t ms);
 void EXPORT_FUNC(grub_millisleep_generic) (grub_uint32_t ms);
 
kern/main.c renamed from grub2/kern/main.c +3 -0
diff -x ChangeLog -x configure -x config.h.in -x CVS -x '*~' -x '*.mk' -urp ../grub2/kern/main.c ./kern/main.c
@@ -106,12 +106,15 @@ grub_load_normal_mode (void)
   grub_print_error ();
 }
 
+grub_uint32_t grub_start_time;
+
 /* The main routine.  */
 void
 grub_main (void)
 {
   /* First of all, initialize the machine.  */
   grub_machine_init ();
+  grub_start_time = grub_get_rtc ();
 
   /* Hello.  */
   grub_setcolorstate (GRUB_TERM_COLOR_HIGHLIGHT);
kern/misc.c renamed from grub2/kern/misc.c +9 -1
diff -x ChangeLog -x configure -x config.h.in -x CVS -x '*~' -x '*.mk' -urp ../grub2/kern/misc.c ./kern/misc.c
@@ -147,7 +147,15 @@ grub_real_dprintf (const char *file, con
   
   if (grub_strword (debug, "all") || grub_strword (debug, condition))
     {
-      grub_printf ("%s:%d: ", file, line);
+      grub_printf (
+#ifndef GRUB_UTIL
+		   "[%u] "
+#endif
+		   "%s:%d: ",
+#ifndef GRUB_UTIL
+		   grub_get_rtc () - grub_start_time,
+#endif
+		   file, line);
       va_start (args, fmt);
       grub_vprintf (fmt, args);
       va_end (args);
#1 lore raw
Quoted 6 lines · Robert Millan

How about adding a counter to grub_dprintf to make it easy to instrument GRUB and find which are the bottlenecks in boot time?

Sidenote: perhaps it'd be a good idea to conditionalize all grub_dprintf calls with #ifdef DEBUG to obtain a smaller core.img. It's not hard to ask a user to rebuild if dprintf is needed,

Are the dprintf's useful for users' debugging, not just debugging GRUB bugs? If it is, I'm not sure... If I accidentally broke something on my disk so that the core image couldn't find the modules/configuration, then it might be a little hard to rebuild grub and reinstall on that machine. Obviously I'll be able to, somehow, if my computer isn't completely hosed, but I'd rather be able to search for debugging information I recorded ASAP so I need fewer iterations of nuisance for myself. Perhaps a minor issue.

-Isaac

#2 lore raw
Quoted 8 lines · Isaac Dupree
Quoted 6 lines · Robert Millan

How about adding a counter to grub_dprintf to make it easy to instrument GRUB and find which are the bottlenecks in boot time?

Sidenote: perhaps it'd be a good idea to conditionalize all grub_dprintf calls with #ifdef DEBUG to obtain a smaller core.img. It's not hard to ask a user to rebuild if dprintf is needed,

Quoted 8 lines

Are the dprintf's useful for users' debugging, not just debugging GRUB bugs? If it is, I'm not sure... If I accidentally broke something on my disk so that the core image couldn't find the modules/configuration, then it might be a little hard to rebuild grub and reinstall on that machine. Obviously I'll be able to, somehow, if my computer isn't completely hosed, but I'd rather be able to search for debugging information I recorded ASAP so I need fewer iterations of nuisance for myself. Perhaps a minor issue.

dprintf can be useful for debugging, but not for fixing the problem (except maybe in very rare situations). So if your system can't boot, it's not going to change much.

Most users won't know about grub_dprintf untill they're told to use it to send a debug trace; so in a typical situation they would still have to boot their system somehow, in order to send us a bug report.

OTOH, it could add maintainance burden for us when we have to explain everyone that they have to rebuild and reinstall GRUB to get the debug output _and_ it opens the door for heisenbugs.

But space in post-mbr area is precious, and if we can save a bit, it means less users who will run into trouble in first place.

Signature · 5 lines
Robert Millan

<GPLv2> I know my rights; I want my phone call!
<DRM> What good is a phone call… if you are unable to speak?
(as seen on /.)
#3 lore raw
Quoted 3 lines · Robert Millan

But space in post-mbr area is precious, and if we can save a bit, it means less users who will run into trouble in first place.

Disclaimer: the following is just the product of brainstorming from a mind tortured by hours of studying projective geometry. Use with care ^^

Why not modify the build system to create _two_ instances of kernel.img, one with and another without debugging? grub_mkimage would create the normal, smaller core.img (without dprintf) for installing and embedding; and store a core_dbg.img in the /boot/grub folder, so that if instrumentation is required the only thing the users needs to do is chain that debug version of GRUB:

grub> multiboot /boot/grub/core_dbg.img
grub> boot

Another option would be to separate grub_dprintf into a module of its own that could, or could not, go into core.img depending on space pressure. We'd still need a "grub_dprintf" in the kernel, but it would just reduce to "Is debug.mod loaded? Yes->call debug_grub_dprintf". This would only result in a substantial reduction of kernel if grub_dprintf is currently a big function (and I haven't even taken a look at it) with format substitution and all. The downside is that we'd have no dprintf at all until modules are loaded, though some logic can be hardcoded so that debug.mod is loaded first, if present.

#4 lore raw
Quoted 28 lines · Javier Martín
Quoted 3 lines · Robert Millan

But space in post-mbr area is precious, and if we can save a bit, it means less users who will run into trouble in first place.

Disclaimer: the following is just the product of brainstorming from a mind tortured by hours of studying projective geometry. Use with care ^^

Why not modify the build system to create _two_ instances of kernel.img, one with and another without debugging? grub_mkimage would create the normal, smaller core.img (without dprintf) for installing and embedding; and store a core_dbg.img in the /boot/grub folder, so that if instrumentation is required the only thing the users needs to do is chain that debug version of GRUB:

grub> multiboot /boot/grub/core_dbg.img
grub> boot

Another option would be to separate grub_dprintf into a module of its own that could, or could not, go into core.img depending on space pressure. We'd still need a "grub_dprintf" in the kernel, but it would just reduce to "Is debug.mod loaded? Yes->call debug_grub_dprintf". This would only result in a substantial reduction of kernel if grub_dprintf is currently a big function (and I haven't even taken a look at it) with format substitution and all. The downside is that we'd have no dprintf at all until modules are loaded, though some logic can be hardcoded so that debug.mod is loaded first, if present.

Quoted 6 lines

_______________________________________________
Grub-devel mailing list
[email protected]
http://lists.gnu.org/mailman/listinfo/grub-devel

Or a set-grub-debug command that triggers grub to debug (load debug module) on next boot. If you're already going to hard code something. (you can set the next default boot so why not this)

Looks very logical to me.
You're only going (and want) to debug when something went wrong. (except devels)
its also the most user friendly way. you can set that flag from grub or any OS. giving you info you need but normally don't want to see.

#5 lore raw
In reply to Javier Martín
Quoted 15 lines · Javier Martín
Quoted 3 lines · Robert Millan

But space in post-mbr area is precious, and if we can save a bit, it means less users who will run into trouble in first place.

Disclaimer: the following is just the product of brainstorming from a mind tortured by hours of studying projective geometry. Use with care ^^

Why not modify the build system to create _two_ instances of kernel.img, one with and another without debugging? grub_mkimage would create the normal, smaller core.img (without dprintf) for installing and embedding; and store a core_dbg.img in the /boot/grub folder, so that if instrumentation is required the only thing the users needs to do is chain that debug version of GRUB:

Quoted 2 lines

grub> multiboot /boot/grub/core_dbg.img
grub> boot

or even to install it if necessary (if it fits! But multiboot, if it works, could help *some* of the time too). I think that prebuilt debug image is important, otherwise when users rebuild a debug version it's much more likely to be built differently somehow from the corresponding non-debug version (especially if it originally came through a packaging system such as Debian).

Quoted 6 lines · Robert Millan

OTOH, it could add maintainance burden for us when we have to explain everyone that they have to rebuild and reinstall GRUB to get the debug output _and_ it opens the door for heisenbugs.

But space in post-mbr area is precious, and if we can save a bit, it means less users who will run into trouble in first place.

the possibility for heisenbugs does seem very real given the diversity of hardware out there. Would it mitigate this to only disable the dprintfs (by default) in space-critical images such as x86 pc? (or would it make things worse...)

-Isaac

#6 lore raw
In reply to Javier Martín
Quoted 5 lines · Javier Martín

Why not modify the build system to create _two_ instances of kernel.img, one with and another without debugging? grub_mkimage would create the normal, smaller core.img (without dprintf) for installing and embedding; and store a core_dbg.img in the /boot/grub folder,

This breaks the design and forces grub-mkimage to have:

a) knowledge about GRUB paths

b) requirement for root perms

instead of just being an utility to generate images. I don't think it's a good idea.

Signature · 5 lines
Robert Millan

<GPLv2> I know my rights; I want my phone call!
<DRM> What good is a phone call… if you are unable to speak?
(as seen on /.)
#7 lore raw
Quoted 7 lines · Robert Millan
Quoted 5 lines · Javier Martín

Why not modify the build system to create _two_ instances of kernel.img, one with and another without debugging? grub_mkimage would create the normal, smaller core.img (without dprintf) for installing and embedding; and store a core_dbg.img in the /boot/grub folder,

Quoted 9 lines

This breaks the design and forces grub-mkimage to have:

a) knowledge about GRUB paths

b) requirement for root perms

instead of just being an utility to generate images. I don't think it's a good idea.

Whoops, sorry, I meant that grub_mkimage would create two core.img images, one per kernel.img version, and then grub_install would copy them as usual. Then grub_setup would embed/set up the normal core.img or the debug version based on a switch. What I propose is basically modifying grub_mkimage to allow choosing the kernel.img file used and then adding some lines to grub_install so that the two versions of core.img are generated (but only the selected is embedded).

#8 lore raw
Quoted 17 lines · Javier Martín
Quoted 7 lines · Robert Millan
Quoted 5 lines · Javier Martín

Why not modify the build system to create _two_ instances of kernel.img, one with and another without debugging? grub_mkimage would create the normal, smaller core.img (without dprintf) for installing and embedding; and store a core_dbg.img in the /boot/grub folder,

Quoted 9 lines

This breaks the design and forces grub-mkimage to have:

a) knowledge about GRUB paths

b) requirement for root perms

instead of just being an utility to generate images. I don't think it's a good idea.

Quoted 7 lines

Whoops, sorry, I meant that grub_mkimage would create two core.img images, one per kernel.img version, and then grub_install would copy them as usual. Then grub_setup would embed/set up the normal core.img or the debug version based on a switch. What I propose is basically modifying grub_mkimage to allow choosing the kernel.img file used and then adding some lines to grub_install so that the two versions of core.img are generated (but only the selected is embedded).

Ah; then it sounds fine, I guess.

Signature · 5 lines
Robert Millan

<GPLv2> I know my rights; I want my phone call!
<DRM> What good is a phone call… if you are unable to speak?
(as seen on /.)
#9 lore raw
Quoted 11 lines · Robert Millan
Quoted 7 lines · Javier Martín

Whoops, sorry, I meant that grub_mkimage would create two core.img images, one per kernel.img version, and then grub_install would copy them as usual. Then grub_setup would embed/set up the normal core.img or the debug version based on a switch. What I propose is basically modifying grub_mkimage to allow choosing the kernel.img file used and then adding some lines to grub_install so that the two versions of core.img are generated (but only the selected is embedded).

Ah; then it sounds fine, I guess.

Sorry for entering this discussion so late. I can tell from my experience that most debug code is only useful to debug once specific problem. Once the problem is fixed, the debug code is not needed. If another problem is found, then some new debug code should be written to debug that problem.

Generic debug code may be useful to get information from users if only they can reproduce the problem. But even then, if may be better to add a few lines to test certain assumptions rather than try to glean useful pieces of information from a long generic log.

Adding a complicated mechanism for having debug and non-debug images looks like an overkill to me. It could create more problems than it would fix.

Signature · 2 lines
Regards,
Pavel Roskin
#10 lore raw
Quoted 18 lines · Pavel Roskin
Quoted 10 lines · Robert Millan
Quoted 7 lines · Javier Martín

Whoops, sorry, I meant that grub_mkimage would create two core.img images, one per kernel.img version, and then grub_install would copy them as usual. Then grub_setup would embed/set up the normal core.img or the debug version based on a switch. What I propose is basically modifying grub_mkimage to allow choosing the kernel.img file used and then adding some lines to grub_install so that the two versions of core.img are generated (but only the selected is embedded).

Ah; then it sounds fine, I guess.

Sorry for entering this discussion so late. I can tell from my experience that most debug code is only useful to debug once specific problem. Once the problem is fixed, the debug code is not needed. If another problem is found, then some new debug code should be written to debug that problem.

Quoted 8 lines

Generic debug code may be useful to get information from users if only they can reproduce the problem. But even then, if may be better to add a few lines to test certain assumptions rather than try to glean useful pieces of information from a long generic log.

Adding a complicated mechanism for having debug and non-debug images looks like an overkill to me. It could create more problems than it would fix.

One way to proceed here is to use debugger for the original benchmarking purpose.

You would put timed breakpoints, when breakpoint is found, time would be recorded and then execution would be automatically continued. This can be almost fully external to the code being executed.

#11 lore raw
Quoted 7 lines · Vesa Jääskeläinen

One way to proceed here is to use debugger for the original benchmarking purpose.

You would put timed breakpoints, when breakpoint is found, time would be recorded and then execution would be automatically continued. This can be almost fully external to the code being executed.

You mean gdb over serial terminal? Never tried this. Does it work well with GRUB?

Signature · 5 lines
Robert Millan

<GPLv2> I know my rights; I want my phone call!
<DRM> What good is a phone call… if you are unable to speak?
(as seen on /.)
#12 lore raw
In reply to Pavel Roskin
Quoted 19 lines · Pavel Roskin
Quoted 11 lines · Robert Millan
Quoted 7 lines · Javier Martín

Whoops, sorry, I meant that grub_mkimage would create two core.img images, one per kernel.img version, and then grub_install would copy them as usual. Then grub_setup would embed/set up the normal core.img or the debug version based on a switch. What I propose is basically modifying grub_mkimage to allow choosing the kernel.img file used and then adding some lines to grub_install so that the two versions of core.img are generated (but only the selected is embedded).

Ah; then it sounds fine, I guess.

Sorry for entering this discussion so late. I can tell from my experience that most debug code is only useful to debug once specific problem. Once the problem is fixed, the debug code is not needed. If another problem is found, then some new debug code should be written to debug that problem.

Quoted 4 lines

Generic debug code may be useful to get information from users if only they can reproduce the problem. But even then, if may be better to add a few lines to test certain assumptions rather than try to glean useful pieces of information from a long generic log.

Ironicaly, this was also true for my original purpose of measuring performance during boot. The standard dprintf calls ate so much time (because of the serial terminal) that they didn't provide any useful output of the time spent doing something else.

In the end, I had to add custom calls to print time in the specific places where I wanted them.

Quoted 3 lines

Adding a complicated mechanism for having debug and non-debug images looks like an overkill to me. It could create more problems than it would fix.

But then, what do you suggest? That we remove debug support altogether?

Signature · 5 lines
Robert Millan

<GPLv2> I know my rights; I want my phone call!
<DRM> What good is a phone call… if you are unable to speak?
(as seen on /.)
#13 lore raw
Quoted 5 lines · Robert Millan
Quoted 3 lines

Adding a complicated mechanism for having debug and non-debug images looks like an overkill to me. It could create more problems than it would fix.

But then, what do you suggest? That we remove debug support altogether?

Keep what we have unless we are under pressure to remove it. Add new stuff only if it's likely to help debugging more than one bug.

Signature · 2 lines
Regards,
Pavel Roskin
#14 lore raw
Quoted 9 lines · Pavel Roskin
Quoted 5 lines · Robert Millan
Quoted 3 lines

Adding a complicated mechanism for having debug and non-debug images looks like an overkill to me. It could create more problems than it would fix.

But then, what do you suggest? That we remove debug support altogether?

Keep what we have unless we are under pressure to remove it.

We _are_ under pressure. Some setups are too big for core.img to fit in post-MBR region already.

Signature · 5 lines
Robert Millan

<GPLv2> I know my rights; I want my phone call!
<DRM> What good is a phone call… if you are unable to speak?
(as seen on /.)
#15 lore raw
Quoted 7 lines · Robert Millan
Quoted 6 lines · Pavel Roskin
Quoted 4 lines · Robert Millan
Quoted 3 lines

Adding a complicated mechanism for having debug and non-debug images looks like an overkill to me. It could create more problems than it would fix.

Quoted 6 lines
Quoted 3 lines
Quoted 1 line

But then, what do you suggest? That we remove debug support altogether?

Keep what we have unless we are under pressure to remove it.

We _are_ under pressure. Some setups are too big for core.img to fit in post-MBR region already.

Then parts of the debugging code that goes into core.img should be good candidates for removal. However, we could probably start with lzma conversion (or did we pick gzip?)

Signature · 2 lines
Regards,
Pavel Roskin
#16 lore raw
In reply to Robert Millan
Quoted 7 lines · Robert Millan

How about adding a counter to grub_dprintf to make it easy to instrument GRUB and find which are the bottlenecks in boot time?

Sidenote: perhaps it'd be a good idea to conditionalize all grub_dprintf calls with #ifdef DEBUG to obtain a smaller core.img. It's not hard to ask a user to rebuild if dprintf is needed, and we can find non-ugly ways to do this without massive #ifdefs all over the code.

How about a configure time switch to *disable* dprintf. I prefer to have it enabled by default. In that case distributions can create two packages. One for normal use and one for debugging.

--
Marco