UBIFS NAND Boot

Thanks Cvetolin for the response,

I was able to find the issue, it was incorrect LEB value for ubifs.mk and wrong vol_name in ubinize.cfg.

Now the Kernel is booting, But it takes huge time to boot. It seems that reading rootfs from NAND is the bottleneck.

Here is the Kernel boot log,

[ 1.611581] oprofile: using arm/armv7
[ 1.615757] nf_conntrack version 0.5.0 (7899 buckets, 31596 max)
[ 1.623124] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 1.628990] Initializing XFRM netlink socket
[ 1.633752] NET: Registered protocol family 10
[ 1.640788] sit: IPv6 over IPv4 tunneling driver
[ 1.647224] NET: Registered protocol family 17
[ 1.651974] NET: Registered protocol family 15
[ 1.656925] Key type dns_resolver registered
[ 1.661763] omap_voltage_late_init: Voltage driver support not added
[ 1.668539] sr_dev_init: No voltage domain specified for smartreflex0. Cannot initialize
[ 1.677083] sr_dev_init: No voltage domain specified for smartreflex1. Cannot initialize
[ 1.686303] cpu cpu0: of_pm_voltdm_notifier_register: Failed to get cpu0 regulator/voltdm: -517
[ 1.695550] cpu cpu0: cpu0 clock notifier not ready, retry
[ 1.701694] ThumbEE CPU extension supported.
[ 1.706283] Registering SWP/SWPB emulation handler
[ 1.711338] SmartReflex Class3 initialized
[ 1.720063] OMAP GPIO hardware version 0.1
[ 1.727834] omap-gpmc 50000000.gpmc: GPMC revision 6.0
[ 1.733375] gpmc_mem_init: disabling cs 0 mapped at 0x0-0x1000000
[ 1.832557] nand: device found, Manufacturer ID: 0x2c, Chip ID: 0xcc
[ 1.839266] nand: Micron MT29F4G16ABADAWP
[ 1.843532] nand: 512 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[ 1.851576] nand: using OMAP_ECC_BCH8_CODE_HW ECC scheme
[ 1.857380] 12 ofpart partitions found on MTD device 8000000.nand
[ 1.863827] Creating 12 MTD partitions on "8000000.nand":
[ 1.869527] 0x000000000000-0x000000040000 : "NAND.SPL1"
[ 1.954936] 0x000000040000-0x000000340000 : "NAND.u-boot1"
[ 1.961869] g_ether gadget: high-speed config #1: CDC Ethernet (EEM)
[ 2.915470] 0x000000340000-0x000000380000 : "NAND.u-boot-env1"
[ 2.994382] 0x000000380000-0x000000400000 : "NAND.kernel-dtb1"
[ 3.154527] 0x000000400000-0x000000c00000 : "NAND.kernel1"
[ 5.713192] cfg80211: Calling CRDA to update world regulatory domain
[ 5.721482] 0x000000c00000-0x000010000000 : "NAND.rootfs1"
[ 82.292427] random: nonblocking pool is initialized
[ 83.803889] cfg80211: Calling CRDA to update world regulatory domain
[ 83.812259] 0x000010000000-0x000010040000 : "NAND.SPL2"
[ 83.894534] 0x000010040000-0x000010340000 : "NAND.u-boot2"
[ 84.854470] 0x000010340000-0x000010380000 : "NAND.u-boot-env2"
[ 84.934384] 0x000010380000-0x000010400000 : "NAND.kernel-dtb2"
[ 85.094617] 0x000010400000-0x000010c00000 : "NAND.kernel2"
[ 87.653183] cfg80211: Calling CRDA to update world regulatory domain
[ 87.661484] 0x000010c00000-0x000020000000 : "NAND.rootfs2"
[ 165.743329] cfg80211: Calling CRDA to update world regulatory domain
[ 165.772838] tps65910 0-002d: No interrupt support, no core IRQ
[ 165.782009] vrtc: failed to get the current voltage(-22)
[ 165.787942] tps65910 0-002d: failed to register tps65910-pmic regulator
[ 165.794976] tps65910-pmic: probe of tps65910-pmic failed with error -22
[ 165.803206] usb 1-1: new high-speed USB device number 3 using musb-hdrc
[ 165.810409] sbs-battery 0-0016: sbs_probe: Failed to get device status
[ 165.817429] sbs-battery: probe of 0-0016 failed with error -121
[ 165.828177] omap_i2c 44e0b000.i2c: bus 0 rev0.11 at 400 kHz
[ 165.836009] i2c i2c-2: of_i2c: modalias failure on /ocp/i2c@4819c000/eep@50
[ 165.843462] i2c i2c-2: of_i2c: modalias failure on /ocp/i2c@4819c000/ts1@48
[ 165.850792] i2c i2c-2: of_i2c: modalias failure on /ocp/i2c@4819c000/ts2@49
[ 165.858152] i2c i2c-2: of_i2c: modalias failure on /ocp/i2c@4819c000/adc@36
[ 165.865533] omap_i2c 4819c000.i2c: bus 2 rev0.11 at 400 kHz
[ 165.872600] omap_hsmmc 48060000.mmc: Got CD GPIO
[ 165.914420] davinci_evm sound: ASoC: DAPM unknown pin MONO_LOUT
[ 165.920665] davinci_evm sound: ASoC: DAPM unknown pin HPLCOM
[ 165.926752] davinci_evm sound: ASoC: DAPM unknown pin HPRCOM
[ 165.937887] davinci_evm sound: null-codec-dai <-> 48038000.mcasp mapping ok
[ 165.945341] davinci_evm sound: ASoC: no source widget found for TX
[ 165.951850] davinci_evm sound: ASoC: Failed to add route TX -> direct -> HDMI Out
[ 165.965557] cpu cpu0: of_pm_voltdm_notifier_register: Failed to get cpu0 regulator/voltdm: -517
[ 165.974846] cpu cpu0: cpu0 clock notifier not ready, retry
[ 165.981540] ubi0: attaching mtd5
[ 166.542595] usb 1-1: New USB device found, idVendor=1546, idProduct=1146
[ 166.549662] usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 166.557208] usb 1-1: Product: MODEM-LTE
[ 166.561246] usb 1-1: Manufacturer: u-blox
[ 166.565495] usb 1-1: SerialNumber: 000000000100
[ 167.444112] rndis_host 1-1:1.0 usb1: register 'rndis_host' at usb-musb-hdrc.1.auto-1, RNDIS device, 02:08:04:16:00:0b
[ 167.456398] cpu cpu0: of_pm_voltdm_notifier_register: Failed to get cpu0 regulator/voltdm: -517
[ 167.465650] cpu cpu0: cpu0 clock notifier not ready, retry
[ 167.472769] cpu cpu0: of_pm_voltdm_notifier_register: Failed to get cpu0 regulator/voltdm: -517
[ 167.481934] cpu cpu0: cpu0 clock notifier not ready, retry
[ 167.489796] cdc_acm 1-1:1.2: ttyACM0: USB ACM device
[ 167.573991] cpu cpu0: of_pm_voltdm_notifier_register: Failed to get cpu0 regulator/voltdm: -517
[ 167.583248] cpu cpu0: cpu0 clock notifier not ready, retry
[ 167.590415] cpu cpu0: of_pm_voltdm_notifier_register: Failed to get cpu0 regulator/voltdm: -517
[ 167.599656] cpu cpu0: cpu0 clock notifier not ready, retry
[ 168.962607] cfg80211: Calling CRDA to update world regulatory domain
[ 172.162585] cfg80211: Calling CRDA to update world regulatory domain
[ 175.362580] cfg80211: Calling CRDA to update world regulatory domain
[ 178.562576] cfg80211: Calling CRDA to update world regulatory domain
[ 181.762576] cfg80211: Calling CRDA to update world regulatory domain
[ 184.962578] cfg80211: Calling CRDA to update world regulatory domain
[ 188.162577] cfg80211: Exceeded CRDA call max attempts. Not calling CRDA
[ 322.242568] ubi0: scanning is finished
[ 322.688072] ubi0: attached mtd5 (name "NAND.rootfs1", size 244 MiB)
[ 322.694811] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
[ 322.702043] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 512
[ 322.709121] ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096
[ 322.716470] ubi0: good PEBs: 1952, bad PEBs: 0, corrupted PEBs: 0
[ 322.722905] ubi0: user volume: 1, internal volumes: 1, max. volumes count: 128
[ 322.730503] ubi0: max/mean erase counter: 2/0, WL threshold: 4096, image sequence number: 2008185989
[ 322.740134] ubi0: available PEBs: 0, total reserved PEBs: 1952, PEBs reserved for bad PEB handling: 80
[ 322.766541] ubi0: background thread "ubi_bgt0d" started, PID 51
[ 322.812504] davinci_mdio 4a101000.mdio: davinci mdio revision 1.6
[ 322.818921] davinci_mdio 4a101000.mdio: no live phy, scanning all
[ 322.825811] davinci_mdio: probe of 4a101000.mdio failed with error -5
[ 322.833723] cpsw 4a100000.ethernet: Missing slave[0] phy_id property
[ 322.840637] cpsw 4a100000.ethernet: Detected MACID = a0:f6:fd:4a:e2:19
[ 322.849860] omap_rtc 44e3e000.rtc: setting system clock to 2000-01-01 00:05:22 UTC (946685122)
[ 322.859049] sr_init: No PMIC hook to init smartreflex
[ 322.864713] sr_init: platform driver register failed for SR
[ 322.879794] vmmcsd_fixed: disabling
[ 322.883812] ALSA device list:


As you can see from the log time after NAND.rootfs1, its taking time.
Can any one give me a clue why its so slow and how to optimize the NAND boot itme.

Thanks

I forgot to add this, This is my device tree patch for the NAND, And I am using Micron MT29F4G16ABADAWP-IT

&gpmc {
status = "okay";
pinctrl-names = "default", "sleep";
pinctrl-0 = <&nandflash_pins_default>;
pinctrl-1 = <&nandflash_pins_sleep>;
ranges = <0 0 0x08000000 0x1000000>; /* CS0: 16MB for NAND */
nand@0,0 {
compatible = "ti,omap2-nand";
reg = <0 0 4>; /* CS0, offset 0, IO size 4 */
interrupt-parent = <&intc>;
interrupts = <100>;
ready-gpio = <&gpmc 0 GPIO_ACTIVE_HIGH>; /* gpmc_wait0 */
ti,nand-ecc-opt = "bch8";
ti,elm-id = <&elm>;
nand-bus-width = <16>;
gpmc,device-width = <2>;
gpmc,sync-clk-ps = <0>;
gpmc,cs-on-ns = <0>;
gpmc,cs-rd-off-ns = <44>;
gpmc,cs-wr-off-ns = <44>;
gpmc,adv-on-ns = <6>;
gpmc,adv-rd-off-ns = <34>;
gpmc,adv-wr-off-ns = <44>;
gpmc,we-on-ns = <0>;
gpmc,we-off-ns = <40>;
gpmc,oe-on-ns = <0>;
gpmc,oe-off-ns = <54>;
gpmc,access-ns = <64>;
gpmc,rd-cycle-ns = <82>;
gpmc,wr-cycle-ns = <82>;
gpmc,bus-turnaround-ns = <0>;
gpmc,cycle2cycle-delay-ns = <0>;
gpmc,clk-activation-ns = <0>;
gpmc,wr-access-ns = <40>;
gpmc,wr-data-mux-bus-ns = <0>;
/* MTD partition table */
#address-cells = <1>;
#size-cells = <1>;
partition@0 {
label = "NAND.SPL1";
reg = <0x00000000 0x000040000>;
};
partition@1 {
label = "NAND.u-boot1";
reg = <0x00040000 0x00300000>;
};
partition@2 {
label = "NAND.u-boot-env1";
reg = <0x00340000 0x00040000>;
};
partition@3 {
label = "NAND.kernel-dtb1";
reg = <0x00380000 0x00080000>;
};
partition@4 {
label = "NAND.kernel1";
reg = <0x00400000 0x00800000>;
};
partition@4 {
label = "NAND.kernel1";
reg = <0x00400000 0x00800000>;
};
partition@5 {
label = "NAND.rootfs1";
reg = <0x00C00000 0x0F400000>;
};
partition@6 {
label = "NAND.SPL2";
reg = <0x10000000 0x000040000>;
};
partition@7 {
label = "NAND.u-boot2";
reg = <0x10040000 0x00300000>;
};
partition@8 {
label = "NAND.u-boot-env2";
reg = <0x10340000 0x00040000>;
};
partition@9 {
label = "NAND.kernel-dtb2";
reg = <0x10380000 0x00080000>;
};
partition@10 {
label = "NAND.kernel2";
reg = <0x10400000 0x00800000>;
};
partition@11 {
label = "NAND.rootfs2";
reg = <0x10C00000 0x0F400000>;
};
};
};

Thanks Cvetolin for your inputs,

Yes, It was wrong configuration of NAND pins in device tree, such as required pins were not pulled-up including R/B signal. Now its booting fast. It still takes around 25 seconds. It would be grateful If you can give me some insights how to reduce it further.

Thanks

Nilan 

Nilan,

Booting time around 25 seconds seems normal but there are some techniques for optimization (reduction) system booting time. You can find details about booting optimization at the linked below articles:
processors.wiki.ti.com/.../Boot_Time_Optimization
processors.wiki.ti.com/.../Optimize_Linux_Boot_Time
processors.wiki.ti.com/.../Sitara_Linux_Training:_Boot_Time_Reduction

BR
Tsvetolin Shulev