[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034] [ 0.000000] Linux version 4.20.0-rc4-next-20181128-00009-g44c557177b8d-dirty (anders@compilator) (gcc version 7.3.1 20180425 [linaro-7.3-2018.05 revision d29120a424ecfbc167ef90065c0eeb7f91977701] (Linaro GCC 7.3-2018.05)) #6 SMP Wed Nov 28 12:30:29 CET 2018 [ 0.000000] Machine model: linux,dummy-virt [ 0.000000] earlycon: pl11 at MMIO 0x0000000009000000 (options '') [ 0.000000] printk: bootconsole [pl11] enabled [ 0.000000] efi: Getting EFI parameters from FDT: [ 0.000000] efi: UEFI not found. [ 0.000000] cma: Reserved 16 MiB at 0x00000000bf000000 [ 0.000000] kmemleak: Kernel memory leak detector disabled [ 0.000000] NUMA: No NUMA configuration found [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000000bfffffff] [ 0.000000] NUMA: NODE_DATA [mem 0xbebf15c0-0xbebf2fff] [ 0.000000] Zone ranges: [ 0.000000] DMA32 [mem 0x0000000040000000-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] 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] random: get_random_bytes called from start_kernel+0xe0/0x6ec with crng_init=0 [ 0.000000] percpu: Embedded 490 pages/cpu @(____ptrval____) s1969240 r8192 d29608 u2007040 [ 0.000000] Detected VIPT I-cache on CPU0 [ 0.000000] CPU features: enabling workaround for ARM erratum 843419 [ 0.000000] CPU features: enabling workaround for ARM erratum 845719 [ 0.000000] CPU features: detected: Kernel page table isolation (KPTI) [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 516096 [ 0.000000] Policy zone: DMA32 [ 0.000000] Kernel command line: root=/dev/root rootfstype=9p rootflags=trans=virtio console=ttyAMA0,38400n8 earlycon=pl011,0x9000000 initcall_debug [ 0.000000] Memory: 993364K/2097152K available (15704K kernel code, 3774K rwdata, 4852K rodata, 6144K init, 23374K bss, 94204K reserved, 16384K cma-reserved) [ 0.000000] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 0.000000] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=1, Nodes=1 [ 0.000000] ftrace: allocating 41986 entries in 165 pages [ 0.000000] Running RCU self tests [ 0.000000] rcu: Hierarchical RCU implementation. [ 0.000000] rcu: RCU event tracing is enabled. [ 0.000000] rcu: RCU dyntick-idle grace-period acceleration is enabled. [ 0.000000] rcu: RCU lockdep checking is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=1. [ 0.000000] rcu: RCU callback double-/use-after-free debug enabled. [ 0.000000] rcu: RCU debug extended QS entry/exit. [ 0.000000] 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] 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.000231] sched_clock: 56 bits at 62MHz, resolution 16ns, wraps every 4398046511096ns [ 0.018078] Console: colour dummy device 80x25 [ 0.023961] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 0.025046] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 0.025545] ... MAX_LOCK_DEPTH: 48 [ 0.026096] ... MAX_LOCKDEP_KEYS: 8191 [ 0.026665] ... CLASSHASH_SIZE: 4096 [ 0.027253] ... MAX_LOCKDEP_ENTRIES: 32768 [ 0.027744] ... MAX_LOCKDEP_CHAINS: 65536 [ 0.028281] ... CHAINHASH_SIZE: 32768 [ 0.029221] memory used by lock dependency info: 7775 kB [ 0.029827] per task-struct memory footprint: 2688 bytes [ 0.030428] ------------------------ [ 0.030876] | Locking API testsuite: [ 0.031335] ---------------------------------------------------------------------------- [ 0.031887] | spin |wlock |rlock |mutex | wsem | rsem | [ 0.032440] -------------------------------------------------------------------------- [ 0.033770] A-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.046483] A-B-B-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.060079] A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.075086] A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.090091] A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.107161] A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.124196] A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.141239] double unlock: ok | ok | ok | ok | ok | ok | ok | [ 0.153277] initialize held: ok | ok | ok | ok | ok | ok | ok | [ 0.165512] -------------------------------------------------------------------------- [ 0.166700] recursive read-lock: | ok | | ok | [ 0.170930] recursive read-lock #2: | ok | | ok | [ 0.174716] mixed read-write-lock: | ok | | ok | [ 0.179055] mixed write-read-lock: | ok | | ok | [ 0.183367] mixed read-lock/lock-write ABBA: |FAILED| | ok | [ 0.187431] mixed read-lock/lock-read ABBA: | ok | | ok | [ 0.191924] mixed write-lock/lock-write ABBA: | ok | | ok | [ 0.196474] -------------------------------------------------------------------------- [ 0.197965] hard-irqs-on + irq-safe-A/12: ok | ok | ok | [ 0.203738] soft-irqs-on + irq-safe-A/12: ok | ok | ok | [ 0.209836] hard-irqs-on + irq-safe-A/21: ok | ok | ok | [ 0.216209] soft-irqs-on + irq-safe-A/21: ok | ok | ok | [ 0.222092] sirq-safe-A => hirqs-on/12: ok | ok | ok | [ 0.227996] sirq-safe-A => hirqs-on/21: ok | ok | ok | [ 0.234374] hard-safe-A + irqs-on/12: ok | ok | ok | [ 0.240174] soft-safe-A + irqs-on/12: ok | ok | ok | [ 0.246113] hard-safe-A + irqs-on/21: ok | ok | ok | [ 0.252547] soft-safe-A + irqs-on/21: ok | ok | ok | [ 0.258626] hard-safe-A + unsafe-B #1/123: ok | ok | ok | [ 0.265312] soft-safe-A + unsafe-B #1/123: ok | ok | ok | [ 0.271702] hard-safe-A + unsafe-B #1/132: ok | ok | ok | [ 0.278414] soft-safe-A + unsafe-B #1/132: ok | ok | ok | [ 0.284750] hard-safe-A + unsafe-B #1/213: ok | ok | ok | [ 0.291553] soft-safe-A + unsafe-B #1/213: ok | ok | ok | [ 0.297992] hard-safe-A + unsafe-B #1/231: ok | ok | ok | [ 0.304622] soft-safe-A + unsafe-B #1/231: ok | ok | ok | [ 0.310862] hard-safe-A + unsafe-B #1/312: ok | ok | ok | [ 0.316681] soft-safe-A + unsafe-B #1/312: ok | ok | ok | [ 0.323067] hard-safe-A + unsafe-B #1/321: ok | ok | ok | [ 0.329168] soft-safe-A + unsafe-B #1/321: ok | ok | ok | [ 0.335852] hard-safe-A + unsafe-B #2/123: ok | ok | ok | [ 0.342269] soft-safe-A + unsafe-B #2/123: ok | ok | ok | [ 0.349129] hard-safe-A + unsafe-B #2/132: ok | ok | ok | [ 0.355390] soft-safe-A + unsafe-B #2/132: ok | ok | ok | [ 0.362242] hard-safe-A + unsafe-B #2/213: ok | ok | ok | [ 0.368379] soft-safe-A + unsafe-B #2/213: ok | ok | ok | [ 0.375285] hard-safe-A + unsafe-B #2/231: ok | ok | ok | [ 0.381421] soft-safe-A + unsafe-B #2/231: ok | ok | ok | [ 0.388300] hard-safe-A + unsafe-B #2/312: ok | ok | ok | [ 0.394379] soft-safe-A + unsafe-B #2/312: ok | ok | ok | [ 0.401145] hard-safe-A + unsafe-B #2/321: ok | ok | ok | [ 0.408478] soft-safe-A + unsafe-B #2/321: ok | ok | ok | [ 0.415176] hard-irq lock-inversion/123: ok | ok | ok | [ 0.421295] soft-irq lock-inversion/123: ok | ok | ok | [ 0.428071] hard-irq lock-inversion/132: ok | ok | ok | [ 0.434189] soft-irq lock-inversion/132: ok | ok | ok | [ 0.441079] hard-irq lock-inversion/213: ok | ok | ok | [ 0.447304] soft-irq lock-inversion/213: ok | ok | ok | [ 0.454099] hard-irq lock-inversion/231: ok | ok | ok | [ 0.460187] soft-irq lock-inversion/231: ok | ok | ok | [ 0.467089] hard-irq lock-inversion/312: ok | ok | ok | [ 0.473203] soft-irq lock-inversion/312: ok | ok | ok | [ 0.480046] hard-irq lock-inversion/321: ok | ok | ok | [ 0.486244] soft-irq lock-inversion/321: ok | ok | ok | [ 0.492954] hard-irq read-recursion/123: ok | [ 0.495375] soft-irq read-recursion/123: ok | [ 0.498294] hard-irq read-recursion/132: ok | [ 0.500685] soft-irq read-recursion/132: ok | [ 0.503588] hard-irq read-recursion/213: ok | [ 0.506019] soft-irq read-recursion/213: ok | [ 0.508898] hard-irq read-recursion/231: ok | [ 0.511324] soft-irq read-recursion/231: ok | [ 0.514226] hard-irq read-recursion/312: ok | [ 0.516617] soft-irq read-recursion/312: ok | [ 0.519556] hard-irq read-recursion/321: ok | [ 0.521963] soft-irq read-recursion/321: ok | [ 0.524851] -------------------------------------------------------------------------- [ 0.525458] | Wound/wait tests | [ 0.525955] --------------------- [ 0.526471] ww api failures: ok | ok | ok | [ 0.534413] ww contexts mixing: ok | ok | [ 0.538598] finishing ww context: ok | ok | ok | ok | [ 0.546109] locking mismatches: ok | ok | ok | [ 0.552442] EDEADLK handling: ok | ok | ok | ok | ok | ok | ok | ok | ok | ok | [ 0.573152] spinlock nest unlocked: ok | [ 0.575770] ----------------------------------------------------- [ 0.576325] |block | try |context| [ 0.576929] ----------------------------------------------------- [ 0.577484] context: ok | ok | ok | [ 0.584154] try: ok | ok | ok | [ 0.589819] block: ok | ok | ok | [ 0.595595] spinlock: ok | ok | ok | [ 0.602377] ------------------------------------------------------- [ 0.603042] Good, all 261 testcases passed! | [ 0.603587] --------------------------------- [ 0.713963] ODEBUG: selftest passed [ 0.719958] Calibrating delay loop (skipped), value calculated using timer frequency.. 125.00 BogoMIPS (lpj=250000) [ 0.721023] pid_max: default: 32768 minimum: 301 [ 0.737811] LSM: Security Framework initializing [ 0.738884] Yama: becoming mindful. [ 0.742345] LoadPin: ready to pin (currently enforcing) [ 0.743484] SELinux: Initializing. [ 0.755182] *** VALIDATE SELinux *** [ 0.756198] AppArmor: AppArmor disabled by boot time parameter [ 0.809029] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes) [ 0.831765] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes) [ 0.836157] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes) [ 0.837829] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes) [ 0.892239] *** VALIDATE proc *** [ 0.919736] *** VALIDATE cgroup1 *** [ 0.920345] *** VALIDATE cgroup2 *** [ 1.016693] ASID allocator initialised with 32768 entries [ 1.032202] rcu: Hierarchical SRCU implementation. [ 1.156070] EFI services will not be available. [ 1.195141] smp: Bringing up secondary CPUs ... [ 1.196384] smp: Brought up 1 node, 1 CPU [ 1.196968] SMP: Total of 1 processors activated. [ 1.197625] CPU features: detected: 32-bit EL0 Support [ 1.198312] CPU features: detected: CRC32 instructions [ 1.559404] CPU features: emulated: Privileged Access Never (PAN) using TTBR0_EL1 switching [ 1.561061] CPU: All CPU(s) started at EL1 [ 1.562363] alternatives: patching kernel code [ 1.564235] _warn_unseeded_randomness: 98 callbacks suppressed [ 1.564651] random: get_random_u64 called from compute_layout+0x138/0x1b8 with crng_init=0 [ 1.620621] random: get_random_u64 called from dup_task_struct+0xdc/0x3d0 with crng_init=0 [ 5.729611] node 0 initialised, 248300 pages in 4ms [ 5.740937] pgdatinit0 (15) used greatest stack depth: 13280 bytes left [ 5.755207] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 5.862494] devtmpfs: initialized [ 6.142137] workqueue: round-robin CPU selection forced, expect performance impact [ 6.176979] gcov: version magic: 0x4137332a [ 6.213026] Registered cp15_barrier emulation handler [ 6.214057] Registered setend emulation handler [ 16.326783] DMA-API: preallocated 65536 debug entries [ 16.327391] DMA-API: debugging enabled by kernel config [ 16.329224] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns [ 16.332929] futex hash table entries: 256 (order: 3, 32768 bytes) [ 16.340703] Running postponed tracer tests: [ 16.342289] Testing tracer function: [ 16.375294] ftrace_replace_code: 1 [ 27.314269] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 27.601077] ftrace_replace_code: 1 [ 37.054498] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 37.058844] PASSED [ 37.059334] Testing dynamic ftrace: [ 39.147132] ftrace_replace_code: 1 [ 39.239041] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 39.484343] PASSED [ 39.485477] Testing dynamic ftrace ops #1: [ 47.813998] ftrace_replace_code: 1 [ 47.912722] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 47.917200] (1 0 1 0 0) [ 47.917413] (1 1 2 0 0) [ 47.928629] ftrace_replace_code: 1 [ 62.198602] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 62.202439] (2 1 3 0 1079037) [ 62.202747] (2 2 4 0 1079058) [ 62.215551] ftrace_replace_code: 1 [ 72.873508] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 72.889074] ftrace_replace_code: 1 [ 72.982884] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 72.987297] ftrace_replace_code: 1 [ 73.079971] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 73.084762] PASSED [ 73.085233] Testing dynamic ftrace ops #2: [ 81.396764] ftrace_replace_code: 1 [ 81.501091] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 81.505256] ftrace_replace_code: 1 [ 81.597549] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 81.616091] ftrace_replace_code: 1 [ 94.978447] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 94.980513] (1 0 1 1047461 0) [ 94.980777] (1 1 2 1047482 0) [ 94.995028] (2 1 3 1 503) [ 94.996239] (2 2 4 136 638) [ 95.032946] ftrace_replace_code: 1 [ 104.490351] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 104.493044] PASSED [ 104.493538] Testing ftrace recursion: [ 106.576117] ftrace_replace_code: 1 [ 106.670995] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 106.675447] ftrace_replace_code: 1 [ 106.768506] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 106.770376] PASSED [ 106.771466] Testing ftrace recursion safe: [ 108.847599] ftrace_replace_code: 1 [ 108.942502] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 108.946961] ftrace_replace_code: 1 [ 109.039950] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 109.041840] PASSED [ 109.042355] Testing ftrace regs(no arch support): [ 111.122704] ftrace_replace_code: 1 [ 111.217728] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 111.222173] ftrace_replace_code: 1 [ 111.315132] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 111.317744] PASSED [ 111.318685] Testing tracer nop: PASSED [ 111.321165] Testing tracer irqsoff: [ 111.336057] ftrace_replace_code: 1 [ 122.048974] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 122.084180] ftrace_replace_code: 1 [ 131.654282] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 131.656619] PASSED [ 131.659556] Testing tracer wakeup: [ 131.690184] ftrace_replace_code: 1 [ 142.337359] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 142.373689] ftrace_replace_code: 1 [ 151.853264] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 151.864290] PASSED [ 151.866291] Testing tracer wakeup_rt: [ 151.894668] ftrace_replace_code: 1 [ 162.671936] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 162.704368] ftrace_replace_code: 1 [ 172.177845] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 172.187364] PASSED [ 172.188421] Testing tracer wakeup_dl: [ 172.220601] ftrace_replace_code: 1 [ 182.896452] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 182.935496] ftrace_replace_code: 1 [ 183.387434] sched: DL replenish lagged too much [ 192.538451] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 192.548662] PASSED [ 192.551536] Testing tracer function_graph: [ 192.579002] ftrace_replace_code: 1 [ 203.163282] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 223.757667] watchdog: BUG: soft lockup - CPU#0 stuck for 21s! [swapper/0:1] [ 223.780973] Modules linked in: [ 223.801588] irq event stamp: 1882638 [ 223.823944] hardirqs last enabled at (1882637): [] _raw_spin_unlock_irq+0x38/0x78 [ 223.855715] hardirqs last disabled at (1882638): [] el1_irq+0xa8/0x1c0 [ 223.886044] softirqs last enabled at (1879012): [] __do_softirq+0x9a8/0x9f0 [ 223.916327] softirqs last disabled at (1878913): [] irq_exit+0x128/0x1b8 [ 223.943799] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G T 4.20.0-rc4-next-20181128-00009-g44c557177b8d-dirty #6 [ 223.975491] Hardware name: linux,dummy-virt (DT) [ 223.996054] pstate: 20400005 (nzCv daif +PAN -UAO) [ 224.019972] pc : _raw_spin_unlock_irq+0x3c/0x78 [ 224.042998] lr : _raw_spin_unlock_irq+0x38/0x78 [ 224.062653] sp : ffffff800804b8e0 [ 224.079107] x29: ffffff800804b8e0 x28: 0000000000000003 [ 224.103689] x27: ffffffc03f558040 x26: ffffff8009c15df8 [ 224.128139] x25: ffffff8009d12fb0 x24: 0000000000000000 [ 224.152539] x23: ffffff8008f07958 x22: ffffffc03f558040 [ 224.176939] x21: ffffffc03f5dc040 x20: ffffff80081a8c40 [ 224.201584] x19: ffffffc07ebdf6c0 x18: 0000000034f4d91d [ 224.226353] x17: 0000000000000000 x16: 0000000000000000 [ 224.251147] x15: ffffff8009c6a580 x14: ffffff800ac4e6a0 [ 224.275919] x13: ffffff800ac4fea0 x12: ffffff800ac4fea0 [ 224.300501] x11: ffffff800ac4ffa8 x10: ffffff800ac4ffa8 [ 224.325916] x9 : 0000000000000c30 x8 : 00000000000ac5e3 [ 224.350883] x7 : 0000000000000c00 x6 : 0000004075191000 [ 224.375621] x5 : ffffff8009cb82b0 x4 : ffffff8009c15bb0 [ 224.400405] x3 : fffffffffffffe80 x2 : ffffff800a6aa530 [ 224.425005] x1 : 000000000000001f x0 : 00000000000de18a [ 224.450612] Call trace: [ 224.470131] _raw_spin_unlock_irq+0x3c/0x78 [ 224.492152] finish_task_switch+0x160/0x220 [ 224.514919] __schedule+0xa78/0xaf8 [ 224.536328] schedule+0x9c/0xe0 [ 224.556460] schedule_timeout+0x960/0x9c8 [ 224.578254] schedule_timeout_uninterruptible+0x3c/0x48 [ 224.602119] msleep+0x3c/0x58 [ 224.622262] trace_selftest_startup_function_graph+0x1e4/0x3c8 [ 224.646972] run_tracer_selftest+0x234/0x384 [ 224.669096] register_tracer+0x488/0x6a8 [ 224.690955] init_graph_trace+0x148/0x170 [ 224.712777] do_one_initcall+0x324/0x6e8 [ 224.734677] do_initcall_level+0x898/0x970 [ 224.756645] do_initcalls+0x64/0xa8 [ 224.777355] do_basic_setup+0x44/0x70 [ 224.798739] kernel_init_freeable+0x178/0x2bc [ 224.821220] kernel_init+0x28/0x140 [ 224.842329] ret_from_fork+0x10/0x18 [ 316.108328] watchdog: BUG: soft lockup - CPU#0 stuck for 30s! [swapper/0:1] [ 316.131360] Modules linked in: [ 316.151340] irq event stamp: 1892006 [ 316.173762] hardirqs last enabled at (1892005): [] _raw_spin_unlock_irq+0x38/0x78 [ 316.205709] hardirqs last disabled at (1892006): [] el1_irq+0xa8/0x1c0 [ 316.236364] softirqs last enabled at (1879012): [] __do_softirq+0x9a8/0x9f0 [ 316.267195] softirqs last disabled at (1878913): [] irq_exit+0x128/0x1b8 [ 316.294376] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G L T 4.20.0-rc4-next-20181128-00009-g44c557177b8d-dirty #6 [ 316.324830] Hardware name: linux,dummy-virt (DT) [ 316.345051] pstate: 20400005 (nzCv daif +PAN -UAO) [ 316.369136] pc : _raw_spin_unlock_irq+0x3c/0x78 [ 316.392878] lr : _raw_spin_unlock_irq+0x38/0x78 [ 316.412717] sp : ffffff800804b8e0 [ 316.429979] x29: ffffff800804b8e0 x28: 0000000000000003 [ 316.455514] x27: ffffffc03f558040 x26: ffffff8009c15df8 [ 316.481124] x25: ffffff8009d12fb0 x24: 0000000000000000 [ 316.506758] x23: ffffff8008f07958 x22: ffffffc03f558040 [ 316.532323] x21: ffffffc03f5dc040 x20: ffffff80081a8c40 [ 316.558326] x19: ffffffc07ebdf6c0 x18: 0000000034f4d91d [ 316.583926] x17: 0000000000000000 x16: 0000000000000000 [ 316.609201] x15: ffffff8009c6a580 x14: ffffff800ac4e6a0 [ 316.634767] x13: ffffff800ac4fea0 x12: ffffff800ac4fea0 [ 316.660771] x11: ffffff800ac4ffa8 x10: ffffff800ac4ffa8 [ 316.686723] x9 : 0000000000000780 x8 : 00000000003ad83b [ 316.712310] x7 : 0000000000000750 x6 : 0000004075191000 [ 316.738153] x5 : ffffff8009cb82b0 x4 : ffffff8009c15bb0 [ 316.763800] x3 : fffffffffffffe80 x2 : ffffff800a6aa530 [ 316.789343] x1 : 000000000000001f x0 : 00000000000e21de [ 316.816198] Call trace: [ 316.836250] _raw_spin_unlock_irq+0x3c/0x78 [ 316.859401] finish_task_switch+0x160/0x220 [ 316.882893] __schedule+0xa78/0xaf8 [ 316.904770] schedule+0x9c/0xe0 [ 316.925996] schedule_timeout+0x960/0x9c8 [ 316.949030] schedule_timeout_uninterruptible+0x3c/0x48 [ 316.973731] msleep+0x3c/0x58 [ 316.994683] trace_selftest_startup_function_graph+0x1e4/0x3c8 [ 317.020868] run_tracer_selftest+0x234/0x384 [ 317.044114] register_tracer+0x488/0x6a8 [ 317.066944] init_graph_trace+0x148/0x170 [ 317.089673] do_one_initcall+0x324/0x6e8 [ 317.112065] do_initcall_level+0x898/0x970 [ 317.134860] do_initcalls+0x64/0xa8 [ 317.156500] do_basic_setup+0x44/0x70 [ 317.178646] kernel_init_freeable+0x178/0x2bc [ 317.201770] kernel_init+0x28/0x140 [ 317.223604] ret_from_fork+0x10/0x18 [ 378.099845] watchdog: BUG: soft lockup - CPU#0 stuck for 30s! [kworker/0:0:5] [ 378.121654] Modules linked in: [ 378.140558] irq event stamp: 8988 [ 378.161452] hardirqs last enabled at (8987): [] _raw_spin_unlock_irq+0x38/0x78 [ 378.191386] hardirqs last disabled at (8988): [] el1_irq+0xa8/0x1c0 [ 378.220350] softirqs last enabled at (454): [] __do_softirq+0x9a8/0x9f0 [ 378.249179] softirqs last disabled at (447): [] irq_exit+0x128/0x1b8 [ 378.274852] CPU: 0 PID: 5 Comm: kworker/0:0 Tainted: G L T 4.20.0-rc4-next-20181128-00009-g44c557177b8d-dirty #6 [ 378.304846] Hardware name: linux,dummy-virt (DT) [ 378.331839] Workqueue: (null) (events) [ 378.355891] pstate: 20400005 (nzCv daif +PAN -UAO) [ 378.378721] pc : _raw_spin_unlock_irq+0x3c/0x78 [ 378.401077] lr : _raw_spin_unlock_irq+0x38/0x78 [ 378.420228] sp : ffffff800806bcd0 [ 378.436617] x29: ffffff800806bcd0 x28: 0000000000000003 [ 378.461214] x27: ffffffc03f588040 x26: ffffff8009c15df8 [ 378.485829] x25: ffffff8009d12fb0 x24: 0000000000000000 [ 378.510319] x23: ffffff8008f07958 x22: ffffffc03f588040 [ 378.535116] x21: ffffffc03f5dc040 x20: ffffff80081a8c40 [ 378.559770] x19: ffffffc07ebdf6c0 x18: 0000000034f4d91d [ 378.584428] x17: 0000000000000000 x16: 0000000000000000 [ 378.609116] x15: ffffff8009c6a580 x14: ffffff800ac4e6a0 [ 378.633709] x13: ffffff800ac4fea0 x12: ffffff800ac4fea0 [ 378.658299] x11: ffffff800ac4ffa8 x10: ffffff800ac4ffa8 [ 378.682718] x9 : 0000000000000db0 x8 : 00000000005b1c23 [ 378.707149] x7 : 0000000000000d80 x6 : 0000004075191000 [ 378.731239] x5 : ffffff8009cb82b0 x4 : ffffff8009c15bb0 [ 378.755371] x3 : 00000000000e5390 x2 : 00000000000e5390 [ 378.779655] x1 : 0000000000000001 x0 : 00000000000e5390 [ 378.804939] Call trace: [ 378.824201] _raw_spin_unlock_irq+0x3c/0x78 [ 378.846121] finish_task_switch+0x160/0x220 [ 378.868728] __schedule+0xa78/0xaf8 [ 378.889660] schedule+0x9c/0xe0 [ 378.909817] worker_thread+0x240/0x2a0 [ 378.930685] kthread+0x154/0x170 [ 378.950794] ret_from_fork+0x10/0x18 [ 379.197472] ftrace_replace_code: 1 [ 391.349921] ../kernel/trace/ftrace.c:2446, loop_counter: 41986 [ 391.353485] PASSED [ 391.566531] _warn_unseeded_randomness: 7 callbacks suppressed [ 391.566807] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 391.568270] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 391.571518] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 391.597088] prandom: seed boundary self test passed [ 391.640312] prandom: 100 self tests passed [ 391.648918] pinctrl core: initialized pinctrl subsystem [ 391.785652] regulator-dummy: Failed to create debugfs directory [ 391.797328] [ 391.797804] ************************************************************* [ 391.798447] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 391.799055] ** ** [ 391.799649] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 391.800807] ** ** [ 391.801388] ** This means that this kernel is built to expose internal ** [ 391.802043] ** IOMMU data structures, which may compromise security on ** [ 391.802667] ** your system. ** [ 391.803231] ** ** [ 391.803795] ** If you see this message and you are not debugging the ** [ 391.804349] ** kernel, report this immediately to your vendor! ** [ 391.805441] ** ** [ 391.806057] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 391.806671] ************************************************************* [ 391.846567] DMI not present or invalid. [ 391.920925] NET: Registered protocol family 16 [ 391.957344] audit: initializing netlink subsys (disabled) [ 392.153984] cpuidle: using governor ladder [ 392.155941] cpuidle: using governor menu [ 392.183391] vdso: 2 pages (1 code @ (____ptrval____), 1 data @ (____ptrval____)) [ 392.185995] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. [ 392.191746] audit: type=2000 audit(208.144:1): state=initialized audit_enabled=0 res=1 [ 392.398707] DMA: preallocated 256 KiB pool for atomic allocations [ 392.519770] Serial: AMBA PL011 UART driver [ 393.580460] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 39, base_baud = 0) is a PL011 rev1 [ 393.584131] printk: console [ttyAMA0] enabled [ 393.584131] printk: console [ttyAMA0] enabled [ 393.585362] printk: bootconsole [pl11] disabled [ 393.585362] printk: bootconsole [pl11] disabled [ 393.727897] _warn_unseeded_randomness: 42 callbacks suppressed [ 393.728161] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 393.730547] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 394.436219] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 394.514609] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 394.699568] kobject: 'renesas,r9a06g032-sysctrl' ((____ptrval____)): kobject_release, parent (____ptrval____) (delayed 750) [ 394.713138] kobject: 'renesas-cpg-mssr' ((____ptrval____)): kobject_release, parent (____ptrval____) (delayed 750) [ 394.783053] arm-v7s io-pgtable: self test ok [ 394.785507] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 32 [ 394.795103] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 36 [ 394.802391] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 40 [ 394.810480] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 42 [ 394.819567] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 44 [ 394.827029] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 48 [ 394.835233] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 32 [ 394.847056] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 36 [ 394.860146] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 40 [ 394.873675] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 42 [ 394.887288] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 44 [ 394.900985] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 48 [ 394.918085] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 32 [ 394.952537] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 36 [ 394.986911] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 40 [ 395.023530] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 42 [ 395.064558] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 44 [ 395.106601] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 48 [ 395.149046] arm-lpae io-pgtable: selftest: completed with 18 PASS 0 FAIL [ 395.191909] vgaarb: loaded [ 395.215798] _warn_unseeded_randomness: 34 callbacks suppressed [ 395.216063] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 395.217799] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 395.254612] pps_core: LinuxPPS API ver. 1 registered [ 395.255323] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 395.260630] PTP clock support registered [ 395.272236] random: get_random_u32 called from kobject_release+0x24/0xf8 with crng_init=0 [ 395.273182] kobject: 'brcmstb-reboot' ((____ptrval____)): kobject_release, parent (____ptrval____) (delayed 500) [ 395.487765] NetLabel: Initializing [ 395.488417] NetLabel: domain hash size = 128 [ 395.489077] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 395.500893] NetLabel: unlabeled traffic allowed by default [ 395.526826] clocksource: Switched to clocksource arch_sys_counter [ 401.702215] _warn_unseeded_randomness: 4 callbacks suppressed [ 401.702482] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 401.704233] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 401.708188] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 401.728116] VFS: Disk quotas dquot_6.6.0 [ 401.734958] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 401.772338] *** VALIDATE hugetlbfs *** [ 402.883531] _warn_unseeded_randomness: 7 callbacks suppressed [ 402.883794] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 402.885511] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 402.888457] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 402.895399] NET: Registered protocol family 2 [ 402.949092] tcp_listen_portaddr_hash hash table entries: 1024 (order: 4, 90112 bytes) [ 402.957251] TCP established hash table entries: 16384 (order: 5, 131072 bytes) [ 402.989085] TCP bind hash table entries: 16384 (order: 8, 1310720 bytes) [ 403.002735] TCP: Hash tables configured (established 16384 bind 16384) [ 403.014749] UDP hash table entries: 1024 (order: 5, 196608 bytes) [ 403.022426] UDP-Lite hash table entries: 1024 (order: 5, 196608 bytes) [ 403.048075] NET: Registered protocol family 1 [ 403.054237] NET: Registered protocol family 44 [ 403.160124] hw perfevents: enabled with armv8_pmuv3 PMU driver, 1 counters available [ 403.174755] kvm [1]: HYP mode not available [ 403.558875] Kprobe smoke test: started [ 404.858848] Kprobe smoke test: passed successfully [ 404.947867] Initialise system trusted keyrings [ 404.950651] _warn_unseeded_randomness: 50 callbacks suppressed [ 404.950905] random: get_random_bytes called from key_alloc+0x380/0x698 with crng_init=0 [ 404.959610] Key type blacklist registered [ 404.967731] random: get_random_u64 called from dup_task_struct+0xdc/0x3d0 with crng_init=0 [ 404.985299] workingset: timestamp_bits=44 max_order=19 bucket_order=0 [ 407.557471] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 407.559343] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 407.588208] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 407.844556] 9p: Installing v9fs 9p2000 file system support [ 407.990777] Allocating IMA blacklist keyring. [ 408.011610] cryptomgr_test (37) used greatest stack depth: 12400 bytes left [ 408.045504] kworker/u2:1 (38) used greatest stack depth: 11936 bytes left [ 409.648488] Key type asymmetric registered [ 409.651341] Asymmetric key parser 'x509' registered [ 409.659864] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245) [ 409.685240] _warn_unseeded_randomness: 26 callbacks suppressed [ 409.685508] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 409.688095] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 409.729114] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 409.958211] kobject: 'brcm-gisb-arb' ((____ptrval____)): kobject_release, parent (____ptrval____) (delayed 250) [ 410.100313] kobject: 'armada-37xx-pinctrl' ((____ptrval____)): kobject_release, parent (____ptrval____) (delayed 1000) [ 410.369135] pl061_gpio 9030000.pl061: PL061 GPIO chip @0x0000000009030000 registered [ 410.378858] pl061_gpio 9030000.pl061: Unbalanced pm_runtime_enable! [ 410.408859] pl061_gpio 9030000.pl061: PL061 GPIO chip @0x0000000009030000 registered [ 410.445262] kobject: 'stmpe-pwm' ((____ptrval____)): kobject_release, parent (____ptrval____) (delayed 750) [ 410.481449] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 410.589203] pci-host-generic 3f000000.pcie: host bridge /pcie@10000000 ranges: [ 410.592799] pci-host-generic 3f000000.pcie: IO 0x3eff0000..0x3effffff -> 0x00000000 [ 410.596591] pci-host-generic 3f000000.pcie: MEM 0x10000000..0x3efeffff -> 0x10000000 [ 410.599035] pci-host-generic 3f000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000 [ 410.605580] pci-host-generic 3f000000.pcie: ECAM at [mem 0x3f000000-0x3fffffff] for [bus 00-0f] [ 410.628048] pci-host-generic 3f000000.pcie: PCI host bridge to bus 0000:00 [ 410.629341] pci_bus 0000:00: root bus resource [bus 00-0f] [ 410.631092] pci_bus 0000:00: root bus resource [io 0x0000-0xffff] [ 410.632617] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff] [ 410.634914] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff] [ 410.640882] pci 0000:00:00.0: calling quirk_mmio_always_on+0x0/0x38 @ 1 [ 410.643434] pci 0000:00:00.0: quirk_mmio_always_on+0x0/0x38 took 130 usecs [ 410.764613] pci 0000:00:01.0: BAR 6: assigned [mem 0x10000000-0x1003ffff pref] [ 410.767218] pci 0000:00:01.0: BAR 4: assigned [mem 0x8000000000-0x8000003fff 64bit pref] [ 410.769530] pci 0000:00:02.0: BAR 4: assigned [mem 0x8000004000-0x8000007fff 64bit pref] [ 410.772413] pci 0000:00:03.0: BAR 4: assigned [mem 0x8000008000-0x800000bfff 64bit pref] [ 410.775111] pci 0000:00:01.0: BAR 1: assigned [mem 0x10040000-0x10040fff] [ 410.776846] pci 0000:00:03.0: BAR 1: assigned [mem 0x10041000-0x10041fff] [ 410.779205] pci 0000:00:03.0: BAR 0: assigned [io 0x1000-0x103f] [ 410.780892] pci 0000:00:01.0: BAR 0: assigned [io 0x1040-0x105f] [ 410.783183] pci 0000:00:02.0: BAR 0: assigned [io 0x1060-0x107f] [ 410.788180] pci 0000:00:00.0: calling tegra_pcie_relax_enable+0x0/0x40 @ 1 [ 410.790872] pci 0000:00:00.0: tegra_pcie_relax_enable+0x0/0x40 took 191 usecs [ 410.794471] pci 0000:00:01.0: calling tegra_pcie_relax_enable+0x0/0x40 @ 1 [ 410.795614] pci 0000:00:01.0: tegra_pcie_relax_enable+0x0/0x40 took 88 usecs [ 410.797352] pci 0000:00:02.0: calling tegra_pcie_relax_enable+0x0/0x40 @ 1 [ 410.799168] pci 0000:00:02.0: tegra_pcie_relax_enable+0x0/0x40 took 87 usecs [ 410.800911] pci 0000:00:03.0: calling tegra_pcie_relax_enable+0x0/0x40 @ 1 [ 410.802692] pci 0000:00:03.0: tegra_pcie_relax_enable+0x0/0x40 took 85 usecs [ 410.873496] _warn_unseeded_randomness: 15 callbacks suppressed [ 410.874940] random: get_random_u32 called from kobject_release+0x24/0xf8 with crng_init=0 [ 410.875864] kobject: 'layerscape-pcie' ((____ptrval____)): kobject_release, parent (____ptrval____) (delayed 750) [ 410.910456] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=0 [ 411.634865] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003) [ 411.679288] random: get_random_u32 called from kobject_release+0x24/0xf8 with crng_init=0 [ 411.680335] kobject: 'virtio0' ((____ptrval____)): kobject_release, parent (null) (delayed 250) [ 411.726615] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003) [ 411.759410] kobject: 'virtio1' ((____ptrval____)): kobject_release, parent (null) (delayed 500) [ 411.806434] virtio-pci 0000:00:03.0: enabling device (0000 -> 0003) [ 411.838711] kobject: 'virtio2' ((____ptrval____)): kobject_release, parent (null) (delayed 500) [ 419.067539] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 419.287585] _warn_unseeded_randomness: 5 callbacks suppressed [ 419.287877] random: get_random_u32 called from kobject_release+0x24/0xf8 with crng_init=0 [ 419.289497] kobject: 'ttyS0' ((____ptrval____)): kobject_release, parent (null) (delayed 750) [ 419.291665] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=0 [ 419.294826] random: get_random_u32 called from kobject_release+0x24/0xf8 with crng_init=0 [ 419.295856] kobject: '(null)' ((____ptrval____)): kobject_release, parent (null) (delayed 1000) [ 419.393555] kobject: 'ttyS1' ((____ptrval____)): kobject_release, parent (null) (delayed 1000) [ 419.396339] kobject: '(null)' ((____ptrval____)): kobject_release, parent (null) (delayed 1000) [ 419.489480] kobject: 'ttyS2' ((____ptrval____)): kobject_release, parent (null) (delayed 500) [ 419.492303] kobject: '(null)' ((____ptrval____)): kobject_release, parent (null) (delayed 250) [ 419.581407] kobject: 'ttyS3' ((____ptrval____)): kobject_release, parent (null) (delayed 250) [ 419.584100] kobject: '(null)' ((____ptrval____)): kobject_release, parent (null) (delayed 250) [ 419.712233] cacheinfo: Unable to detect cache hierarchy for CPU 0 [ 419.729475] KGDB: Registered I/O driver kgdbts [ 419.731461] kgdbts:RUN plant and detach test Entering kdb (current=0xffffffc03f558040, pid 1) on processor 0 due to Keyboard Entry [0]kdb> [ 419.743268] kgdbts:RUN sw breakpoint test [ 419.761009] kgdbts:RUN bad memory access test [ 419.764873] kgdbts:RUN singlestep test 1000 iterations [ 419.799859] kgdbts:RUN singlestep [0/1000]