From: eLinux.org
Filesystem Information
Boot Time with various file systems
Noboru Wakabayashi of Hitachi provided the following report.
On the OMAP Innovator he built the following file systems:
- CRAMFS
- CRAMFS with XIP
- ROMFS
- JFFS2
- ext2 over RAM disk
He measured the time to initialize these file systems by logic analyzer.
This was done by modifying the busybox init program to make LED turn on
red. When innovator power on, the LED lights up green. So the time from
the light turning from green to red was measured. Also, he measured the
time using KFI (from start_kernel() to to_usrspace()).
Results are shown in the following table. (The result is average of 10
trials for each configuration.)
Configuration/Filesystem | logic analyzer(sec) | KFI(usec) |
---|---|---|
CRAMFS | 3.638850 | 842789.1 |
CRAMFS with XIP | 2.788076 | 764141.3 |
CRAMFS with XIP and PLPJ | 2.583988 | 551735.5 |
ROMFS | 3.510876 | 839078.2 |
JFFS2 | 4.822642 | 1241068.4(log full) |
ext2 over RAM disk | cannot measure | 2952081.6(log full) |
JFFS2: JFFS2 required much time at first boot time, so he measured
from the 2nd starting.CRAMFS: At first, he also measured the time with CONFIG_KFI by
logic analyzer. The result is 4.324660 sec. It costs more than
without CONFIG_KFI. So, he measured file systems without
CONFIG_KFI when he used logic analyzer.
The attached zip file has the kfi logfiles for these different tests: no
zip found: kfi-results-omap-filesystems.zip
Next he remeasured the time to initialize “CRAMFS with XIP and PLPJ”
using the “quiet” option. The result is 280676 usec from start_kernel()
to to_userspace(). The above result is 551735.5 usec.The time is
reduced about 50%.
The following table shows output from ‘kd’ on the kfi logfile.
Function | Count | Time | Average | Local | Max-sub | Ms count |
---|---|---|---|---|---|---|
do_basic_setup | 1 | 114068 | 114068 | 509 | do_initcalls | 1 |
mem_init | 1 | 110376 | 110376 | 490 | free_all_bootmem_node | 1 |
free_all_bootmem_node | 1 | 109378 | 109378 | 12 | free_all_bootmem_core | 1 |
free_all_bootmem_core | 1 | 109366 | 109366 | 109366 | - | 0 |
schedule | 10 | 84482 | 8448 | 34 | do_schedule | 10 |
do_schedule | 10 | 84448 | 8444 | 574 | switch_to | 9 |
do_initcalls | 1 | 84159 | 84159 | 3831 | device_init | 1 |
switch_to | 9 | 83874 | 9319 | 83874 | - | 0 |
register_proc_table | 22 | 39161 | 1780 | 13079 | register_proc_table | 18 |
device_register | 11 | 22297 | 2027 | 415 | device_add | 11 |
device_add | 11 | 21882 | 1989 | 1439 | kobject_add | 11 |
device_init | 1 | 20633 | 20633 | 30 | net_dev_init | 1 |
tifb_init | 1 | 18759 | 18759 | 844 | register_framebuffer | 1 |
register_framebuffer | 1 | 13092 | 13092 | 88 | take_over_console | 1 |
take_over_console | 1 | 13004 | 13004 | 819 | redraw_screen | 1 |
kobject_add | 15 | 12996 | 866 | 738 | create_dir | 15 |
setup_arch | 1 | 12542 | 12542 | 131 | paging_init | 1 |
paging_init | 1 | 12411 | 12411 | 386 | free_area_init_node | 1 |
create_dir | 15 | 12258 | 817 | 3625 | populate_dir | 9 |
free_area_init_node | 1 | 12025 | 12025 | 30 | free_area_init_core | 1 |
free_area_init_core | 1 | 11995 | 11995 | 7496 | __alloc_bootmem_node | 1 |
rs_init | 1 | 11794 | 11794 | 377 | printk | 3 |
inet_init | 1 | 11696 | 11696 | 1718 | ip_init | 1 |
redraw_screen | 2 | 11247 | 5623 | 871 | do_update_region | 1 |
printk | 18 | 10870 | 603 | 10870 | - | 0 |
net_dev_init | 1 | 10334 | 10334 | 3102 | ethif_probe | 1 |
Probe times for various file systems
As part of work supported by Sony/Matsushita, Todd Poynor got the
following numbers using KFI on a 200MHz IBM 405GP “Walnut” evaluation
board with a 100MHz core bus and 33MHz PCI bus. A Seagate Barracuda ATA
IV 60GB disk drive is cabled to one of the two IDE interfaces on a
Promise Ultra66 PCI-IDE bridge card (PDC20262 chipset). All of the
drivers for PCI, IDE, PCI-IDE disk, and EXT2 filesystem are built into
the kernel.
Boot execution time of IDE/PCI-IDE/MS-DOS partition drivers: 262 msecs.
This includes the time to probe and identify the IDE drive device and
read the disk partition information from the drive. We booted the kernel
with option hdf=none to turn off the slave device on interface ide2, so
that it would not be probed. We also modified the kernel to turn off
probes of the second IDE interface on the Promise card. (This was prior
to fixing the “ide\
probing the second empty IDE interface then probling takes 1.3 seconds
on both a PPC 405GP and a MIPS ITE8172!)
About 250 msecs of the time is spent during the bus probe in repeated
calls to ide_delay_50ms() during probe and drive identification, which
busywaits (in order to let the IDE controller make progress before
polling for status or to allow previous operations to complete). Reading
capacity info, etc. also blocks using a wait_for_completion(). The
MSDOS partition code also locks pages, which can call schedule() to wait
for locks.
If the IDE drivers are made modules for delayed initialization, allowing
concurrent module initialization with application execution, then kernel
preemption is turned off for about 252 msecs during init of the
ide-probe-mod module, which could significantly interfere with real-time
response of other threads. (This was verified using the
CONFIG_PREEMPT_TIMES feature that gives preemption lock times in
/proc/latencytimes, which is also supported in the CELF kernel.) Because
the Big Kernel Lock (BKL) is held during module initialization,
preemption is disabled while the module init routines runs and uses
busywait calls, but preemption is allowed when CPU-yielding wait calls
are employed (the linux scheduler drops and reacquires the BKL in this
case).
So we changed the ide_delay_50ms() busywaits to call
schedule_timeout() instead (this is also in the CELF kernel; select
CONFIG_IDE_PREEMPT), resulting in a 9.68 msec maximum preempt off
time. Note that if you’re not using modules but are instead building the
drivers statically into the kernel, then the CPU-yielding calls do add
some amount of time to the total execution time due to context-switch
overhead, etc.
My coworker Dave Singleton also did some analysis and improvement of IDE
on the MIPS ITE8172 (again for Sony/Matsushita). He found that with his
7200RPM Maxtor drive, he could reduce the 50ms probe delays to 1ms with
no problem. With this, plus some context switch removal and the other
optimizations given above, the following boot times were observed, by
filesystem type:
{{{ ext2: 167 milliseconds ext3: 457 milliseconds xfs: 236 milliseconds
}}}
He explains: “Both EXT3 and XFS file systems cause a log replay at
boot/mount time. To improve this time the log recovery feature was by
passed in the case of XFS. The log was not replayed and the root file
system was mounted readonly. The first init script after booting
remounted the root file system readwrite and replayed the log to ensure
file system integrity. No such changes were made to EXT3, which is the
reason it had the slowest boot times of all 3 file system types.”