Re: [patch] enhance initcall_debug, measure latency

[Ingo Molnar]

* Ingo Molnar <mingo@xxxxxxx> wrote:

> some boot time analysis using this facility:

using a non-allyesconfig kernel gives the results below. The entries 
that seem to take a bit too long (considering what they do):

initcall 0xc069bac5 ran for 519 msecs: init_nic+0x0/0x2c()
initcall 0xc0699610 ran for 344 msecs: isapnp_init+0x0/0x435()
initcall 0xc069af66 ran for 245 msecs: serial8250_init+0x0/0x112()
initcall 0xc06981e8 ran for 183 msecs: acpi_pci_link_init+0x0/0x43()
initcall 0xc06a07b0 ran for 175 msecs: pci_acpi_init+0x0/0x9b()
initcall 0xc06980ef ran for 110 msecs: acpi_pci_root_init+0x0/0x25()
initcall 0xc069fa24 ran for 69 msecs: pcibios_assign_resources+0x0/0x92()
initcall 0xc0246fd6 ran for 64 msecs: pci_init+0x0/0x2c()
initcall 0xc0695fc2 ran for 62 msecs: pcie_portdrv_init+0x0/0x46()
initcall 0xc0698656 ran for 54 msecs: pnp_system_init+0x0/0xf()
initcall 0xc06a27ac ran for 43 msecs: inet_init+0x0/0x390()
initcall 0xc069f88e ran for 28 msecs: init_acpi_pm_clocksource+0x0/0x173()

these amount to almost 50% of the ~4 seconds total bootup initcall time!

	Ingo

initcall 0xc069c43b ran for 1147 msecs: ide_init+0x0/0x8a()
initcall 0xc069bac5 ran for 519 msecs: init_nic+0x0/0x2c()
initcall 0xc069cbe0 ran for 497 msecs: ide_generic_init+0x0/0x11()
initcall 0xc0699610 ran for 344 msecs: isapnp_init+0x0/0x435()
initcall 0xc069af66 ran for 245 msecs: serial8250_init+0x0/0x112()
initcall 0xc06981e8 ran for 183 msecs: acpi_pci_link_init+0x0/0x43()
initcall 0xc06a07b0 ran for 175 msecs: pci_acpi_init+0x0/0x9b()
initcall 0xc06980ef ran for 110 msecs: acpi_pci_root_init+0x0/0x25()
initcall 0xc068b878 ran for 97 msecs: check_nmi_watchdog+0x0/0x1d1()
initcall 0xc069cbf1 ran for 75 msecs: idedisk_init+0x0/0xf()
initcall 0xc069fa24 ran for 69 msecs: pcibios_assign_resources+0x0/0x92()
initcall 0xc0246fd6 ran for 64 msecs: pci_init+0x0/0x2c()
initcall 0xc0695fc2 ran for 62 msecs: pcie_portdrv_init+0x0/0x46()
initcall 0xc0698656 ran for 54 msecs: pnp_system_init+0x0/0xf()
initcall 0xc06a27ac ran for 43 msecs: inet_init+0x0/0x390()
initcall 0xc069f88e ran for 28 msecs: init_acpi_pm_clocksource+0x0/0x173()
initcall 0xc069bb07 ran for 23 msecs: rtl8139_init_module+0x0/0x16()
initcall 0xc069eeae ran for 18 msecs: psmouse_init+0x0/0x64()
initcall 0xc0111a26 ran for 18 msecs: powernowk8_init+0x0/0x78()
initcall 0xc069e932 ran for 17 msecs: i8042_init+0x0/0x321()
initcall 0xc069baf1 ran for 16 msecs: cp_init+0x0/0x16()
initcall 0xc06979b8 ran for 16 msecs: acpi_init+0x0/0x1ff()
initcall 0xc0697bfc ran for 15 msecs: acpi_scan_init+0x0/0xfc()
initcall 0xc06a3154 ran for 12 msecs: netlbl_init+0x0/0x71()
initcall 0xc069e512 ran for 11 msecs: usb_init+0x0/0x103()
initcall 0xc06986cd ran for 11 msecs: pnpacpi_init+0x0/0x69()

-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/