AnsweredAssumed Answered

android6.0 imx6q & imx6dl kernel boot very slow (two issue)

Question asked by 昌清 黄 on Mar 28, 2017
Latest reply on Jan 17, 2018 by jiu jin hong
Our central control system started very slow, the customer asked to optimize the speed,
I found two serious problems in kernel4.1.15


Starting kernel ...

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Initializing cgroup subsys cpu
[ 0.000000] Initializing cgroup subsys cpuacct
[ 0.000000] Linux version 4.1.15 (huangcq@dell-PowerEdge-R720) (gcc version 4.9.x-google 20140827 (prerelease) (GCC) ) #53 SMP PREEMPT Tue Mar 28 15:40:18 CST 2017
[ 0.000000] CPU: ARMv7 Processor [412fc09a] revision 10 (ARMv7), cr=10c53c7d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] Machine model: Freescale i.MX6 Quad SABRE Smart Device Board
[ 0.000000] cma: Reserved 384 MiB at 0x26000000
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] PERCPU: Embedded 13 pages/cpu @eeeda000 s22144 r8192 d22912 u53248
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 522528
[ 0.000000] Kernel command line: console=ttymxc0,115200 init=/init video=mxcfb0:dev=ldb,bpp=32 video=mxcfb1:off video=mxcfb2:off video=mxcfb3:off vmalloc=256M androidboot.console=ttymxc0 consoleblank=0 androidboot.hardware=freescale cma=384M androidboot.selinux=disabled androidboot.dm_verity=disabled androidboot.serialno=011439d4e317e252
[ 0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Memory: 1664596K/2096128K available (11555K kernel code, 848K rwdata, 3532K rodata, 2048K init, 644K bss, 38316K reserved, 393216K cma-reserved, 1326080K highmem)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
[ 0.000000] vmalloc : 0xef800000 - 0xff000000 ( 248 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xef000000 ( 752 MB)
[ 0.000000] pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB)
[ 0.000000] modules : 0xbf000000 - 0xbfe00000 ( 14 MB)
[ 0.000000] .text : 0xc0008000 - 0xc0fbbdb4 (16080 kB)
[ 0.000000] .init : 0xc1000000 - 0xc1200000 (2048 kB)
[ 0.000000] .data : 0xc1200000 - 0xc12d4010 ( 849 kB)
[ 0.000000] .bss : 0xc12d4010 - 0xc13752e4 ( 645 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] Preemptible hierarchical RCU implementation.
[ 0.000000] Additional per-CPU info printed with stalls.
[ 0.000000] NR_IRQS:16 nr_irqs:16 16
[ 0.000000] L2C-310 erratum 769419 enabled
[ 0.000000] L2C-310 enabling early BRESP for Cortex-A9
[ 0.000000] L2C-310 full line of zeros enabled for Cortex-A9
[ 0.000000] L2C-310 ID prefetch enabled, offset 16 lines
[ 0.000000] L2C-310 dynamic clock gating enabled, standby mode enabled
[ 0.000000] L2C-310 cache controller enabled, 16 ways, 1024 kB
[ 0.000000] L2C-310: CACHE_ID 0x410000c7, AUX_CTRL 0x76070001
[ 0.000000] mxc_clocksource_init 3000000
[ 0.000000] Switching to timer-based delay loop, resolution 333ns
[ 0.000006] sched_clock: 32 bits at 3000kHz, resolution 333ns, wraps every 715827882841ns
[ 0.000024] clocksource mxc_timer1: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 637086815595 ns
[ 0.001078] Console: colour dummy device 80x30
[ 0.001099] Calibrating delay loop (skipped), value calculated using timer frequency.. 6.00 BogoMIPS (lpj=30000)
[ 0.001115] pid_max: default: 32768 minimum: 301
[ 0.001198] Security Framework initialized
[ 0.001211] SELinux: Initializing.
[ 0.001254] AppArmor: AppArmor disabled by boot time parameter
[ 0.001293] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.001305] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.002014] Initializing cgroup subsys freezer
[ 0.002035] Initializing cgroup subsys debug
[ 0.002063] CPU: Testing write buffer coherency: ok
[ 0.002411] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.002516] Setting up static identity map for 0x10100000 - 0x10100058
[ 0.060297] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.080278] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[ 0.100274] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[ 0.100348] Brought up 4 CPUs
[ 0.100373] SMP: Total of 4 processors activated (24.00 BogoMIPS).
[ 0.100382] CPU: All CPU(s) started in SVC mode.
[ 0.101020] devtmpfs: initialized
[ 0.113179] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
[ 0.113652] clocksource jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.135537] pinctrl core: initialized pinctrl subsystem
[ 0.136774] NET: Registered protocol family 16
[ 0.146475] DMA: preallocated 256 KiB pool for atomic coherent allocations
[ 0.169692] cpuidle: using governor ladder
[ 0.199687] cpuidle: using governor menu
[ 0.200263] CPU identified as i.MX6Q, silicon rev 1.5
[ 0.200379] Use WDOG1 as reset source
[ 0.226802] !!request miniPCIE Power On gpio
[ 0.226853] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.
[ 0.226862] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.226882] VDSO is not a valid ELF object!
[ 0.227594] imx6q-pinctrl 20e0000.iomuxc: Invalid fsl,pins property in node /soc/aips-bus@02000000/iomuxc@020e0000/imx6qdl-sabresd/enetgrp
[ 0.227616] imx6q-pinctrl 20e0000.iomuxc: no fsl,pins property in node /soc/aips-bus@02000000/iomuxc@020e0000/imx6qdl-sabresd/hdmicecgrp
[ 0.227657] imx6q-pinctrl 20e0000.iomuxc: no fsl,pins property in node /soc/aips-bus@02000000/iomuxc@020e0000/imx6qdl-sabresd/pwm1grp
[ 0.227693] imx6q-pinctrl 20e0000.iomuxc: Invalid fsl,pins property in node /soc/aips-bus@02000000/iomuxc@020e0000/imx6qdl-sabresd/wdoggrp
[ 0.227708] imx6q-pinctrl 20e0000.iomuxc: Invalid fsl,pins property in node /soc/aips-bus@02000000/iomuxc@020e0000/gpio_leds/gpioledsgrp
[ 0.228042] imx6q-pinctrl 20e0000.iomuxc: initialized IMX pinctrl driver
[ 0.272883] mxs-dma 110000.dma-apbh: initialized
[ 0.274557] MPCIE_3V3: Failed to request enable GPIO83: -16
[ 0.274680] reg-fixed-voltage regulators:regulator@3: Failed to register regulator: -16
[ 0.274709] reg-fixed-voltage: probe of regulators:regulator@3 failed with error -16
[ 0.277099] SCSI subsystem initialized
[ 0.277627] usbcore: registered new interface driver usbfs
[ 0.277711] usbcore: registered new interface driver hub
[ 0.277812] usbcore: registered new device driver usb
[ 0.278012] 2000000.aips-bus:usbphy_nop1 supply vcc not found, using dummy regulator
[ 0.278166] 2000000.aips-bus:usbphy_nop2 supply vcc not found, using dummy regulator
[ 0.279264] i2c i2c-0: Failed to register i2c client mma8451 at 0x1c (-16)
[ 0.279278] i2c i2c-0: of_i2c: Failure registering /soc/aips-bus@02100000/i2c@021a0000/mma8451@1c
[ 0.279440] i2c i2c-0: IMX I2C adapter registered
[ 0.279458] i2c i2c-0: can't use DMA
[ 0.280491] i2c i2c-1: IMX I2C adapter registered
[ 0.280507] i2c i2c-1: can't use DMA
[ 0.281272] i2c i2c-2: IMX I2C adapter registered
[ 0.281287] i2c i2c-2: can't use DMA
[ 0.281456] Linux video capture interface: v2.00
[ 0.299733] imx-ipuv3 2400000.ipu: IPU DMFC NORMAL mode: 1(0~1), 5B(4,5), 5F(6,7)
[ 0.319730] imx-ipuv3 2800000.ipu: IPU DMFC NORMAL mode: 1(0~1), 5B(4,5), 5F(6,7)
[ 0.321034] MIPI CSI2 driver module loaded
[ 0.321324] Advanced Linux Sound Architecture Driver Initialized.
[ 0.322681] Bluetooth: Core ver 2.20
[ 0.322730] NET: Registered protocol family 31
[ 0.322739] Bluetooth: HCI device and connection manager initialized
[ 0.322754] Bluetooth: HCI socket layer initialized
[ 0.322769] Bluetooth: L2CAP socket layer initialized
[ 0.322812] Bluetooth: SCO socket layer initialized
[ 0.324460] Switched to clocksource mxc_timer1
[ 0.406370] NET: Registered protocol family 2
[ 0.407139] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[ 0.407240] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[ 0.407401] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.407600] UDP hash table entries: 512 (order: 2, 16384 bytes)
[ 0.407647] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[ 0.407895] NET: Registered protocol family 1
[ 0.408303] RPC: Registered named UNIX socket transport module.
[ 0.408315] RPC: Registered udp transport module.
[ 0.408324] RPC: Registered tcp transport module.
[ 0.408332] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.408645] Trying to unpack rootfs image as initramfs...
[ 0.476431] Freeing initrd memory: 1008K (c5000000 - c50fc000)
[ 0.477340] CPU PMU: Failed to parse /soc/pmu/interrupt-affinity[0]
[ 0.477408] hw perfevents: enabled with armv7_cortex_a9 PMU driver, 7 counters available
[ 0.479679] imx rpmsg driver is registered.
[ 0.480715] Bus freq driver module loaded
[ 0.481232] register_console pre console_unlock >>>>>>>>
[ 0.481881] register_console console_unlock() complete >>>>>>>>
[ 0.481938] console [pstore-1] enabled
[ 0.481950] pstore: Registered ramoops as persistent store backend
[ 0.481962] ramoops: attached 0x100000@0x8bf00000, ecc: 0/0
[ 0.481980] mxc_ramoops device success loaded
[ 0.482299] bt power gpio is:2
[ 0.482505] rfkill: BT RF going to : on
[ 0.482517] mxc_bt_rfkill_reset
[ 0.484580] mxc_bt_rfkill driver success loaded
[ 0.485886] futex hash table entries: 1024 (order: 4, 65536 bytes)
[ 0.485997] audit: initializing netlink subsys (disabled)
[ 0.486085] audit: type=2000 audit(0.480:1): initialized
[ 0.493679] VFS: Disk quotas dquot_6.6.0
[ 0.493881] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.496392] NFS: Registering the id_resolver key type
[ 0.496435] Key type id_resolver registered
[ 0.496448] Key type id_legacy registered
[ 0.496551] ntfs: driver 2.1.32 [Flags: R/W DEBUG].
[ 0.496852] jffs2: version 2.2. (NAND) 漏 2001-2006 Red Hat, Inc.
[ 0.497577] fuse init (API version 7.23)
[ 0.503272] bounce: pool size: 64 pages
[ 0.503296] io scheduler noop registered
[ 0.503316] io scheduler deadline registered
[ 0.503508] io scheduler cfq registered (default)
[ 0.504075] imx-weim 21b8000.weim: Driver registered.
[ 0.505549] pwm-backlight supply power not found, using dummy regulator
[ 0.507229] 21e0000.mipi supply disp-power-on not found, using dummy regulator
[ 0.507448] mxc_mipi_dsi 21e0000.mipi: i.MX MIPI DSI driver probed
[ 0.507580] MIPI DSI driver module loaded
[ 0.507838] MIPI DSI driver module loaded
[ 0.508131] ldb 2000000.aips-bus:ldb@020e0008: split mode
[ 0.508357] ldb 2000000.aips-bus:ldb@020e0008: split mode or dual mode, ignoring second output
[ 0.510376] mxc_sdc_fb fb@0: registered mxc display driver ldb
[ 0.510453] mxcfb_map_video_memory start >>>>>>>>>
[ 2.011318] mxc_sdc_fb fb@0: allocated fb @ paddr=0x26100000, size=5529600.
[ 2.024538] imx-ipuv3 2800000.ipu: IPU DMFC DP HIGH RESOLUTION: 1(0,1), 5B(2~5), 5F(6,7)
[ 2.101765] Console: switching to colour frame buffer device 240x45
[ 2.135702] mxcfb_map_video_memory start >>>>>>>>>
[ 2.140977] mxc_sdc_fb fb@0: allocated fb @ paddr=0x26700000, size=921600.
[ 2.141899] mxc_sdc_fb fb@2: Can't get fb option for mxcfb2!
[ 2.141978] mxc_sdc_fb fb@3: Can't get fb option for mxcfb3!
[ 2.144648] imx-sdma 20ec000.sdma: no iram assigned, using external mem
[ 2.145107] imx-sdma 20ec000.sdma: no event needs to be remapped
[ 2.145407] imx-sdma 20ec000.sdma: loaded firmware 3.3
[ 2.148220] imx-sdma 20ec000.sdma: initialized
[ 2.149130] 2020000.serial: ttymxc0 at MMIO 0x2020000 (irq = 24, base_baud = 5000000) is a IMX
[ 2.149189] register_console pre console_unlock >>>>>>>>
[ 3.203392] register_console console_unlock() complete >>>>>>>>
[ 3.209366] console [ttymxc0] enabled
[ 3.213751] 21e8000.serial: ttymxc1 at MMIO 0x21e8000 (irq = 296, base_baud = 5000000) is a IMX
[ 3.222983] 21ec000.serial: ttymxc2 at MMIO 0x21ec000 (irq = 297, base_baud = 5000000) is a IMX
[ 3.232225] 21f0000.serial: ttymxc3 at MMIO 0x21f0000 (irq = 298, base_baud = 5000000) is a IMX
[ 3.241473] 21f4000.serial: ttymxc4 at MMIO 0x21f4000 (irq = 299, base_baud = 5000000) is a IMX
[ 3.252503] imx sema4 driver is registered.
[ 3.256797] [drm] Initialized drm 1.1.0 20060810
[ 3.261992] [drm] Initialized vivante 1.0.0 20120216 on minor 0
[ 3.277947] brd: module loaded
[ 3.287632] loop: module loaded
[ 3.291370] zram: Created 1 device(s)

 

 

trace log:

[ 0.510453] mxcfb_map_video_memory start >>>>>>>>>
[ 2.011318] mxc_sdc_fb fb@0: allocated fb @ paddr=0x26100000, size=5529600.
[ 2.024538] imx-ipuv3 2800000.ipu: IPU DMFC DP HIGH RESOLUTION: 1(0,1), 5B(2~5), 5F(6,7)

code:

myandroid/kernel_imx/drivers/video/fbdev/mxc/mxc_ipuv3_fb.c

static int mxcfb_map_video_memory(struct fb_info *fbi)
{
struct mxcfb_info *mxc_fbi = (struct mxcfb_info *)fbi->par;

printk("%s start >>>>>>>>>\n", __func__);

if (fbi->fix.smem_len < fbi->var.yres_virtual * fbi->fix.line_length)
fbi->fix.smem_len = fbi->var.yres_virtual *
fbi->fix.line_length;

if (mxc_fbi->resolve && mxc_fbi->gpu_sec_buf_off) {
if (fbi->var.vmode & FB_VMODE_YWRAP)
fbi->fix.smem_len = mxc_fbi->gpu_sec_buf_off +
fbi->fix.smem_len / 2;
else
fbi->fix.smem_len = mxc_fbi->gpu_sec_buf_off *
(fbi->var.yres_virtual / fbi->var.yres) +
fbi->fix.smem_len / 2;
}

fbi->screen_base = dma_alloc_writecombine(fbi->device,
fbi->fix.smem_len,
(dma_addr_t *)&fbi->fix.smem_start,
GFP_DMA | GFP_KERNEL);
if (fbi->screen_base == 0) {
dev_err(fbi->device, "Unable to allocate framebuffer memory\n");
fbi->fix.smem_len = 0;
fbi->fix.smem_start = 0;
return -EBUSY;
}

dev_dbg(fbi->device, "allocated fb @ paddr=0x%08X, size=%d.\n",
(uint32_t) fbi->fix.smem_start, fbi->fix.smem_len);

 

 

 

 

 

[ 2.149130] 2020000.serial: ttymxc0 at MMIO 0x2020000 (irq = 24, base_baud = 5000000) is a IMX
[ 2.149189] register_console pre console_unlock >>>>>>>>
[ 3.203392] register_console console_unlock() complete >>>>>>>>
[ 3.209366] console [ttymxc0] enabled
[ 3.213751] 21e8000.serial: ttymxc1 at MMIO 0x21e8000 (irq = 296, base_baud = 5000000) is a IMX

 

code:

diff --git a/myandroid/kernel_imx/kernel/printk/printk.c b/myandroid/kernel_imx/kernel/printk/printk.c
index 58562f5..457bf31 100644
--- a/myandroid/kernel_imx/kernel/printk/printk.c
+++ b/myandroid/kernel_imx/kernel/printk/printk.c
+       printk("%s pre console_unlock >>>>>>>>\n", __func__);
        console_unlock();
+       printk("%s console_unlock() complete >>>>>>>>\n", __func__);
        console_sysfs_notify();

 

 

 

 

Outcomes