在Sitara平台上如何优化Linux启动过程？

只看该作者 · 2011-6-28 01:02

先卖个关子，请问目前大家的平台上，Linux从启动到运行自己的图形程序，需要大概多少秒？

具体如何优化，后续我会结合目前合众达在售的SEED-DIM3517平台来实际讲解一下。

只看该作者 · 2011-7-11 21:45

5s？

只看该作者 · 2011-7-18 13:36

不知道

只看该作者 · 2011-7-18 21:33

这个没有运用到

只看该作者 · 2011-7-18 21:33

等待版主的结果

只看该作者 · 2011-7-19 13:57

这个跟其他平台没有太大区别吧

只看该作者 · 2011-7-19 22:44

拖得比较久了

久了也要做呀！

不能像某些YY小说一样，做太监。

我们要想优化一个系统的启动时间，首先我们需要知道这个系统都把启动时间花在哪里了！
其次就是你的目标，是让系统在多少秒之内完成启动？

那要如何才能知道，系统在启动过程中，主要都将精力放在什么地方了呢？

（1）首先是对Linux启动过程的跟踪和分析，生成详细的启动时间报告。

　　较为简单可行的方式是通过PrintkTime功能为启动过程的所有内核信息增加时间戳，便于汇总分析。PrintkTime最早为CELF所提供的一个内核补丁，在后来的Kernel 2.6.11版本中正式纳入标准内核。所以大家可能在新版本的内核中直接启用该功能。如果你的Linux内核因为某些原因不能更新为2.6.11之后的版本，那么可以参考CELF提供的方法修改或直接下载它们提供的补丁：http://tree.celinuxforum.org/CelfPubWiki/PrintkTimes

　　开启PrintkTime功能的方法很简单，只需在内核启动参数中增加“time”即可。当然，你也可以选择在编译内核时直接指定“Kernel hacking”中的“Show timing information on printks”来强制每次启动均为内核信息增加时间戳。这一种方式还有另一个好处：你可以得到内核在解析启动参数前所有信息的时间。因此，我选择后一种方式。

　　当完成上述配置后，重新启动Linux，然后通过以下命令将内核启动信息输出到文件：

　　dmesg >　boottime.log
　　然后利用一个脚本“show_delta”（位于Linux源码的scripts文件夹下）将上述输出的文件转换为时间增量显示格式：

　　/usr/src/linux-x.xx.xx/scripts/show_delta ktime >dtime

　　这样，你就得到了一份关于Linux启动时间消耗的详细报告。

　　（2）然后，我们就来通过这份报告，找出启动中相对耗时的过程。

　　必须明确一点：报告中的时间增量和内核信息之间没有必然的对应关系，真正的时间消耗必须从内核源码入手分析。

　　这一点对于稍微熟悉编程的朋友来说都不难理解，因为时间增量只是两次调用printk之间的时间差值。通常来说，内核启动过程中在完成一些耗时的任务，如创建hash索引、probe硬件设备等操作后会通过printk将结果打印出来，这种情况下，时间增量往往反映的是信息对应过程的耗时；但有些时候，内核是在调用printk输出信息后才开始相应的过程，那么报告中内核信息相应过程的时间消耗对应的是其下一行的时间增量；还有一些时候，时间消耗在了两次内核信息输出之间的某个不确定的时段，这样时间增量可能就完全无法通过内核信息反应出来了。

　　所以，为了准确判断真正的时间消耗，我们需要结合内核源码进行分析。必要的时候，例如上述第三种情形下，还得自己在源码中插入printk打印，以进一步确定实际的时间消耗过程。

——未完待续——

只看该作者 · 2011-7-19 22:45

明后天以合众达的板子为例实际跑一下。

只看该作者 · 2011-7-22 01:20

在合众达板子上，进入合众达提供的内核源码树目录下执行如下命令，配置内核为合众达出厂配置(这是一种考虑尽量多兼容性的配置）
$make ARCH=arm CROSS_COMPILE=arm-none-linux-gnueabi- SEED_DIM3517_defconfig
用如下命令编译出默认内核
$make ARCH=arm CROSS_COMPILE=arm-none-linux-gnueabi- uImage
现在你可以试用一下默认内核感受一下内核的启动速度
如果你觉得内核的启动速度已经可以接受，则可以跳过下面的内容。
如果你认为速度还需要进一步改善，请接着往下看。
这时打开内核的printktimes选项。按下面两个图操作始可

重新生成uImage, 并用新的uImage文件启动。

按照在７楼的说法得到内核中各个模块启动时间如下。
[975.592071 < 0.035187 >] bio: create slab <bio-0> at 0
[975.594665 < 0.002594 >] SCSI subsystem initialized
[975.596405 < 0.001740 >] usbcore: registered new interface driver usbfs
[975.596893 < 0.000488 >] usbcore: registered new interface driver hub
[975.597229 < 0.000336 >] usbcore: registered new device driver usb
[975.598419 < 0.001190 >] i2c_omap i2c_omap.1: bus 1 rev3.12 at 400 kHz
[975.600860 < 0.002441 >] regulator: VDCDC1: 1200 mV normal
[975.601531 < 0.000671 >] regulator: VDCDC2: 3300 mV normal
[975.602111 < 0.000580 >] regulator: VDCDC3: 1800 mV normal
[975.602691 < 0.000580 >] regulator: LDO1: 1800 mV normal
[975.603302 < 0.000611 >] regulator: LDO2: 3300 mV normal
[975.603790 < 0.000488 >] i2c_omap i2c_omap.2: bus 2 rev3.12 at 400 kHz
[975.615753 < 0.011963 >] pca953x 2-0021: failed reading register
[975.615814 < 0.000061 >] pca953x: probe of 2-0021 failed with error -5
[975.631347 < 0.015533 >] i2c_omap i2c_omap.3: bus 3 rev3.12 at 400 kHz
[975.646972 < 0.015625 >] tca6416-keypad 3-0020: failed reading register
[975.647003 < 0.000031 >] tca6416-keypad: probe of 3-0020 failed with error -5
[975.647369 < 0.000366 >] pca953x 3-0021: failed reading register
[975.647399 < 0.000030 >] pca953x: probe of 3-0021 failed with error -5
[975.649597 < 0.002198 >] Switching to clocksource 32k_counter
[975.652587 < 0.002990 >] musb_hdrc: version 6.0, cppi4.1-dma, otg (peripheral+host), debug=0
[975.673583 < 0.020996 >] AM3517 OTG revision 4ea41001, PHY f0036a2, control 00
[975.673980 < 0.000397 >] musb_hdrc: ConfigData=0x1e (UTMI-8, dyn FIFOs, HB-ISO Rx, HB-ISO Tx, SoftConn)
[975.674011 < 0.000031 >] musb_hdrc: MHDRC RTL version 1.900
[975.674041 < 0.000030 >] musb_hdrc: setup fifo_mode 4
[975.674072 < 0.000031 >] musb_hdrc: 28/31 max ep, 16384/32768 memory
[975.674133 < 0.000061 >] musb_hdrc: USB OTG mode controller at c8810000 using DMA, IRQ 71
[975.674957 < 0.000824 >] NET: Registered protocol family 2
[975.675170 < 0.000213 >] IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
[975.675750 < 0.000580 >] TCP established hash table entries: 4096 (order: 3, 32768 bytes)
[975.675903 < 0.000153 >] TCP bind hash table entries: 4096 (order: 2, 16384 bytes)
[975.675994 < 0.000091 >] TCP: Hash tables configured (established 4096 bind 4096)
[975.676025 < 0.000031 >] TCP reno registered
[975.676025 < 0.000000 >] UDP hash table entries: 256 (order: 0, 4096 bytes)
[975.676086 < 0.000061 >] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes)
[975.676300 < 0.000214 >] NET: Registered protocol family 1
[975.676757 < 0.000457 >] RPC: Registered udp transport module.
[975.676757 < 0.000000 >] RPC: Registered tcp transport module.
[975.676788 < 0.000031 >] RPC: Registered tcp NFSv4.1 backchannel transport module.
[975.677612 < 0.000824 >] AM3517 Linux PSP version 03.00.01.06 (AM3517EVM)
[975.677642 < 0.000030 >] NetWinder Floating Point Emulator V0.97 (double precision)
[975.679718 < 0.002076 >] VFS: Disk quotas dquot_6.5.2
[975.679809 < 0.000091 >] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[975.681152 < 0.001343 >] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
[975.681915 < 0.000763 >] JFFS2 version 2.2. (NAND) © 2001-2006 Red Hat, Inc.
[975.682556 < 0.000641 >] yaffs Jul 21 2011 23:38:33 Installing.
[975.682647 < 0.000091 >] msgmni has been set to 234
[975.684478 < 0.001831 >] alg: No test for stdrng (krng)
[975.684570 < 0.000092 >] io scheduler noop registered
[975.684600 < 0.000030 >] io scheduler deadline registered
[975.684783 < 0.000183 >] io scheduler cfq registered (default)
[975.743713 < 0.058930 >] OMAP DSS rev 2.0
[975.743774 < 0.000061 >] OMAP DISPC rev 3.0
[975.743835 < 0.000061 >] OMAP VENC rev 2
[975.744262 < 0.000427 >] OMAP DSI rev 1.0
[976.093170 < 0.348908 >] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[976.115844 < 0.022674 >] serial8250.0: ttyS0 at MMIO 0x4806a000 (irq = 72) is a ST16654
[976.136901 < 0.021057 >] serial8250.1: ttyS1 at MMIO 0x4806c000 (irq = 73) is a ST16654
[976.157775 < 0.020874 >] serial8250.2: ttyS2 at MMIO 0x49020000 (irq = 74) is a ST16654
[976.640075 < 0.482300 >] console [ttyS2] enabled
[976.655975 < 0.015900 >] brd: module loaded
[976.665496 < 0.009521 >] loop: module loaded
[976.669799 < 0.004303 >] omap2-nand driver initializing
[976.674407 < 0.004608 >] NAND device: Manufacturer ID: 0xec, Chip ID: 0xdc (Samsung NAND 512MiB 3,3V 8-bit)
[976.683166 < 0.008759 >] Creating 5 MTD partitions on "omap2-nand.0":
[976.688537 < 0.005371 >] 0x000000000000-0x000000080000 : "xloader-nand"
[976.696075 < 0.007538 >] 0x000000080000-0x000000240000 : "uboot-nand"
[976.703582 < 0.007507 >] 0x000000240000-0x000000280000 : "params-nand"
[976.710388 < 0.006806 >] 0x000000280000-0x000000780000 : "linux-nand"
[976.719055 < 0.008667 >] 0x000000780000-0x000020000000 : "jffs2-nand"
[976.934783 < 0.215728 >] vcan: Virtual CAN interface driver
[976.939331 < 0.004548 >] CAN device driver interface
[976.943206 < 0.003875 >] TI High End CAN Controller Driver 0.7
[976.948028 < 0.004822 >] failed to get can_stb
[976.952362 < 0.004334 >] ti_hecc ti_hecc.1: device registered (reg_base=c8870000, irq=24)
[976.960357 < 0.007995 >] usbcore: registered new interface driver hwa-rc
[976.966766 < 0.006409 >] usbmon: debugfs is not available
[976.971130 < 0.004364 >] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[976.977783 < 0.006653 >] ~~~~~~~~~~~~~~~~~~~~~0!!!!!!!!!!!~~~~~~~~~`
[976.983093 < 0.005310 >] ~~~~~~~~~~~~~~~~~~~~~1!!!!!!!!!!!~~~~~~~~~`
[976.988555 < 0.005462 >] ehci-omap ehci-omap.0: OMAP-EHCI Host Controller
[976.994445 < 0.005890 >] ehci-omap ehci-omap.0: new USB bus registered, assigned bus number 1
[977.002136 < 0.007691 >] ehci-omap ehci-omap.0: irq 77, io mem 0x48064800
[977.016937 < 0.014801 >] ehci-omap ehci-omap.0: USB 2.0 started, EHCI 1.00
[977.023925 < 0.006988 >] hub 1-0:1.0: USB hub found
[977.027801 < 0.003876 >] hub 1-0:1.0: 3 ports detected
[977.056243 < 0.028442 >] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[977.062957 < 0.006714 >] usbcore: registered new interface driver hwa-hc
[977.069000 < 0.006043 >] usbcore: registered new interface driver wusb-cbaf
[977.074920 < 0.005920 >] Initializing USB Mass Storage driver...
[977.080230 < 0.005310 >] usbcore: registered new interface driver usb-storage
[977.086273 < 0.006043 >] USB Mass Storage support registered.
[977.091033 < 0.004760 >] g_ether gadget: using random self ethernet address
[977.096954 < 0.005921 >] g_ether gadget: using random host ethernet address
[977.103607 < 0.006653 >] usb0: MAC 2a:eb:77:58:8e:fb
[977.107482 < 0.003875 >] usb0: HOST MAC 8e:c8:d7:06:a7:9f
[977.111907 < 0.004425 >] g_ether gadget: Ethernet Gadget, version: Memorial Day 2008
[977.118591 < 0.006684 >] g_ether gadget: g_ether ready
[977.122650 < 0.004059 >] musb_hdrc musb_hdrc: MUSB HDRC host driver
[977.127929 < 0.005279 >] musb_hdrc musb_hdrc: new USB bus registered, assigned bus number 2
[977.136474 < 0.008545 >] hub 2-0:1.0: USB hub found
[977.140289 < 0.003815 >] hub 2-0:1.0: 1 port detected
[977.145568 < 0.005279 >] mice: PS/2 mouse device common for all mice
[977.151184 < 0.005616 >] tsc2003 init
[977.153900 < 0.002716 >] tsc2003 probe
[977.156585 < 0.002685 >] mux: Setting signal mcspi1_cs2.gpio176 0x0114 -> 0x011c
[977.156616 < 0.000031 >] tsc2003 begin
[977.159454 < 0.002838 >] GPIO176 irqqq :336
[977.162963 < 0.003509 >] input: tsc2003 as /class/input/input0
[977.212280 < 0.049317 >] tsc2003 x:-5 y:-5 z:-5 bate:-5
[977.419555 < 0.207275 >] rtc-s35390a 1-0030: error resetting chip
[977.426361 < 0.006806 >] rtc-s35390a: probe of 1-0030 failed with error -5
[977.432525 < 0.006164 >] Linux video capture interface: v2.00
[977.437622 < 0.005097 >] vpfe_init
[977.440124 < 0.002502 >] vpfe-capture vpfe-capture: v4l2 device registered
[977.446350 < 0.006226 >] vpfe-capture vpfe-capture: video device registered
[977.452911 < 0.006561 >] tvp514x 3-005c: tvp514x 3-005c decoder driver registered !!
[977.459655 < 0.006744 >] vpfe-capture vpfe-capture: v4l2 sub device tvp5146 registered
[977.466827 < 0.007172 >] vpfe_register_ccdc_device: DM6446 CCDC
[977.471832 < 0.005005 >] DM6446 CCDC is registered with vpfe.
[977.477508 < 0.005676 >] OMAP Watchdog Timer Rev 0x31: initial timeout 60 sec
[977.484954 < 0.007446 >] mmci-omap-hs mmci-omap-hs.1: err -16 configuring card detect
[977.493164 < 0.008210 >] usbcore: registered new interface driver usbhid
[977.498840 < 0.005676 >] usbhid: USB HID core driver
[977.503112 < 0.004272 >] Advanced Linux Sound Architecture Driver Version 1.0.21.
[977.512542 < 0.009430 >] No device for DAI AD73311
[977.516479 < 0.003937 >] Asahi Kasei AK4104 ALSA SoC Codec Driver
[977.521820 < 0.005341 >] No device for DAI AK4535
[977.526000 < 0.004180 >] Cirrus Logic CS4270 ALSA SoC Codec Driver
[977.531311 < 0.005311 >] No device for DAI PCM3008 HiFi
[977.536804 < 0.005493 >] No device for DAI SSM2602
[977.540588 < 0.003784 >] No device for DAI tlv320aic23
[977.657623 < 0.117035 >] mmc0: new high speed SD card at address 6919
[977.663635 < 0.006012 >] mmcblk0: mmc0:6919 SD02G 1.83 GiB
[977.668487 < 0.004852 >] mmcblk0: p1 p2
[977.993530 < 0.325043 >] No device for DAI tlv320aic3x
[977.998107 < 0.004577 >] No device for DAI UDA134X
[978.002105 < 0.003998 >] No device for DAI WM8510 HiFi
[978.007354 < 0.005249 >] No device for DAI WM8728
[978.011505 < 0.004151 >] No device for DAI WM8750
[978.016510 < 0.005005 >] No device for DAI WM8971
[978.021636 < 0.005126 >] No device for DAI WM8990 ADC/DAC Primary
[978.027679 < 0.006043 >] No device for DAI omap-mcbsp-dai-0
[978.032135 < 0.004456 >] No device for DAI omap-mcbsp-dai-1
[978.036712 < 0.004577 >] No device for DAI omap-mcbsp-dai-2
[978.041229 < 0.004517 >] No device for DAI omap-mcbsp-dai-3
[978.045684 < 0.004455 >] No device for DAI omap-mcbsp-dai-4
[978.050170 < 0.004486 >] OMAP3517 / AM3517 EVM SoC init
[978.056335 < 0.006165 >] asoc: tlv320aic3x <-> omap-mcbsp-dai-0 mapping ok
[978.063140 < 0.006805 >] Failed to add route IN1L->LINE1L
[978.067504 < 0.004364 >] dapm: tlv320aic3x: configuring unknown pin Line Out
[978.080322 < 0.012818 >] ALSA device list:
[978.083312 < 0.002990 >] #0: am3517evm (tlv320aic3x)
[978.087646 < 0.004334 >] TCP cubic registered
[978.090911 < 0.003265 >] NET: Registered protocol family 17
[978.095458 < 0.004547 >] NET: Registered protocol family 15
[978.099975 < 0.004517 >] can: controller area network core (rev 20090105 abi 8)
[978.106353 < 0.006378 >] NET: Registered protocol family 29
[978.110931 < 0.004578 >] can: raw protocol (rev 20090105)
[978.115203 < 0.004272 >] can: broadcast manager protocol (rev 20090105 t)
[978.121582 < 0.006379 >] Power Management for TI OMAP3.
[978.125976 < 0.004394 >] Disabling unused clock "emac_fck"
[978.125976 < 0.000000 >] Disabling unused clock "emac_ick"
[978.126007 < 0.000031 >] Disabling unused clock "mcbsp_fck"
[978.126037 < 0.000030 >] Disabling unused clock "mcbsp_fck"
[978.126037 < 0.000000 >] Disabling unused clock "mcbsp_fck"
[978.126068 < 0.000031 >] Disabling unused clock "mcbsp_ick"
[978.126098 < 0.000030 >] Disabling unused clock "mcbsp_ick"
[978.126098 < 0.000000 >] Disabling unused clock "mcbsp_ick"
[978.126129 < 0.000031 >] Disabling unused clock "gpt2_ick"
[978.126129 < 0.000000 >] Disabling unused clock "gpt3_ick"
[978.126159 < 0.000030 >] Disabling unused clock "gpt4_ick"
[978.126159 < 0.000000 >] Disabling unused clock "gpt5_ick"
[978.126190 < 0.000031 >] Disabling unused clock "gpt6_ick"
[978.126220 < 0.000030 >] Disabling unused clock "gpt7_ick"
[978.126220 < 0.000000 >] Disabling unused clock "gpt8_ick"
[978.126251 < 0.000031 >] Disabling unused clock "gpt9_ick"
[978.126251 < 0.000000 >] Disabling unused clock "wdt3_ick"
[978.126281 < 0.000030 >] Disabling unused clock "wdt3_fck"
[978.126342 < 0.000061 >] Disabling unused clock "gpio2_dbck"
[978.126373 < 0.000031 >] Disabling unused clock "gpio3_dbck"
[978.126373 < 0.000000 >] Disabling unused clock "gpio4_dbck"
[978.126403 < 0.000030 >] Disabling unused clock "gpio5_dbck"
[978.126403 < 0.000000 >] Disabling unused clock "gpio6_dbck"
[978.126434 < 0.000031 >] Disabling unused clock "gpt9_fck"
[978.126464 < 0.000030 >] Disabling unused clock "gpt8_fck"
[978.126464 < 0.000000 >] Disabling unused clock "gpt7_fck"
[978.126495 < 0.000031 >] Disabling unused clock "gpt6_fck"
[978.126495 < 0.000000 >] Disabling unused clock "gpt5_fck"
[978.126525 < 0.000030 >] Disabling unused clock "gpt4_fck"
[978.126525 < 0.000000 >] Disabling unused clock "gpt3_fck"
[978.126556 < 0.000031 >] Disabling unused clock "gpt2_fck"
[978.126556 < 0.000000 >] Disabling unused clock "gpt12_ick"
[978.126586 < 0.000030 >] Disabling unused clock "wdt1_ick"
[978.126617 < 0.000031 >] Disabling unused clock "gpio1_dbck"
[978.126617 < 0.000000 >] Disabling unused clock "mcbsp_ick"
[978.126647 < 0.000030 >] Disabling unused clock "mcbsp_ick"
[978.126678 < 0.000031 >] Disabling unused clock "gpt10_ick"
[978.126678 < 0.000000 >] Disabling unused clock "gpt11_ick"
[978.126708 < 0.000030 >] Disabling unused clock "mcspi_ick"
[978.126708 < 0.000000 >] Disabling unused clock "mcspi_ick"
[978.126739 < 0.000031 >] Disabling unused clock "mcspi_ick"
[978.126770 < 0.000031 >] Disabling unused clock "mcspi_ick"
[978.126770 < 0.000000 >] Disabling unused clock "hdq_ick"
[978.126800 < 0.000030 >] Disabling unused clock "hdq_fck"
[978.126800 < 0.000000 >] Disabling unused clock "mcspi_fck"
[978.126831 < 0.000031 >] Disabling unused clock "mcspi_fck"
[978.126831 < 0.000000 >] Disabling unused clock "mcspi_fck"
[978.126861 < 0.000030 >] Disabling unused clock "mcspi_fck"
[978.126861 < 0.000000 >] Disabling unused clock "mcbsp_fck"
[978.126892 < 0.000031 >] Disabling unused clock "mcbsp_fck"
[978.126922 < 0.000030 >] Disabling unused clock "gpt11_fck"
[978.126922 < 0.000000 >] Disabling unused clock "gpt10_fck"
[978.126953 < 0.000031 >] Disabling unused clock "dpll4_m6x2_ck"
[978.126983 < 0.000030 >] Disabling unused clock "dpll4_m5x2_ck"
[978.126983 < 0.000000 >] Disabling unused clock "dpll3_m3x2_ck"
[978.127014 < 0.000031 >] Disabling unused clock "sys_clkout1"
[978.127593 < 0.000579 >] VFP support v0.3: implementor 41 architecture 3 part 30 variant c rev 1
[978.151489 < 0.023896 >] Console: switching to colour frame buffer device 100x30
[978.239227 < 0.087738 >] omapdss DPI: Could not find exact pixel clock. Requested 35087 kHz, got 35086 kHz
[978.250549 < 0.011322 >] davinci_emac_probe: using random MAC addr: 4e:14:cb:c5:2f:c9
[978.260040 < 0.009491 >] emac-mii: probed
[978.263214 < 0.003174 >] drivers/rtc/hctosys.c: unable to open rtc device (rtc0)
[978.269744 < 0.006530 >] omapdss DPI error: display already enabled
[978.274932 < 0.005188 >] omap_vout omap_vout: 'lcd' Display already enabled
[978.280822 < 0.005890 >] omapdss DPI error: display already enabled
[978.286010 < 0.005188 >] omap_vout omap_vout: 'lcd' Display already enabled
[978.291931 < 0.005921 >] omap_vout omap_vout: Buffer Size = 3686400
[978.298675 < 0.006744 >] omap_vout omap_vout: : registered and initialized video device 1
[978.305816 < 0.007141 >] omap_vout omap_vout: Buffer Size = 3686400
[978.312561 < 0.006745 >] omap_vout omap_vout: : registered and initialized video device 2
[978.823852 < 0.511291 >] eth0: attached PHY driver [Generic PHY] (mii_bus:phy_addr=ffffffff:00, id=221613)
[979.837310 < 1.013458 >] Sending DHCP and RARP requests ...... timed out!
[1054.362609 < 74.525299 >] IP-Config: Reopening network devices...
[1054.869781 < 0.507172 >] eth0: attached PHY driver [Generic PHY] (mii_bus:phy_addr=ffffffff:00, id=221613)
[1055.884124 < 1.014343 >] Sending DHCP and RARP requests ...... timed out!
[1131.878112 < 75.993988 >] IP-Config: Auto-configuration of network failed.
[1134.965942 < 3.087830 >] Empty flash at 0x00c5f3e4 ends at 0x00c5f800
[1137.241119 < 2.275177 >] Empty flash at 0x1ae5d108 ends at 0x1ae5d800
[1137.671966 < 0.430847 >] VFS: Mounted root (jffs2 filesystem) on device 31:4.
[1137.678161 < 0.006195 >] Freeing init memory: 168K
[1139.638549 < 1.960388 >] JFFS2 notice: (596) check_node_data: wrong data CRC in data node at 0x1ae5cfac: read 0x2efd2e64, calculated 0x5fa9cf47.
[1143.775421 < 4.136872 >] yaffs: dev is 187695104 name is "mmcblk0"
[1143.780517 < 0.005096 >] yaffs: passed flags ""
[1143.783996 < 0.003479 >] yaffs: Attempting MTD mount on 179.0, "mmcblk0"
[1143.938781 < 0.154785 >] yaffs: dev is 187695104 name is "mmcblk0"
[1143.944000 < 0.005219 >] yaffs: passed flags ""
[1143.947448 < 0.003448 >] yaffs: Attempting MTD mount on 179.0, "mmcblk0"
[1145.161468 < 1.214020 >] EXT2-fs (mmcblk0p2): warning: mounting ext3 filesystem as ext2
[1145.168579 < 0.007111 >] EXT2-fs (mmcblk0p2): warning: maximal mount count reached, running e2fsck is recommended

首先我们发现最浪费时间的在试图动态获得网络IP那一块。然后第二多的就是各种文件系统初始化花费的时间。
作为一款Cortex-A8产品，TI的AM3517在基本的代码运行方面可以说表现得非常出色。不需要做太多的优化。
那前面提到的IP获取那一块，及文件系统方面问题怎么解决呢。
网络，请在内核配置里关掉相关的动态获取ＩＰ的选择，对于嵌入式产品通常这是用不到的，而这里的慢，也正是因为实质上没有提供ＤＨＣＰ服务器。
当然，如果能进一步优化一下网络PHY那一块的代码，使得驱动只汇报有一个PHY, 也会快不少。
eth0: attached PHY driver [Generic PHY] (mii_bus:phy_addr=ffffffff:00, id=221613)　（这是合众达优化前检测ＰＨＹ的地址，导致系统后面按照32个ＰＨＹ去做ＤＨＣＰ请求，显然会是超慢的）
eth0: attached PHY driver [Generic PHY] (mii_bus:phy_addr=1:00, id=221613　（这是合众达优化后的情况，系统正确的识别了只有一个ＰＨＹ，这样后面的检测自然会快很多）

文件系统，只保留你用得到的，其它的都关掉吧。比如上面的同时启用Flash的JFFS2和YAFFS2, 实际的产品中是不可能同时使用两种文件系统的，除非板子上即用了Nor Flash又使用了NAND Flash

这是内核方面的问题。

后面我们将继续讲述，UBoot加载内核时发生的情况。

——未完待续——

只看该作者 · 2011-7-24 22:56

本帖最后由 blacksword 于 2011-7-24 22:59 编辑

按照前一讲所述的方法处理后Linux内核的启动已经相当快了。
但很多人可能注意到在系统上电以后在内核开始有输出之前使用的时间太长了，可能有几秒。
那这是怎么一回事呢？

目前由于Linux系统比较庞大，大部份产品都使用了NAND　Flash。　
大家都知道，NAND　Flash本身是不可以CPU直接寻址的，因此不可以直接执行代码，因此要执行NAND里面的代码，就必须把NAND里面的代码复制到RAM里去。Linux内核本身也是系统需要运行的代码，当然也不能免俗。
我们知道所有TI的EVM上，我们知道Linux内核的启动是由一个叫作UBoot的启动引导器完成的。
那么UBoot要能够从NAND里复制Linux内核，当然是需要时间的。这个时间的长度与两个方面的因素有关系。
1. 内核本身的大小。显然一个1MB大小的内核要花费比一个2MB大小的内核少一半的时间
2. UBoot复制内核的速度。

对于问题1, 很明显，我们需要加快时间，就必须让内核尽可能的小。这就需要我们非常明确哪些是系统必须的功能。比如一个只有NAND也不会接USB存储器的系统，可能只需要引入一个YAFFS2文件系统，而内核所带的其它文件系统都可以裁掉。不用网络的系统，所有网络相关的内容都可以去掉，即使是使用网络，可能对于大部分人来说IPV6也不是必须以。通过这一步将内核的大小控制在1MB以下是非常现实的。

对于问题２,　这个问题通常不大对于大部分人而言，只要内核裁剪到１MB以下，从UBoot开始加载内核到内核启动完成应该在4秒钟以内（UBoot的等待功能关闭）。当然有些应用中可能需要进一步优化这一块的时间，这里其实还是有比较大的优化空间的，那就是要修改UBoot的MTD相关的驱动了，通过使用DMA来进行NAND的而传输，而不是CPU直接读取的方式。不过这一块获得的好处不会超过０.５秒。

其实还有一个隐性的问题，大家都没有注意到。那就是UBoot本身也是代码，也是存放在NAND里面的。系统一上电时，CPU的硬件逻辑只会从NAND里面读取一个块。而这一个块只有小小的几KB。也是不可能存放下全部的UBOOT代码的。也就是UBOOT代码本身要完成其余部分的加载。而在这一块代码的好坏影响非常大。比如说在S3C2410的平台上，DENX提供的默认代码，需要花10秒左右来复制UBOOT的剩余部分。而笔者修改之后只需要0.1秒即可。这主要是由于系统刚开始是工作在较低的主频下造成的。
这在Cortex-A8的Sitara平台上可能问题都不大，在UB00t之前TI有一个叫做X-Loader的程序，该程序一上来就已经将CPU设置到最快的运行速度上，这样系统的复制速度应该还可以。

那么对于使用ARM926的一些TI产品，你需要检查一下这一块所耗费的时间，如果时间比较长的话，你可以看一下U-Boot/cpu/arm926ejs/start.S文件。在relocate:之前完成CPU时钟的设置。

/*
  * we do sys-critical inits only at reboot,
  * not when booting from ram!
  */
#ifndef CONFIG_SKIP_LOWLEVEL_INIT
bl cpu_init_crit
#endif
#ifndef CONFIG_SKIP_RELOCATE_UBOOT
relocate: /* relocate U-Boot to RAM    */
adr r0, _start  /* r0 <- current position of code */
ldr r1, _TEXT_BASE  /* test if we run from flash or RAM */
cmp    r0, r1                /* don't reloc during debug       */
beq    stack_setup
ldr r2, _armboot_start
ldr r3, _bss_start
sub r2, r3, r2  /* r2 <- size of armboot          */
add r2, r0, r2  /* r2 <- source end address       */
copy_loop:　　　/* 这段循环即是用来复制UBOOT本身的 */
ldmia r0!, {r3-r10}  /* copy from source address [r0] */
stmia r1!, {r3-r10}  /* copy to target address [r1] */
cmp r0, r2 /* until source end addreee [r2] */
ble copy_loop
#endif /* CONFIG_SKIP_RELOCATE_UBOOT */

这时UBoot相关的情况。

——未完待续——

只看该作者 · 2011-7-31 08:40

鲜花，掌声，板砖，或是臭**蛋神马的有木有？
扔点过来呀。

只看该作者 · 2011-8-4 17:02

鼓励一下，看最终能做到多少秒！！！

我之前用400M的arm9，linux2.6.21，yaffs文件系统，从按复位到自己的GUI起来能在5秒内完成，也没做什么特殊优化。。就是裁剪掉不需要的功能，bootloader中一开机设置主频，开MMU，基本上就能在5秒左右。

只看该作者 · 2011-8-13 23:18

前面我们讲述了：
１内核对耗时较大的功能对启动速度的影响．
２内核的大小对启动速度的影响
３bootloader对启动速度的影响

那么这一节，我们看一下基本文件系统及工具对启动速度的影响．
４　基本文件系统对启动速度的影响
使用TI　arago文件系统的朋友可能会发现一个问题，在内核启动结束到串口看到命令行提示符耗时非常多．这个问题不光在arago文件系统中存在，在以前使用MontaVista Linux的产品上同样存在．
如果朋友们有拿秒表测试过的话，会知道，使用MV的文件系统和arago文件系统的启动时间通常在１分半钟甚至在2分钟以上．
按说原厂或是专业Linux厂商提供的文件系统应该很好才对，可是为什么反而启动得非常慢呢？
其实这就是一对非常典型的矛盾造成的．向MontaVista这样的嵌入式Linux发行版或是厂商提供的Linux文件系统希望能够解决启动速度的问题，但他们又面监一个非常严重的兼容性问题，不同的客户有不同的功能及实用工具需求．而后者是可用性的问题，必须放在第一位来解决的．这个前提一确定，无论发行版厂商或是原厂如何努力，只要您不是下单单独定制相关的文件系统，那么无论如何你的Linux启动都是非常慢的，只是比不做优化稍好点而已．
那么是不是我们就没有办法了，如果说你要开发的产品是用来替代PC功能，最终产品除了操作系统由Windows换到Linux以外，仍然少不了PC那样的应用需求．那么建议您还是使用一个发行版会好些，毕竟在这样的系统上满足系统更多的功能需求比启动速度提供两三秒更有意义．
如果是功能专一的产品，那么我们有什么理由还让文件系统里存在那些我们八辈子也用不着的东西．套用我们老家的一句话＂八杆子也打不着的亲戚，不是亲戚＂．
这时我们可以有两个选择：
选择a 使用发行版来开发产品，最后拿发行版的文件系统来进行量体裁衣．
这里我要澄清一个概念，以前经常听人说嵌入式系统要做文件系统的裁剪，这样的提法本质上可以说是相当错误的．裁剪是什么意思，就是一个大而全的系统里做减法，百密难免一疏，出来的系统不可能是非常干净的，肯定有很多脏东西（用不到的影响系统速度的东西）．因此可以说做减法就像是在拿一件大人的衣服改小给小孩穿，无论裁缝的水平多高，多少这件衣服是有那么一点不合身的．因此最理想的做法是做加法，也就是拿原来的那一堆东西当原理，当成布，用他来设计新衣服．那么应该如何来做这个加法呢．　工具链的提供通常都提供了一个工具ldd. 你可以在产品上运行ldd也可以在主机上运行如arm-linux-gnueabi-ldd. 参数就是你最终为产品开发的那些程序．运行ldd工具，它会列出你的产品都调用了哪些库，这样你只要抓出这些最基本的库加上你开发的东西，足以形成一个最精简的产品文件系统．当然为了满足将来产品方便做现在调试，可能还要加上一些实用小工具，这一块就需要有比较的Linux实用工具背景了，才知道放哪些东西对自己的产品比较合适．但我想对于大部分人ls cat 等基本工具都是必须的．

选择a 使用busybox来从头构建自己的全定制文件系统，这也是我个人最喜欢的方式．因为这种方式定制出来的东西，绝对是深度嵌入式的．而已需要加哪些小工具，是直接在一个选择列表里进行选择的，每一个选择项都比较简明扼要的相关说明．然后您应该基于这个文件系统来开发相关的产品软件．

这一讲是基本文件系统相关的内容．

——未完待续—— 求鲜花 **蛋掌声嘘声板砖，多扔少扔多少要扔早扔晚扔早晚要扔

只看该作者 · 2011-8-13 23:29

对于基本文件系统的补充，
如果你不知如何使用busybox来构建相关的文件系统，那么建议购买一套seed-dim3517-kit

当时我在合众达负责相关产品时，组织落实了《SEED-DIM3517文件系统移植指南》。由于时间匆忙的原因，这篇文档可能写得不是尽善尽美，但只要有一点点的基础，看完这篇指南还是可以搞定文件系统这个问题的。

合众达SEED-DIM3517系列产品的光盘提供的全部文档如下
|---03. User Manual
| | |---SEED-DIM3517 硬件用户指南
| | |---SEED-DIM_GB 硬件用户指南
| | |---SEED-DIM3517 快速入门手册
| | |---SEED-DIM3517 3DQT移植指南
| | |---SEED-DIM3517 文件系统移植指南
| | |---SEED-DIM3517 LINUX 软件移植指南
| | |---SEED-DIM3517 QT图形库移植及使用指南
| |---|---SEED-DIM3517 Linux BSP 移植及使用指南

如果有相关的需求，可以直接联系合众达各地的办事处。
这里我就不公布合众达各办事处的联系电话了，否则太有为老东家做广告的嫌疑。

当然了，如果你急需购买一套产品的话，怕走那边的流程太慢，或许想要一个内部价的话，请我吃饭呀（开玩笑的，找合众达官方买是正途）。

只看该作者 · 2011-8-15 23:24

好文，支持！

只看该作者 · 2011-8-15 23:26

好文，支持！

我们目前只做到了7-8s的样子，300M的ARM

只看该作者 · 2011-8-19 10:07

太强了，居然是小说连载。逼着大家顶你的帖子啊：）

只看该作者 · 2011-9-6 16:01

1）首先是对Linux启动过程的跟踪和分析，生成详细的启动时间报告。

　　较为简单可行的方式是通过PrintkTime功能为启动过程的所有内核信息增加时间戳，便于汇总分析。PrintkTime最早为CELF所提供的一个内核补丁，在后来的Kernel 2.6.11版本中正式纳入标准内核。所以大家可能在新版本的内核中直接启用该功能。如果你的Linux内核因为某些原因不能更新为2.6.11之后的版本，那么可以参考CELF提供的方法修改或直接下载它们提供的补丁：http://tree.celinuxforum.org/CelfPubWiki/PrintkTimes

　　开启PrintkTime功能的方法很简单，只需在内核启动参数中增加“time”即可。当然，你也可以选择在编译内核时直接指定“Kernel hacking”中的“Show timing information on printks”来强制每次启动均为内核信息增加时间戳。这一种方式还有另一个好处：你可以得到内核在解析启动参数前所有信息的时间。因此，我选择后一种方式。

　　当完成上述配置后，重新启动Linux，然后通过以下命令将内核启动信息输出到文件：

　　dmesg >　boottime.log
　　然后利用一个脚本“show_delta”（位于Linux源码的scripts文件夹下）将上述输出的文件转换为时间增量显示格式：

　　/usr/src/linux-x.xx.xx/scripts/show_delta ktime >dtime

　　这样，你就得到了一份关于Linux启动时间消耗的详细报告。

　　（2）然后，我们就来通过这份报告，找出启动中相对耗时的过程。

　　必须明确一点：报告中的时间增量和内核信息之间没有必然的对应关系，真正的时间消耗必须从内核源码入手分析。

　　这一点对于稍微熟悉编程的朋友来说都不难理解，因为时间增量只是两次调用printk之间的时间差值。通常来说，内核启动过程中在完成一些耗时的任务，如创建hash索引、probe硬件设备等操作后会通过printk将结果打印出来，这种情况下，时间增量往往反映的是信息对应过程的耗时；但有些时候，内核是在调用printk输出信息后才开始相应的过程，那么报告中内核信息相应过程的时间消耗对应的是其下一行的时间增量；还有一些时候，时间消耗在了两次内核信息输出之间的某个不确定的时段，这样时间增量可能就完全无法通过内核信息反应出来了。

　　所以，为了准确判断真正的时间消耗，我们需要结合内核源码进行分析。必要的时候，例如上述第三种情形下，还得自己在源码中插入printk打印，以进一步确定实际的时间消耗过程。