Bug 204131

Summary:	Various boot delays
Product:	Platform Specific/Hardware	Reporter:	Stuart Naylor (stuartiannaylor)
Component:	ARM	Assignee:	linux-arm-kernel (linux-arm-kernel)
Status:	NEW ---
Severity:	normal	CC:	nikolai.lontke
Priority:	P1
Hardware:	ARM
OS:	Linux
Kernel Version:	5.2	Subsystem:
Regression:	No	Bisected commit-id:

Description Stuart Naylor 2019-07-11 06:42:45 UTC

Kernel 5.2 Release RK3399 Rockpi4
Boot delays always at same points

[    1.100844] Serial: AMBA PL011 UART driver
[    3.089528] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    3.092720] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages
[    3.094821] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    3.096896] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages


[   68.026279] media: Linux media interface: v0.10
[   68.029270] videodev: Linux video capture interface: v2.00
[   68.032496] pps_core: LinuxPPS API ver. 1 registered
[   68.034046] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[   68.037445] PTP clock support registered
[   68.046820] EDAC MC: Ver: 3.0.0
[   68.101017] Advanced Linux Sound Architecture Driver Initialized.
[   68.122384] NetLabel: Initializing
[   68.123615] NetLabel:  domain hash size = 128
[   68.124978] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[   68.129116] NetLabel:  unlabeled traffic allowed by default
[   68.145928] clocksource: Switched to clocksource arch_sys_counter
[   92.325715] watchdog: BUG: soft lockup - CPU#5 stuck for 22s! [swapper/0:1]
[   92.327825] Modules linked in:
[   92.329249] CPU: 5 PID: 1 Comm: swapper/0 Not tainted 5.2.0-1-MANJARO-ARM #1
[   92.331368] Hardware name: Radxa ROCK Pi 4 (DT)
[   92.332977] pstate: 60000005 (nZCv daif -PAN -UAO)
[   92.334808] pc : trace_event_eval_update+0xf0/0x330
[   92.336514] lr : trace_event_eval_update+0x138/0x330
[   92.338021] sp : ffff00001004bce0
[   92.339158] x29: ffff00001004bce0 x28: 0000000000000000 
[   92.341047] x27: ffff000011796fc0 x26: ffff00001185fb40 
[   92.342832] x25: ffff000011155288 x24: 00000000000000a0 
[   92.344645] x23: 0000000000000015 x22: ffff0000116d9550 
[   92.346379] x21: 00000000000001f3 x20: 00000000000000bf 
[   92.348138] x19: ffff00001184cd7f x18: 0000000000000001 
[   92.349906] x17: 00000000f867c081 x16: 00000000279696e8 
[   92.351673] x15: 2937367b1910031c x14: ff00000000000000 
[   92.353432] x13: 0000000000000000 x12: 0000000000000007 
[   92.355138] x11: 0101010101010101 x10: 0000000000000015 
[   92.356846] x9 : 0000000000000003 x8 : 0000000000000008 
[   92.358560] x7 : fefeff4348445340 x6 : 0000000000808080 
[   92.360269] x5 : 8080800000000000 x4 : 0000000000000052 
[   92.362013] x3 : 0000000000000002 x2 : ffff00001184cd70 
[   92.363771] x1 : 00000000000000a0 x0 : 0000000000000020 
[   92.365525] Call trace:
[   92.366635]  trace_event_eval_update+0xf0/0x330
[   92.368374]  tracer_init_tracefs+0x178/0x208
[   92.369922]  do_one_initcall+0x54/0x230
[   92.371394]  kernel_init_freeable+0x294/0x33c
[   92.372886]  kernel_init+0x18/0x104
[   92.374186]  ret_from_fork+0x10/0x1c
[  105.050816] VFS: Disk quotas dquot_6.6.0
[  105.054634] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[  105.060769] *** VALIDATE hugetlbfs ***
[  105.079375] pnp: PnP ACPI: disabled


[  105.596417] RPC: Registered tcp transport module.
[  105.597878] RPC: Registered tcp NFSv4.1 backchannel transport module.
[  105.599949] PCI: CLS 0 bytes, default 64
[  105.607767] Trying to unpack rootfs image as initramfs...

[  129.361371] Initramfs unpacking failed: invalid magic at start of compressed archive
[  130.004789] Freeing initrd memory: 20480K
[  130.039725] hw perfevents: enabled with armv8_cortex_a53 PMU driver, 7 counters available
[  130.059094] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available
[  130.079222] kvm [1]: IPA Size Limit: 40bits
[  130.123485] kvm [1]: vgic-v2@fff20000
[  130.126393] kvm [1]: GIC system register CPU interface enabled
[  130.135195] kvm [1]: vgic interrupt IRQ10
[  130.146627] kvm [1]: Hyp mode initialized successfully

[  154.980379] Initialise system trusted keyrings
[  154.986733] workingset: timestamp_bits=46 max_order=19 bucket_order=0
[  155.276330] zbud: loaded

Comment 1 Nikolai Lontke 2019-10-15 06:51:41 UTC

I am seeing the same on Kernel 5.3.6-1-ARCH (archlinuxarm aarch64) using a RockPi 4 Model A v1.4 board.
I can post a full boot-log including u-boot, if this is of any use.

[    0.224041] Serial: AMBA PL011 UART driver
[    2.249532] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    2.251776] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages
[    2.253918] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    2.256989] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages
[   65.000362] cryptd: max_cpu_qlen set to 1000
[   65.371812] alg: No test for lzo-rle (lzo-rle-generic)
[   65.381341] alg: No test for lzo-rle (lzo-rle-scomp)
[   65.852536] ACPI: Interpreter disabled.
[   65.890577] vcc5v0_sys: supplied by vcc12v_dcin
[   65.909526] vcc3v3_pcie: supplied by vcc5v0_sys
[   65.924494] vcc3v3_sys: supplied by vcc5v0_sys
[   65.943152] vcc5v0_host: supplied by vcc5v0_sys
[   65.960997] vcc5v0_typec: supplied by vcc5v0_sys
[   66.120561] vgaarb: loaded
[   66.154271] SCSI subsystem initialized
[   66.172101] usbcore: registered new interface driver usbfs
[   66.175636] usbcore: registered new interface driver hub
[   66.181667] usbcore: registered new device driver usb
[   66.227135] pps_core: LinuxPPS API ver. 1 registered
[   66.228708] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[   66.232577] PTP clock support registered
[   66.240616] EDAC MC: Ver: 3.0.0
[   66.296416] Advanced Linux Sound Architecture Driver Initialized.
[   66.319756] NetLabel: Initializing
[   66.321049] NetLabel:  domain hash size = 128
[   66.322413] NetLabel:  protocols = UNLABELED CIPSOv4 CALIPSO
[   66.326596] NetLabel:  unlabeled traffic allowed by default
[   66.346153] clocksource: Switched to clocksource arch_sys_counter
[   92.195948] watchdog: BUG: soft lockup - CPU#5 stuck for 22s! [swapper/0:1]
[   92.198019] Modules linked in:
[   92.199379] CPU: 5 PID: 1 Comm: swapper/0 Not tainted 5.3.6-1-ARCH #1
[   92.201261] Hardware name: Radxa ROCK Pi 4 (DT)
[   92.202816] pstate: 20000005 (nzCv daif -PAN -UAO)
[   92.204576] pc : trace_event_eval_update+0x100/0x330
[   92.206186] lr : trace_event_eval_update+0x138/0x330
[   92.207669] sp : ffff00001004bce0
[   92.208767] x29: ffff00001004bce0 x28: 0000000000000000 
[   92.210546] x27: ffff0000117718d0 x26: ffff000011846268 
[   92.212271] x25: ffff00001113bcf8 x24: 00000000000000e8 
[   92.213965] x23: 0000000000000006 x22: ffff0000116b3850 
[   92.215664] x21: 0000000000000224 x20: 0000000000000185 
[   92.217343] x19: ffff00001183208b x18: 0000000000000001 
[   92.219016] x17: 00000000f746f7a4 x16: 00000000941f6d46 
[   92.220704] x15: ffffffffffffffff x14: ffff000000000000 
[   92.222379] x13: ffffffffffffffff x12: 0000000000000003 
[   92.224052] x11: 0101010101010101 x10: 0000000000000006 
[   92.225775] x9 : 7f7f7f7f7f7f7f7f x8 : 0000000000bf2a15 
[   92.227467] x7 : 170c10697737ffff x6 : 7272377769100c17 
[   92.229187] x5 : ffff000000000000 x4 : 0000000000000052 
[   92.230901] x3 : 0000000000000002 x2 : ffff000011832074 
[   92.232620] x1 : 00000000000000a0 x0 : 0000000000000031 
[   92.234296] Call trace:
[   92.235350]  trace_event_eval_update+0x100/0x330
[   92.236897]  tracer_init_tracefs+0x178/0x214
[   92.238376]  do_one_initcall+0x54/0x220
[   92.239703]  kernel_init_freeable+0x28c/0x334
[   92.241237]  kernel_init+0x18/0x104
[   92.242497]  ret_from_fork+0x10/0x18
[  108.652175] VFS: Disk quotas dquot_6.6.0
[  108.657129] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[  108.662756] *** VALIDATE hugetlbfs ***
[  108.682215] pnp: PnP ACPI: disabled
[  109.052440] thermal_sys: Registered thermal governor 'fair_share'
[  109.052633] thermal_sys: Registered thermal governor 'bang_bang'
[  109.054626] thermal_sys: Registered thermal governor 'step_wise'
[  109.057118] thermal_sys: Registered thermal governor 'user_space'
[  109.058965] thermal_sys: Registered thermal governor 'power_allocator'