Re: linux-next: stall warnings and deadlock on Arm64 (was: [PATCH] kfence: Avoid stalling...)

Marco Elver
2020-11-24T14:03:47Z

[-- Attachment #1: Type: text/plain, Size: 2521 bytes --]

On Mon, Nov 23, 2020 at 07:32PM +0000, Mark Rutland wrote:
> On Fri, Nov 20, 2020 at 03:03:32PM +0100, Marco Elver wrote:
> > On Fri, Nov 20, 2020 at 10:30AM +0000, Mark Rutland wrote:
> > > On Thu, Nov 19, 2020 at 10:53:53PM +0000, Will Deacon wrote:
> > > > FWIW, arm64 is known broken wrt lockdep and irq tracing atm. Mark has been
> > > > looking at that and I think he is close to having something workable.
> > > >
> > > > Mark -- is there anything Marco and Paul can try out?
> > >
> > > I initially traced some issues back to commit:
> > >
> > > 044d0d6de9f50192 ("lockdep: Only trace IRQ edges")
> > >
> > > ... and that change of semantic could cause us to miss edges in some
> > > cases, but IIUC mostly where we haven't done the right thing in
> > > exception entry/return.
> > >
> > > I don't think my patches address this case yet, but my WIP (currently
> > > just fixing user<->kernel transitions) is at:
> > >
> > > https://git.kernel.org/pub/scm/linux/kernel/git/mark/linux.git/log/?h=arm64/irq-fixes
> > >
> > > I'm looking into the kernel<->kernel transitions now, and I know that we
> > > mess up RCU management for a small window around arch_cpu_idle, but it's
> > > not immediately clear to me if either of those cases could cause this
> > > report.
> >
> > Thank you -- I tried your irq-fixes, however that didn't seem to fix the
> > problem (still get warnings and then a panic). :-/
>
> I've just updated that branch with a new version which I hope covers
> kernel<->kernel transitions too. If you get a chance, would you mind
> giving that a spin?
>
> The HEAD commit should be:
>
> a51334f033f8ee88 ("HACK: check IRQ tracing has RCU watching")

Thank you! Your series appears to work and fixes the stalls and
deadlocks (3 trials)! I noticed there are a bunch of warnings in the log
that might be relevant (see attached).

Note, I also reverted

sched/core: Allow try_invoke_on_locked_down_task() with irqs disabled

and that still works.

Thanks,
-- Marco

> Otherwise, I intend to clean that up and post it tomorrow (without the
> additional debug hacks). I've thrown my local Syzkaller instance at it
> in the mean time (and if I get the chance tomrrow I'll try to get
> rcutorture setup), and the only report I'm seeing so far looks genuine:
>
> | BUG: sleeping function called from invalid context in sta_info_move_state
>
> ... as that was reported on x86 too, per:
>
> https://syzkaller.appspot.com/bug?id=6c7899acf008be2ddcddb46a2567c2153193632a
>
> Thanks,
> Mark.

[-- Attachment #2: vm.log --]
[-- Type: text/plain, Size: 29420 bytes --]

[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x411fd070]
[ 0.000000] Linux version 5.10.0-rc4-next-20201119-00002-g51c2bf0ac853 (elver@elver.muc.corp.google.com) (aarch64-none-linux-gnu-gcc (GNU Toolchain for the A-profile Architecture 9.2-2019.12 (arm-9.10)) 9.2.1 20191025, GNU ld (GNU Toolchain for the A-profile Architecture 9.2-2019.12 (arm-9.10)) 2.33.1.20191209) #25 SMP PREEMPT Tue Nov 24 13:47:30 CET 2020
[ 0.000000] Machine model: linux,dummy-virt
[ 0.000000] efi: UEFI not found.
[ 0.000000] cma: Reserved 32 MiB at 0x00000000be000000
[ 0.000000] earlycon: pl11 at MMIO 0x0000000009000000 (options '')
[ 0.000000] printk: bootconsole [pl11] enabled
[ 0.000000] NUMA: No NUMA configuration found
[ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000000bfffffff]
[ 0.000000] NUMA: NODE_DATA [mem 0xbdbf6000-0xbdbf7fff]
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x0000000040000000-0x000000007fffffff]
[ 0.000000] DMA32 [mem 0x0000000080000000-0x00000000bfffffff]
[ 0.000000] Normal empty
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000040000000-0x00000000bfffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000040000000-0x00000000bfffffff]
[ 0.000000] On node 0 totalpages: 524288
[ 0.000000] DMA zone: 4096 pages used for memmap
[ 0.000000] DMA zone: 0 pages reserved
[ 0.000000] DMA zone: 262144 pages, LIFO batch:63
[ 0.000000] DMA32 zone: 4096 pages used for memmap
[ 0.000000] DMA32 zone: 262144 pages, LIFO batch:63
[ 0.000000] psci: probing for conduit method from DT.
[ 0.000000] psci: PSCIv0.2 detected in firmware.
[ 0.000000] psci: Using standard PSCI v0.2 function IDs
[ 0.000000] psci: Trusted OS migration not required
[ 0.000000] percpu: Embedded 49 pages/cpu s162704 r8192 d29808 u200704
[ 0.000000] pcpu-alloc: s162704 r8192 d29808 u200704 alloc=49*4096
[ 0.000000] pcpu-alloc: [0] 0
[ 0.000000] Detected PIPT I-cache on CPU0
[ 0.000000] CPU features: detected: ARM erratum 832075
[ 0.000000] CPU features: detected: ARM erratum 834220
[ 0.000000] CPU features: detected: EL2 vector hardening
[ 0.000000] CPU features: kernel page table isolation forced ON by KASLR
[ 0.000000] CPU features: detected: Kernel page table isolation (KPTI)
[ 0.000000] CPU features: detected: Spectre-v2
[ 0.000000] CPU features: detected: Spectre-v4
[ 0.000000] CPU features: detected: ARM errata 1165522, 1319367, or 1530923
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 516096
[ 0.000000] Policy zone: DMA32
[ 0.000000] Kernel command line: console=ttyAMA0 root=/dev/sda debug earlycon earlyprintk=serial slub_debug=UZ slub_debug=- workqueue.watchdog_thresh=10
[ 0.000000] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] software IO TLB: mapped [mem 0x000000007bfff000-0x000000007ffff000] (64MB)
[ 0.000000] Memory: 1903696K/2097152K available (20800K kernel code, 4024K rwdata, 8508K rodata, 8896K init, 11238K bss, 160688K reserved, 32768K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[ 0.000000] ftrace: allocating 56178 entries in 220 pages
[ 0.000000] ftrace: allocated 220 pages with 5 groups
[ 0.000000] Running RCU self tests
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] rcu: RCU event tracing is enabled.
[ 0.000000] rcu: RCU lockdep checking is enabled.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=1.
[ 0.000000] Trampoline variant of Tasks RCU enabled.
[ 0.000000] Rude variant of Tasks RCU enabled.
[ 0.000000] Tracing variant of Tasks RCU enabled.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[ 0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[ 0.000000] GICv2m: range[mem 0x08020000-0x08020fff], SPI[80:143]
[ 0.000000] random: get_random_bytes called from start_kernel+0x468/0x670 with crng_init=0
[ 0.000000] arch_timer: cp15 timer(s) running at 62.50MHz (virt).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x1cd42e208c, max_idle_ns: 881590405314 ns
[ 0.000291] sched_clock: 56 bits at 62MHz, resolution 16ns, wraps every 4398046511096ns
[ 0.014280] Console: colour dummy device 80x25
[ 0.015796] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[ 0.016131] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 0.016378] ... MAX_LOCK_DEPTH: 48
[ 0.016626] ... MAX_LOCKDEP_KEYS: 8192
[ 0.016887] ... CLASSHASH_SIZE: 4096
[ 0.017138] ... MAX_LOCKDEP_ENTRIES: 32768
[ 0.017385] ... MAX_LOCKDEP_CHAINS: 65536
[ 0.017633] ... CHAINHASH_SIZE: 32768
[ 0.017884] memory used by lock dependency info: 6365 kB
[ 0.018144] memory used for stack traces: 4224 kB
[ 0.018400] per task-struct memory footprint: 1920 bytes
[ 0.021247] Calibrating delay loop (skipped), value calculated using timer frequency.. 125.00 BogoMIPS (lpj=250000)
[ 0.021914] pid_max: default: 32768 minimum: 301
[ 0.025132] LSM: Security Framework initializing
[ 0.027343] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.028580] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.115959] rcu: Hierarchical SRCU implementation.
[ 0.135096] EFI services will not be available.
[ 0.139828] smp: Bringing up secondary CPUs ...
[ 0.140267] smp: Brought up 1 node, 1 CPU
[ 0.140587] SMP: Total of 1 processors activated.
[ 0.141037] CPU features: detected: 32-bit EL0 Support
[ 0.141769] CPU features: detected: CRC32 instructions
[ 0.142144] CPU features: detected: 32-bit EL1 Support
[ 0.547379] CPU: All CPU(s) started at EL1
[ 0.548418] alternatives: patching kernel code
[ 0.606936] devtmpfs: initialized
[ 0.679006] KASLR enabled
[ 0.707823] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.708867] futex hash table entries: 256 (order: 3, 32768 bytes, linear)
[ 0.710674] Running postponed tracer tests:
[ 0.714449] Testing tracer function: PASSED
[ 8.629279] Testing dynamic ftrace: PASSED
[ 9.591794] Testing dynamic ftrace ops #1:
[ 12.266300] (1 0 1 0 0)
[ 12.266797] (1 1 2 0 0)
[ 20.579408] (2 1 3 0 1141111)
[ 20.582238] (2 2 4 0 1141539) PASSED
[ 24.613636] Testing dynamic ftrace ops #2:
[ 34.951883] (1 0 1 1116153 0)
[ 34.954384] (1 1 2 1116600 0)
[ 35.023400] (2 1 3 1 3074)
[ 35.024655] (2 2 4 200 3273) PASSED
[ 38.154182] Testing ftrace recursion: PASSED
[ 38.921470] Testing ftrace recursion safe: PASSED
[ 39.687688] Testing ftrace regs: PASSED
[ 40.462198] Testing tracer nop: PASSED
[ 40.466389] Testing tracer irqsoff: PASSED
[ 48.407206] Testing tracer preemptoff: PASSED
[ 56.413646] Testing tracer preemptirqsoff: PASSED
[ 64.506770] Testing tracer wakeup: PASSED
[ 72.330196] Testing tracer wakeup_rt: PASSED
[ 80.131803] Testing tracer wakeup_dl: PASSED
[ 87.972631] Testing tracer function_graph:
[ 91.178997]
[ 91.184432] =============================
[ 91.188301] WARNING: suspicious RCU usage
[ 91.192316] 5.10.0-rc4-next-20201119-00002-g51c2bf0ac853 #25 Tainted: G W
[ 91.197536] -----------------------------
[ 91.201431] kernel/trace/trace_preemptirq.c:78 RCU not watching trace_hardirqs_off()!
[ 91.206546]
[ 91.206546] other info that might help us debug this:
[ 91.206546]
[ 91.211790]
[ 91.211790] rcu_scheduler_active = 2, debug_locks = 0
[ 91.216454] RCU used illegally from extended quiescent state!
[ 91.220890] no locks held by swapper/0/0.
[ 91.224712]
[ 91.224712] stack backtrace:
[ 91.228794] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G W 5.10.0-rc4-next-20201119-00002-g51c2bf0ac853 #25
[ 91.234877] Hardware name: linux,dummy-virt (DT)
[ 91.239032] Call trace:
[ 91.242587] dump_backtrace+0x0/0x240
[ 91.246500] show_stack+0x34/0x88
[ 91.250295] dump_stack+0x140/0x1bc
[ 91.254159] lockdep_rcu_suspicious+0xe4/0xf8
[ 91.258332] trace_hardirqs_off+0x214/0x330
[ 91.262462] trace_graph_return+0x1ac/0x1d8
[ 91.266564] ftrace_return_to_handler+0xa4/0x170
[ 91.270809] return_to_handler+0x1c/0x38
[ 91.274826] default_idle_call+0x94/0x38c
[ 91.278869] do_idle+0x240/0x290
[ 91.282633] rest_init+0x1e8/0x2dc
[ 91.286529] arch_call_rest_init+0x1c/0x28
[ 91.290585] start_kernel+0x638/0x670
[ 91.295524] WARNING: CPU: 0 PID: 0 at kernel/locking/lockdep.c:5279 check_flags.part.0+0x1d4/0x1f8
[ 91.296302] Modules linked in:
[ 91.297644] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.10.0-rc4-next-20201119-00002-g51c2bf0ac853 #25
[ 91.298317] Hardware name: linux,dummy-virt (DT)
[ 91.298975] pstate: 80000085 (Nzcv daIf -PAN -UAO -TCO BTYPE=--)
[ 91.299648] pc : check_flags.part.0+0x1d4/0x1f8
[ 91.300303] lr : check_flags.part.0+0x1d4/0x1f8
[ 91.300960] sp : ffffdb60f8d73a50
[ 91.301628] x29: ffffdb60f8d73a50 x28: ffffdb60f8d84000
[ 91.303527] x27: ffffdb60f869cbb8 x26: ffffdb60f6835930
[ 91.305431] x25: 0000000000000000 x24: 0000000000000000
[ 91.307343] x23: ffffdb60f8daf360 x22: 0000000000000001
[ 91.309242] x21: 0000000000000000 x20: 0000000000000001
[ 91.311145] x19: ffffdb60f9bcf000 x18: 00000000749f6e65
[ 91.313044] x17: 00000000dcd3f761 x16: 0000000000000005
[ 91.314954] x15: 0000000000000000 x14: 0000000000000028
[ 91.316854] x13: 000000000000067a x12: 0000000000000028
[ 91.318753] x11: 0101010101010101 x10: ffffdb60f8d73820
[ 91.320657] x9 : ffffdb60f6960ff8 x8 : 4e5241575f534b43
[ 91.322582] x7 : 4f4c5f4755424544 x6 : ffff4454fdbd3667
[ 91.324486] x5 : 00000000ffffffc8 x4 : ffff4454fdbd2c60
[ 91.326413] x3 : ffffdb60f6800000 x2 : ffffdb60f7c60000
[ 91.328308] x1 : 1c0af7741e0f0c00 x0 : 0000000000000000
[ 91.330227] Call trace:
[ 91.330880] check_flags.part.0+0x1d4/0x1f8
[ 91.331547] lock_acquire+0x208/0x508
[ 91.332200] _raw_spin_lock+0x5c/0x80
[ 91.332849] vprintk_emit+0xb4/0x380
[ 91.333528] vprintk_default+0x4c/0x60
[ 91.334189] vprintk_func+0x120/0x330
[ 91.334863] printk+0x78/0x9c
[ 91.335523] lockdep_rcu_suspicious+0x2c/0xf8
[ 91.336195] trace_hardirqs_off+0x214/0x330
[ 91.336854] trace_graph_return+0x1ac/0x1d8
[ 91.337518] ftrace_return_to_handler+0xa4/0x170
[ 91.338190] return_to_handler+0x1c/0x38
[ 91.338841] default_idle_call+0x94/0x38c
[ 91.339512] do_idle+0x240/0x290
[ 91.340166] rest_init+0x1e8/0x2dc
[ 91.340840] arch_call_rest_init+0x1c/0x28
[ 91.341499] start_kernel+0x638/0x670
[ 91.342147] irq event stamp: 1727
[ 91.342832] hardirqs last enabled at (1727): [<ffffdb60f7c33094>] exit_el1_irq_or_nmi+0x24/0x50
[ 91.343502] hardirqs last disabled at (1724): [<ffffdb60f7c33060>] enter_el1_irq_or_nmi+0x20/0x30
[ 91.344193] softirqs last enabled at (1726): [<ffffdb60f6835930>] return_to_handler+0x0/0x38
[ 91.344866] softirqs last disabled at (1725): [<ffffdb60f68c6880>] irq_enter_rcu+0x88/0xa8
[ 91.345546] ---[ end trace e131d25144579308 ]---
[ 91.346413]
[ 91.347055]
[ 91.347707] =============================
[ 91.348363] WARNING: suspicious RCU usage
[ 91.349058] 5.10.0-rc4-next-20201119-00002-g51c2bf0ac853 #25 Not tainted
[ 91.349714] -----------------------------
[ 91.350398] include/trace/events/ipi.h:19 suspicious rcu_dereference_check() usage!
[ 91.351025]
[ 91.351702] other info that might help us debug this:
[ 91.352324]
[ 91.352949]
[ 91.353626] rcu_scheduler_active = 2, debug_locks = 1
[ 91.354291] RCU used illegally from extended quiescent state!
[ 91.354965] no locks held by swapper/0/0.
[ 91.355590]
[ 91.356257] stack backtrace:
[ 91.356937] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.10.0-rc4-next-20201119-00002-g51c2bf0ac853 #25
[ 91.357611] Hardware name: linux,dummy-virt (DT)
[ 91.358270] Call trace:
[ 91.358925] dump_backtrace+0x0/0x240
[ 91.359597] show_stack+0x34/0x88
[ 91.360255] dump_stack+0x140/0x1bc
[ 91.360932] lockdep_rcu_suspicious+0xe4/0xf8
[ 91.361594] smp_cross_call+0x220/0x228
[ 91.362264] arch_irq_work_raise+0x40/0x50
[ 91.362925] __irq_work_queue_local+0xb0/0xe8
[ 91.363580] irq_work_queue+0x5c/0xb8
[ 91.364252] printk_safe_log_store+0x1a0/0x1d8
[ 91.364906] vprintk_func+0x23c/0x330
[ 91.365566] printk+0x78/0x9c
[ 91.366215] lockdep_rcu_suspicious+0x2c/0xf8
[ 91.366883] lock_acquire+0x340/0x508
[ 91.367538] _raw_spin_lock+0x5c/0x80
[ 91.368192] vprintk_emit+0xb4/0x380
[ 91.368866] vprintk_default+0x4c/0x60
[ 91.369521] vprintk_func+0x120/0x330
[ 91.370191] printk+0x78/0x9c
[ 91.370845] lockdep_rcu_suspicious+0x2c/0xf8
[ 91.371519] trace_hardirqs_off+0x214/0x330
[ 91.372172] trace_graph_return+0x1ac/0x1d8
[ 91.372842] ftrace_return_to_handler+0xa4/0x170
[ 91.373503] return_to_handler+0x1c/0x38
[ 91.374158] default_idle_call+0x94/0x38c
[ 91.374825] do_idle+0x240/0x290
[ 91.375479] rest_init+0x1e8/0x2dc
[ 91.376152] arch_call_rest_init+0x1c/0x28
[ 91.376804] start_kernel+0x638/0x670
[ 91.377475] =============================
[ 91.378132] WARNING: suspicious RCU usage
[ 91.378793] 5.10.0-rc4-next-20201119-00002-g51c2bf0ac853 #25 Not tainted
[ 91.379466] -----------------------------
[ 91.380129] include/trace/events/lock.h:13 suspicious rcu_dereference_check() usage!
[ 91.380769]
[ 91.381432] other info that might help us debug this:
[ 91.382066]
[ 91.382690]
[ 91.383349] rcu_scheduler_active = 2, debug_locks = 1
[ 91.384023] RCU used illegally from extended quiescent state!
[ 91.384675] no locks held by swapper/0/0.
[ 91.385316]
[ 91.385962] stack backtrace:
[ 91.386647] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.10.0-rc4-next-20201119-00002-g51c2bf0ac853 #25
[ 91.387307] Hardware name: linux,dummy-virt (DT)
[ 91.387956] Call trace:
[ 91.388626] dump_backtrace+0x0/0x240
[ 91.389283] show_stack+0x34/0x88
[ 91.389952] dump_stack+0x140/0x1bc
[ 91.390602] lockdep_rcu_suspicious+0xe4/0xf8
[ 91.391270] lock_acquire+0x340/0x508
[ 91.391926] _raw_spin_lock+0x5c/0x80
[ 91.392580] vprintk_emit+0xb4/0x380
[ 91.393259] vprintk_default+0x4c/0x60
[ 91.393913] vprintk_func+0x120/0x330
[ 91.394581] printk+0x78/0x9c
[ 91.395230] lockdep_rcu_suspicious+0x2c/0xf8
[ 91.395899] trace_hardirqs_off+0x214/0x330
[ 91.396555] trace_graph_return+0x1ac/0x1d8
[ 91.397243] ftrace_return_to_handler+0xa4/0x170
[ 91.397901] return_to_handler+0x1c/0x38
[ 91.398556] default_idle_call+0x94/0x38c
[ 91.399231] do_idle+0x240/0x290
[ 91.399883] rest_init+0x1e8/0x2dc
[ 91.400562] arch_call_rest_init+0x1c/0x28
[ 91.401227] start_kernel+0x638/0x670
[ 91.401909] ------------[ cut here ]------------
[ 91.402584] DEBUG_LOCKS_WARN_ON(lockdep_hardirqs_enabled())possible reason: unannotated irqs-off.
[ 91.403248] irq event stamp: 1727
[ 91.403939] hardirqs last enabled at (1727): [<ffffdb60f7c33094>] exit_el1_irq_or_nmi+0x24/0x50
[ 91.404614] hardirqs last disabled at (1724): [<ffffdb60f7c33060>] enter_el1_irq_or_nmi+0x20/0x30
[ 91.405305] softirqs last enabled at (1726): [<ffffdb60f6835930>] return_to_handler+0x0/0x38
[ 91.405976] softirqs last disabled at (1725): [<ffffdb60f68c6880>] irq_enter_rcu+0x88/0xa8
[ 94.124678] PASSED
[ 94.137271] pinctrl core: initialized pinctrl subsystem
[ 94.166010] DMI not present or invalid.
[ 94.181220] NET: Registered protocol family 16
[ 94.221500] DMA: preallocated 256 KiB GFP_KERNEL pool for atomic allocations
[ 94.222319] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[ 94.224040] DMA: preallocated 256 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[ 94.225379] audit: initializing netlink subsys (disabled)
[ 94.232973] audit: type=2000 audit(82.136:1): state=initialized audit_enabled=0 res=1
[ 94.251959] thermal_sys: Registered thermal governor 'step_wise'
[ 94.252110] thermal_sys: Registered thermal governor 'power_allocator'
[ 94.254016] cpuidle: using governor menu
[ 94.259177] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 94.260165] ASID allocator initialised with 32768 entries
[ 94.280847] Serial: AMBA PL011 UART driver
[ 94.897305] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 47, base_baud = 0) is a PL011 rev1
[ 94.899357] printk: console [ttyAMA0] enabled
[ 94.899357] printk: console [ttyAMA0] enabled
[ 94.899994] printk: bootconsole [pl11] disabled
[ 94.899994] printk: bootconsole [pl11] disabled
[ 95.136385] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[ 95.136940] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages
[ 95.137256] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[ 95.137555] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages
[ 95.172131] cryptd: max_cpu_qlen set to 1000
[ 95.238749] ACPI: Interpreter disabled.
[ 95.280884] iommu: Default domain type: Translated
[ 95.286381] vgaarb: loaded
[ 95.292824] SCSI subsystem initialized
[ 95.295892] libata version 3.00 loaded.
[ 95.301200] usbcore: registered new interface driver usbfs
[ 95.302249] usbcore: registered new interface driver hub
[ 95.303362] usbcore: registered new device driver usb
[ 95.319691] pps_core: LinuxPPS API ver. 1 registered
[ 95.319974] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[ 95.320522] PTP clock support registered
[ 95.324309] EDAC MC: Ver: 3.0.0
[ 95.356513] FPGA manager framework
[ 95.358764] Advanced Linux Sound Architecture Driver Initialized.
[ 95.379906] clocksource: Switched to clocksource arch_sys_counter
[ 109.397497] VFS: Disk quotas dquot_6.6.0
[ 109.398763] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 109.404469] pnp: PnP ACPI: disabled
[ 109.525997] NET: Registered protocol family 2
[ 109.539351] tcp_listen_portaddr_hash hash table entries: 1024 (order: 4, 81920 bytes, linear)
[ 109.541579] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 109.546171] TCP bind hash table entries: 16384 (order: 8, 1179648 bytes, linear)
[ 109.550508] TCP: Hash tables configured (established 16384 bind 16384)
[ 109.553087] UDP hash table entries: 1024 (order: 5, 163840 bytes, linear)
[ 109.554809] UDP-Lite hash table entries: 1024 (order: 5, 163840 bytes, linear)
[ 109.558939] NET: Registered protocol family 1
[ 109.569986] RPC: Registered named UNIX socket transport module.
[ 109.570338] RPC: Registered udp transport module.
[ 109.570584] RPC: Registered tcp transport module.
[ 109.570826] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 109.571261] PCI: CLS 0 bytes, default 64
[ 109.591131] hw perfevents: enabled with armv8_pmuv3 PMU driver, 5 counters available
[ 109.592826] kvm [1]: HYP mode not available
[ 109.700178] Initialise system trusted keyrings
[ 109.703933] workingset: timestamp_bits=44 max_order=19 bucket_order=0
[ 109.829691] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 109.839361] NFS: Registering the id_resolver key type
[ 109.840697] Key type id_resolver registered
[ 109.841002] Key type id_legacy registered
[ 109.842732] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 109.846885] 9p: Installing v9fs 9p2000 file system support
[ 109.923870] Key type asymmetric registered
[ 109.924235] Asymmetric key parser 'x509' registered
[ 109.925108] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245)
[ 109.925557] io scheduler mq-deadline registered
[ 109.925920] io scheduler kyber registered
[ 110.181262] pl061_gpio 9030000.pl061: PL061 GPIO chip registered
[ 110.220260] pci-host-generic 4010000000.pcie: host bridge /pcie@10000000 ranges:
[ 110.221906] pci-host-generic 4010000000.pcie: IO 0x003eff0000..0x003effffff -> 0x0000000000
[ 110.223253] pci-host-generic 4010000000.pcie: MEM 0x0010000000..0x003efeffff -> 0x0010000000
[ 110.224080] pci-host-generic 4010000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000
[ 110.226250] pci-host-generic 4010000000.pcie: ECAM at [mem 0x4010000000-0x401fffffff] for [bus 00-ff]
[ 110.229496] pci-host-generic 4010000000.pcie: PCI host bridge to bus 0000:00
[ 110.230080] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 110.230473] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]
[ 110.230784] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff]
[ 110.231097] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff]
[ 110.233438] pci 0000:00:00.0: [1b36:0008] type 00 class 0x060000
[ 110.243007] pci 0000:00:01.0: [1af4:1009] type 00 class 0x000200
[ 110.244685] pci 0000:00:01.0: reg 0x10: [io 0x0000-0x003f]
[ 110.246053] pci 0000:00:01.0: reg 0x14: [mem 0x00000000-0x00000fff]
[ 110.250653] pci 0000:00:01.0: reg 0x20: [mem 0x00000000-0x00003fff 64bit pref]
[ 110.260991] pci 0000:00:02.0: [1af4:1009] type 00 class 0x000200
[ 110.262072] pci 0000:00:02.0: reg 0x10: [io 0x0000-0x003f]
[ 110.262820] pci 0000:00:02.0: reg 0x14: [mem 0x00000000-0x00000fff]
[ 110.264321] pci 0000:00:02.0: reg 0x20: [mem 0x00000000-0x00003fff 64bit pref]
[ 110.269991] pci 0000:00:03.0: [1af4:1000] type 00 class 0x020000
[ 110.270750] pci 0000:00:03.0: reg 0x10: [io 0x0000-0x001f]
[ 110.271274] pci 0000:00:03.0: reg 0x14: [mem 0x00000000-0x00000fff]
[ 110.272464] pci 0000:00:03.0: reg 0x20: [mem 0x00000000-0x00003fff 64bit pref]
[ 110.273043] pci 0000:00:03.0: reg 0x30: [mem 0x00000000-0x0003ffff pref]
[ 110.278520] pci 0000:00:04.0: [1af4:1004] type 00 class 0x010000
[ 110.279261] pci 0000:00:04.0: reg 0x10: [io 0x0000-0x003f]
[ 110.280022] pci 0000:00:04.0: reg 0x14: [mem 0x00000000-0x00000fff]
[ 110.280997] pci 0000:00:04.0: reg 0x20: [mem 0x00000000-0x00003fff 64bit pref]
[ 110.293126] pci 0000:00:03.0: BAR 6: assigned [mem 0x10000000-0x1003ffff pref]
[ 110.293948] pci 0000:00:01.0: BAR 4: assigned [mem 0x8000000000-0x8000003fff 64bit pref]
[ 110.294793] pci 0000:00:02.0: BAR 4: assigned [mem 0x8000004000-0x8000007fff 64bit pref]
[ 110.295597] pci 0000:00:03.0: BAR 4: assigned [mem 0x8000008000-0x800000bfff 64bit pref]
[ 110.296522] pci 0000:00:04.0: BAR 4: assigned [mem 0x800000c000-0x800000ffff 64bit pref]
[ 110.297205] pci 0000:00:01.0: BAR 1: assigned [mem 0x10040000-0x10040fff]
[ 110.297717] pci 0000:00:02.0: BAR 1: assigned [mem 0x10041000-0x10041fff]
[ 110.298201] pci 0000:00:03.0: BAR 1: assigned [mem 0x10042000-0x10042fff]
[ 110.298701] pci 0000:00:04.0: BAR 1: assigned [mem 0x10043000-0x10043fff]
[ 110.299193] pci 0000:00:01.0: BAR 0: assigned [io 0x1000-0x103f]
[ 110.299921] pci 0000:00:02.0: BAR 0: assigned [io 0x1040-0x107f]
[ 110.300409] pci 0000:00:04.0: BAR 0: assigned [io 0x1080-0x10bf]
[ 110.300883] pci 0000:00:03.0: BAR 0: assigned [io 0x10c0-0x10df]
[ 110.359603] EINJ: ACPI disabled.
[ 110.756520] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003)
[ 110.766562] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003)
[ 110.774880] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003)
[ 110.781745] virtio-pci 0000:00:04.0: enabling device (0000 -> 0003)
[ 110.894006] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[ 110.949875] SuperH (H)SCI(F) driver initialized
[ 110.962431] msm_serial: driver initialized
[ 110.995190] cacheinfo: Unable to detect cache hierarchy for CPU 0
[ 111.135917] loop: module loaded
[ 111.155979] megasas: 07.714.04.00-rc1
[ 111.179577] scsi host0: Virtio SCSI HBA
[ 111.201653] scsi 0:0:0:0: Direct-Access QEMU QEMU HARDDISK 2.5+ PQ: 0 ANSI: 5
[ 112.559093] random: fast init done
[ 112.595812] sd 0:0:0:0: Power-on or device reset occurred
[ 112.611860] sd 0:0:0:0: [sda] 524288 512-byte logical blocks: (268 MB/256 MiB)
[ 112.613211] sd 0:0:0:0: [sda] Write Protect is off
[ 112.613728] sd 0:0:0:0: [sda] Mode Sense: 63 00 00 08
[ 112.620764] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 112.623873] sda: detected capacity change from 0 to 268435456
[ 112.697968] physmap-flash 0.flash: physmap platform flash device: [mem 0x00000000-0x03ffffff]
[ 112.704568] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000
[ 112.705537] Intel/Sharp Extended Query Table at 0x0031
[ 112.706704] Using buffer write method
[ 112.707437] erase region 0: offset=0x0,size=0x40000,blocks=256
[ 112.714453] physmap-flash 0.flash: physmap platform flash device: [mem 0x04000000-0x07ffffff]
[ 112.715449] 0.flash: Found 2 x16 devices at 0x0 in 32-bit bank. Manufacturer ID 0x000000 Chip ID 0x000000
[ 112.716117] Intel/Sharp Extended Query Table at 0x0031
[ 112.717014] Using buffer write method
[ 112.717344] erase region 0: offset=0x0,size=0x40000,blocks=256
[ 112.717696] Concatenating MTD devices:
[ 112.717962] (0): "0.flash"
[ 112.718183] (1): "0.flash"
[ 112.718396] into device "0.flash"
[ 112.733693] sda: detected capacity change from 0 to 268435456
[ 112.734221] sd 0:0:0:0: [sda] Attached SCSI disk
[ 112.868897] libphy: Fixed MDIO Bus: probed
[ 112.896853] tun: Universal TUN/TAP device driver, 1.6
[ 112.932681] thunder_xcv, ver 1.0
[ 112.933749] thunder_bgx, ver 1.0
[ 112.934733] nicpf, ver 1.0
[ 112.968658] hclge is initializing
[ 112.969507] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version
[ 112.969832] hns3: Copyright (c) 2017 Huawei Corporation.
[ 112.971113] e1000: Intel(R) PRO/1000 Network Driver
[ 112.971392] e1000: Copyright (c) 1999-2006 Intel Corporation.
[ 112.972667] e1000e: Intel(R) PRO/1000 Network Driver
[ 112.972954] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[ 112.974131] igb: Intel(R) Gigabit Ethernet Network Driver
[ 112.974412] igb: Copyright (c) 2007-2014 Intel Corporation.
[ 112.975297] igbvf: Intel(R) Gigabit Virtual Function Network Driver
[ 112.975775] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.
[ 112.985686] sky2: driver version 1.30
[ 113.009304] VFIO - User Level meta-driver version: 0.3
[ 113.048551] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 113.048946] ehci-pci: EHCI PCI platform driver
[ 113.049956] ehci-platform: EHCI generic platform driver
[ 113.053241] ehci-orion: EHCI orion driver
[ 113.056368] ehci-exynos: EHCI Exynos driver
[ 113.059235] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 113.060113] ohci-pci: OHCI PCI platform driver
[ 113.061205] ohci-platform: OHCI generic platform driver
[ 113.064420] ohci-exynos: OHCI Exynos driver
[ 113.075583] usbcore: registered new interface driver usb-storage
[ 113.146880] rtc-pl031 9010000.pl031: registered as rtc0
[ 113.148308] rtc-pl031 9010000.pl031: setting system clock to 2020-11-24T13:08:31 UTC (1606223311)
[ 113.164111] i2c /dev entries driver
[ 113.325456] sdhci: Secure Digital Host Controller Interface driver
[ 113.325754] sdhci: Copyright(c) Pierre Ossman
[ 113.336779] Synopsys Designware Multimedia Card Interface Driver
[ 113.363215] sdhci-pltfm: SDHCI platform and OF driver helper
[ 113.400526] ledtrig-cpu: registered to indicate activity on CPUs
[ 113.441824] usbcore: registered new interface driver usbhid
[ 113.442164] usbhid: USB HID core driver
[ 113.560589] drop_monitor: Initializing network drop monitor service
[ 113.562809] NET: Registered protocol family 17
[ 113.566122] 9pnet: Installing 9P2000 support
[ 113.577170] Key type dns_resolver registered
[ 113.581865] registered taskstats version 1
[ 113.582937] Running tests on all trace events:
[ 113.583197] Testing all events: OK
[ 136.678315] Running tests again, along with the function tracer
[ 136.683603] Running tests on all trace events:
[ 136.689620] Testing all events: OK
[ 349.011031] Testing ftrace filter: OK
[ 349.030607] Loading compiled-in X.509 certificates
[ 349.062241] input: gpio-keys as /devices/platform/gpio-keys/input/input0
[ 349.080633] ALSA device list:
[ 349.081036] No soundcards found.
[ 349.081340] TAP version 14
[ 349.081565] 1..0
[ 349.088742] uart-pl011 9000000.pl011: no DMA platform data
[ 349.105332] EXT4-fs (sda): mounting ext3 file system using the ext4 subsystem
[ 349.195485] EXT4-fs (sda): mounted filesystem with ordered data mode. Opts: (null)
[ 349.197107] VFS: Mounted root (ext3 filesystem) readonly on device 8:0.
[ 349.201501] devtmpfs: mounted
[ 349.369972] Freeing unused kernel memory: 8896K
[ 349.371955] Run /sbin/init as init process
[ 349.372238] with arguments:
[ 349.372474] /sbin/init
[ 349.372689] with environment:
[ 349.372927] HOME=/
[ 349.373135] TERM=linux
[ 349.373345] earlyprintk=serial
[ 349.838705] EXT4-fs (sda): re-mounted. Opts: (null)
[ 349.840571] ext3 filesystem being remounted at / supports timestamps until 2038 (0x7fffffff)