AnsweredAssumed Answered

optimize  kernel  run times

Question asked by 越超 贾 on Jul 6, 2018
Latest reply on Jul 11, 2018 by igorpadykov

Hello:

         we use  imx8qxp   board, when optimize kernel  find some questions,

1- uboot  startup  over ,we set gpio 1

2-kernel  startup over and before load  init.rc  ,we set gpio 0

by  test gpio time is 1.04s

 

but: by cat log 534ms before startup init.rc,

I don't know about  400ms times  Where does it cost,

         

    

[    0.000000] start kernel --------------------------
[    0.000000] start kerneli222222222222 --------------------------
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.9.51 (jyc@jyc) (gcc version 6.2.0 (GCC) ) #23 SMP PREEMPT Fri Jul 6 14:38:26 8
[    0.000000] Boot CPU: AArch64 Processor [410fd041]
[    0.000000] earlycon: lpuart32 at MMIO 0x000000005a060000 (options '115200,115200')
[    0.000000] bootconsole [lpuart32] enabled
[    0.000000] OF: reserved mem: failed to allocate memory for node 'linux,cma'
[    0.000000] cma: Reserved 320 MiB at 0x00000000ec000000
[    0.000000] On node 0 totalpages: 784128
[    0.000000]   DMA zone: 8184 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 521984 pages, LIFO batch:31
[    0.000000]   Normal zone: 4096 pages used for memmap
[    0.000000]   Normal zone: 262144 pages, LIFO batch:31
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: PSCIv1.0 detected in firmware.
[    0.000000] psci: Using standard PSCI v0.2 function IDs
[    0.000000] psci: MIGRATE_INFO_TYPE not supported.
[    0.000000] percpu: Embedded 21 pages/cpu @ffff80083ff54000 s47896 r8192 d29928 u86016
[    0.000000] pcpu-alloc: s47896 r8192 d29928 u86016 alloc=21*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Detected VIPT I-cache on CPU0
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 771848
[    0.000000] Kernel command line: console=ttyLP0,115200 earlycon=lpuart32,0x5a060000,115200,115200 android2
[    0.000000] log_buf_len individual max cpu contribution: 4096 bytes
[    0.000000] log_buf_len total cpu_extra contributions: 12288 bytes
[    0.000000] log_buf_len min size: 16384 bytes
[    0.000000] log_buf_len: 32768 bytes
[    0.000000] early log buf free: 14412(87%)
[    0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
[    0.000000] software IO TLB [mem 0xe7fff000-0xebfff000] (64MB) mapped at [ffff800067fff000-ffff80006bffef]
[    0.000000] Memory: 2545080K/3136512K available (6270K kernel code, 458K rwdata, 2276K rodata, 384K init,)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     modules : 0xffff000000000000 - 0xffff000008000000   (   128 MB)
[    0.000000]     vmalloc : 0xffff000008000000 - 0xffff7dffbfff0000   (129022 GB)
[    0.000000]       .text : 0xffff000008080000 - 0xffff0000086a0000   (  6272 KB)
[    0.000000]     .rodata : 0xffff0000086a0000 - 0xffff0000088e0000   (  2304 KB)
[    0.000000]       .init : 0xffff0000088e0000 - 0xffff000008940000   (   384 KB)
[    0.000000]       .data : 0xffff000008940000 - 0xffff0000089b2808   (   459 KB)
[    0.000000]        .bss : 0xffff0000089b2808 - 0xffff0000089f5b04   (   269 KB)
[    0.000000]     fixed   : 0xffff7dfffe7fd000 - 0xffff7dfffec00000   (  4108 KB)
[    0.000000]     PCI I/O : 0xffff7dfffee00000 - 0xffff7dffffe00000   (    16 MB)
[    0.000000]     vmemmap : 0xffff7e0000000000 - 0xffff800000000000   (  2048 GB maximum)
[    0.000000]               0xffff7e0000008000 - 0xffff7e0021000000   (   527 MB actual)
[    0.000000]     memory  : 0xffff800000200000 - 0xffff800840000000   ( 33790 MB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000]  Build-time adjustment of leaf fanout to 64.
[    0.000000]  RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=4.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
[    0.000000] NR_IRQS:64 nr_irqs:64 0
[    0.000000] GICv3: GIC: Using split EOI/Deactivate mode
[    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x0000000051b00000
[    0.000000] arm_arch_timer: Architected cp15 timer(s) running at 8.00MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x1d854df40, max_idle_ns: 4s
[    0.000004] sched_clock: 56 bits at 8MHz, resolution 125ns, wraps every 2199023255500ns
[    0.000289] Calibrating delay loop (skipped), value calculated using timer frequency.. 16.00 BogoMIPS (lp)
[    0.000300] pid_max: default: 32768 minimum: 301
[    0.000366] Security Framework initialized
[    0.000409] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes)
[    0.000417] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes)
[    0.001096] --------------rest_init---------
[    0.001304] ASID allocator initialised with 65536 entries
[    0.032122] *****Initialized MU
[    0.032143] ***** imx8_init_pm_domains *****
[    0.032874] CPU identified as i.MX8QXP, silicon rev 1.0
[    0.080431] Detected VIPT I-cache on CPU1
[    0.080460] GICv3: CPU1: found redistributor 1 region 0:0x0000000051b20000
[    0.080489] CPU1: Booted secondary processor [410fd041]
[    0.080560] Brought up 2 CPUs
[    0.080573] SMP: Total of 2 processors activated.
[    0.080580] CPU features: detected feature: GIC system register CPU interface
[    0.080590] CPU features: detected feature: 32-bit EL0 Support
[    0.080630] CPU: All CPU(s) started at EL2
[    0.080909] ---------------do_basic_setup-------
[    0.081177] devtmpfs: initialized
[    0.091853] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 s
[    0.091874] futex hash table entries: 1024 (order: 5, 131072 bytes)
[    0.099636] pinctrl core: initialized pinctrl subsystem
[    0.100726] NET: Registered protocol family 16
[    0.112673] cpuidle: using governor menu
[    0.113516] vdso: 2 pages (1 code @ ffff0000086a7000, 1 data @ ffff000008944000)
[    0.113533] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[    0.117545] DMA: preallocated 256 KiB pool for atomic allocations
[    0.119288] MU and Power domains initialized
[    0.119303] ***** imx8qxp_clocks_init *****
[    0.174498] i.MX8QXP clk 168: register failed with -19
[    0.174511] i.MX8QXP clk 169: register failed with -19
[    0.175377] imx8qxp-pinctrl iomuxc: initialized IMX pinctrl driver
[    0.188980] 5b100000.usbphy supply phy-3p0 not found, using dummy regulator
[    0.209207] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.210203] GPIO line 491 (lvds0_panel_pwr_en) hogged as output/high
[    0.210218] GPIO line 507 (soc_off_rdy) hogged as output/high
[    0.211313] GPIO line 474 (lvds0_panel_reset) hogged as output/high
[    0.211325] GPIO line 476 (lvds0_panel_stbyb) hogged as output/high
[    0.211336] GPIO line 475 (lvds0_panel_pwm) hogged as output/high
[    0.211347] GPIO line 461 (peri_3v3_sw) hogged as output/high
[    0.211360] GPIO line 462 (peri_1v8_sw) hogged as output/high
[    0.213525] GPIO line 408 (ipod_psw) hogged as output/high
[    0.228548] mxs-dma 5b810000.dma-apbh: initialized
[    0.230681] SCSI subsystem initialized
[    0.231064] usbcore: registered new interface driver usbfs
[    0.231147] usbcore: registered new interface driver hub
[    0.231246] usbcore: registered new device driver usb
[    0.231444] usbphynop1 supply vcc not found, using dummy regulator
[    0.232467] media: Linux media interface: v0.10
[    0.232536] Linux video capture interface: v2.00
[    0.233679] MU is ready for cross core communication!
[    0.234885] virtio_rpmsg_bus virtio0: rpmsg host is online
[    0.235112] imx rpmsg driver is registered.
[    0.235321] Advanced Linux Sound Architecture Driver Initialized.
[    0.236172] clocksource: Switched to clocksource arch_sys_counter
[    0.236318] VFS: Disk quotas dquot_6.6.0
[    0.236371] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.238168] NET: Registered protocol family 2
[    0.238617] TCP established hash table entries: 32768 (order: 6, 262144 bytes)
[    0.238908] TCP bind hash table entries: 32768 (order: 7, 524288 bytes)
[    0.239397] TCP: Hash tables configured (established 32768 bind 32768)
[    0.239460] UDP hash table entries: 2048 (order: 4, 65536 bytes)
[    0.239543] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes)
[    0.239747] NET: Registered protocol family 1
[    0.239983] Unpacking initramfs...
[    0.290333] Freeing initrd memory: 908K
[    0.290709] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 counters available
[    0.293800] workingset: timestamp_bits=46 max_order=20 bucket_order=0
[    0.307142] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[    0.307158] io scheduler noop registered
[    0.307318] io scheduler cfq registered (default)
[    0.307372] LinuxCrashDump[Debug]: Init the linux crash dump driver
[    0.307452] LinuxCrashDump[Debug]: Probe the linux crash dump driver
[    0.307544] LinuxCrashDump[Debug]: get reserved memory, paddr: 0x9FD00000, vaddr: 0xFFFF00000B800000, siz0
[    0.307833] LinuxCrashDumpDebugModule: linux crash dump physical address=0x9fd00000,size=0x300000,virtual0
[    0.311676] 5a060000.serial: ttyLP0 at MMIO 0x5a060000 (irq = 49, base_baud = 5000000) is a FSL_LPUART
[    0.313819] console [ttyLP0] enabled
[    0.313826] bootconsole [lpuart32] disabled
[    0.314074] fsl-lpuart 5a060000.serial: NO DMA tx channel, run at cpu mode
[    0.314083] fsl-lpuart 5a060000.serial: NO DMA rx channel, run at cpu mode
[    0.314338] SPI driver initialize successful! .
[    0.333073] imx8-dpr-channel 560d0000.dpr-channel: Linked as a consumer to 56040000.prg
[    0.335176] imx8-dpr-channel 560e0000.dpr-channel: Linked as a consumer to 56050000.prg
[    0.337274] imx8-dpr-channel 560f0000.dpr-channel: Linked as a consumer to 56060000.prg
[    0.339399] imx8-dpr-channel 56100000.dpr-channel: Linked as a consumer to 56070000.prg
[    0.339420] imx8-dpr-channel 56100000.dpr-channel: Linked as a consumer to 56080000.prg
[    0.341510] imx8-dpr-channel 56110000.dpr-channel: Linked as a consumer to 56090000.prg
[    0.341531] imx8-dpr-channel 56110000.dpr-channel: Linked as a consumer to 560a0000.prg
[    0.343630] imx8-dpr-channel 56120000.dpr-channel: Linked as a consumer to 560b0000.prg
[    0.343650] imx8-dpr-channel 56120000.dpr-channel: Linked as a consumer to 560c0000.prg
[    0.346473] dpu-core 56180000.dpu: Linked as a consumer to 56100000.dpr-channel
[    0.346507] dpu-core 56180000.dpu: Linked as a consumer to 56110000.dpr-channel
[    0.346855] dpu-core 56180000.dpu: driver probed
[    0.347101] [drm] Initialized
[    0.348743] lvds1_panel supply power not found, using dummy regulator
[    0.350142] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    0.350150] [drm] No driver support for vblank timestamp query.
[    0.350272] imx-drm display-subsystem: bound imx-drm-dpu-bliteng.2 (ops dpu_bliteng_ops)
[    0.350283] imx-dpu-crtc imx-dpu-crtc.0: dpu_crtc_init, stream_id=0
[    0.350567] imx-drm display-subsystem: bound imx-dpu-crtc.0 (ops dpu_crtc_ops)
[    0.350578] imx-dpu-crtc imx-dpu-crtc.1: dpu_crtc_init, stream_id=1
[    0.350811] imx-drm display-subsystem: bound imx-dpu-crtc.1 (ops dpu_crtc_ops)
[    0.350965] imx-ldb ldb@562210e0: no ddc available
[    0.351028] imx-ldb ldb@562210e0: find phy 3a87a000 for channel 0
[    0.351091] imx-ldb ldb@562210e0: dual-channel mode
[    0.351102] imx-ldb ldb@562210e0: i=1, imx_ldb=3a5e7018, imx_regmap=3a3fb800, imx_regmap_slave=3a3fbc00
[    0.351154] imx-ldb ldb@562210e0: find phy 3a87a400 for channel 1
[    0.351223] imx-drm display-subsystem: bound ldb@562210e0 (ops imx_ldb_ops)
[    0.353944] imx-drm display-subsystem: fb0:  frame buffer device
[    0.363162] loop: module loaded
[    0.363787] slram: not enough parameters.
[    0.364430] fsl_lpspi 5a020000.lpspi: [fsl_lpspi_probe 607] spi-slave-mode
[    0.364636] fsl_lpspi 5a020000.lpspi: [fsl_lpspi_probe 623]  gpio_req: 466
[    0.365087] spi spi0.0: fsl_lpspi_setup: mode 0, 8 bpw, 20000000 hz
[    0.365458] spidev_probe : 831 : spi-slave-mode
[    0.365473] fsl_lpspi 5a020000.lpspi: lpspi probed
[    0.365893] libphy: Fixed MDIO Bus: probed
[    0.365996] usbcore: registered new interface driver cdc_ncm
[    0.366658] usbcore: registered new interface driver usb-storage
[    0.367170] imx_sc_rtc rtc: rtc core: registered rtc as rtc0
[    0.367334] i2c /dev entries driver
[    0.369752] mx8-img-md: Registered mxc_isi.0.capture as /dev/video0
[    0.369923] mx8-img-md: Registered mxc_isi.1.capture as /dev/video1
[    0.370080] mx8-img-md: Registered mxc_isi.2.capture as /dev/video2
[    0.370233] mx8-img-md: Registered mxc_isi.3.capture as /dev/video3
[    0.370976] mxc-jpeg 58400000.jpegdec: decoder device registered as /dev/video4 (81,4)
[    0.371427] mxc-jpeg 58450000.jpegenc: encoder device registered as /dev/video5 (81,5)
[    0.373719] sdhci: Secure Digital Host Controller Interface driver
[    0.373728] sdhci: Copyright(c) Pierre Ossman
[    0.373734] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.374930] *****************sdhci_pltfm_init*****************
[    0.420199] mmc0: SDHCI controller on 5b010000.usdhc [5b010000.usdhc] using ADMA
[    0.426490] galcore 80000000.imx8_gpu_ss: bound 53100000.gpu (ops mxc_gpu_sub_ops)
[    0.426809] Galcore version 6.2.4.138003
[    0.504814] ashmem: initialized
[    0.505040] logger: created 256K log 'log_main'
[    0.505199] logger: created 256K log 'log_events'
[    0.505354] logger: created 256K log 'log_radio'
[    0.505506] logger: created 256K log 'log_system'
[    0.505561] mmc0: new DDR MMC card at address 0001
[    0.507736] NET: Registered protocol family 26
[    0.508534] NET: Registered protocol family 10
[    0.509231] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[    0.509802] NET: Registered protocol family 17
[    0.509830] Key type dns_resolver registered
[    0.510413] mmcblk0: mmc0:0001 064G32 58.2 GiB 
[    0.510589] mmcblk0boot0: mmc0:0001 064G32 partition 1 8.00 MiB
[    0.510744] mmcblk0boot1: mmc0:0001 064G32 partition 2 8.00 MiB
[    0.510895] mmcblk0rpmb: mmc0:0001 064G32 partition 3 4.00 MiB
[    0.511594] registered taskstats version 1
[    0.512108]  mmcblk0: p1 p2
[    0.529254] imx8_cpufreq_init: cluster 0 running at freq 1200 MHz, suspend freq 1200 MHz
[    0.529838] imx_sc_rtc rtc: setting system clock to 1970-01-01 00:31:56 UTC (1916)
[    0.531835] SD1_SPWR: disabling
[    0.531844] ALSA device list:
[    0.531848]   No soundcards found.
[    0.534182] Freeing unused kernel memory: 384K
[    0.536690] (EE) init: /init.rc: 392: invalid option 'seclabel'
[    0.536723] (EE) init: /init.rc: 393: invalid option 'seclabel'
[    0.536931] init (1): /proc/1/oom_adj is deprecated, please use /proc/1/oom_score_adj instead.
[    0.536966] (!!) init: starting 'ueventd'
[    0.579877] EXT4-fs (mmcblk0p1): mounted filesystem with ordered data mode. Opts: journal_checksum
[    0.579961] (!!) init: processing action 0x1c850fa0 (wait_for_coldboot_done)
[    0.590136] (!!) init: processing action 0x1c851030 (property_init)
[    0.590528] (!!) init: processing action 0x1c8510c0 (keychord_init)
[    0.590546] (!!) init: processing action 0x1c851150 (console_init)
[    0.590668] (!!) init: processing action 0x1c8511e0 (set_init_properties)
[    0.590709] (!!) init: processing action 0x1c84c8e0 (init)
[    0.591988] (EE) init: command 'write /dev/cpuctl/cpu.shares 1024', r=-22
[    0.599918] EXT4-fs (mmcblk0p2): recovery complete
[    0.600356] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: nodelalloc,journal_checm
[    0.610680] (II) linuxcrashdump: main() start Dump ==
[    0.610722] (II) linuxcrashdump: main() /proc/linux_crash_dump  not exist  do nothing ==
[    0.611335] (II) init: mount /system success
[    0.611346] (II) init: /system mount OK at the end
[    0.611437] (II) init: mount /var success
[    0.611624] (II) init: /var mount OK at the end
[    0.654905] random: fast init done
[    0.926566] binder: 1062:1062 unknown command 1074815758
[    0.926582] binder: 1062:1062 ioctl c0306201 ffffe532ad90 returned -22
[    1.164695] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    1.254265] 5b0d0200.usbmisc supply vbus-wakeup not found, using dummy regulator
[    1.270421] 5b0d0000.usb supply vbus not found, using dummy regulator
[    1.279540] ci_hdrc ci_hdrc.0: EHCI Host Controller
[    1.279566] ci_hdrc ci_hdrc.0: new USB bus registered, assigned bus number 1
[    1.296205] ci_hdrc ci_hdrc.0: USB 2.0 started, EHCI 1.00
[    1.297135] hub 1-0:1.0: USB hub found
[    1.297172] hub 1-0:1.0: 1 port detected
[    1.380675] imx-ldb ldb@562210e0: imx_ldb_encoder_atomic_mode_set
[    1.380694] imx-ldb ldb@562210e0: imx_ldb_set_clock
[    1.401844] imx-ldb ldb@562210e0: imx_ldb_encoder_enable
[    1.508224] imx-ldb ldb@562210e0: before write, ldb->ldb_ctrl=50000b5, ldb->ldb_ctrl_slave=150000b5
[    1.508251] imx-ldb ldb@562210e0: after write, ldb->ldb_ctrl=b5, ldb->ldb_ctrl_slave=100000b5
[    1.510324] dpu_pixel_link_validate
[    1.624201] usb 1-1: new high-speed USB device number 2 using ci_hdrc
[    1.818415] usb-storage 1-1:1.0: USB Mass Storage device detected
[    1.819856] scsi host0: usb-storage 1-1:1.0

Outcomes