Hi, To see where my bootmenu thingy[0][1] is spending it's time I've tried to measure boot time with the om-gta02-2.6.32 kernel (Thanks again, Lars).
>From bootloader to the extracted kernel it takes about 3.48 seconds. This can be further split up into: 2.15s for Qi to load the kernel + initramfs from NAND 1.33s to uncompress the kernel + initramfs This is with gzip. I still have to try it with an uncompressed kernel and a lzma compressed one. Then it takes about 4.25 seconds for the kernel to boot until userspace is reached. This is messured based on the data which arrives on the serial port according to the kernel's printk time it takes only 2.61 seconds. I should probably also take a look at CONFIG_BOOT_TRACERS... Any ideas on how to speed that part up? I so far disabled everything which didn't seem necessary in the kernel configuration[2] (usbnet is there to make it useable as a rescue system) and specified a pre calculated value for the callibration loop (lpj=...) on the kernel command line. Any hints to further speed it up? Then comes userspace which takes about 0.6s this is probably because everything is already in RAM. So reducing the size of userspace will also reduce kernel size and thus improve step 1 of the boot process. Here I would like to try to statically link the qi-bootmenu app to see if that makes a difference size/performance wise. Below is the full boot log so if anyone would like to comment inline on specific areas feel free to do so. Thanks, Marc [0] http://thread.gmane.org/gmane.comp.handhelds.openmoko.devel/4434 [1] http://repo.or.cz/w/qi-bootmenu-system.git [2] http://repo.or.cz/w/qi-bootmenu-system.git/blob/HEAD:/sources/configs/miniconfig-linux Opening serial port /dev/ttyUSB0 115200:8N1:xonxoff=0:rtcdtc=0 Program will end in 60 seconds Printing timing information for each line Use Control-C to stop... [ 0.000003] [ 0.000121] [ 0.000170] [ 0.000202] Qi Bootloader s3c2442 debbook master_ef00a82485f393ee [ 0.005112] Tue Dec 22 18:38:57 CET 2009 Copyright (C) 2008 Openmoko, Inc. [ 0.011050] [ 0.011105] Detected: Freerunner / GTA02, A6 PCB [ 0.014273] Battery condition reasonable [ 0.017084] [ 0.017119] Trying kernel: SD Card EXT2 P3 Kernel [ 0.101989] Card Type: SD 2.0 / Mfr: 0x03, OEM "SD" / SU02G", rev 8.0 / s/n: 31352965 / date: 6/2008 [ 0.111974] MMC/SD size: 511 MiB [ 0.127987] Partition: 3 start +1975680 512-byte blocks, size 972 MiB [ 0.133209] ** skipping [ 0.134157] Failed to mount ext2 filesystem... [ 0.137165] Unable to mount ext2 filesystem [ 0.178002] [ 0.178980] Trying kernel: NAND Kernel [ 0.181077] RAW open: +1024 512-byte blocks [ 0.184957] Found: "Openmoko GTA02 Bootmenu" [ 0.189040] Size: 2677 KiB [ 0.191015] RAW open: +1024 512-byte blocks [ 1.965028] Cmdline: loglevel=4 console=tty0 console=ttySAC2,115200 init=/sbin/init ro mtdparts=physmap-flash:-(nor);neo1973-nand:0x00040000(qi),0x00040000(depr-ub-env),0x00800000(kernel),0x000a0000(depr),0x00040000(identity-ext2),0x0f6a0000(rootfs) g_ether.dev_addr=00:1F:11:01:3E:3B g_ether.host_addr=00:1F:11:01:3E:3C rootfstype=jffs2 root=/dev/mtdblock6 lpj=496640 loglevel=8 [ 2.156026] Starting ---> [ 2.157203] [ 2.158977] Uncompressing Linux............................................................................................................................................................................................ done, booting the kernel. [ 3.483027] [ 0.000000] Linux version 2.6.32 (m...@debbook) (gcc version 4.2.1) #1 PREEMPT Tue Dec 22 17:08:39 CET 2009 [ 3.493217] [ 0.000000] CPU: ARM920T [41129200] revision 0 (ARMv4T), cr=c0007177 [ 3.499113] [ 0.000000] CPU: VIVT data cache, VIVT instruction cache [ 3.504200] [ 0.000000] Machine: GTA02 [ 3.507050] [ 0.000000] Memory policy: ECC disabled, Data cache writeback [ 3.513016] [ 0.000000] On node 0 totalpages: 32768 [ 3.516165] [ 0.000000] free_area_init_node: node 0, pgdat c05cb014, node_mem_map c05ed000 [ 3.523975] [ 0.000000] Normal zone: 256 pages used for memmap [ 3.528466] [ 0.000000] Normal zone: 0 pages reserved [ 3.533194] [ 0.000000] Normal zone: 32512 pages, LIFO batch:7 [ 3.537982] [ 0.000000] CPU S3C2442B (id 0x32440aab) [ 3.541567] [ 0.000000] S3C24XX Clocks, (c) 2004 Simtec Electronics [ 3.547044] [ 0.000000] S3C244X: core 400.000 MHz, memory 100.000 MHz, peripheral 50.000 MHz [ 3.554124] [ 0.000000] CLOCK: Slow mode (1.500 MHz), fast, MPLL on, UPLL on [ 3.560181] [ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 32512 [ 3.568131] [ 0.000000] Kernel command line: loglevel=4 console=tty0 console=ttySAC2,115200 init=/sbin/init ro mtdparts=physmap-flash:-(nor);neo1973-nand:0x00040000(qi),0x00040000(depr-ub-env),0x00800000(kernel),0x000a0000(depr),0x00040000(identity-ext2),0x0f6a0000(rootfs) g_ether.dev_addr=00:1F:11:01:3E:3B g_ether.host_addr=00:1F:11:01:3E:3C rootfstype=jffs2 root=/dev/mtdblock6 lpj=496640 loglevel=8 [ 3.602340] [ 0.000000] PID hash table entries: 512 (order: -1, 2048 bytes) [ 3.608301] [ 0.000000] Dentry cache hash table entries: 16384 (order: 4, 65536 bytes) [ 3.615222] [ 0.000000] Inode-cache hash table entries: 8192 (order: 3, 32768 bytes) [ 3.622040] [ 0.000000] Memory: 128MB = 128MB total [ 3.625393] [ 0.000000] Memory: 123732KB available (2412K code, 229K data, 3388K init, 0K highmem) [ 3.633343] [ 0.000000] Hierarchical RCU implementation. [ 3.637979] [ 0.000000] NR_IRQS:94 [ 3.640110] [ 0.000000] irq: clearing pending ext status 000b12f0 [ 3.645355] [ 0.000000] irq: clearing pending ext status 000902d0 [ 3.650215] [ 0.000000] irq: clearing subpending status 00000180 [ 3.655129] [ 0.000000] irq: clearing subpending status 00000080 [ 3.660069] [ 0.000000] timer tcon=00000000, tcnt a2c1, tcfg 00000200,00000000, usec 00001eb8 [ 3.667299] [ 0.000000] Console: colour dummy device 80x30 [ 3.671977] [ 0.000000] console [tty0] enabled [ 3.675255] [ 0.000000] console [ttySAC2] enabled [ 3.678973] [ 0.010000] Calibrating delay loop (skipped) preset value.. 198.65 BogoMIPS (lpj=496640) [ 3.687040] [ 0.020000] Mount-cache hash table entries: 512 [ 3.691166] [ 0.025000] CPU: Testing write buffer coherency: ok [ 3.696222] [ 0.030000] devtmpfs: initialized [ 3.699976] [ 0.035000] regulator: core version 0.5 [ 3.703491] [ 0.040000] NET: Registered protocol family 16 [ 3.743002] [ 0.080000] s3c24xx-adc s3c24xx-adc: attached adc driver [ 3.748301] [ 0.080000] S3C2442: Initialising architecture [ 3.753228] [ 0.085000] S3C244X: Clock Support, DVS off [ 3.757203] [ 0.090000] s3c24xx-pwm s3c24xx-pwm.0: tin at 25000000, tdiv at 25000000, tin=divclk, base 0 [ 3.766767] [ 0.095000] s3c24xx-pwm s3c24xx-pwm.1: tin at 25000000, tdiv at 25000000, tin=divclk, base 8 [ 3.773988] [ 0.100000] s3c24xx-pwm s3c24xx-pwm.3: tin at 8333333, tdiv at 8333333, tin=divclk, base 16 [ 3.821996] [ 0.150000] bio: create slab <bio-0> at 0 [ 3.828981] [ 0.155000] usbcore: registered new interface driver usbfs [ 3.837106] [ 0.155000] usbcore: registered new interface driver hub [ 3.840324] [ 0.165000] usbcore: registered new device driver usb [ 3.845278] [ 0.170000] s3c-i2c s3c2440-i2c: slave address 0x10 [ 3.850203] [ 0.170000] s3c-i2c s3c2440-i2c: bus frequency set to 97 KHz [ 3.870962] [ 0.200000] pcf50633 0-0073: Probed device version 19 variant 132 [ 3.991012] [ 0.320000] regulator: auto: 3300 mV normal [ 4.010991] [ 0.340000] regulator: down1: 1300 <--> 1600 mV normal [ 4.040996] [ 0.370000] regulator: down2: 1800 mV normal [ 4.050985] [ 0.380000] regulator: ldo1: 3300 mV normal [ 4.063963] [ 0.390000] regulator: ldo2: 3300 mV normal [ 4.070980] [ 0.400000] regulator: ldo3: 3000 mV normal [ 4.080986] [ 0.410000] regulator: ldo4: 3200 mV normal [ 4.090989] [ 0.420000] regulator: ldo5: 3000 mV normal [ 4.095976] [ 0.420000] regulator: ldo6: 3000 mV normal [ 4.115997] [ 0.445000] regulator: hcldo: 2000 <--> 3300 mV normal [ 4.121410] [ 0.445000] regulator: memldo: 1800 mV normal [ 4.126091] [ 0.445000] pcf50633 0-0073: IRQ 53 cannot be enabled as wake-up sourcein this hardware revision [ 4.134972] [ 0.455000] s3c24xx-pwm s3c24xx-pwm.2: tin at 8333333, tdiv at 8333333, tin=divclk, base 12 [ 4.143183] [ 0.460000] s3c-i2c s3c2440-i2c: i2c-0: S3C I2C adapter [ 4.161169] [ 0.480000] NET: Registered protocol family 2 [ 4.165290] [ 0.485000] IP route cache hash table entries: 1024 (order: 0, 4096 bytes) [ 4.172134] [ 0.490000] TCP established hash table entries: 4096 (order: 3, 32768 bytes) [ 4.179222] [ 0.495000] TCP bind hash table entries: 4096 (order: 2, 16384 bytes) [ 4.185364] [ 0.500000] TCP: Hash tables configured (established 4096 bind 4096) [ 4.192041] [ 0.505000] TCP reno registered [ 4.195132] [ 0.505000] NET: Registered protocol family 1 [ 4.339025] [ 0.655000] gta02-pm-bt gta02-pm-bt.0: Openmoko Freerunner Bluetooth Power Management: starting [ 4.351986] [ 0.670000] gta02-pm-gps gta02-pm-gps.0: starting [ 4.381978] [ 0.700000] gta02-pm-wlan gta02-pm-wlan.0: starting [ 4.594027] [ 0.910000] JFFS2 version 2.2. (NAND) (SUMMARY) © 2001-2006 Red Hat, Inc. [ 4.600457] [ 0.910000] msgmni has been set to 241 [ 4.625009] [ 0.940000] io scheduler noop registered [ 4.629269] [ 0.940000] io scheduler deadline registered (default) [ 4.748018] [ 1.065000] s3c2440-uart.0: s3c2410_serial0 at MMIO 0x50000000 (irq = 70) is a S3C2440 [ 4.755951] [ 1.070000] s3c2440-uart.1: s3c2410_serial1 at MMIO 0x50004000 (irq = 73) is a S3C2440 [ 4.763416] [ 1.075000] s3c2440-uart.2: s3c2410_serial2 at MMIO 0x50008000 (irq = 76) is a S3C2440 [ 4.810005] [ 1.125000] glamo3362 glamo3362.0: Glamo core PLL1: 49119232Hz, PLL2: 89980928Hz [ 4.817255] [ 1.130000] SMEDIA Glamo frame buffer driver (C) 2007 Openmoko, Inc. [ 4.823273] [ 1.135000] glamo-fb glamo-fb.0: spin_lock_init [ 5.240028] [ 1.225000] Console: switching to colour frame buffer device 60x40 [ 5.246382] [ 1.320000] fb0: SMedia Glamo frame buffer device [ 5.251223] [ 1.325000] glamo-mci glamo-mci.0: glamo_mci driver (C)2007 Openmoko, Inc [ 5.258069] [ 1.335000] glamo-mci glamo-mci.0: glamo_mci_set_ios: power down. [ 5.264131] [ 1.335000] ENABLE [ 5.266071] [ 1.340000] physmap platform flash device: 00200000 at 18000000 [ 5.272040] [ 1.345000] physmap-flash.0: Found 1 x16 devices at 0x0 in 16-bit bank [ 5.301995] [ 1.350000] Intel/Sharp Extended Query Table at 0x0039 [ 5.317994] [ 1.355000] Intel/Sharp Extended Query Table at 0x0039 [ 5.331980] [ 1.360000] Intel/Sharp Extended Query Table at 0x0039 [ 5.344994] [ 1.365000] Intel/Sharp Extended Query Table at 0x0039 [ 5.356994] [ 1.370000] Intel/Sharp Extended Query Table at 0x0039 [ 5.366981] [ 1.380000] cfi_cmdset_0001: Erase suspend on write enabled [ 5.382991] [ 1.385000] erase region 0: offset=0x0,size=0x2000,blocks=8 [ 5.402991] [ 1.390000] erase region 1: offset=0x10000,size=0x10000,blocks=31 [ 5.428998] [ 1.395000] physmap-flash.0: 1 set(s) of 1 interleaved chips --> 4 partitions of 512 KiB [ 5.477008] [ 1.415000] RedBoot partition parsing not available [ 5.500999] [ 1.425000] S3C24XX NAND Driver, (c) 2004 Simtec Electronics [ 5.533015] [ 1.430000] s3c24xx-nand s3c2440-nand: Tacls=1, 10ns Twrph0=3 30ns, Twrph1=2 20ns [ 5.566999] [ 1.435000] s3c24xx-nand s3c2440-nand: NAND soft ECC [ 5.582987] [ 1.440000] NAND device: Manufacturer ID: 0xec, Chip ID: 0xaa (Samsung NAND 256MiB 1,8V 8-bit) [ 5.617994] [ 1.445000] 6 cmdlinepart partitions found on MTD device neo1973-nand [ 5.650009] [ 1.450000] Creating 6 MTD partitions on "neo1973-nand": [ 5.666986] [ 1.455000] 0x000000000000-0x000000040000 : "qi" [ 5.687991] [ 1.465000] 0x000000040000-0x000000080000 : "depr-ub-env" [ 5.704991] [ 1.470000] glamo-mci glamo-mci.0: powered (vdd = 21) clk: 0kHz div=0 (req: 0kHz). Bus width=0 [ 5.740957] [ 1.475000] 0x000000080000-0x000000880000 : "kernel" [ 5.761985] [ 1.490000] 0x000000880000-0x000000920000 : "depr" [ 5.782961] [ 1.505000] glamo-mci glamo-mci.0: powered (vdd = 21) clk: 399kHz div=0 (req: 400kHz). Bus width=0 [ 5.815984] [ 1.510000] 0x000000920000-0x000000960000 : "identity-ext2" [ 5.849004] [ 1.520000] 0x000000960000-0x000010000000 : "rootfs" [ 5.914007] [ 1.575000] glamo-mci glamo-mci.0: powered (vdd = 21) clk: 399kHz div=0 (req: 400kHz). Bus width=0 [ 5.954993] [ 1.585000] glamo-mci glamo-mci.0: powered (vdd = 21) clk: 399kHz div=0 (req: 400kHz). Bus width=0 [ 6.076009] [ 1.675000] glamo-mci glamo-mci.0: powered (vdd = 15) clk: 399kHz div=0 (req: 400kHz). Bus width=0 [ 6.117025] [ 1.685000] glamo-mci glamo-mci.0: powered (vdd = 15) clk: 399kHz div=0 (req: 400kHz). Bus width=0 [ 6.161973] [ 1.700000] glamo-mci glamo-mci.0: powered (vdd = 15) clk: 399kHz div=0 (req: 400kHz). Bus width=0 [ 6.227007] [ 1.735000] glamo-mci glamo-mci.0: powered (vdd = 15) clk: 399kHz div=0 (req: 400kHz). Bus width=0 [ 6.271996] [ 1.750000] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver [ 6.307996] [ 1.755000] s3c2410-ohci s3c2410-ohci: S3C24XX OHCI [ 6.324987] [ 1.760000] s3c2410-ohci s3c2410-ohci: new USB bus registered, assigned bus number 1 [ 6.358226] [ 1.765000] s3c2410-ohci s3c2410-ohci: irq 42, io mem 0x49000000 [ 6.394996] [ 1.775000] glamo-mci glamo-mci.0: powered (vdd = 15) clk: 16373kHz div=0 (req: 21000kHz). Bus width=0 [ 6.435015] [ 1.785000] glamo-mci glamo-mci.0: powered (vdd = 15) clk: 16373kHz div=0 (req: 21000kHz). Bus width=2 [ 6.473010] [ 1.790000] mmc0: new SD card at address beff [ 6.520005] [ 1.825000] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001 [ 6.553997] [ 1.830000] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1 [ 6.587997] [ 1.835000] usb usb1: Product: S3C24XX OHCI [ 6.603990] [ 1.840000] usb usb1: Manufacturer: Linux 2.6.32 ohci_hcd [ 6.619989] [ 1.845000] usb usb1: SerialNumber: s3c24xx [ 6.636995] [ 1.855000] usb usb1: configuration #1 chosen from 1 choice [ 6.665995] [ 1.865000] hub 1-0:1.0: USB hub found [ 6.679988] [ 1.870000] hub 1-0:1.0: 2 ports detected [ 6.704995] [ 1.885000] s3c2440-usbgadget s3c2440-usbgadget: S3C2440: increasing FIFO to 128 bytes [ 6.736991] [ 1.895000] usb0: MAC 00:1f:11:01:3e:3b [ 6.750001] [ 1.900000] usb0: HOST MAC 00:1f:11:01:3e:3c [ 6.763999] [ 1.905000] g_ether gadget: Ethernet Gadget, version: Memorial Day 2008 [ 6.790996] [ 1.910000] g_ether gadget: g_ether ready [ 6.807990] [ 1.915000] mice: PS/2 mouse device common for all mice [ 6.823992] [ 1.920000] input: gpio-keys as /devices/platform/gpio-keys/input/input0 [ 6.855012] [ 1.925000] s3c2410-ts s3c2410-ts: Starting [ 6.870990] [ 1.935000] s3c2410-ts s3c2410-ts: Created Group filter len:12 coords:2 close:10 thresh:6 [ 6.902001] [ 1.940000] s3c2410-ts s3c2410-ts: Created Median filter len:20 coords:2 dec_threshold:24 [ 6.934350] [ 1.945000] s3c2410-ts s3c2410-ts: Created Mean filter len:4 coords:2 [ 6.965058] [ 1.950000] s3c2410-ts s3c2410-ts: Created Linear filter coords:2 [ 6.998363] [ 1.955000] s3c2410-ts s3c2410-ts: 4 filter(s) initialized [ 7.031004] [ 1.960000] s3c2410-ts s3c2410-ts: Successfully loaded [ 7.051008] [ 1.965000] input: s3c2410 TouchScreen as /devices/virtual/input/input1 [ 7.089998] [ 1.975000] input: PCF50633 PMU events as /devices/virtual/input/input2 [ 7.128008] [ 1.985000] pcf50633-rtc pcf50633-rtc: rtc core: registered pcf50633-rtc as rtc0 [ 7.164001] [ 1.990000] S3C24XX RTC, (c) 2004,2006 Simtec Electronics [ 7.182982] [ 1.995000] i2c /dev entries driver [ 7.239008] [ 2.040000] bq27000-battery bq27000-battery.0: BQ27000 Battery Driver (C) 2008 Openmoko, Inc [ 7.278996] [ 2.050000] S3C2410 Watchdog Timer, (c) 2004 Simtec Electronics [ 7.313001] [ 2.055000] s3c2410-wdt s3c2410-wdt: watchdog inactive, reset disabled, irq enabled [ 7.350015] [ 2.060000] cpuidle: using governor ladder [ 7.367994] [ 2.065000] mmcblk0: mmc0:beff SU02G 1.89 GiB [ 7.383987] [ 2.070000] mmcblk0: [ 7.486022] [ 2.160000] g_ether gadget: full speed config #1: CDC Ethernet (ECM) [ 7.803037] [ 2.455000] p1 p2 p3 [ 7.826004] [ 2.465000] Registered led device: gta02:red:aux [ 7.843995] [ 2.475000] usbcore: registered new interface driver usbhid [ 7.868996] [ 2.480000] usbhid: v2.6:USB HID core driver [ 7.882985] [ 2.485000] TCP cubic registered [ 7.895947] [ 2.490000] NET: Registered protocol family 17 [ 7.946025] [ 2.535000] regulator_init_complete: incomplete constraints, leaving memldo on [ 8.031005] [ 2.600000] pcf50633-rtc pcf50633-rtc: setting system clock to 2009-12-22 17:49:41 UTC (1261504181) [ 8.065983] [ 2.610000] Freeing init memory: 3388K [ 8.080982] [ 2.615000] Warning: unable to open an initial console. [ 8.205021] Starting qi-bootmenu [ 8.364020] ECORE_FB: TSLIB_TSDEVICE = '/dev/input/event1' [ 8.430017] Couldn't identify filesystem on '/dev/mmcblk0' [ 8.465003] [ 2.985000] EXT3-fs: mounted filesystem with writeback data mode. [ 8.471031] [ 2.985000] kjournald starting. Commit interval 5 seconds [ 8.526966] [ 3.050000] EXT3-fs: mounted filesystem with writeback data mode. [ 8.532976] [ 3.050000] kjournald starting. Commit interval 5 seconds [ 8.599006] entering main loop [ 10.536035] [ 5.060000] pcf50633 0-0073: usb curlim to 500 mA [ 14.644020] /bin/sh: can't access tty; job control turned off [ 14.648112] / # -- Marc Andre Tanner >< http://www.brain-dump.org/ >< GPG key: CF7D56C0
