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<x>=noprobe" option bug. If you don't turn off 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."
