Implement boot time analysis framework.
This commit is contained in:
parent
e5a2dd7b55
commit
e744219bb6
14 changed files with 232 additions and 8 deletions
|
@ -1,6 +1,10 @@
|
|||
2013-03-19 Vladimir Serbinenko <phcoder@gmail.com>
|
||||
|
||||
remove get_endpoint_descriptor and change all functions needing
|
||||
Implement boot time analysis framework.
|
||||
|
||||
2013-03-19 Vladimir Serbinenko <phcoder@gmail.com>
|
||||
|
||||
Remove get_endpoint_descriptor and change all functions needing
|
||||
descriptor to just receive it as argument rather than endpoint
|
||||
address.
|
||||
|
||||
|
|
|
@ -8,6 +8,7 @@
|
|||
|
||||
/* Define to 1 to enable disk cache statistics. */
|
||||
#define DISK_CACHE_STATS @DISK_CACHE_STATS@
|
||||
#define BOOT_TIME_STATS @BOOT_TIME_STATS@
|
||||
|
||||
#if defined (GRUB_UTIL) || !defined (GRUB_MACHINE)
|
||||
#include <config-util.h>
|
||||
|
|
19
configure.ac
19
configure.ac
|
@ -798,6 +798,17 @@ else
|
|||
fi
|
||||
AC_SUBST([DISK_CACHE_STATS])
|
||||
|
||||
AC_ARG_ENABLE([boot-time],
|
||||
AS_HELP_STRING([--enable-boot-time],
|
||||
[enable boot time statistics collection]))
|
||||
|
||||
if test x$enable_boot_time = xyes; then
|
||||
BOOT_TIME_STATS=1
|
||||
else
|
||||
BOOT_TIME_STATS=0
|
||||
fi
|
||||
AC_SUBST([BOOT_TIME_STATS])
|
||||
|
||||
AC_ARG_ENABLE([grub-emu-usb],
|
||||
[AS_HELP_STRING([--enable-grub-emu-usb],
|
||||
[build and install the `grub-emu' debugging utility with USB support (default=guessed)])])
|
||||
|
@ -1159,6 +1170,7 @@ AM_CONDITIONAL([COND_GRUB_PE2ELF], [test x$TARGET_OBJ2ELF != x])
|
|||
AM_CONDITIONAL([COND_APPLE_CC], [test x$TARGET_APPLE_CC = x1])
|
||||
AM_CONDITIONAL([COND_ENABLE_EFIEMU], [test x$enable_efiemu = xyes])
|
||||
AM_CONDITIONAL([COND_ENABLE_CACHE_STATS], [test x$DISK_CACHE_STATS = x1])
|
||||
AM_CONDITIONAL([COND_ENABLE_BOOT_TIME_STATS], [test x$BOOT_TIME_STATS = x1])
|
||||
|
||||
AM_CONDITIONAL([COND_HAVE_ASM_USCORE], [test x$HAVE_ASM_USCORE = x1])
|
||||
AM_CONDITIONAL([COND_CYGWIN], [test x$host_os = xcygwin])
|
||||
|
@ -1231,6 +1243,13 @@ echo With disk cache statistics: Yes
|
|||
else
|
||||
echo With disk cache statistics: No
|
||||
fi
|
||||
|
||||
if [ x"$enable_boot_time" = xyes ]; then
|
||||
echo With boot time statistics: Yes
|
||||
else
|
||||
echo With boot time statistics: No
|
||||
fi
|
||||
|
||||
if [ x"$efiemu_excuse" = x ]; then
|
||||
echo efiemu runtime: Yes
|
||||
else
|
||||
|
|
|
@ -1868,6 +1868,12 @@ module = {
|
|||
condition = COND_ENABLE_CACHE_STATS;
|
||||
};
|
||||
|
||||
module = {
|
||||
name = boottime;
|
||||
common = commands/boottime.c;
|
||||
condition = COND_ENABLE_BOOT_TIME_STATS;
|
||||
};
|
||||
|
||||
module = {
|
||||
name = adler32;
|
||||
common = lib/adler32.c;
|
||||
|
|
|
@ -715,6 +715,7 @@ grub_ehci_pci_iter (grub_pci_device_t dev, grub_pci_id_t pciid,
|
|||
usblegsup = grub_pci_read (pciaddr_eecp);
|
||||
if (usblegsup & GRUB_EHCI_BIOS_OWNED)
|
||||
{
|
||||
grub_boot_time ("Taking ownership of EHCI port");
|
||||
grub_dprintf ("ehci",
|
||||
"EHCI grub_ehci_pci_iter: EHCI owned by: BIOS\n");
|
||||
/* Ownership change - set OS_OWNED bit */
|
||||
|
@ -741,6 +742,7 @@ grub_ehci_pci_iter (grub_pci_device_t dev, grub_pci_id_t pciid,
|
|||
/* Ensure PCI register is written */
|
||||
grub_pci_read (pciaddr_eecp);
|
||||
}
|
||||
grub_boot_time ("Ownership of EHCI port taken");
|
||||
}
|
||||
else if (usblegsup & GRUB_EHCI_OS_OWNED)
|
||||
/* XXX: What to do in this case - nothing ? Can it happen ? */
|
||||
|
@ -1706,10 +1708,12 @@ grub_ehci_portstatus (grub_usb_controller_t dev,
|
|||
/* Reset RESET bit and wait for the end of reset */
|
||||
grub_ehci_port_resbits (e, port, GRUB_EHCI_PORT_RESET);
|
||||
endtime = grub_get_time_ms () + 1000;
|
||||
grub_boot_time ("Resetting port %d", port);
|
||||
while (grub_ehci_port_read (e, port) & GRUB_EHCI_PORT_RESET)
|
||||
if (grub_get_time_ms () > endtime)
|
||||
return grub_error (GRUB_ERR_IO,
|
||||
"portstatus: EHCI Timed out - reset port");
|
||||
grub_boot_time ("Port %d reset", port);
|
||||
/* Remember "we did the reset" - needed by detect_dev */
|
||||
e->reset |= (1 << port);
|
||||
/* Test if port enabled, i.e. HIGH speed device connected */
|
||||
|
@ -1911,8 +1915,11 @@ GRUB_MOD_INIT (ehci)
|
|||
{
|
||||
COMPILE_TIME_ASSERT (sizeof (struct grub_ehci_td) == 64);
|
||||
COMPILE_TIME_ASSERT (sizeof (struct grub_ehci_qh) == 96);
|
||||
grub_boot_time ("Initing EHCI hardware");
|
||||
grub_ehci_inithw ();
|
||||
grub_boot_time ("Registering EHCI driver");
|
||||
grub_usb_controller_dev_register (&usb_controller);
|
||||
grub_boot_time ("EHCI driver registered");
|
||||
grub_loader_register_preboot_hook (grub_ehci_fini_hw, grub_ehci_restore_hw,
|
||||
GRUB_LOADER_PREBOOT_HOOK_PRIO_DISK);
|
||||
}
|
||||
|
|
|
@ -262,8 +262,13 @@ void grub_usb_device_attach (grub_usb_device_t dev)
|
|||
continue;
|
||||
|
||||
for (desc = attach_hooks; desc; desc = desc->next)
|
||||
if (interf->class == desc->class && desc->hook (dev, 0, i))
|
||||
dev->config[0].interf[i].attached = 1;
|
||||
if (interf->class == desc->class)
|
||||
{
|
||||
grub_boot_time ("Probing USB device driver class %x", desc->class);
|
||||
if (desc->hook (dev, 0, i))
|
||||
dev->config[0].interf[i].attached = 1;
|
||||
grub_boot_time ("Probed USB device driver class %x", desc->class);
|
||||
}
|
||||
|
||||
if (dev->config[0].interf[i].attached)
|
||||
continue;
|
||||
|
|
|
@ -52,6 +52,8 @@ grub_usb_hub_add_dev (grub_usb_controller_t controller,
|
|||
int i;
|
||||
grub_usb_err_t err;
|
||||
|
||||
grub_boot_time ("Attaching USB device");
|
||||
|
||||
dev = grub_zalloc (sizeof (struct grub_usb_device));
|
||||
if (! dev)
|
||||
return NULL;
|
||||
|
@ -108,8 +110,12 @@ grub_usb_hub_add_dev (grub_usb_controller_t controller,
|
|||
|
||||
/* Wait "recovery interval", spec. says 2ms */
|
||||
grub_millisleep (2);
|
||||
|
||||
grub_boot_time ("Probing USB device driver");
|
||||
|
||||
grub_usb_device_attach (dev);
|
||||
|
||||
grub_boot_time ("Attached USB device");
|
||||
|
||||
return dev;
|
||||
}
|
||||
|
@ -194,6 +200,8 @@ attach_root_port (struct grub_usb_hub *hub, int portno,
|
|||
grub_usb_speed_t current_speed = GRUB_USB_SPEED_NONE;
|
||||
int changed=0;
|
||||
|
||||
grub_boot_time ("detect_dev USB root portno=%d\n", portno);
|
||||
|
||||
#if 0
|
||||
/* Specification does not say about disabling of port when device
|
||||
* connected. If disabling is really necessary for some devices,
|
||||
|
@ -203,6 +211,9 @@ attach_root_port (struct grub_usb_hub *hub, int portno,
|
|||
if (err)
|
||||
return;
|
||||
#endif
|
||||
|
||||
grub_boot_time ("Before the stable power wait portno=%d", portno);
|
||||
|
||||
/* Wait for completion of insertion and stable power (USB spec.)
|
||||
* Should be at least 100ms, some devices requires more...
|
||||
* There is also another thing - some devices have worse contacts
|
||||
|
@ -239,6 +250,8 @@ attach_root_port (struct grub_usb_hub *hub, int portno,
|
|||
/* If the device is a Hub, scan it for more devices. */
|
||||
if (dev->descdev.class == 0x09)
|
||||
grub_usb_add_hub (dev);
|
||||
|
||||
grub_boot_time ("Attached root port");
|
||||
}
|
||||
|
||||
grub_usb_err_t
|
||||
|
@ -248,6 +261,8 @@ grub_usb_root_hub (grub_usb_controller_t controller)
|
|||
struct grub_usb_hub *hub;
|
||||
int changed=0;
|
||||
|
||||
grub_boot_time ("Registering USB root hub");
|
||||
|
||||
hub = grub_malloc (sizeof (*hub));
|
||||
if (!hub)
|
||||
return GRUB_USB_ERR_INTERNAL;
|
||||
|
@ -287,6 +302,8 @@ grub_usb_root_hub (grub_usb_controller_t controller)
|
|||
}
|
||||
}
|
||||
|
||||
grub_boot_time ("USB root hub registered");
|
||||
|
||||
return GRUB_USB_ERR_NONE;
|
||||
}
|
||||
|
||||
|
@ -407,12 +424,13 @@ poll_nonroot_hub (grub_usb_device_t dev)
|
|||
/* Connected and status of connection changed ? */
|
||||
if (status & GRUB_USB_HUB_STATUS_PORT_CONNECTED)
|
||||
{
|
||||
grub_boot_time ("Before the stable power wait portno=%d", i);
|
||||
/* A device is actually connected to this port. */
|
||||
/* Wait for completion of insertion and stable power (USB spec.)
|
||||
* Should be at least 100ms, some devices requires more...
|
||||
* There is also another thing - some devices have worse contacts
|
||||
* and connected signal is unstable for some time - we should handle
|
||||
* it - but prevent deadlock in case when device is too faulty... */
|
||||
/* Wait for completion of insertion and stable power (USB spec.)
|
||||
* Should be at least 100ms, some devices requires more...
|
||||
* There is also another thing - some devices have worse contacts
|
||||
* and connected signal is unstable for some time - we should handle
|
||||
* it - but prevent deadlock in case when device is too faulty... */
|
||||
for (total = j = 0; (j < 250) && (total < 2000); j++, total++)
|
||||
{
|
||||
grub_millisleep (1);
|
||||
|
@ -432,6 +450,9 @@ poll_nonroot_hub (grub_usb_device_t dev)
|
|||
if (!(current_status & GRUB_USB_HUB_STATUS_PORT_CONNECTED))
|
||||
j = 0;
|
||||
}
|
||||
|
||||
grub_boot_time ("After the stable power wait portno=%d", i);
|
||||
|
||||
grub_dprintf ("usb", "(non-root) total=%d\n", total);
|
||||
if (total >= 2000)
|
||||
continue;
|
||||
|
@ -443,6 +464,8 @@ poll_nonroot_hub (grub_usb_device_t dev)
|
|||
GRUB_USB_REQ_SET_FEATURE,
|
||||
GRUB_USB_HUB_FEATURE_PORT_RESET,
|
||||
i, 0, 0);
|
||||
grub_boot_time ("Resetting port %d", i);
|
||||
|
||||
rescan = 1;
|
||||
/* We cannot reset more than one device at the same time !
|
||||
* Resetting more devices together results in very bad
|
||||
|
@ -464,6 +487,8 @@ poll_nonroot_hub (grub_usb_device_t dev)
|
|||
GRUB_USB_REQ_CLEAR_FEATURE,
|
||||
GRUB_USB_HUB_FEATURE_C_PORT_RESET, i, 0, 0);
|
||||
|
||||
grub_boot_time ("Port %d reset", i);
|
||||
|
||||
if (status & GRUB_USB_HUB_STATUS_PORT_CONNECTED)
|
||||
{
|
||||
grub_usb_speed_t speed;
|
||||
|
|
66
grub-core/commands/boottime.c
Normal file
66
grub-core/commands/boottime.c
Normal file
|
@ -0,0 +1,66 @@
|
|||
/* cacheinfo.c - disk cache statistics */
|
||||
/*
|
||||
* GRUB -- GRand Unified Bootloader
|
||||
* Copyright (C) 2008,2010 Free Software Foundation, Inc.
|
||||
*
|
||||
* GRUB 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 3 of the License, or
|
||||
* (at your option) any later version.
|
||||
*
|
||||
* GRUB 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 GRUB. If not, see <http://www.gnu.org/licenses/>.
|
||||
*/
|
||||
|
||||
#include <grub/dl.h>
|
||||
#include <grub/misc.h>
|
||||
#include <grub/command.h>
|
||||
#include <grub/i18n.h>
|
||||
|
||||
GRUB_MOD_LICENSE ("GPLv3+");
|
||||
|
||||
|
||||
static grub_err_t
|
||||
grub_cmd_boottime (struct grub_command *cmd __attribute__ ((unused)),
|
||||
int argc __attribute__ ((unused)),
|
||||
char *argv[] __attribute__ ((unused)))
|
||||
{
|
||||
struct grub_boot_time *cur;
|
||||
grub_uint64_t last_time = 0, start_time = 0;
|
||||
if (!grub_boot_time_head)
|
||||
{
|
||||
grub_puts_ (N_("No boot time statistics is available\n"));
|
||||
return 0;
|
||||
}
|
||||
start_time = last_time = grub_boot_time_head->tp;
|
||||
for (cur = grub_boot_time_head; cur; cur = cur->next)
|
||||
{
|
||||
grub_uint32_t tmabs = cur->tp - start_time;
|
||||
grub_uint32_t tmrel = cur->tp - last_time;
|
||||
last_time = cur->tp;
|
||||
|
||||
grub_printf ("%3d.%03ds %2d.%03ds %s:%d %s\n",
|
||||
tmabs / 1000, tmabs % 1000, tmrel / 1000, tmrel % 1000, cur->file, cur->line,
|
||||
cur->msg);
|
||||
}
|
||||
return 0;
|
||||
}
|
||||
|
||||
static grub_command_t cmd_boottime;
|
||||
|
||||
GRUB_MOD_INIT(boottime)
|
||||
{
|
||||
cmd_boottime =
|
||||
grub_register_command ("boottime", grub_cmd_boottime,
|
||||
0, N_("Get boot time statistics."));
|
||||
}
|
||||
|
||||
GRUB_MOD_FINI(boottime)
|
||||
{
|
||||
grub_unregister_command (cmd_boottime);
|
||||
}
|
|
@ -151,6 +151,8 @@ grub_usbms_attach (grub_usb_device_t usbdev, int configno, int interfno)
|
|||
unsigned curnum;
|
||||
grub_usb_err_t err = GRUB_ERR_NONE;
|
||||
|
||||
grub_boot_time ("Attaching USB mass storage");
|
||||
|
||||
if (first_available_slot == ARRAY_SIZE (grub_usbms_devices))
|
||||
return 0;
|
||||
|
||||
|
@ -246,6 +248,8 @@ grub_usbms_attach (grub_usb_device_t usbdev, int configno, int interfno)
|
|||
|
||||
usbdev->config[configno].interf[interfno].detach_hook = grub_usbms_detach;
|
||||
|
||||
grub_boot_time ("Attached USB mass storage");
|
||||
|
||||
#if 0 /* All this part should be probably deleted.
|
||||
* This make trouble on some devices if they are not in
|
||||
* Phase Error state - and there they should be not in such state...
|
||||
|
|
|
@ -648,7 +648,10 @@ grub_dl_load_core (void *addr, grub_size_t size)
|
|||
|
||||
grub_dprintf ("modules", "module name: %s\n", mod->name);
|
||||
grub_dprintf ("modules", "init function: %p\n", mod->init);
|
||||
|
||||
grub_boot_time ("Initing module %s", mod->name);
|
||||
grub_dl_call_init (mod);
|
||||
grub_boot_time ("Module %s inited", mod->name);
|
||||
|
||||
if (grub_dl_add (mod))
|
||||
{
|
||||
|
|
|
@ -254,6 +254,8 @@ grub_main (void)
|
|||
/* First of all, initialize the machine. */
|
||||
grub_machine_init ();
|
||||
|
||||
grub_boot_time ("After machine init.");
|
||||
|
||||
/* Hello. */
|
||||
grub_setcolorstate (GRUB_TERM_COLOR_HIGHLIGHT);
|
||||
grub_printf ("Welcome to GRUB!\n\n");
|
||||
|
@ -261,6 +263,8 @@ grub_main (void)
|
|||
|
||||
grub_load_config ();
|
||||
|
||||
grub_boot_time ("Before loading embedded modules.");
|
||||
|
||||
/* Load pre-loaded modules and free the space. */
|
||||
grub_register_exported_symbols ();
|
||||
#ifdef GRUB_LINKER_HAVE_INIT
|
||||
|
@ -268,6 +272,8 @@ grub_main (void)
|
|||
#endif
|
||||
grub_load_modules ();
|
||||
|
||||
grub_boot_time ("After loading embedded modules.");
|
||||
|
||||
/* It is better to set the root device as soon as possible,
|
||||
for convenience. */
|
||||
grub_set_prefix_and_root ();
|
||||
|
@ -277,11 +283,17 @@ grub_main (void)
|
|||
/* Reclaim space used for modules. */
|
||||
reclaim_module_space ();
|
||||
|
||||
grub_boot_time ("After reclaiming module space.");
|
||||
|
||||
grub_register_core_commands ();
|
||||
|
||||
grub_boot_time ("Before execution of embedded config.");
|
||||
|
||||
if (load_config)
|
||||
grub_parser_execute (load_config);
|
||||
|
||||
grub_boot_time ("After execution of embedded config. Attempt to go to normal mode");
|
||||
|
||||
grub_load_normal_mode ();
|
||||
grub_rescue_run ();
|
||||
}
|
||||
|
|
|
@ -1130,3 +1130,42 @@ void __deregister_frame_info (void)
|
|||
}
|
||||
#endif
|
||||
|
||||
#if BOOT_TIME_STATS
|
||||
|
||||
#include <grub/time.h>
|
||||
|
||||
struct grub_boot_time *grub_boot_time_head;
|
||||
static struct grub_boot_time **boot_time_last = &grub_boot_time_head;
|
||||
|
||||
void
|
||||
grub_real_boot_time (const char *file,
|
||||
const int line,
|
||||
const char *fmt, ...)
|
||||
{
|
||||
struct grub_boot_time *n;
|
||||
va_list args;
|
||||
|
||||
grub_error_push ();
|
||||
n = grub_malloc (sizeof (*n));
|
||||
if (!n)
|
||||
{
|
||||
grub_errno = 0;
|
||||
grub_error_pop ();
|
||||
return;
|
||||
}
|
||||
n->file = file;
|
||||
n->line = line;
|
||||
n->tp = grub_get_time_ms ();
|
||||
n->next = 0;
|
||||
|
||||
va_start (args, fmt);
|
||||
n->msg = grub_xvasprintf (fmt, args);
|
||||
va_end (args);
|
||||
|
||||
*boot_time_last = n;
|
||||
boot_time_last = &n->next;
|
||||
|
||||
grub_errno = 0;
|
||||
grub_error_pop ();
|
||||
}
|
||||
#endif
|
||||
|
|
|
@ -296,6 +296,8 @@ grub_normal_execute (const char *config, int nested, int batch)
|
|||
grub_register_variable_hook ("prefix", NULL, read_lists_hook);
|
||||
}
|
||||
|
||||
grub_boot_time ("Executing config file");
|
||||
|
||||
if (config)
|
||||
{
|
||||
menu = read_config_file (config);
|
||||
|
@ -304,10 +306,14 @@ grub_normal_execute (const char *config, int nested, int batch)
|
|||
grub_errno = GRUB_ERR_NONE;
|
||||
}
|
||||
|
||||
grub_boot_time ("Executed config file");
|
||||
|
||||
if (! batch)
|
||||
{
|
||||
if (menu && menu->size)
|
||||
{
|
||||
|
||||
grub_boot_time ("Entering menu");
|
||||
grub_show_menu (menu, nested, 0);
|
||||
if (nested)
|
||||
grub_normal_free_menu (menu);
|
||||
|
@ -319,12 +325,15 @@ grub_normal_execute (const char *config, int nested, int batch)
|
|||
void
|
||||
grub_enter_normal_mode (const char *config)
|
||||
{
|
||||
grub_boot_time ("Entering normal mode");
|
||||
nested_level++;
|
||||
grub_normal_execute (config, 0, 0);
|
||||
grub_boot_time ("Entering shell");
|
||||
grub_cmdline_run (0);
|
||||
nested_level--;
|
||||
if (grub_normal_exit_level)
|
||||
grub_normal_exit_level--;
|
||||
grub_boot_time ("Exiting normal mode");
|
||||
}
|
||||
|
||||
/* Enter normal mode from rescue mode. */
|
||||
|
@ -504,6 +513,8 @@ GRUB_MOD_INIT(normal)
|
|||
{
|
||||
unsigned i;
|
||||
|
||||
grub_boot_time ("Preparing normal module");
|
||||
|
||||
/* Previously many modules depended on gzio. Be nice to user and load it. */
|
||||
grub_dl_load ("gzio");
|
||||
grub_errno = 0;
|
||||
|
@ -556,6 +567,8 @@ GRUB_MOD_INIT(normal)
|
|||
grub_env_export ("grub_cpu");
|
||||
grub_env_set ("grub_platform", GRUB_PLATFORM);
|
||||
grub_env_export ("grub_platform");
|
||||
|
||||
grub_boot_time ("Normal module prepared");
|
||||
}
|
||||
|
||||
GRUB_MOD_FINI(normal)
|
||||
|
|
|
@ -458,4 +458,24 @@ grub_error_load (const struct grub_error_saved *save)
|
|||
grub_errno = save->grub_errno;
|
||||
}
|
||||
|
||||
#if BOOT_TIME_STATS
|
||||
struct grub_boot_time
|
||||
{
|
||||
struct grub_boot_time *next;
|
||||
grub_uint64_t tp;
|
||||
const char *file;
|
||||
int line;
|
||||
char *msg;
|
||||
};
|
||||
|
||||
extern struct grub_boot_time *EXPORT_VAR(grub_boot_time_head);
|
||||
|
||||
void EXPORT_FUNC(grub_real_boot_time) (const char *file,
|
||||
const int line,
|
||||
const char *fmt, ...) __attribute__ ((format (printf, 3, 4)));
|
||||
#define grub_boot_time(fmt, args...) grub_real_boot_time(GRUB_FILE, __LINE__, fmt, ## args)
|
||||
#else
|
||||
#define grub_boot_time(fmt, args...)
|
||||
#endif
|
||||
|
||||
#endif /* ! GRUB_MISC_HEADER */
|
||||
|
|
Loading…
Reference in a new issue