[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034] [ 0.000000] Linux version 4.20.0-rc3-next-20181122-00007-g64e3bffc54df-dirty (anders@compilator) (gcc version 7.3.1 20180425 [linaro-7.3-2018.05 revision d29120a424ecfbc167ef90065c0eeb7f91977701] (Linaro GCC 7.3-2018.05)) #43 SMP Mon Nov 26 13:30:21 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] NUMA: No NUMA configuration found [ 0.000000] NUMA: Faking a node at [mem 0x0000000040000000-0x00000000bfffffff] [ 0.000000] NUMA: NODE_DATA [mem 0xbefea5c0-0xbefebfff] [ 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+0xa8/0x498 with crng_init=0 [ 0.000000] percpu: Embedded 490 pages/cpu @(____ptrval____) s1967960 r8192 d30888 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 [ 0.000000] Memory: 997132K/2097152K available (16008K kernel code, 3358K rwdata, 4656K rodata, 4096K init, 21766K bss, 86396K 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 41424 entries in 162 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 lockdep checking is enabled. [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=1. [ 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] kmemleak: Kernel memory leak detector disabled [ 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.000183] sched_clock: 56 bits at 62MHz, resolution 16ns, wraps every 4398046511096ns [ 0.012965] Console: colour dummy device 80x25 [ 0.014053] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar [ 0.014494] ... MAX_LOCKDEP_SUBCLASSES: 8 [ 0.014803] ... MAX_LOCK_DEPTH: 48 [ 0.015116] ... MAX_LOCKDEP_KEYS: 8191 [ 0.015428] ... CLASSHASH_SIZE: 4096 [ 0.015750] ... MAX_LOCKDEP_ENTRIES: 32768 [ 0.016102] ... MAX_LOCKDEP_CHAINS: 65536 [ 0.016784] ... CHAINHASH_SIZE: 32768 [ 0.017179] memory used by lock dependency info: 7775 kB [ 0.017568] per task-struct memory footprint: 2688 bytes [ 0.018006] ------------------------ [ 0.018354] | Locking API testsuite: [ 0.018713] ---------------------------------------------------------------------------- [ 0.019145] | spin |wlock |rlock |mutex | wsem | rsem | [ 0.019525] -------------------------------------------------------------------------- [ 0.020253] A-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.031490] A-B-B-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.042539] A-B-B-C-C-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.054623] A-B-C-A-B-C deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.066784] A-B-B-C-C-D-D-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.079730] A-B-C-D-B-D-D-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.092435] A-B-C-D-B-C-D-A deadlock: ok | ok | ok | ok | ok | ok | ok | [ 0.105351] double unlock: ok | ok | ok | ok | ok | ok | ok | [ 0.115285] initialize held: ok | ok | ok | ok | ok | ok | ok | [ 0.124986] -------------------------------------------------------------------------- [ 0.125363] recursive read-lock: | ok | | ok | [ 0.128942] recursive read-lock #2: | ok | | ok | [ 0.132075] mixed read-write-lock: | ok | | ok | [ 0.135757] mixed write-read-lock: | ok | | ok | [ 0.139446] mixed read-lock/lock-write ABBA: |FAILED| | ok | [ 0.142867] mixed read-lock/lock-read ABBA: | ok | | ok | [ 0.146227] mixed write-lock/lock-write ABBA: | ok | | ok | [ 0.149926] -------------------------------------------------------------------------- [ 0.150666] hard-irqs-on + irq-safe-A/12: ok | ok | ok | [ 0.155941] soft-irqs-on + irq-safe-A/12: ok | ok | ok | [ 0.161020] hard-irqs-on + irq-safe-A/21: ok | ok | ok | [ 0.165949] soft-irqs-on + irq-safe-A/21: ok | ok | ok | [ 0.170819] sirq-safe-A => hirqs-on/12: ok | ok | ok | [ 0.175899] sirq-safe-A => hirqs-on/21: ok | ok | ok | [ 0.180810] hard-safe-A + irqs-on/12: ok | ok | ok | [ 0.185741] soft-safe-A + irqs-on/12: ok | ok | ok | [ 0.190810] hard-safe-A + irqs-on/21: ok | ok | ok | [ 0.195786] soft-safe-A + irqs-on/21: ok | ok | ok | [ 0.200866] hard-safe-A + unsafe-B #1/123: ok | ok | ok | [ 0.206707] soft-safe-A + unsafe-B #1/123: ok | ok | ok | [ 0.212082] hard-safe-A + unsafe-B #1/132: ok | ok | ok | [ 0.217188] soft-safe-A + unsafe-B #1/132: ok | ok | ok | [ 0.222658] hard-safe-A + unsafe-B #1/213: ok | ok | ok | [ 0.227864] soft-safe-A + unsafe-B #1/213: ok | ok | ok | [ 0.233068] hard-safe-A + unsafe-B #1/231: ok | ok | ok | [ 0.238235] soft-safe-A + unsafe-B #1/231: ok | ok | ok | [ 0.243467] hard-safe-A + unsafe-B #1/312: ok | ok | ok | [ 0.248381] soft-safe-A + unsafe-B #1/312: ok | ok | ok | [ 0.253359] hard-safe-A + unsafe-B #1/321: ok | ok | ok | [ 0.258831] soft-safe-A + unsafe-B #1/321: ok | ok | ok | [ 0.264072] hard-safe-A + unsafe-B #2/123: ok | ok | ok | [ 0.269747] soft-safe-A + unsafe-B #2/123: ok | ok | ok | [ 0.275096] hard-safe-A + unsafe-B #2/132: ok | ok | ok | [ 0.280392] soft-safe-A + unsafe-B #2/132: ok | ok | ok | [ 0.285745] hard-safe-A + unsafe-B #2/213: ok | ok | ok | [ 0.291136] soft-safe-A + unsafe-B #2/213: ok | ok | ok | [ 0.296606] hard-safe-A + unsafe-B #2/231: ok | ok | ok | [ 0.301829] soft-safe-A + unsafe-B #2/231: ok | ok | ok | [ 0.307088] hard-safe-A + unsafe-B #2/312: ok | ok | ok | [ 0.312265] soft-safe-A + unsafe-B #2/312: ok | ok | ok | [ 0.317578] hard-safe-A + unsafe-B #2/321: ok | ok | ok | [ 0.322750] soft-safe-A + unsafe-B #2/321: ok | ok | ok | [ 0.327937] hard-irq lock-inversion/123: ok | ok | ok | [ 0.333156] soft-irq lock-inversion/123: ok | ok | ok | [ 0.338543] hard-irq lock-inversion/132: ok | ok | ok | [ 0.343773] soft-irq lock-inversion/132: ok | ok | ok | [ 0.349022] hard-irq lock-inversion/213: ok | ok | ok | [ 0.354294] soft-irq lock-inversion/213: ok | ok | ok | [ 0.359515] hard-irq lock-inversion/231: ok | ok | ok | [ 0.364674] soft-irq lock-inversion/231: ok | ok | ok | [ 0.369992] hard-irq lock-inversion/312: ok | ok | ok | [ 0.375229] soft-irq lock-inversion/312: ok | ok | ok | [ 0.380563] hard-irq lock-inversion/321: ok | ok | ok | [ 0.385787] soft-irq lock-inversion/321: ok | ok | ok | [ 0.391099] hard-irq read-recursion/123: ok | [ 0.393373] soft-irq read-recursion/123: ok | [ 0.395435] hard-irq read-recursion/132: ok | [ 0.397777] soft-irq read-recursion/132: ok | [ 0.399841] hard-irq read-recursion/213: ok | [ 0.402141] soft-irq read-recursion/213: ok | [ 0.404117] hard-irq read-recursion/231: ok | [ 0.406444] soft-irq read-recursion/231: ok | [ 0.408416] hard-irq read-recursion/312: ok | [ 0.410724] soft-irq read-recursion/312: ok | [ 0.412683] hard-irq read-recursion/321: ok | [ 0.415014] soft-irq read-recursion/321: ok | [ 0.417073] -------------------------------------------------------------------------- [ 0.417448] | Wound/wait tests | [ 0.417782] --------------------- [ 0.418094] ww api failures: ok | ok | ok | [ 0.424975] ww contexts mixing: ok | ok | [ 0.428487] finishing ww context: ok | ok | ok | ok | [ 0.435041] locking mismatches: ok | ok | ok | [ 0.440002] EDEADLK handling: ok | ok | ok | ok | ok | ok | ok | ok | ok | ok | [ 0.457039] spinlock nest unlocked: ok | [ 0.458809] ----------------------------------------------------- [ 0.459144] |block | try |context| [ 0.459497] ----------------------------------------------------- [ 0.459831] context: ok | ok | ok | [ 0.465037] try: ok | ok | ok | [ 0.469899] block: ok | ok | ok | [ 0.474700] spinlock: ok | ok | ok | [ 0.479903] ------------------------------------------------------- [ 0.480260] Good, all 261 testcases passed! | [ 0.480976] --------------------------------- [ 0.485771] Calibrating delay loop (skipped), value calculated using timer frequency.. 125.00 BogoMIPS (lpj=250000) [ 0.486502] pid_max: default: 32768 minimum: 301 [ 0.496790] LSM: Security Framework initializing [ 0.497471] Yama: becoming mindful. [ 0.500163] LoadPin: ready to pin (currently enforcing) [ 0.500944] AppArmor: AppArmor disabled by boot time parameter [ 0.526561] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes) [ 0.536061] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes) [ 0.538932] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes) [ 0.539902] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes) [ 0.573213] *** VALIDATE proc *** [ 0.590983] *** VALIDATE cgroup1 *** [ 0.591421] *** VALIDATE cgroup2 *** [ 0.652442] ASID allocator initialised with 32768 entries [ 0.659188] rcu: Hierarchical SRCU implementation. [ 0.722578] EFI services will not be available. [ 0.745443] smp: Bringing up secondary CPUs ... [ 0.745936] smp: Brought up 1 node, 1 CPU [ 0.746278] SMP: Total of 1 processors activated. [ 0.746758] CPU features: detected: 32-bit EL0 Support [ 0.747199] CPU features: detected: CRC32 instructions [ 1.026076] CPU features: emulated: Privileged Access Never (PAN) using TTBR0_EL1 switching [ 1.026896] CPU: All CPU(s) started at EL1 [ 1.028302] alternatives: patching kernel code [ 1.503718] node 0 initialised, 249310 pages in 4ms [ 1.511192] pgdatinit0 (15) used greatest stack depth: 13408 bytes left [ 1.591674] devtmpfs: initialized [ 1.799933] _warn_unseeded_randomness: 81 callbacks suppressed [ 1.800338] random: get_random_u32 called from bucket_table_alloc+0x130/0x1a8 with crng_init=0 [ 1.802145] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 1.802883] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 1.814361] Registered cp15_barrier emulation handler [ 2.467084] workqueue: round-robin CPU selection forced, expect performance impact [ 8.123736] DMA-API: preallocated 65536 debug entries [ 8.124144] DMA-API: debugging enabled by kernel config [ 8.124592] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns [ 8.126197] futex hash table entries: 256 (order: 3, 32768 bytes) [ 8.128782] Running postponed tracer tests: [ 8.134014] Testing tracer function: PASSED [ 25.978870] Testing dynamic ftrace: PASSED [ 27.179806] Testing dynamic ftrace ops #1: [ 30.843476] (1 0 1 0 0) [ 30.843996] (1 1 2 0 0) [ 46.994695] (2 1 3 0 945662) [ 46.998740] (2 2 4 0 946013) [ 49.820836] watchdog: BUG: soft lockup - CPU#0 stuck for 21s! [swapper/0:1] [ 49.822724] Modules linked in: [ 49.823631] irq event stamp: 547580 [ 49.824585] hardirqs last enabled at (547579): [] _raw_spin_unlock_irqrestore+0x50/0x98 [ 49.826145] hardirqs last disabled at (547580): [] el1_irq+0xa8/0x1c0 [ 49.827466] softirqs last enabled at (547540): [] __do_softirq+0x988/0x9d0 [ 49.828847] softirqs last disabled at (547533): [] irq_exit+0x128/0x1b8 [ 49.830392] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 4.20.0-rc3-next-20181122-00007-g64e3bffc54df-dirty #43 [ 49.831812] Hardware name: linux,dummy-virt (DT) [ 49.832892] pstate: 20400005 (nzCv daif +PAN -UAO) [ 49.833906] pc : _raw_spin_unlock_irqrestore+0x54/0x98 [ 49.834959] lr : _raw_spin_unlock_irqrestore+0x50/0x98 [ 49.835814] sp : ffffff800804b840 [ 49.836516] x29: ffffff800804b840 x28: ffffffc0795b8080 [ 49.837609] x27: 0000000000000001 x26: 0000000000000242 [ 49.838596] x25: ffffff8009a9a608 x24: 0000000000000001 [ 49.839560] x23: 0000000097f28edb x22: ffffff80083e6c5c [ 49.840519] x21: ffffff8008e00038 x20: ffffff8009a251f0 [ 49.841477] x19: 0000000000000000 x18: 0000000034f4d91d [ 49.842444] x17: 000000000000002a x16: 0000000000000000 [ 49.843402] x15: 0000000000001353 x14: ffffff8009a61628 [ 49.844362] x13: ffffff8009aebca8 x12: ffffff800a444030 [ 49.845323] x11: ffffff800804bb20 x10: ffffff800804bb20 [ 49.846316] x9 : ffffff8009a25208 x8 : ffffff8009d52398 [ 49.847278] x7 : ffffff8008e0000c x6 : ffffffbefe7fec60 [ 49.848235] x5 : 00000000ae1d16cd x4 : 00000000b6044d77 [ 49.849192] x3 : fffffffffffffe80 x2 : ffffff800a4423b0 [ 49.850155] x1 : 000000000000001a x0 : 0000000000041c86 [ 49.851209] Call trace: [ 49.851896] _raw_spin_unlock_irqrestore+0x54/0x98 [ 49.852768] __aarch64_insn_write+0x60/0x78 [ 49.853552] aarch64_insn_write+0x24/0x30 [ 49.854331] aarch64_insn_patch_text_nosync+0x30/0x68 [ 49.855197] ftrace_modify_code+0x50/0xc8 [ 49.856005] ftrace_make_nop+0x1e0/0x230 [ 49.856794] __ftrace_replace_code+0xb8/0xf0 [ 49.857590] ftrace_replace_code+0x7c/0x128 [ 49.858388] ftrace_modify_all_code+0x54/0x148 [ 49.859194] arch_ftrace_update_code+0x1c/0x28 [ 49.860001] ftrace_run_update_code+0x54/0x60 [ 49.860803] ftrace_shutdown+0x174/0x368 [ 49.861570] unregister_ftrace_function+0x38/0x58 [ 49.862409] trace_selftest_ops+0x2c8/0x3bc [ 49.863214] trace_selftest_startup_dynamic_tracing.constprop.4+0x16c/0x1e4 [ 49.864277] trace_selftest_startup_function+0x144/0x1b4 [ 49.865170] run_tracer_selftest+0x180/0x260 [ 49.865963] init_trace_selftests+0xa8/0x188 [ 49.866757] do_one_initcall+0x31c/0x6c8 [ 49.867525] do_initcall_level+0x4ac/0x50c [ 49.868303] do_initcalls+0x28/0x40 [ 49.869025] do_basic_setup+0x34/0x3c [ 49.869765] kernel_init_freeable+0x12c/0x1d4 [ 49.870569] kernel_init+0x28/0x140 [ 49.871286] ret_from_fork+0x10/0x18 [ 56.572742] PASSED [ 56.573134] Testing dynamic ftrace ops #2: [ 75.220172] (1 0 1 914672 0) [ 75.221749] (1 1 2 914802 0) [ 75.315018] (2 1 3 1 3618) [ 75.318704] (2 2 4 359 3976) [ 79.400702] watchdog: BUG: soft lockup - CPU#0 stuck for 21s! [swapper/0:1] [ 79.401662] Modules linked in: [ 79.402079] irq event stamp: 795516 [ 79.402593] hardirqs last enabled at (795515): [] _raw_spin_unlock_irqrestore+0x50/0x98 [ 79.403280] hardirqs last disabled at (795516): [] el1_irq+0xa8/0x1c0 [ 79.403895] softirqs last enabled at (795464): [] __do_softirq+0x988/0x9d0 [ 79.404540] softirqs last disabled at (795457): [] irq_exit+0x128/0x1b8 [ 79.405272] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G L 4.20.0-rc3-next-20181122-00007-g64e3bffc54df-dirty #43 [ 79.405983] Hardware name: linux,dummy-virt (DT) [ 79.406465] pstate: 20400005 (nzCv daif +PAN -UAO) [ 79.406937] pc : _raw_spin_unlock_irqrestore+0x54/0x98 [ 79.407419] lr : _raw_spin_unlock_irqrestore+0x50/0x98 [ 79.407858] sp : ffffff800804b840 [ 79.408225] x29: ffffff800804b840 x28: ffffffc0795b8080 [ 79.408760] x27: 0000000000000002 x26: 0000000000002250 [ 79.409289] x25: ffffff8009a9a608 x24: 0000000000000001 [ 79.409819] x23: 0000000097e247dd x22: ffffff80087f8854 [ 79.410354] x21: ffffff8008e00038 x20: ffffff8009a251f0 [ 79.410880] x19: 0000000000000000 x18: 0000000034f4d91d [ 79.411410] x17: 000000000000002a x16: 0000000000000000 [ 79.411939] x15: 0000000000001392 x14: ffffff8009a61628 [ 79.412472] x13: ffffff8009aece70 x12: 0000000000000002 [ 79.413001] x11: 0000000000000000 x10: ffffff800804bb20 [ 79.413531] x9 : ffffff8009a25208 x8 : ffffff8009d52398 [ 79.414062] x7 : ffffff8008e0000c x6 : ffffffbefe7fe858 [ 79.414591] x5 : 00000000ae1d16cd x4 : 00000000b6044d77 [ 79.415117] x3 : fffffffffffffe80 x2 : ffffff800a4423b0 [ 79.415643] x1 : 000000000000001a x0 : 000000000005e976 [ 79.416176] Call trace: [ 79.416579] _raw_spin_unlock_irqrestore+0x54/0x98 [ 79.417050] __aarch64_insn_write+0x60/0x78 [ 79.417492] aarch64_insn_write+0x24/0x30 [ 79.417931] aarch64_insn_patch_text_nosync+0x30/0x68 [ 79.418419] ftrace_modify_code+0x50/0xc8 [ 79.418853] ftrace_make_nop+0x1e0/0x230 [ 79.419295] __ftrace_replace_code+0xb8/0xf0 [ 79.419744] ftrace_replace_code+0x7c/0x128 [ 79.420200] ftrace_modify_all_code+0x54/0x148 [ 79.420655] arch_ftrace_update_code+0x1c/0x28 [ 79.421120] ftrace_run_update_code+0x54/0x60 [ 79.421576] ftrace_shutdown+0x174/0x368 [ 79.422021] unregister_ftrace_function+0x38/0x58 [ 79.422487] trace_selftest_ops+0x308/0x3bc [ 79.422948] trace_selftest_startup_dynamic_tracing.constprop.4+0x1a8/0x1e4 [ 79.423509] trace_selftest_startup_function+0x144/0x1b4 [ 79.424010] run_tracer_selftest+0x180/0x260 [ 79.424479] init_trace_selftests+0xa8/0x188 [ 79.424950] do_one_initcall+0x31c/0x6c8 [ 79.425409] do_initcall_level+0x4ac/0x50c [ 79.425874] do_initcalls+0x28/0x40 [ 79.426309] do_basic_setup+0x34/0x3c [ 79.426756] kernel_init_freeable+0x12c/0x1d4 [ 79.427230] kernel_init+0x28/0x140 [ 79.427660] ret_from_fork+0x10/0x18 [ 83.196610] PASSED [ 83.196981] Testing ftrace recursion: PASSED [ 84.227318] Testing ftrace recursion safe: PASSED [ 85.256552] Testing ftrace regs(no arch support): PASSED [ 86.295298] Testing tracer nop: PASSED [ 86.296192] Testing tracer irqsoff: PASSED [ 104.465533] Testing tracer function_graph: [ 111.583317] watchdog: BUG: soft lockup - CPU#0 stuck for 23s! [swapper/0:1] [ 111.584573] Modules linked in: [ 111.585165] irq event stamp: 1135776 [ 111.585914] hardirqs last enabled at (1135775): [] _raw_spin_unlock_irqrestore+0x50/0x98 [ 111.586880] hardirqs last disabled at (1135776): [] el1_irq+0xa8/0x1c0 [ 111.587730] softirqs last enabled at (1135734): [] __do_softirq+0x988/0x9d0 [ 111.588604] softirqs last disabled at (1135727): [] irq_exit+0x128/0x1b8 [ 111.589470] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G L 4.20.0-rc3-next-20181122-00007-g64e3bffc54df-dirty #43 [ 111.590341] Hardware name: linux,dummy-virt (DT) [ 111.590984] pstate: 20400005 (nzCv daif +PAN -UAO) [ 111.591658] pc : _raw_spin_unlock_irqrestore+0x54/0x98 [ 111.592345] lr : _raw_spin_unlock_irqrestore+0x50/0x98 [ 111.592939] sp : ffffff800804b8f0 [ 111.593439] x29: ffffff800804b8f0 x28: 0000000000000000 [ 111.594185] x27: ffffff8009489000 x26: ffffff800a9da598 [ 111.594931] x25: ffffff8009a9a608 x24: 0000000000000001 [ 111.595666] x23: 00000000d503201f x22: ffffff8008abea90 [ 111.596405] x21: ffffff8008e00038 x20: ffffff8009a251f0 [ 111.597141] x19: 0000000000000000 x18: 0000000034f4d91d [ 111.597883] x17: 000000000000002a x16: 0000000000000000 [ 111.598625] x15: 00000000000013c0 x14: ffffff8009a61628 [ 111.599380] x13: ffffff8009aece70 x12: 0000000000000001 [ 111.600122] x11: 0000000000000000 x10: 0000000000008008 [ 111.600858] x9 : ffffff8009a25208 x8 : ffffff8009d52398 [ 111.601593] x7 : ffffff8008e0000c x6 : ffffff8009a9d200 [ 111.602334] x5 : 0000000000000000 x4 : 00000000b6044d77 [ 111.603071] x3 : fffffffffffffe80 x2 : ffffff800a4423b0 [ 111.603813] x1 : 000000000000001a x0 : 00000000000866ec [ 111.604569] Call trace: [ 111.605170] _raw_spin_unlock_irqrestore+0x54/0x98 [ 111.605848] __aarch64_insn_write+0x60/0x78 [ 111.606507] aarch64_insn_write+0x24/0x30 [ 111.607164] aarch64_insn_patch_text_nosync+0x30/0x68 [ 111.607858] ftrace_modify_code+0x50/0xc8 [ 111.608503] ftrace_make_call+0x16c/0x248 [ 111.609150] __ftrace_replace_code+0x94/0xf0 [ 111.609808] ftrace_replace_code+0x7c/0x128 [ 111.610465] ftrace_modify_all_code+0x54/0x148 [ 111.611133] arch_ftrace_update_code+0x1c/0x28 [ 111.611798] ftrace_run_update_code+0x54/0x60 [ 111.612460] ftrace_startup_enable+0x6c/0x80 [ 111.613129] ftrace_startup+0x124/0x158 [ 111.613772] register_ftrace_graph+0x104/0x140 [ 111.614443] trace_selftest_startup_function_graph+0xa8/0x194 [ 111.615164] run_tracer_selftest+0x180/0x260 [ 111.615812] register_tracer+0x180/0x268 [ 111.616436] init_graph_trace+0x84/0x9c [ 111.617057] do_one_initcall+0x31c/0x6c8 [ 111.617698] do_initcall_level+0x4ac/0x50c [ 111.618346] do_initcalls+0x28/0x40 [ 111.618966] do_basic_setup+0x34/0x3c [ 111.619595] kernel_init_freeable+0x12c/0x1d4 [ 111.620253] kernel_init+0x28/0x140 [ 111.620872] ret_from_fork+0x10/0x18 [ 123.094653] PASSED [ 123.105222] _warn_unseeded_randomness: 2 callbacks suppressed [ 123.105465] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 123.106520] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 123.107626] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 123.117837] prandom: seed boundary self test passed [ 123.142618] prandom: 100 self tests passed [ 123.146989] pinctrl core: initialized pinctrl subsystem [ 123.218441] regulator-dummy: Failed to create debugfs directory [ 123.225093] [ 123.225424] ************************************************************* [ 123.225825] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 123.226251] ** ** [ 123.226635] ** IOMMU DebugFS SUPPORT HAS BEEN ENABLED IN THIS KERNEL ** [ 123.227022] ** ** [ 123.227404] ** This means that this kernel is built to expose internal ** [ 123.228171] ** IOMMU data structures, which may compromise security on ** [ 123.228624] ** your system. ** [ 123.228990] ** ** [ 123.229371] ** If you see this message and you are not debugging the ** [ 123.229741] ** kernel, report this immediately to your vendor! ** [ 123.230128] ** ** [ 123.230511] ** NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE NOTICE ** [ 123.230884] ************************************************************* [ 123.248835] DMI not present or invalid. [ 123.280652] NET: Registered protocol family 16 [ 123.301836] audit: initializing netlink subsys (disabled) [ 123.400413] cpuidle: using governor ladder [ 123.401117] cpuidle: using governor menu [ 123.413287] vdso: 2 pages (1 code @ (____ptrval____), 1 data @ (____ptrval____)) [ 123.414072] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers. [ 123.417897] audit: type=2000 audit(102.572:1): state=initialized audit_enabled=0 res=1 [ 123.479301] DMA: preallocated 256 KiB pool for atomic allocations [ 123.531407] Serial: AMBA PL011 UART driver [ 124.122261] 9000000.pl011: ttyAMA0 at MMIO 0x9000000 (irq = 39, base_baud = 0) is a PL011 rev1 [ 124.125161] printk: console [ttyAMA0] enabled [ 124.125161] printk: console [ttyAMA0] enabled [ 124.126116] printk: bootconsole [pl11] disabled [ 124.126116] printk: bootconsole [pl11] disabled [ 124.209870] _warn_unseeded_randomness: 39 callbacks suppressed [ 124.210053] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 124.211277] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 124.631566] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 124.666417] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages [ 124.807442] arm-v7s io-pgtable: self test ok [ 124.808543] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 32 [ 124.814504] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 36 [ 124.818035] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 40 [ 124.821973] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 42 [ 124.826138] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 44 [ 124.829917] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x40201000, IAS 48 [ 124.833419] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 32 [ 124.839520] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 36 [ 124.845692] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 40 [ 124.852391] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 42 [ 124.858732] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 44 [ 124.865607] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x02004000, IAS 48 [ 124.873213] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 32 [ 124.889940] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 36 [ 124.906719] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 40 [ 124.924009] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 42 [ 124.942845] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 44 [ 124.962413] arm-lpae io-pgtable: selftest: pgsize_bitmap 0x20010000, IAS 48 [ 124.981384] arm-lpae io-pgtable: selftest: completed with 18 PASS 0 FAIL [ 125.003997] vgaarb: loaded [ 125.044837] pps_core: LinuxPPS API ver. 1 registered [ 125.045363] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti [ 125.048256] PTP clock support registered [ 125.166853] NetLabel: Initializing [ 125.167350] NetLabel: domain hash size = 128 [ 125.168294] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO [ 125.175442] NetLabel: unlabeled traffic allowed by default [ 125.188850] clocksource: Switched to clocksource arch_sys_counter [ 127.803509] _warn_unseeded_randomness: 39 callbacks suppressed [ 127.803734] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 127.805601] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 127.807126] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 127.816764] VFS: Disk quotas dquot_6.6.0 [ 127.820327] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes) [ 127.829939] *** VALIDATE hugetlbfs *** [ 128.452084] NET: Registered protocol family 2 [ 128.484927] tcp_listen_portaddr_hash hash table entries: 1024 (order: 4, 90112 bytes) [ 128.488802] TCP established hash table entries: 16384 (order: 5, 131072 bytes) [ 128.503283] TCP bind hash table entries: 16384 (order: 8, 1310720 bytes) [ 128.512340] TCP: Hash tables configured (established 16384 bind 16384) [ 128.518626] UDP hash table entries: 1024 (order: 5, 196608 bytes) [ 128.522779] UDP-Lite hash table entries: 1024 (order: 5, 196608 bytes) [ 128.533243] NET: Registered protocol family 1 [ 128.601808] hw perfevents: enabled with armv8_pmuv3 PMU driver, 1 counters available [ 128.607633] kvm [1]: HYP mode not available [ 128.631706] kworker/u2:1 (34) used greatest stack depth: 11920 bytes left [ 128.807127] Initialise system trusted keyrings [ 128.809014] _warn_unseeded_randomness: 56 callbacks suppressed [ 128.809186] random: get_random_bytes called from key_alloc+0x380/0x698 with crng_init=0 [ 128.813576] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=0 [ 128.821799] workingset: timestamp_bits=44 max_order=19 bucket_order=0 [ 130.227655] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 130.228987] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 130.244718] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 130.395283] 9p: Installing v9fs 9p2000 file system support [ 131.074502] Key type asymmetric registered [ 131.075539] Asymmetric key parser 'x509' registered [ 131.081724] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 245) [ 131.476608] pl061_gpio 9030000.pl061: PL061 GPIO chip @0x0000000009030000 registered [ 131.482042] pl061_gpio 9030000.pl061: Unbalanced pm_runtime_enable! [ 131.501527] pl061_gpio 9030000.pl061: PL061 GPIO chip @0x0000000009030000 registered [ 131.547006] shpchp: Standard Hot Plug PCI Controller Driver version: 0.4 [ 131.596475] pci-host-generic 3f000000.pcie: host bridge /pcie@10000000 ranges: [ 131.598437] pci-host-generic 3f000000.pcie: IO 0x3eff0000..0x3effffff -> 0x00000000 [ 131.600869] pci-host-generic 3f000000.pcie: MEM 0x10000000..0x3efeffff -> 0x10000000 [ 131.601988] pci-host-generic 3f000000.pcie: MEM 0x8000000000..0xffffffffff -> 0x8000000000 [ 131.605591] pci-host-generic 3f000000.pcie: ECAM at [mem 0x3f000000-0x3fffffff] for [bus 00-0f] [ 131.618475] pci-host-generic 3f000000.pcie: PCI host bridge to bus 0000:00 [ 131.619483] pci_bus 0000:00: root bus resource [bus 00-0f] [ 131.620850] pci_bus 0000:00: root bus resource [io 0x0000-0xffff] [ 131.621565] pci_bus 0000:00: root bus resource [mem 0x10000000-0x3efeffff] [ 131.622255] pci_bus 0000:00: root bus resource [mem 0x8000000000-0xffffffffff] [ 131.684519] pci 0000:00:01.0: BAR 6: assigned [mem 0x10000000-0x1003ffff pref] [ 131.685505] pci 0000:00:01.0: BAR 4: assigned [mem 0x8000000000-0x8000003fff 64bit pref] [ 131.686717] pci 0000:00:02.0: BAR 4: assigned [mem 0x8000004000-0x8000007fff 64bit pref] [ 131.687638] pci 0000:00:01.0: BAR 1: assigned [mem 0x10040000-0x10040fff] [ 131.688909] pci 0000:00:02.0: BAR 1: assigned [mem 0x10041000-0x10041fff] [ 131.689596] pci 0000:00:02.0: BAR 0: assigned [io 0x1000-0x103f] [ 131.690306] pci 0000:00:01.0: BAR 0: assigned [io 0x1040-0x105f] [ 132.123310] virtio-pci 0000:00:01.0: enabling device (0000 -> 0003) [ 132.180695] virtio-pci 0000:00:02.0: enabling device (0000 -> 0003) [ 135.993622] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled [ 136.293961] SuperH (H)SCI(F) driver initialized [ 136.369810] cacheinfo: Unable to detect cache hierarchy for CPU 0 [ 136.431381] libphy: Fixed MDIO Bus: probed [ 136.550748] _warn_unseeded_randomness: 38 callbacks suppressed [ 136.550942] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=0 [ 136.843416] ledtrig-cpu: registered to indicate activity on CPUs [ 136.868916] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 136.869801] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 136.911390] ashmem: initialized [ 137.067113] 9pnet: Installing 9P2000 support [ 137.325266] registered taskstats version 1 [ 137.325836] Running tests on trace events: [ 137.326374] Testing event initcall_finish: OK [ 137.357323] Testing event initcall_start: OK [ 137.382634] Testing event initcall_level: OK [ 137.410863] Testing event sys_exit: OK [ 137.437529] Testing event sys_enter: OK [ 137.463145] Testing event ipi_exit: OK [ 137.489309] Testing event ipi_entry: OK [ 137.515461] Testing event ipi_raise: OK [ 137.542449] Testing event instruction_emulation: OK [ 137.566664] Testing event kvm_halt_poll_ns: OK [ 137.593597] Testing event kvm_age_page: OK [ 137.619293] Testing event kvm_fpu: OK [ 137.645044] Testing event kvm_mmio: OK [ 137.671038] Testing event kvm_ack_irq: OK [ 137.697440] Testing event kvm_set_irq: OK [ 137.723442] Testing event kvm_vcpu_wakeup: OK [ 137.750617] Testing event kvm_userspace_exit: OK [ 137.774464] Testing event kvm_timer_update_irq: OK [ 137.798537] Testing event kvm_toggle_cache: OK [ 137.825496] Testing event kvm_set_way_flush: OK [ 137.851339] Testing event kvm_test_age_hva: OK [ 137.878649] Testing event kvm_age_hva: OK [ 137.902508] Testing event kvm_set_spte_hva: OK [ 137.926902] Testing event kvm_unmap_hva_range: OK [ 137.954879] Testing event kvm_mmio_emulate: OK [ 137.978349] Testing event kvm_irq_line: OK [ 138.002530] Testing event kvm_access_fault: OK [ 138.029503] Testing event kvm_guest_fault: OK [ 138.055357] Testing event kvm_exit: OK [ 138.082461] Testing event kvm_entry: OK [ 138.109456] Testing event kvm_set_guest_debug: OK [ 138.135342] Testing event kvm_handle_sys_reg: OK [ 138.160670] Testing event trap_reg: OK [ 138.189077] Testing event kvm_arm_set_regset: OK [ 138.214828] Testing event kvm_arm_set_dreg32: OK [ 138.242621] Testing event kvm_arm_clear_debug: OK [ 138.269366] Testing event kvm_arm_setup_debug: OK [ 138.294528] Testing event kvm_hvc_arm64: OK [ 138.322158] Testing event kvm_wfx_arm64: OK [ 138.349549] Testing event vgic_update_irq_pending: OK [ 138.374685] Testing event task_rename: OK [ 138.402004] Testing event task_newtask: OK [ 138.429674] Testing event cpuhp_exit: OK [ 138.457599] Testing event cpuhp_multi_enter: OK [ 138.483684] Testing event cpuhp_enter: OK [ 138.510555] Testing event softirq_raise: OK [ 138.537164] Testing event softirq_exit: OK [ 138.562515] Testing event softirq_entry: OK [ 138.590313] Testing event irq_handler_exit: OK [ 138.617478] Testing event irq_handler_entry: OK [ 138.642803] Testing event signal_deliver: OK [ 138.669719] Testing event signal_generate: OK [ 138.698957] Testing event workqueue_execute_end: OK [ 138.727173] Testing event workqueue_execute_start: OK [ 138.754862] Testing event workqueue_activate_work: OK [ 138.781524] Testing event workqueue_queue_work: OK [ 138.807509] Testing event sched_wake_idle_without_ipi: OK [ 138.835338] Testing event sched_swap_numa: OK [ 138.861399] Testing event sched_stick_numa: OK [ 138.887637] Testing event sched_move_numa: OK [ 138.914483] Testing event sched_process_hang: OK [ 138.938481] Testing event sched_pi_setprio: OK [ 138.962519] Testing event sched_stat_runtime: [ 138.965817] Scheduler tracepoints stat_sleep, stat_iowait, stat_blocked and stat_runtime require the kernel parameter schedstats=enable or kernel.sched_schedstats=1 [ 138.994390] OK [ 138.994854] Testing event sched_stat_blocked: OK [ 139.021925] Testing event sched_stat_iowait: OK [ 139.049523] Testing event sched_stat_sleep: OK [ 139.074843] Testing event sched_stat_wait: OK [ 139.102280] Testing event sched_process_exec: OK [ 139.127160] Testing event sched_process_fork: OK [ 139.153582] Testing event sched_process_wait: OK [ 139.178253] Testing event sched_wait_task: OK [ 139.202874] Testing event sched_process_exit: OK [ 139.230053] Testing event sched_process_free: OK [ 139.254923] Testing event sched_migrate_task: OK [ 139.281473] Testing event sched_switch: OK [ 139.307327] Testing event sched_wakeup_new: OK [ 139.334673] Testing event sched_wakeup: OK [ 139.361130] Testing event sched_waking: OK [ 139.388833] Testing event sched_kthread_stop_ret: OK [ 139.414694] Testing event sched_kthread_stop: OK [ 139.441282] Testing event lock_acquired: OK [ 139.474720] Testing event lock_contended: OK [ 139.498573] Testing event lock_release: OK [ 139.537201] Testing event lock_acquire: OK [ 139.574530] Testing event console: OK [ 139.599694] Testing event rcu_barrier: OK [ 139.626506] Testing event rcu_torture_read: OK [ 139.650576] Testing event rcu_batch_end: OK [ 139.677557] Testing event rcu_invoke_kfree_callback: OK [ 139.703370] Testing event rcu_invoke_callback: OK [ 139.730330] Testing event rcu_batch_start: OK [ 139.754697] Testing event rcu_kfree_callback: OK [ 139.778632] Testing event rcu_callback: OK [ 139.805480] Testing event rcu_dyntick: OK [ 139.835172] Testing event rcu_fqs: OK [ 139.859678] Testing event rcu_quiescent_state_report: OK [ 139.887230] Testing event rcu_unlock_preempted_task: OK [ 139.914368] Testing event rcu_preempt_task: OK [ 139.938779] Testing event rcu_exp_funnel_lock: OK [ 139.962327] Testing event rcu_exp_grace_period: OK [ 139.989589] Testing event rcu_grace_period_init: OK [ 140.015033] Testing event rcu_future_grace_period: OK [ 140.042415] Testing event rcu_grace_period: OK [ 140.074835] Testing event rcu_utilization: OK [ 140.105425] Testing event swiotlb_bounced: OK [ 140.130070] Testing event tick_stop: OK [ 140.154823] Testing event itimer_expire: OK [ 140.181688] Testing event itimer_state: OK [ 140.209935] Testing event hrtimer_cancel: OK [ 140.238709] Testing event hrtimer_expire_exit: OK [ 140.265223] Testing event hrtimer_expire_entry: OK [ 140.290760] Testing event hrtimer_start: OK [ 140.317754] Testing event hrtimer_init: OK [ 140.343030] Testing event timer_cancel: OK [ 140.369550] Testing event timer_expire_exit: OK [ 140.394624] Testing event timer_expire_entry: OK [ 140.418926] Testing event timer_start: OK [ 140.448888] Testing event timer_init: OK [ 140.474258] Testing event alarmtimer_cancel: OK [ 140.498969] Testing event alarmtimer_start: OK [ 140.525676] Testing event alarmtimer_fired: OK [ 140.550924] Testing event alarmtimer_suspend: OK [ 140.577554] Testing event module_request: OK [ 140.603322] Testing event module_put: OK [ 140.630423] Testing event module_get: OK [ 140.657687] Testing event module_free: OK [ 140.685637] Testing event module_load: OK [ 140.711405] Testing event cgroup_transfer_tasks: OK [ 140.737590] Testing event cgroup_attach_task: OK [ 140.763705] Testing event cgroup_rename: OK [ 140.790676] Testing event cgroup_release: OK [ 140.814873] Testing event cgroup_rmdir: OK [ 140.841587] Testing event cgroup_mkdir: OK [ 140.868741] Testing event cgroup_remount: OK [ 140.894663] Testing event cgroup_destroy_root: OK [ 140.918635] Testing event cgroup_setup_root: OK [ 140.942489] Testing event irq_enable: OK [ 140.978760] Testing event irq_disable: OK [ 141.014340] Testing event ftrace_test_filter: OK [ 141.038784] Testing event dev_pm_qos_remove_request: OK [ 141.065926] Testing event dev_pm_qos_update_request: OK [ 141.093861] Testing event dev_pm_qos_add_request: OK [ 141.119564] Testing event pm_qos_update_flags: OK [ 141.146599] Testing event pm_qos_update_target: OK [ 141.170560] Testing event pm_qos_update_request_timeout: OK [ 141.194541] Testing event pm_qos_remove_request: OK [ 141.220941] Testing event pm_qos_update_request: OK [ 141.246976] Testing event pm_qos_add_request: OK [ 141.273487] Testing event power_domain_target: OK [ 141.299145] Testing event clock_set_rate: OK [ 141.325108] Testing event clock_disable: OK [ 141.350365] Testing event clock_enable: OK [ 141.374378] Testing event wakeup_source_deactivate: OK [ 141.398565] Testing event wakeup_source_activate: OK [ 141.422534] Testing event suspend_resume: OK [ 141.461214] Testing event device_pm_callback_end: OK [ 141.487103] Testing event device_pm_callback_start: OK [ 141.515316] Testing event cpu_frequency_limits: OK [ 141.542704] Testing event cpu_frequency: OK [ 141.566677] Testing event pstate_sample: OK [ 141.590419] Testing event powernv_throttle: OK [ 141.616877] Testing event cpu_idle: OK [ 141.643266] Testing event rpm_return_int: OK [ 141.671652] Testing event rpm_idle: OK [ 141.698615] Testing event rpm_resume: OK [ 141.722736] Testing event rpm_suspend: OK [ 141.746592] Testing event benchmark_event: OK [ 141.875049] Testing event xdp_devmap_xmit: OK [ 141.902804] Testing event xdp_cpumap_enqueue: OK [ 141.929172] Testing event xdp_cpumap_kthread: OK [ 141.955541] Testing event xdp_redirect_map_err: OK [ 141.982590] Testing event xdp_redirect_map: OK [ 142.009168] Testing event xdp_redirect_err: OK [ 142.034748] Testing event xdp_redirect: OK [ 142.062506] Testing event xdp_exception: OK [ 142.091061] Testing event rseq_ip_fixup: OK [ 142.117374] Testing event rseq_update: OK [ 142.143540] Testing event file_check_and_advance_wb_err: OK [ 142.170534] Testing event filemap_set_wb_err: OK [ 142.194487] Testing event mm_filemap_add_to_page_cache: OK [ 142.220933] Testing event mm_filemap_delete_from_page_cache: OK [ 142.247364] Testing event compact_retry: OK [ 142.274539] Testing event skip_task_reaping: OK [ 142.298587] Testing event finish_task_reaping: OK [ 142.325569] Testing event start_task_reaping: OK [ 142.351155] Testing event wake_reaper: OK [ 142.377106] Testing event mark_victim: OK [ 142.402667] Testing event reclaim_retry_zone: OK [ 142.426499] Testing event oom_score_adj_update: OK [ 142.450533] Testing event mm_lru_activate: OK [ 142.477208] Testing event mm_lru_insertion: OK [ 142.502589] Testing event mm_vmscan_inactive_list_is_low: OK [ 142.530408] Testing event mm_vmscan_lru_shrink_active: OK [ 142.557267] Testing event mm_vmscan_lru_shrink_inactive: OK [ 142.582605] Testing event mm_vmscan_writepage: OK [ 142.606531] Testing event mm_vmscan_lru_isolate: OK [ 142.630540] Testing event mm_shrink_slab_end: OK [ 142.657526] Testing event mm_shrink_slab_start: OK [ 142.683331] Testing event mm_vmscan_memcg_softlimit_reclaim_end: OK [ 142.710942] Testing event mm_vmscan_memcg_reclaim_end: OK [ 142.737581] Testing event mm_vmscan_direct_reclaim_end: OK [ 142.763153] Testing event mm_vmscan_memcg_softlimit_reclaim_begin: OK [ 142.789305] Testing event mm_vmscan_memcg_reclaim_begin: OK [ 142.814486] Testing event mm_vmscan_direct_reclaim_begin: OK [ 142.838569] Testing event mm_vmscan_wakeup_kswapd: OK [ 142.862604] Testing event mm_vmscan_kswapd_wake: OK [ 142.886556] Testing event mm_vmscan_kswapd_sleep: OK [ 142.912968] Testing event percpu_destroy_chunk: OK [ 142.938880] Testing event percpu_create_chunk: OK [ 142.965550] Testing event percpu_alloc_percpu_fail: OK [ 142.991402] Testing event percpu_free_percpu: OK [ 143.018825] Testing event percpu_alloc_percpu: OK [ 143.045431] Testing event mm_page_alloc_extfrag: OK [ 143.070894] Testing event mm_page_pcpu_drain: OK [ 143.097438] Testing event mm_page_alloc_zone_locked: OK [ 143.123502] Testing event mm_page_alloc: OK [ 143.150601] Testing event mm_page_free_batched: OK [ 143.177875] Testing event mm_page_free: OK [ 143.205819] Testing event kmem_cache_free: OK [ 143.234042] Testing event kfree: OK [ 143.261312] Testing event kmem_cache_alloc_node: OK [ 143.286926] Testing event kmalloc_node: OK [ 143.313931] Testing event kmem_cache_alloc: OK [ 143.339292] Testing event kmalloc: OK [ 143.366874] Testing event mm_compaction_kcompactd_wake: OK [ 143.393444] Testing event mm_compaction_wakeup_kcompactd: OK [ 143.418758] Testing event mm_compaction_kcompactd_sleep: OK [ 143.445384] Testing event mm_compaction_defer_reset: OK [ 143.471277] Testing event mm_compaction_defer_compaction: OK [ 143.497301] Testing event mm_compaction_deferred: OK [ 143.522398] Testing event mm_compaction_suitable: OK [ 143.546557] Testing event mm_compaction_finished: OK [ 143.570606] Testing event mm_compaction_try_to_compact_pages: OK [ 143.597542] Testing event mm_compaction_end: OK [ 143.623408] Testing event mm_compaction_begin: OK [ 143.650391] Testing event mm_compaction_migratepages: OK [ 143.677558] Testing event mm_compaction_isolate_freepages: OK [ 143.703422] Testing event mm_compaction_isolate_migratepages: OK [ 143.730572] Testing event mm_migrate_pages: OK [ 143.754599] Testing event mm_collapse_huge_page_swapin: OK [ 143.785463] Testing event mm_collapse_huge_page_isolate: OK [ 143.810753] Testing event mm_collapse_huge_page: OK [ 143.837430] Testing event mm_khugepaged_scan_pmd: OK [ 143.863223] Testing event test_pages_isolated: OK [ 143.889191] Testing event cma_release: OK [ 143.914645] Testing event cma_alloc: OK [ 143.938562] Testing event page_ref_unfreeze: OK [ 143.968836] Testing event page_ref_freeze: OK [ 143.996937] Testing event page_ref_mod_unless: OK [ 144.028745] Testing event page_ref_mod_and_return: OK [ 144.054469] Testing event page_ref_mod_and_test: OK [ 144.188836] Testing event page_ref_mod: OK [ 144.247607] Testing event page_ref_set: OK [ 144.278078] Testing event sb_clear_inode_writeback: OK [ 144.303507] Testing event sb_mark_inode_writeback: OK [ 144.330599] Testing event writeback_dirty_inode_enqueue: OK [ 144.354654] Testing event writeback_lazytime_iput: OK [ 144.381485] Testing event writeback_lazytime: OK [ 144.407411] Testing event writeback_single_inode: OK [ 144.434944] Testing event writeback_single_inode_start: OK [ 144.458622] Testing event writeback_wait_iff_congested: OK [ 144.482663] Testing event writeback_congestion_wait: OK [ 144.509397] Testing event writeback_sb_inodes_requeue: OK [ 144.535395] Testing event balance_dirty_pages: OK [ 144.562842] Testing event bdi_dirty_ratelimit: OK [ 144.586568] Testing event global_dirty_state: OK [ 144.613495] Testing event writeback_queue_io: OK [ 144.639147] Testing event wbc_writepage: OK [ 144.665304] Testing event writeback_bdi_register: OK [ 144.691124] Testing event writeback_wake_background: OK [ 144.717290] Testing event writeback_pages_written: OK [ 144.745028] Testing event writeback_wait: OK [ 144.770928] Testing event writeback_written: OK [ 144.797434] Testing event writeback_start: OK [ 144.823348] Testing event writeback_exec: OK [ 144.850635] Testing event writeback_queue: OK [ 144.874606] Testing event writeback_write_inode: OK [ 144.898936] Testing event writeback_write_inode_start: OK [ 144.925699] Testing event writeback_dirty_inode: OK [ 144.950939] Testing event writeback_dirty_inode_start: OK [ 144.977524] Testing event writeback_mark_inode_dirty: OK [ 145.003270] Testing event writeback_dirty_page: OK [ 145.029151] Testing event dax_writeback_one: OK [ 145.054413] Testing event dax_writeback_range_done: OK [ 145.081541] Testing event dax_writeback_range: OK [ 145.107377] Testing event dax_insert_mapping: OK [ 145.134443] Testing event dax_insert_pfn_mkwrite: OK [ 145.162025] Testing event dax_insert_pfn_mkwrite_no_entry: OK [ 145.189445] Testing event dax_load_hole: OK [ 145.215148] Testing event dax_pte_fault_done: OK [ 145.243068] Testing event dax_pte_fault: OK [ 145.269609] Testing event dax_pmd_insert_mapping: OK [ 145.295008] Testing event dax_pmd_load_hole_fallback: OK [ 145.321170] Testing event dax_pmd_load_hole: OK [ 145.346434] Testing event dax_pmd_fault_done: OK [ 145.370336] Testing event dax_pmd_fault: OK [ 145.394413] Testing event generic_add_lease: OK [ 145.418463] Testing event time_out_leases: OK [ 145.445480] Testing event generic_delete_lease: OK [ 145.471536] Testing event break_lease_unblock: OK [ 145.499052] Testing event break_lease_block: OK [ 145.524743] Testing event break_lease_noblock: OK [ 145.550274] Testing event flock_lock_inode: OK [ 145.578153] Testing event locks_remove_posix: OK [ 145.606095] Testing event fcntl_setlk: OK [ 145.633227] Testing event posix_lock_inode: OK [ 145.658302] Testing event locks_get_lock_context: OK [ 145.682683] Testing event block_rq_remap: OK [ 145.709188] Testing event block_bio_remap: OK [ 145.735339] Testing event block_split: OK [ 145.762391] Testing event block_unplug: OK [ 145.789993] Testing event block_plug: OK [ 145.817564] Testing event block_sleeprq: OK [ 145.842936] Testing event block_getrq: OK [ 145.870455] Testing event block_bio_queue: OK [ 145.894494] Testing event block_bio_frontmerge: OK [ 145.921901] Testing event block_bio_backmerge: OK [ 145.949622] Testing event block_bio_complete: OK [ 145.974023] Testing event block_bio_bounce: OK [ 145.998713] Testing event block_rq_issue: OK [ 146.022769] Testing event block_rq_insert: OK [ 146.048700] Testing event block_rq_complete: OK [ 146.074601] Testing event block_rq_requeue: OK [ 146.098475] Testing event block_dirty_buffer: OK [ 146.122590] Testing event block_touch_buffer: OK [ 146.149161] Testing event wbt_timer: OK [ 146.174626] Testing event wbt_step: OK [ 146.205752] Testing event wbt_lat: OK [ 146.230638] Testing event wbt_stat: OK [ 146.258038] Testing event gpio_value: OK [ 146.286212] Testing event gpio_direction: OK [ 146.313640] Testing event clk_set_duty_cycle_complete: OK [ 146.339451] Testing event clk_set_duty_cycle: OK [ 146.366393] Testing event clk_set_phase_complete: OK [ 146.394129] Testing event clk_set_phase: OK [ 146.421307] Testing event clk_set_parent_complete: OK [ 146.447144] Testing event clk_set_parent: OK [ 146.475520] Testing event clk_set_rate_complete: OK [ 146.502440] Testing event clk_set_rate: OK [ 146.526599] Testing event clk_unprepare_complete: OK [ 146.550781] Testing event clk_unprepare: OK [ 146.577545] Testing event clk_prepare_complete: OK [ 146.602846] Testing event clk_prepare: OK [ 146.629857] Testing event clk_disable_complete: OK [ 146.657587] Testing event clk_disable: OK [ 146.683409] Testing event clk_enable_complete: OK [ 146.710585] Testing event clk_enable: OK [ 146.738343] Testing event rpmh_send_msg: OK [ 146.765303] Testing event rpmh_tx_done: OK [ 146.790499] Testing event regulator_set_voltage_complete: OK [ 146.814836] Testing event regulator_set_voltage: OK [ 146.841427] Testing event regulator_disable_complete: OK [ 146.867429] Testing event regulator_disable: OK [ 146.894487] Testing event regulator_enable_complete: OK [ 146.918543] Testing event regulator_enable_delay: OK [ 146.942582] Testing event regulator_enable: OK [ 146.966573] Testing event urandom_read: OK [ 146.992921] Testing event random_read: OK [ 147.018627] Testing event extract_entropy_user: OK [ 147.046319] Testing event extract_entropy: OK [ 147.073292] Testing event get_random_bytes_arch: OK [ 147.098373] Testing event get_random_bytes: OK [ 147.125394] Testing event xfer_secondary_pool: OK [ 147.151329] Testing event add_disk_randomness: OK [ 147.178934] Testing event add_input_randomness: OK [ 147.205360] Testing event debit_entropy: OK [ 147.231419] Testing event push_to_pool: OK [ 147.258481] Testing event credit_entropy_bits: OK [ 147.282545] Testing event mix_pool_bytes_nolock: OK [ 147.306509] Testing event mix_pool_bytes: OK [ 147.333628] Testing event add_device_randomness: OK [ 147.362087] Testing event io_page_fault: OK [ 147.389263] Testing event unmap: OK [ 147.415320] Testing event map: OK [ 147.442657] Testing event detach_device_from_domain: OK [ 147.466526] Testing event attach_device_to_domain: OK [ 147.493490] Testing event remove_device_from_group: OK [ 147.519300] Testing event add_device_to_group: OK [ 147.546692] Testing event regcache_drop_region: OK [ 147.570534] Testing event regmap_async_complete_done: OK [ 147.594609] Testing event regmap_async_complete_start: OK [ 147.621454] Testing event regmap_async_io_complete: OK [ 147.647308] Testing event regmap_async_write_start: OK [ 147.674917] Testing event regmap_cache_bypass: OK [ 147.698625] Testing event regmap_cache_only: OK [ 147.725190] Testing event regcache_sync: OK [ 147.751316] Testing event regmap_hw_write_done: OK [ 147.778003] Testing event regmap_hw_write_start: OK [ 147.803058] Testing event regmap_hw_read_done: OK [ 147.829261] Testing event regmap_hw_read_start: OK [ 147.855344] Testing event regmap_reg_read_cache: OK [ 147.882457] Testing event regmap_reg_read: OK [ 147.909535] Testing event regmap_reg_write: OK [ 147.935340] Testing event dma_fence_wait_end: OK [ 147.962446] Testing event dma_fence_wait_start: OK [ 147.989863] Testing event dma_fence_signaled: OK [ 148.017523] Testing event dma_fence_enable_signal: OK [ 148.043600] Testing event dma_fence_destroy: OK [ 148.070775] Testing event dma_fence_init: OK [ 148.097552] Testing event dma_fence_emit: OK [ 148.123154] Testing event sync_timeline: OK [ 148.149639] Testing event spi_transfer_stop: OK [ 148.174948] Testing event spi_transfer_start: OK [ 148.201508] Testing event spi_message_done: OK [ 148.227374] Testing event spi_message_start: OK [ 148.254877] Testing event spi_message_submit: OK [ 148.281770] Testing event spi_controller_busy: OK [ 148.309550] Testing event spi_controller_idle: OK [ 148.334686] Testing event mdio_access: OK [ 148.362510] Testing event rtc_timer_fired: OK [ 148.389288] Testing event rtc_timer_dequeue: OK [ 148.415371] Testing event rtc_timer_enqueue: OK [ 148.443535] Testing event rtc_read_offset: OK [ 148.470634] Testing event rtc_set_offset: OK [ 148.494596] Testing event rtc_alarm_irq_enable: OK [ 148.518671] Testing event rtc_irq_set_state: OK [ 148.545367] Testing event rtc_irq_set_freq: OK [ 148.570946] Testing event rtc_read_alarm: OK [ 148.597543] Testing event rtc_set_alarm: OK [ 148.623327] Testing event rtc_read_time: OK [ 148.650668] Testing event rtc_set_time: OK [ 148.674661] Testing event memory_failure_event: OK [ 148.701215] Testing event aer_event: OK [ 148.726455] Testing event non_standard_event: OK [ 148.754363] Testing event arm_event: OK [ 148.781178] Testing event mc_event: OK [ 148.806181] Testing event binder_return: OK [ 148.831054] Testing event binder_command: OK [ 148.857707] Testing event binder_unmap_kernel_end: OK [ 148.882768] Testing event binder_unmap_kernel_start: OK [ 148.906614] Testing event binder_unmap_user_end: OK [ 148.933532] Testing event binder_unmap_user_start: OK [ 148.958823] Testing event binder_alloc_page_end: OK [ 148.985880] Testing event binder_alloc_page_start: OK [ 149.013872] Testing event binder_free_lru_end: OK [ 149.039268] Testing event binder_free_lru_start: OK [ 149.066947] Testing event binder_alloc_lru_end: OK [ 149.093415] Testing event binder_alloc_lru_start: OK [ 149.119303] Testing event binder_update_page_range: OK [ 149.146677] Testing event binder_transaction_failed_buffer_release: OK [ 149.170639] Testing event binder_transaction_buffer_release: OK [ 149.197379] Testing event binder_transaction_alloc_buf: OK [ 149.223539] Testing event binder_transaction_fd_recv: OK [ 149.250519] Testing event binder_transaction_fd_send: OK [ 149.274495] Testing event binder_transaction_ref_to_ref: OK [ 149.298607] Testing event binder_transaction_ref_to_node: OK [ 149.325490] Testing event binder_transaction_node_to_ref: OK [ 149.351391] Testing event binder_transaction_received: OK [ 149.379009] Testing event binder_transaction: OK [ 149.402491] Testing event binder_wait_for_work: OK [ 149.429562] Testing event binder_read_done: OK [ 149.454715] Testing event binder_write_done: OK [ 149.481879] Testing event binder_ioctl_done: OK [ 149.509671] Testing event binder_unlock: OK [ 149.534886] Testing event binder_locked: OK [ 149.561608] Testing event binder_lock: OK [ 149.586729] Testing event binder_ioctl: OK [ 149.613313] Testing event br_fdb_update: OK [ 149.639350] Testing event fdb_delete: OK [ 149.665374] Testing event br_fdb_external_learn_add: OK [ 149.690176] Testing event br_fdb_add: OK [ 149.714364] Testing event qdisc_dequeue: OK [ 149.741622] Testing event fib_table_lookup: OK [ 149.767032] Testing event tcp_probe: OK [ 149.793913] Testing event tcp_retransmit_synack: OK [ 149.819270] Testing event tcp_rcv_space_adjust: OK [ 149.845172] Testing event tcp_destroy_sock: OK [ 149.870567] Testing event tcp_receive_reset: OK [ 149.894543] Testing event tcp_send_reset: OK [ 149.921680] Testing event tcp_retransmit_skb: OK [ 149.949689] Testing event udp_fail_queue_rcv_skb: OK [ 149.975675] Testing event inet_sock_set_state: OK [ 150.002322] Testing event sock_exceed_buf_limit: OK [ 150.029381] Testing event sock_rcvqueue_full: OK [ 150.054845] Testing event napi_poll: OK [ 150.082320] Testing event netif_rx_ni_entry: OK [ 150.107219] Testing event netif_rx_entry: OK [ 150.133231] Testing event netif_receive_skb_list_entry: OK [ 150.158383] Testing event netif_receive_skb_entry: OK [ 150.182534] Testing event napi_gro_receive_entry: OK [ 150.206566] Testing event napi_gro_frags_entry: OK [ 150.230566] Testing event netif_rx: OK [ 150.256939] Testing event netif_receive_skb: OK [ 150.282932] Testing event net_dev_queue: OK [ 150.309943] Testing event net_dev_xmit: OK [ 150.337746] Testing event net_dev_start_xmit: OK [ 150.362580] Testing event skb_copy_datagram_iovec: OK [ 150.389550] Testing event consume_skb: OK [ 150.418029] Testing event kfree_skb: OK [ 150.445362] Testing event 9p_protocol_dump: OK [ 150.478950] Testing event 9p_client_res: OK [ 150.505514] Testing event 9p_client_req: OK [ 150.530240] Running tests on trace event systems: [ 150.530736] Testing event system 9p: OK [ 150.567531] Testing event system skb: OK [ 150.598908] Testing event system net: OK [ 150.633569] Testing event system napi: OK [ 150.659550] Testing event system sock: OK [ 150.689605] Testing event system udp: OK [ 150.715110] Testing event system tcp: OK [ 150.748602] Testing event system fib: OK [ 150.775619] Testing event system qdisc: OK [ 150.805125] Testing event system bridge: OK [ 150.831209] Testing event system binder: OK [ 150.877054] Testing event system ras: OK [ 150.915294] Testing event system rtc: OK [ 150.952390] Testing event system mdio: OK [ 150.979350] Testing event system spi: OK [ 151.013743] Testing event system sync_trace: OK [ 151.039665] Testing event system dma_fence: OK [ 151.074257] Testing event system regmap: OK [ 151.114671] Testing event system iommu: OK [ 151.145860] Testing event system random: OK [ 151.184854] Testing event system regulator: OK [ 151.217666] Testing event system rpmh: OK [ 151.253400] Testing event system clk: OK [ 151.294510] Testing event system gpio: OK [ 151.325224] Testing event system wbt: OK [ 151.357808] Testing event system block: OK [ 151.398075] Testing event system filelock: OK [ 151.430611] Testing event system fs_dax: OK [ 151.466646] Testing event system writeback: OK [ 151.514185] Testing event system page_ref: OK [ 151.704927] Testing event system cma: OK [ 151.735566] Testing event system page_isolation: OK [ 151.763620] Testing event system huge_memory: OK [ 151.793477] Testing event system migrate: OK [ 151.821283] Testing event system compaction: OK [ 151.859388] Testing event system kmem: OK [ 151.897040] Testing event system percpu: OK [ 151.928944] Testing event system vmscan: OK [ 151.967289] Testing event system pagemap: OK [ 151.995549] Testing event system oom: OK [ 152.032599] Testing event system filemap: OK [ 152.061141] Testing event system rseq: OK [ 152.090110] Testing event system xdp: OK [ 152.125611] Testing event system benchmark: OK [ 152.246901] Testing event system rpm: OK [ 152.278082] Testing event system power: OK [ 152.334211] Testing event system test: OK [ 152.361477] Testing event system preemptirq: OK [ 152.417187] Testing event system cgroup: OK [ 152.452907] Testing event system module: OK [ 152.483399] Testing event system alarmtimer: OK [ 152.512779] Testing event system timer: OK [ 152.553663] Testing event system swiotlb: OK [ 152.582085] Testing event system rcu: OK [ 152.636733] Testing event system printk: OK [ 152.663354] Testing event system lock: OK [ 152.737174] Testing event system sched: OK [ 152.786760] Testing event system workqueue: OK [ 152.822987] Testing event system signal: OK [ 152.850747] Testing event system irq: OK [ 152.882004] Testing event system cpuhp: OK [ 152.913247] Testing event system task: OK [ 152.941076] Testing event system kvm: OK [ 152.990326] Testing event system emulation: OK [ 153.015487] Testing event system ipi: OK [ 153.049082] Testing event system raw_syscalls: OK [ 153.077332] Testing event system initcall: OK [ 153.107361] Running tests on all trace events: [ 153.108592] Testing all events: OK [ 177.497081] watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper/0:1] [ 177.498942] Modules linked in: [ 177.500902] irq event stamp: 1684534 [ 177.503027] hardirqs last enabled at (1684533): [] _raw_spin_unlock_irqrestore+0x50/0x98 [ 177.505186] hardirqs last disabled at (1684534): [] el1_irq+0xa8/0x1c0 [ 177.507440] softirqs last enabled at (1666792): [] __do_softirq+0x988/0x9d0 [ 177.509580] softirqs last disabled at (1666783): [] irq_exit+0x128/0x1b8 [ 177.511524] CPU: 0 PID: 1 Comm: swapper/0 Tainted: G L 4.20.0-rc3-next-20181122-00007-g64e3bffc54df-dirty #43 [ 177.513328] Hardware name: linux,dummy-virt (DT) [ 177.515080] pstate: 20400005 (nzCv daif +PAN -UAO) [ 177.517172] pc : _raw_spin_unlock_irqrestore+0x54/0x98 [ 177.519286] lr : _raw_spin_unlock_irqrestore+0x50/0x98 [ 177.520925] sp : ffffff800804b9d0 [ 177.522410] x29: ffffff800804b9d0 x28: 0000000000000000 [ 177.524581] x27: ffffff8009489000 x26: ffffff8009a15df8 [ 177.526735] x25: ffffff8009a9a608 x24: 0000000000000001 [ 177.528876] x23: 00000000d503201f x22: ffffff80084ac5bc [ 177.531101] x21: ffffff8008e00038 x20: ffffff8009a251f0 [ 177.533249] x19: 0000000000000000 x18: 0000000034f4d91d [ 177.535384] x17: 0000000000000000 x16: 0000000000000000 [ 177.537594] x15: 00000000000027e0 x14: ffffff8009a61628 [ 177.539766] x13: 00000000000027de x12: ffffff800a444ab0 [ 177.541912] x11: ffffff8009e16d68 x10: 0000000000008008 [ 177.544110] x9 : ffffff8009a25208 x8 : ffffff8009d52398 [ 177.546302] x7 : ffffff8008e0000c x6 : ffffff8009a9d200 [ 177.548434] x5 : 0000000000000000 x4 : 0000000000000002 [ 177.550578] x3 : fffffffffffffe80 x2 : ffffff800a4423b0 [ 177.552701] x1 : 000000000000001a x0 : 00000000000ee580 [ 177.555011] Call trace: [ 177.557053] _raw_spin_unlock_irqrestore+0x54/0x98 [ 177.559110] __aarch64_insn_write+0x60/0x78 [ 177.561175] aarch64_insn_write+0x24/0x30 [ 177.563194] aarch64_insn_patch_text_nosync+0x30/0x68 [ 177.565258] ftrace_modify_code+0x50/0xc8 [ 177.567337] ftrace_make_call+0x16c/0x248 [ 177.569312] __ftrace_replace_code+0x94/0xf0 [ 177.571374] ftrace_replace_code+0x7c/0x128 [ 177.573388] ftrace_modify_all_code+0x54/0x148 [ 177.575433] arch_ftrace_update_code+0x1c/0x28 [ 177.577422] ftrace_run_update_code+0x54/0x60 [ 177.579500] ftrace_startup_enable+0x6c/0x80 [ 177.581532] ftrace_startup+0x124/0x158 [ 177.583566] register_ftrace_function+0x78/0x98 [ 177.585651] event_trace_self_test_with_function+0xa0/0xc4 [ 177.587784] event_trace_self_tests_init+0x4c/0x60 [ 177.589821] do_one_initcall+0x31c/0x6c8 [ 177.591844] do_initcall_level+0x4ac/0x50c [ 177.593898] do_initcalls+0x28/0x40 [ 177.596029] do_basic_setup+0x34/0x3c [ 177.598129] kernel_init_freeable+0x12c/0x1d4 [ 177.600190] kernel_init+0x28/0x140 [ 177.602294] ret_from_fork+0x10/0x18 [ 180.813471] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 180.816543] rcu: (detected by 0, t=6502 jiffies, g=8605, q=499) [ 180.818794] rcu: All QSes seen, last rcu_sched kthread activity 6502 (4294932283-4294925781), jiffies_till_next_fqs=1, root ->qsmask 0x0 [ 180.820578] swapper/0 R running task 9616 1 0 0x0000002a [ 180.823229] Call trace: [ 180.825260] dump_backtrace+0x0/0x230 [ 180.827375] show_stack+0x28/0x38 [ 180.829390] sched_show_task+0x394/0x3e0 [ 180.831459] print_other_cpu_stall+0x3b8/0x440 [ 180.833628] check_cpu_stall+0x1ac/0x1f0 [ 180.835779] rcu_pending+0x38/0x128 [ 180.837818] rcu_check_callbacks+0x31c/0x598 [ 180.839914] update_process_times+0x38/0x68 [ 180.842029] tick_sched_handle+0x68/0x80 [ 180.844087] tick_sched_timer+0x58/0xb0 [ 180.846146] __run_hrtimer+0x620/0x950 [ 180.848161] __hrtimer_run_queues+0xf4/0x150 [ 180.850329] hrtimer_interrupt+0x11c/0x338 [ 180.852361] arch_timer_handler_virt+0x44/0x60 [ 180.854442] handle_percpu_devid_irq+0x360/0x758 [ 180.856504] generic_handle_irq+0x40/0x60 [ 180.858549] __handle_domain_irq+0xa8/0xd8 [ 180.860695] gic_handle_irq+0x8c/0xe8 [ 180.862713] el1_irq+0xec/0x1c0 [ 180.864720] _raw_spin_unlock_irqrestore+0x54/0x98 [ 180.866850] __aarch64_insn_write+0x60/0x78 [ 180.868863] aarch64_insn_write+0x24/0x30 [ 180.870932] aarch64_insn_patch_text_nosync+0x30/0x68 [ 180.872957] ftrace_modify_code+0x50/0xc8 [ 180.875041] ftrace_make_call+0x16c/0x248 [ 180.877136] __ftrace_replace_code+0x94/0xf0 [ 180.879180] ftrace_replace_code+0x7c/0x128 [ 180.881292] ftrace_modify_all_code+0x54/0x148 [ 180.883306] arch_ftrace_update_code+0x1c/0x28 [ 180.885370] ftrace_run_update_code+0x54/0x60 [ 180.887479] ftrace_startup_enable+0x6c/0x80 [ 180.889493] ftrace_startup+0x124/0x158 [ 180.891601] register_ftrace_function+0x78/0x98 [ 180.893675] event_trace_self_test_with_function+0xa0/0xc4 [ 180.895717] event_trace_self_tests_init+0x4c/0x60 [ 180.897770] do_one_initcall+0x31c/0x6c8 [ 180.899885] do_initcall_level+0x4ac/0x50c [ 180.901909] do_initcalls+0x28/0x40 [ 180.903970] do_basic_setup+0x34/0x3c [ 180.906049] kernel_init_freeable+0x12c/0x1d4 [ 180.908080] kernel_init+0x28/0x140 [ 180.910144] ret_from_fork+0x10/0x18 [ 180.912022] rcu: rcu_sched kthread starved for 6502 jiffies! g8605 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0 [ 180.913753] rcu: RCU grace-period kthread stack dump: [ 180.915363] rcu_sched R running task 13840 10 2 0x00000028 [ 180.917831] Call trace: [ 180.919829] __switch_to+0x5c/0x68 [ 180.921903] __schedule+0xa3c/0xac0 [ 180.923999] schedule+0x9c/0xe0 [ 180.926116] schedule_timeout+0x950/0x9b8 [ 180.928204] rcu_gp_fqs_loop+0x39c/0xc10 [ 180.930272] rcu_gp_kthread+0x5fc/0x618 [ 180.932324] kthread+0x150/0x168 [ 180.934360] ret_from_fork+0x10/0x18 [ 180.941532] hrtimer: interrupt took 132718368 ns [ 258.833783] rcu: INFO: rcu_sched detected stalls on CPUs/tasks: [ 258.841968] rcu: (detected by 0, t=26007 jiffies, g=8605, q=499) [ 258.850016] rcu: All QSes seen, last rcu_sched kthread activity 26007 (4294951788-4294925781), jiffies_till_next_fqs=1, root ->qsmask 0x0 [ 258.863184] swapper/0 R running task 9616 1 0 0x0000002a [ 258.872650] Call trace: [ 258.877214] dump_backtrace+0x0/0x230 [ 258.882955] show_stack+0x28/0x38 [ 258.888344] sched_show_task+0x394/0x3e0 [ 258.894330] print_other_cpu_stall+0x3b8/0x440 [ 258.900871] check_cpu_stall+0x1ac/0x1f0 [ 258.906820] rcu_pending+0x38/0x128 [ 258.912438] rcu_check_callbacks+0x31c/0x598 [ 258.918874] update_process_times+0x38/0x68 [ 258.925421] tick_sched_handle+0x68/0x80 [ 258.931492] tick_sched_timer+0x58/0xb0 [ 258.937692] __run_hrtimer+0x620/0x950 [ 258.943788] __hrtimer_run_queues+0xf4/0x150 [ 258.950480] hrtimer_interrupt+0x11c/0x338 [ 258.956988] arch_timer_handler_virt+0x44/0x60 [ 258.963745] handle_percpu_devid_irq+0x360/0x758 [ 258.970774] generic_handle_irq+0x40/0x60 [ 258.977205] __handle_domain_irq+0xa8/0xd8 [ 258.983762] gic_handle_irq+0x8c/0xe8 [ 258.989974] el1_irq+0xec/0x1c0 [ 258.995402] _raw_spin_lock_irqsave+0x0/0xd0 [ 259.002046] aarch64_insn_write+0x24/0x30 [ 259.008414] aarch64_insn_patch_text_nosync+0x30/0x68 [ 259.015884] ftrace_modify_code+0x50/0xc8 [ 259.022211] ftrace_make_call+0x16c/0x248 [ 259.028646] __ftrace_replace_code+0x94/0xf0 [ 259.035271] ftrace_replace_code+0x7c/0x128 [ 259.041854] ftrace_modify_all_code+0x54/0x148 [ 259.048549] arch_ftrace_update_code+0x1c/0x28 [ 259.055531] ftrace_run_update_code+0x54/0x60 [ 259.062428] ftrace_startup_enable+0x6c/0x80 [ 259.069131] ftrace_startup+0x124/0x158 [ 259.075377] register_ftrace_function+0x78/0x98 [ 259.082289] event_trace_self_test_with_function+0xa0/0xc4 [ 259.090402] event_trace_self_tests_init+0x4c/0x60 [ 259.097645] do_one_initcall+0x31c/0x6c8 [ 259.103901] do_initcall_level+0x4ac/0x50c [ 259.110361] do_initcalls+0x28/0x40 [ 259.116380] do_basic_setup+0x34/0x3c [ 259.122419] kernel_init_freeable+0x12c/0x1d4 [ 259.129101] kernel_init+0x28/0x140 [ 259.134888] ret_from_fork+0x10/0x18 [ 259.140528] rcu: rcu_sched kthread starved for 26007 jiffies! g8605 f0x2 RCU_GP_WAIT_FQS(5) ->state=0x0 ->cpu=0 [ 259.152687] rcu: RCU grace-period kthread stack dump: [ 259.160236] rcu_sched R running task 13840 10 2 0x00000028 [ 259.170189] Call trace: [ 259.175072] __switch_to+0x5c/0x68 [ 259.180939] __schedule+0xa3c/0xac0 [ 259.186763] schedule+0x9c/0xe0 [ 259.192267] schedule_timeout+0x950/0x9b8 [ 259.198717] rcu_gp_fqs_loop+0x39c/0xc10 [ 259.204963] rcu_gp_kthread+0x5fc/0x618 [ 259.211135] kthread+0x150/0x168 [ 259.216672] ret_from_fork+0x10/0x18 [ 269.211946] Running tests again, along with the function tracer [ 269.241860] Running tests on trace events: [ 269.247769] Testing event initcall_finish: OK [ 275.443528] Testing event initcall_start: OK [ 276.074455] Testing event initcall_level: OK [ 276.722542] Testing event sys_exit: OK [ 277.174328] Testing event sys_enter: OK [ 277.827632] Testing event ipi_exit: OK [ 278.733189] Testing event ipi_entry: OK [ 279.183573] Testing event ipi_raise: OK [ 279.886630] Testing event instruction_emulation: OK [ 280.569244] Testing event kvm_halt_poll_ns: OK [ 281.304940] Testing event kvm_age_page: OK [ 281.771802] Testing event kvm_fpu: OK [ 282.623839] Testing event kvm_mmio: OK [ 283.276928] Testing event kvm_ack_irq: OK [ 283.974775] Testing event kvm_set_irq: OK [ 284.879252] Testing event kvm_vcpu_wakeup: OK [ 285.467675] Testing event kvm_userspace_exit: OK [ 285.945076] Testing event kvm_timer_update_irq: OK [ 286.475642] Testing event kvm_toggle_cache: OK [ 287.291744] Testing event kvm_set_way_flush: OK [ 288.133321] Testing event kvm_test_age_hva: OK [ 288.704900] Testing event kvm_age_hva: OK [ 289.513528] Testing event kvm_set_spte_hva: OK [ 290.101425] Testing event kvm_unmap_hva_range: OK [ 290.780999] Testing event kvm_mmio_emulate: OK [ 291.340847] Testing event kvm_irq_line: OK [ 292.131776] Testing event kvm_access_fault: OK [ 292.676610] Testing event kvm_guest_fault: OK [ 293.245105] Testing event kvm_exit: OK [ 293.834688] Testing event kvm_entry: OK [ 294.628673] Testing event kvm_set_guest_debug: OK [ 295.300914] Testing event kvm_handle_sys_reg: OK [ 296.026078] Testing event trap_reg: OK [ 296.583800] Testing event kvm_arm_set_regset: OK [ 297.161435] Testing event kvm_arm_set_dreg32: OK [ 297.955830] Testing event kvm_arm_clear_debug: OK [ 298.637280] Testing event kvm_arm_setup_debug: OK [ 299.365423] Testing event kvm_hvc_arm64: OK [ 300.092648] Testing event kvm_wfx_arm64: OK [ 300.775838] Testing event vgic_update_irq_pending: OK [ 301.317358] Testing event task_rename: OK [ 301.939455] Testing event task_newtask: OK [ 302.771580] Testing event cpuhp_exit: OK [ 303.394777] Testing event cpuhp_multi_enter: OK [ 304.140945] Testing event cpuhp_enter: OK [ 304.875696] Testing event softirq_raise: OK [ 305.507480] Testing event softirq_exit: OK [ 306.067556] Testing event softirq_entry: OK [ 306.867806] Testing event irq_handler_exit: OK [ 307.530407] Testing event irq_handler_entry: OK [ 308.173162] Testing event signal_deliver: OK [ 308.841990] Testing event signal_generate: OK [ 309.517422] Testing event workqueue_execute_end: OK [ 309.999543] Testing event workqueue_execute_start: OK [ 310.461661] Testing event workqueue_activate_work: OK [ 311.284614] Testing event workqueue_queue_work: OK [ 312.214828] Testing event sched_wake_idle_without_ipi: OK [ 313.209740] Testing event sched_swap_numa: OK [ 313.715807] Testing event sched_stick_numa: OK [ 314.461290] Testing event sched_move_numa: OK [ 314.894676] Testing event sched_process_hang: OK [ 315.509143] Testing event sched_pi_setprio: OK [ 316.268749] Testing event sched_stat_runtime: OK [ 316.941369] Testing event sched_stat_blocked: OK [ 317.684688] Testing event sched_stat_iowait: OK [ 318.635725] Testing event sched_stat_sleep: OK [ 319.325183] Testing event sched_stat_wait: OK [ 319.908642] Testing event sched_process_exec: OK [ 320.790223] Testing event sched_process_fork: OK [ 321.399670] Testing event sched_process_wait: OK [ 321.866530] Testing event sched_wait_task: OK [ 322.911705] Testing event sched_process_exit: OK [ 323.429614] Testing event sched_process_free: OK [ 323.930427] Testing event sched_migrate_task: OK [ 324.900995] Testing event sched_switch: OK [ 325.470834] Testing event sched_wakeup_new: OK [ 326.118351] Testing event sched_wakeup: OK [ 326.844650] Testing event sched_waking: OK [ 327.566666] Testing event sched_kthread_stop_ret: OK [ 328.113631] Testing event sched_kthread_stop: OK [ 328.904946] Testing event lock_acquired: OK [ 329.502278] Testing event lock_contended: OK [ 330.143777] Testing event lock_release: OK [ 330.990404] Testing event lock_acquire: OK [ 331.804655] Testing event console: OK [ 332.595788] Testing event rcu_barrier: OK [ 333.090498] Testing event rcu_torture_read: OK [ 333.508523] Testing event rcu_batch_end: OK [ 334.107802] Testing event rcu_invoke_kfree_callback: OK [ 334.986254] Testing event rcu_invoke_callback: OK [ 335.523676] Testing event rcu_batch_start: OK [ 336.122282] Testing event rcu_kfree_callback: OK [ 336.840735] Testing event rcu_callback: OK [ 337.478931] Testing event rcu_dyntick: OK [ 338.139686] Testing event rcu_fqs: OK [ 338.982356] Testing event rcu_quiescent_state_report: OK [ 339.638001] Testing event rcu_unlock_preempted_task: OK [ 340.035702] Testing event rcu_preempt_task: OK [ 340.522686] Testing event rcu_exp_funnel_lock: OK [ 341.488978] Testing event rcu_exp_grace_period: OK [ 342.345390] Testing event rcu_grace_period_init: OK [ 343.067649] Testing event rcu_future_grace_period: OK [ 343.664964] Testing event rcu_grace_period: OK [ 344.255785] Testing event rcu_utilization: OK [ 344.999817] Testing event swiotlb_bounced: OK [ 345.623588] Testing event tick_stop: OK [ 346.271209] Testing event itimer_expire: OK [ 346.990413] Testing event itimer_state: OK [ 347.494658] Testing event hrtimer_cancel: OK [ 348.449448] Testing event hrtimer_expire_exit: OK [ 349.125549] Testing event hrtimer_expire_entry: OK [ 349.797671] Testing event hrtimer_start: OK [ 350.555650] Testing event hrtimer_init: OK [ 351.141753] Testing event timer_cancel: OK [ 351.603671] Testing event timer_expire_exit: OK [ 352.470416] Testing event timer_expire_entry: OK [ 352.945658] Testing event timer_start: OK [ 353.603590] Testing event timer_init: OK [ 354.174620] Testing event alarmtimer_cancel: OK [ 354.855710] Testing event alarmtimer_start: OK [ 355.447764] Testing event alarmtimer_fired: OK [ 356.211717] Testing event alarmtimer_suspend: OK [ 356.644868] Testing event module_request: OK [ 357.511156] Testing event module_put: OK [ 358.058511] Testing event module_get: OK [ 359.058432] Testing event module_free: OK [ 359.629561] Testing event module_load: OK [ 360.313368] Testing event cgroup_transfer_tasks: OK [ 360.991688] Testing event cgroup_attach_task: OK [ 361.722290] Testing event cgroup_rename: OK [ 362.080707] Testing event cgroup_release: OK [ 362.556799] Testing event cgroup_rmdir: OK [ 363.260713] Testing event cgroup_mkdir: OK [ 363.889088] Testing event cgroup_remount: OK [ 364.565875] Testing event cgroup_destroy_root: OK [ 365.400878] Testing event cgroup_setup_root: OK [ 366.146344] Testing event irq_enable: OK [ 367.191709] Testing event irq_disable: OK [ 368.606486] Testing event ftrace_test_filter: OK [ 369.313211] Testing event dev_pm_qos_remove_request: OK [ 369.792812] Testing event dev_pm_qos_update_request: OK [ 370.476934] Testing event dev_pm_qos_add_request: OK [ 370.930367] Testing event pm_qos_update_flags: OK [ 371.444767] Testing event pm_qos_update_target: OK [ 372.281665] Testing event pm_qos_update_request_timeout: OK [ 372.932681] Testing event pm_qos_remove_request: OK [ 373.584827] Testing event pm_qos_update_request: OK [ 374.275608] Testing event pm_qos_add_request: OK [ 374.983583] Testing event power_domain_target: OK [ 375.749268] Testing event clock_set_rate: OK [ 376.311766] Testing event clock_disable: OK [ 376.755616] Testing event clock_enable: OK [ 377.532658] Testing event wakeup_source_deactivate: OK [ 378.227798] Testing event wakeup_source_activate: OK [ 379.277696] Testing event suspend_resume: OK [ 379.991629] Testing event device_pm_callback_end: OK [ 380.847723] Testing event device_pm_callback_start: OK [ 381.470287] Testing event cpu_frequency_limits: OK [ 382.144890] Testing event cpu_frequency: OK [ 382.585183] Testing event pstate_sample: OK [ 383.165814] Testing event powernv_throttle: OK [ 383.727785] Testing event cpu_idle: OK [ 384.579820] Testing event rpm_return_int: OK [ 385.057223] Testing event rpm_idle: OK [ 385.715643] Testing event rpm_resume: OK [ 386.427109] Testing event rpm_suspend: OK [ 386.827617] Testing event benchmark_event: OK [ 387.711483] Testing event xdp_devmap_xmit: OK [ 388.274130] Testing event xdp_cpumap_enqueue: OK [ 388.950072] Testing event xdp_cpumap_kthread: OK [ 389.552595] Testing event xdp_redirect_map_err: OK [ 390.086470] Testing event xdp_redirect_map: OK [ 390.519545] Testing event xdp_redirect_err: OK [ 391.430578] Testing event xdp_redirect: OK [ 392.156852] Testing event xdp_exception: OK [ 392.966723] Testing event rseq_ip_fixup: OK [ 393.749369] Testing event rseq_update: OK [ 394.372703] Testing event file_check_and_advance_wb_err: OK [ 395.357118] Testing event filemap_set_wb_err: OK [ 395.805367] Testing event mm_filemap_add_to_page_cache: OK [ 396.376967] Testing event mm_filemap_delete_from_page_cache: OK [ 397.026661] Testing event compact_retry: OK [ 397.659707] Testing event skip_task_reaping: OK [ 398.449092] Testing event finish_task_reaping: OK [ 399.262392] Testing event start_task_reaping: OK [ 399.851460] Testing event wake_reaper: OK [ 400.409072] Testing event mark_victim: OK [ 401.060752] Testing event reclaim_retry_zone: OK [ 401.764632] Testing event oom_score_adj_update: OK [ 402.585688] Testing event mm_lru_activate: OK [ 403.202388] Testing event mm_lru_insertion: OK [ 404.106474] Testing event mm_vmscan_inactive_list_is_low: OK [ 405.050164] Testing event mm_vmscan_lru_shrink_active: OK [ 405.678113] Testing event mm_vmscan_lru_shrink_inactive: OK [ 406.246467] Testing event mm_vmscan_writepage: OK [ 407.001320] Testing event mm_vmscan_lru_isolate: OK [ 407.641671] Testing event mm_shrink_slab_end: OK [ 408.275812] Testing event mm_shrink_slab_start: OK [ 409.204651] Testing event mm_vmscan_memcg_softlimit_reclaim_end: OK [ 409.827573] Testing event mm_vmscan_memcg_reclaim_end: OK [ 410.577321] Testing event mm_vmscan_direct_reclaim_end: OK [ 411.070361] Testing event mm_vmscan_memcg_softlimit_reclaim_begin: OK [ 411.888985] Testing event mm_vmscan_memcg_reclaim_begin: OK [ 412.508582] Testing event mm_vmscan_direct_reclaim_begin: OK [ 413.225539] Testing event mm_vmscan_wakeup_kswapd: OK [ 413.887647] Testing event mm_vmscan_kswapd_wake: OK [ 414.606556] Testing event mm_vmscan_kswapd_sleep: OK [ 415.221656] Testing event percpu_destroy_chunk: OK [ 415.750045] Testing event percpu_create_chunk: OK [ 416.385277] Testing event percpu_alloc_percpu_fail: OK [ 416.909508] Testing event percpu_free_percpu: OK [ 417.307795] Testing event percpu_alloc_percpu: OK [ 417.917043] Testing event mm_page_alloc_extfrag: OK [ 418.609180] Testing event mm_page_pcpu_drain: OK [ 419.433433] Testing event mm_page_alloc_zone_locked: OK [ 420.285689] Testing event mm_page_alloc: OK [ 420.929518] Testing event mm_page_free_batched: OK [ 421.731636] Testing event mm_page_free: OK [ 422.251818] Testing event kmem_cache_free: OK [ 422.719668] Testing event kfree: OK [ 423.529274] Testing event kmem_cache_alloc_node: OK [ 424.239762] Testing event kmalloc_node: OK [ 424.891809] Testing event kmem_cache_alloc: OK [ 425.578420] Testing event kmalloc: OK [ 426.128661] Testing event mm_compaction_kcompactd_wake: OK [ 426.991483] Testing event mm_compaction_wakeup_kcompactd: OK [ 427.705219] Testing event mm_compaction_kcompactd_sleep: OK [ 428.453981] Testing event mm_compaction_defer_reset: OK [ 429.067693] Testing event mm_compaction_defer_compaction: OK [ 429.601204] Testing event mm_compaction_deferred: OK [ 429.923640] Testing event mm_compaction_suitable: OK [ 430.732772] Testing event mm_compaction_finished: OK [ 431.419618] Testing event mm_compaction_try_to_compact_pages: OK [ 432.018311] Testing event mm_compaction_end: OK [ 432.748652] Testing event mm_compaction_begin: OK [ 433.203699] Testing event mm_compaction_migratepages: OK [ 433.901736] Testing event mm_compaction_isolate_freepages: OK [ 434.654431] Testing event mm_compaction_isolate_migratepages: OK [ 435.107669] Testing event mm_migrate_pages: OK [ 435.684694] Testing event mm_collapse_huge_page_swapin: OK [ 436.355775] Testing event mm_collapse_huge_page_isolate: OK [ 437.084743] Testing event mm_collapse_huge_page: OK [ 437.938356] Testing event mm_khugepaged_scan_pmd: OK [ 438.656654] Testing event test_pages_isolated: OK [ 439.226322] Testing event cma_release: OK [ 439.796894] Testing event cma_alloc: OK [ 440.302083] Testing event page_ref_unfreeze: OK [ 440.967621] Testing event page_ref_freeze: OK [ 441.704188] Testing event page_ref_mod_unless: OK [ 442.508636] Testing event page_ref_mod_and_return: OK [ 443.206389] Testing event page_ref_mod_and_test: OK [ 445.746431] Testing event page_ref_mod: OK [ 447.165059] Testing event page_ref_set: OK [ 447.987796] Testing event sb_clear_inode_writeback: OK [ 448.935606] Testing event sb_mark_inode_writeback: OK [ 449.695528] Testing event writeback_dirty_inode_enqueue: OK [ 450.200926] Testing event writeback_lazytime_iput: OK [ 451.002306] Testing event writeback_lazytime: OK [ 451.828659] Testing event writeback_single_inode: OK [ 452.567819] Testing event writeback_single_inode_start: OK [ 453.478573] Testing event writeback_wait_iff_congested: OK [ 454.128671] Testing event writeback_congestion_wait: OK [ 454.847687] Testing event writeback_sb_inodes_requeue: OK [ 455.616641] Testing event balance_dirty_pages: OK [ 456.199832] Testing event bdi_dirty_ratelimit: OK [ 456.950131] Testing event global_dirty_state: OK [ 457.763567] Testing event writeback_queue_io: OK [ 458.483714] Testing event wbc_writepage: OK [ 459.050317] Testing event writeback_bdi_register: OK [ 459.850067] Testing event writeback_wake_background: OK [ 460.512642] Testing event writeback_pages_written: OK [ 461.476606] Testing event writeback_wait: OK [ 461.979678] Testing event writeback_written: OK [ 462.406370] Testing event writeback_start: OK [ 463.074321] Testing event writeback_exec: OK [ 463.790551] Testing event writeback_queue: OK [ 464.509519] Testing event writeback_write_inode: OK [ 465.134950] Testing event writeback_write_inode_start: OK [ 466.214246] Testing event writeback_dirty_inode: OK [ 466.654567] Testing event writeback_dirty_inode_start: OK [ 467.313826] Testing event writeback_mark_inode_dirty: OK [ 467.818199] Testing event writeback_dirty_page: OK [ 468.467628] Testing event dax_writeback_one: OK [ 469.172836] Testing event dax_writeback_range_done: OK [ 469.792972] Testing event dax_writeback_range: OK [ 470.447684] Testing event dax_insert_mapping: OK [ 471.281355] Testing event dax_insert_pfn_mkwrite: OK [ 471.821694] Testing event dax_insert_pfn_mkwrite_no_entry: OK [ 472.403149] Testing event dax_load_hole: OK [ 473.081168] Testing event dax_pte_fault_done: OK [ 473.687763] Testing event dax_pte_fault: OK [ 474.374519] Testing event dax_pmd_insert_mapping: OK [ 474.914671] Testing event dax_pmd_load_hole_fallback: OK [ 475.367479] Testing event dax_pmd_load_hole: OK [ 475.831785] Testing event dax_pmd_fault_done: OK [ 476.513080] Testing event dax_pmd_fault: OK [ 477.047746] Testing event generic_add_lease: OK [ 477.667668] Testing event time_out_leases: OK [ 478.529253] Testing event generic_delete_lease: OK [ 479.245780] Testing event break_lease_unblock: OK [ 479.693461] Testing event break_lease_block: OK [ 480.252679] Testing event break_lease_noblock: OK [ 481.086028] Testing event flock_lock_inode: OK [ 481.763815] Testing event locks_remove_posix: OK [ 482.377174] Testing event fcntl_setlk: OK [ 483.089075] Testing event posix_lock_inode: OK [ 483.811794] Testing event locks_get_lock_context: OK [ 484.609968] Testing event block_rq_remap: OK [ 485.301588] Testing event block_bio_remap: OK [ 486.013342] Testing event block_split: OK [ 486.971818] Testing event block_unplug: OK [ 487.394102] Testing event block_plug: OK [ 487.972763] Testing event block_sleeprq: OK [ 488.591580] Testing event block_getrq: OK [ 489.227722] Testing event block_bio_queue: OK [ 490.041141] Testing event block_bio_frontmerge: OK [ 490.755808] Testing event block_bio_backmerge: OK [ 491.356613] Testing event block_bio_complete: OK [ 492.185929] Testing event block_bio_bounce: OK [ 492.866070] Testing event block_rq_issue: OK [ 493.601896] Testing event block_rq_insert: OK [ 494.521471] Testing event block_rq_complete: OK [ 495.141433] Testing event block_rq_requeue: OK [ 495.874459] Testing event block_dirty_buffer: OK [ 496.537709] Testing event block_touch_buffer: OK [ 497.311615] Testing event wbt_timer: OK [ 497.831809] Testing event wbt_step: OK [ 498.644651] Testing event wbt_lat: OK [ 499.489639] Testing event wbt_stat: OK [ 500.423607] Testing event gpio_value: OK [ 501.271654] Testing event gpio_direction: OK [ 502.170270] Testing event clk_set_duty_cycle_complete: OK [ 502.985410] Testing event clk_set_duty_cycle: OK [ 503.567758] Testing event clk_set_phase_complete: OK [ 504.348657] Testing event clk_set_phase: OK [ 504.890888] Testing event clk_set_parent_complete: OK [ 505.468603] Testing event clk_set_parent: OK [ 506.002447] Testing event clk_set_rate_complete: OK [ 506.389210] Testing event clk_set_rate: OK [ 506.892617] Testing event clk_unprepare_complete: OK [ 507.607247] Testing event clk_unprepare: OK [ 508.392644] Testing event clk_prepare_complete: OK [ 509.287730] Testing event clk_prepare: OK [ 510.052707] Testing event clk_disable_complete: OK [ 510.830468] Testing event clk_disable: OK [ 511.459574] Testing event clk_enable_complete: OK [ 512.301605] Testing event clk_enable: OK [ 513.041058] Testing event rpmh_send_msg: OK [ 513.670600] Testing event rpmh_tx_done: OK [ 514.143698] Testing event regulator_set_voltage_complete: OK [ 514.827484] Testing event regulator_set_voltage: OK [ 515.572698] Testing event regulator_disable_complete: OK [ 515.972720] Testing event regulator_disable: OK [ 516.794533] Testing event regulator_enable_complete: OK [ 517.598066] Testing event regulator_enable_delay: OK [ 518.255806] Testing event regulator_enable: OK [ 518.747668] Testing event urandom_read: OK [ 519.392634] Testing event random_read: OK [ 519.966140] Testing event extract_entropy_user: OK [ 520.715707] Testing event extract_entropy: OK [ 521.403666] Testing event get_random_bytes_arch: OK [ 522.033215] Testing event get_random_bytes: OK [ 522.624892] Testing event xfer_secondary_pool: OK [ 523.287676] Testing event add_disk_randomness: OK [ 524.075801] Testing event add_input_randomness: OK [ 524.816659] Testing event debit_entropy: OK [ 525.629275] Testing event push_to_pool: OK [ 526.181555] Testing event credit_entropy_bits: OK [ 526.711607] Testing event mix_pool_bytes_nolock: OK [ 527.254766] Testing event mix_pool_bytes: OK [ 528.147584] Testing event add_device_randomness: OK [ 528.837718] Testing event io_page_fault: OK [ 529.572026] Testing event unmap: OK [ 530.377524] Testing event map: OK [ 531.183693] Testing event detach_device_from_domain: OK [ 531.804830] Testing event attach_device_to_domain: OK [ 532.387281] Testing event remove_device_from_group: OK [ 533.173315] Testing event add_device_to_group: OK [ 533.603772] Testing event regcache_drop_region: OK [ 534.301312] Testing event regmap_async_complete_done: OK [ 534.961406] Testing event regmap_async_complete_start: OK [ 535.517144] Testing event regmap_async_io_complete: OK [ 535.984674] Testing event regmap_async_write_start: OK [ 536.568716] Testing event regmap_cache_bypass: OK [ 537.595725] Testing event regmap_cache_only: OK [ 538.367676] Testing event regcache_sync: OK [ 539.078253] Testing event regmap_hw_write_done: OK [ 539.855792] Testing event regmap_hw_write_start: OK [ 540.471786] Testing event regmap_hw_read_done: OK [ 541.099756] Testing event regmap_hw_read_start: OK [ 541.677511] Testing event regmap_reg_read_cache: OK [ 542.259746] Testing event regmap_reg_read: OK [ 542.826282] Testing event regmap_reg_write: OK [ 543.729346] Testing event dma_fence_wait_end: OK [ 544.258312] Testing event dma_fence_wait_start: OK [ 544.929286] Testing event dma_fence_signaled: OK [ 545.631593] Testing event dma_fence_enable_signal: OK [ 546.366507] Testing event dma_fence_destroy: OK [ 547.089087] Testing event dma_fence_init: OK [ 547.717425] Testing event dma_fence_emit: OK [ 548.528701] Testing event sync_timeline: OK [ 549.114768] Testing event spi_transfer_stop: OK [ 549.812650] Testing event spi_transfer_start: OK [ 550.431839] Testing event spi_message_done: OK [ 550.975820] Testing event spi_message_start: OK [ 551.407731] Testing event spi_message_submit: OK [ 551.995782] Testing event spi_controller_busy: OK [ 552.573728] Testing event spi_controller_idle: OK [ 553.099816] Testing event mdio_access: OK [ 553.821757] Testing event rtc_timer_fired: OK [ 554.491196] Testing event rtc_timer_dequeue: OK [ 555.283712] Testing event rtc_timer_enqueue: OK [ 556.169031] Testing event rtc_read_offset: OK [ 556.820662] Testing event rtc_set_offset: OK [ 557.809174] Testing event rtc_alarm_irq_enable: OK [ 558.301664] Testing event rtc_irq_set_state: OK [ 559.058503] Testing event rtc_irq_set_freq: OK [ 559.828963] Testing event rtc_read_alarm: OK [ 560.711694] Testing event rtc_set_alarm: OK [ 561.529137] Testing event rtc_read_time: OK [ 562.111484] Testing event rtc_set_time: OK [ 562.825762] Testing event memory_failure_event: OK [ 563.591786] Testing event aer_event: OK [ 564.099244] Testing event non_standard_event: OK [ 564.612645] Testing event arm_event: OK [ 565.055732] Testing event mc_event: OK [ 565.631542] Testing event binder_return: OK [ 566.292709] Testing event binder_command: OK [ 566.988420] Testing event binder_unmap_kernel_end: OK [ 567.515830] Testing event binder_unmap_kernel_start: OK [ 567.996674] Testing event binder_unmap_user_end: OK [ 568.682051] Testing event binder_unmap_user_start: OK [ 569.357391] Testing event binder_alloc_page_end: OK [ 569.846494] Testing event binder_alloc_page_start: OK [ 570.525634] Testing event binder_free_lru_end: OK [ 571.284967] Testing event binder_free_lru_start: OK [ 571.876609] Testing event binder_alloc_lru_end: OK [ 572.401259] Testing event binder_alloc_lru_start: OK [ 572.841254] Testing event binder_update_page_range: OK [ 573.529646] Testing event binder_transaction_failed_buffer_release: OK [ 574.043800] Testing event binder_transaction_buffer_release: OK [ 574.544838] Testing event binder_transaction_alloc_buf: OK [ 575.109815] Testing event binder_transaction_fd_recv: OK [ 576.059645] Testing event binder_transaction_fd_send: OK [ 576.490620] Testing event binder_transaction_ref_to_ref: OK [ 577.089823] Testing event binder_transaction_ref_to_node: OK [ 577.667702] Testing event binder_transaction_node_to_ref: OK [ 578.401074] Testing event binder_transaction_received: OK [ 578.930050] Testing event binder_transaction: OK [ 579.418837] Testing event binder_wait_for_work: OK [ 580.035417] Testing event binder_read_done: OK [ 580.648672] Testing event binder_write_done: OK [ 581.468760] Testing event binder_ioctl_done: OK [ 582.017537] Testing event binder_unlock: OK [ 582.742749] Testing event binder_locked: OK [ 583.196648] Testing event binder_lock: OK [ 583.829198] Testing event binder_ioctl: OK [ 584.443830] Testing event br_fdb_update: OK [ 585.316714] Testing event fdb_delete: OK [ 586.043797] Testing event br_fdb_external_learn_add: OK [ 586.687344] Testing event br_fdb_add: OK [ 587.447768] Testing event qdisc_dequeue: OK [ 588.252823] Testing event fib_table_lookup: OK [ 588.975026] Testing event tcp_probe: OK [ 589.631655] Testing event tcp_retransmit_synack: OK [ 590.134027] Testing event tcp_rcv_space_adjust: OK [ 590.876739] Testing event tcp_destroy_sock: OK [ 591.492886] Testing event tcp_receive_reset: OK [ 592.233412] Testing event tcp_send_reset: OK [ 592.821165] Testing event tcp_retransmit_skb: OK [ 593.286385] Testing event udp_fail_queue_rcv_skb: OK [ 594.083717] Testing event inet_sock_set_state: OK [ 594.593166] Testing event sock_exceed_buf_limit: OK [ 595.304695] Testing event sock_rcvqueue_full: OK [ 595.950955] Testing event napi_poll: OK [ 596.551841] Testing event netif_rx_ni_entry: OK [ 597.231742] Testing event netif_rx_entry: OK [ 597.864976] Testing event netif_receive_skb_list_entry: OK [ 598.297736] Testing event netif_receive_skb_entry: OK [ 598.978301] Testing event napi_gro_receive_entry: OK [ 599.607703] Testing event napi_gro_frags_entry: OK [ 600.489128] Testing event netif_rx: OK [ 601.197494] Testing event netif_receive_skb: OK [ 601.719483] Testing event net_dev_queue: OK [ 602.375643] Testing event net_dev_xmit: OK [ 603.232807] Testing event net_dev_start_xmit: OK [ 603.925344] Testing event skb_copy_datagram_iovec: OK [ 604.553752] Testing event consume_skb: OK [ 605.498413] Testing event kfree_skb: OK [ 606.081682] Testing event 9p_protocol_dump: OK [ 607.077189] Testing event 9p_client_res: OK [ 607.883605] Testing event 9p_client_req: OK [ 608.340786] Running tests on trace event systems: [ 608.351806] Testing event system 9p: OK [ 609.343805] Testing event system skb: OK [ 610.287816] Testing event system net: OK [ 611.038711] Testing event system napi: OK [ 611.699774] Testing event system sock: OK [ 612.580996] Testing event system udp: OK [ 613.163691] Testing event system tcp: OK [ 613.948613] Testing event system fib: OK [ 614.775586] Testing event system qdisc: OK [ 615.361176] Testing event system bridge: OK [ 616.048645] Testing event system binder: OK [ 617.428802] Testing event system ras: OK [ 618.292782] Testing event system rtc: OK [ 619.279787] Testing event system mdio: OK [ 620.108851] Testing event system spi: OK [ 620.858742] Testing event system sync_trace: OK [ 621.539507] Testing event system dma_fence: OK [ 622.423526] Testing event system regmap: OK [ 623.748778] Testing event system iommu: OK [ 624.808882] Testing event system random: OK [ 626.181110] Testing event system regulator: OK [ 627.025207] Testing event system rpmh: OK [ 628.049101] Testing event system clk: OK [ 629.104773] Testing event system gpio: OK [ 629.741070] Testing event system wbt: OK [ 630.420648] Testing event system block: OK [ 631.508691] Testing event system filelock: OK [ 632.473086] Testing event system fs_dax: OK [ 633.519751] Testing event system writeback: OK [ 634.767534] Testing event system page_ref: OK [ 638.853223] Testing event system cma: OK [ 639.641362] Testing event system page_isolation: OK [ 640.298081] Testing event system huge_memory: OK [ 641.053303] Testing event system migrate: OK [ 641.601191] Testing event system compaction: OK [ 642.502712] Testing event system kmem: OK [ 643.479718] Testing event system percpu: OK [ 644.388667] Testing event system vmscan: OK [ 645.285405] Testing event system pagemap: OK [ 645.987543] Testing event system oom: OK [ 646.640701] Testing event system filemap: OK [ 647.633599] Testing event system rseq: OK [ 648.296948] Testing event system xdp: OK [ 649.233101] Testing event system benchmark: OK [ 650.366309] Testing event system rpm: OK [ 651.183405] Testing event system power: OK [ 652.647822] Testing event system test: OK [ 653.627671] Testing event system preemptirq: OK [ 655.626455] Testing event system cgroup: OK [ 656.401017] Testing event system module: OK [ 657.203625] Testing event system alarmtimer: OK [ 657.749174] Testing event system timer: OK [ 658.652771] Testing event system swiotlb: OK [ 659.371220] Testing event system rcu: OK [ 660.972597] Testing event system printk: OK [ 661.872876] Testing event system lock: OK [ 662.232975] Testing event system sched: OK [ 663.248617] Testing event system workqueue: OK [ 664.175733] Testing event system signal: OK [ 665.173438] Testing event system irq: OK [ 665.952568] Testing event system cpuhp: OK [ 666.421083] Testing event system task: OK [ 666.935701] Testing event system kvm: OK [ 668.412753] Testing event system emulation: OK [ 669.440951] Testing event system ipi: OK [ 670.159720] Testing event system raw_syscalls: OK [ 670.881989] Testing event system initcall: OK [ 671.761351] Running tests on all trace events: [ 671.767936] Testing all events: OK [ 728.409551] Testing ftrace filter: OK [ 728.522080] trace_kprobe: Testing kprobe tracing: OK [ 728.929356] Loading compiled-in X.509 certificates [ 729.036940] _warn_unseeded_randomness: 7 callbacks suppressed [ 729.037175] random: get_random_bytes called from key_alloc+0x380/0x698 with crng_init=0 [ 729.039514] Loaded X.509 cert 'Build time autogenerated kernel key: 4054958e39d9099bc90ea5e944013505afd1c71c' [ 729.043350] page_owner is disabled [ 729.158927] Key type big_key registered [ 729.219550] Key type encrypted registered [ 729.222350] ima: No TPM chip found, activating TPM-bypass! [ 729.223203] ima: Allocated hash algorithm: sha1 [ 729.226922] No architecture policies found [ 729.233036] random: get_random_bytes called from prandom_seed_full_state+0xc0/0x198 with crng_init=0 [ 729.256554] hctosys: unable to open rtc device (rtc0) [ 729.272309] psci_checker: PSCI checker started using 1 CPUs [ 729.272949] psci_checker: Starting hotplug tests [ 729.273709] psci_checker: Trying to turn off and on again all CPUs [ 729.274689] psci_checker: Trying to turn off and on again group 0 (CPUs 0) [ 729.275573] psci_checker: Hotplug tests passed OK [ 729.276560] psci_checker: Starting suspend tests (10 cycles per state) [ 729.277343] psci_checker: cpuidle not available on CPU 0, ignoring [ 729.278158] psci_checker: Could not start suspend tests on any CPU [ 729.278767] psci_checker: PSCI checker completed [ 729.322985] Duplicate name in testcase-data, renamed to "duplicate-name#1" [ 729.516591] ### dt-test ### start of unittest - you will see error messages [ 729.543250] OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1 [ 729.544695] OF: /testcase-data/phandle-tests/consumer-a: could not get #phandle-cells-missing for /testcase-data/phandle-tests/provider1 [ 729.545697] OF: /testcase-data/phandle-tests/consumer-a: could not find phandle [ 729.546420] OF: /testcase-data/phandle-tests/consumer-a: could not find phandle [ 729.547235] OF: /testcase-data/phandle-tests/consumer-a: arguments longer than property [ 729.548594] OF: /testcase-data/phandle-tests/consumer-a: arguments longer than property [ 729.565506] OF: /testcase-data/phandle-tests/consumer-b: could not get #phandle-missing-cells for /testcase-data/phandle-tests/provider1 [ 729.567208] OF: /testcase-data/phandle-tests/consumer-b: could not find phandle [ 729.569283] OF: /testcase-data/phandle-tests/consumer-b: arguments longer than property [ 729.972488] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest0/status [ 730.021474] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest1/status [ 730.043697] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest2/status [ 730.090540] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest3/status [ 730.165001] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest5/status [ 730.229885] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest6/status [ 730.273417] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest7/status [ 730.350007] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest8/status [ 730.393397] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data/overlay-node/test-bus/test-unittest8/property-foo [ 730.395289] OF: overlay: node_overlaps_later_cs: #6 overlaps with #7 @/testcase-data/overlay-node/test-bus/test-unittest8 [ 730.396631] OF: overlay: overlay #6 is not topmost [ 730.660530] OF: overlay: remove: Could not find overlay #7 [ 730.661200] ### dt-test ### of_unittest_destroy_tracked_overlays: no overlay to destroy for #7 [ 730.886416] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/substation@100/status [ 730.891525] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/fairway-1/status [ 730.894176] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/fairway-1/ride@100/track@30/incline-up [ 730.895706] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/fairway-1/ride@100/track@40/incline-up [ 730.908304] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/lights@40000/status [ 730.909362] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/lights@40000/color [ 730.910671] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/lights@40000/rate [ 730.912696] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /__symbols__/hvac_2 [ 730.914152] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /__symbols__/ride_200 [ 730.915472] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /__symbols__/ride_200_left [ 730.917309] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /__symbols__/ride_200_right [ 731.018420] OF: overlay: ERROR: multiple fragments add and/or delete node /testcase-data-2/substation@100/motor-1/controller [ 731.022312] OF: overlay: ERROR: multiple fragments add, update, and/or delete property /testcase-data-2/substation@100/motor-1/controller/name [ 731.033818] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/substation@100/motor-1/rpm_avail [ 731.035263] OF: overlay: WARNING: memory leak will occur if overlay removed, property: /testcase-data-2/substation@100/motor-1/rpm_avail [ 731.037128] OF: overlay: ERROR: multiple fragments add, update, and/or delete property /testcase-data-2/substation@100/motor-1/rpm_avail [ 731.054783] ### dt-test ### end of unittest - 217 passed, 0 failed [ 731.074006] uart-pl011 9000000.pl011: no DMA platform data [ 731.428803] random: get_random_u64 called from kmem_cache_open+0x38/0x1d8 with crng_init=0 [ 731.429887] random: get_random_u64 called from cache_random_seq_create+0x64/0x110 with crng_init=0 [ 731.472844] VFS: Mounted root (9p filesystem) readonly on device 0:18. [ 731.491621] devtmpfs: mounted [ 732.182136] Freeing unused kernel memory: 4096K [ 732.203175] Checked W+X mappings: passed, no W+X pages found [ 732.204486] rodata_test: all tests were successful [ 732.205464] Run /sbin/init as init process [ 732.321761] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=0 [ 732.649328] _warn_unseeded_randomness: 4 callbacks suppressed [ 732.649532] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=0 [ 733.271692] random: fast init done [ 736.489917] systemd[1]: System time before build time, advancing clock. [ 736.991034] systemd[1]: Failed to insert module 'autofs4': No such file or directory [ 740.376748] random: systemd: uninitialized urandom read (16 bytes read) [ 740.734357] random: systemd: uninitialized urandom read (16 bytes read) [ 740.739209] random: systemd: uninitialized urandom read (16 bytes read) [ 746.212819] systemd[1]: systemd 232 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN) [ 746.291540] systemd[1]: Detected virtualization qemu. [ 746.299469] systemd[1]: Detected architecture arm64. Welcome to Debian GNU/Linux 9 (stretch)! [ 746.450721] systemd[1]: Set hostname to . [ 746.633492] random: get_random_u32 called from bucket_table_alloc+0x130/0x1a8 with crng_init=1 [ 746.691449] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=1 [ 747.308542] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 747.829520] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 747.830494] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 747.831229] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 748.947035] _warn_unseeded_randomness: 20 callbacks suppressed [ 748.947230] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 748.982089] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 748.983091] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 750.162357] random: systemd: uninitialized urandom read (16 bytes read) [ 750.289849] _warn_unseeded_randomness: 11 callbacks suppressed [ 750.290088] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 750.291662] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 750.298731] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=1 [ 751.959375] _warn_unseeded_randomness: 11 callbacks suppressed [ 751.959562] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 751.961314] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 751.962051] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 753.063131] _warn_unseeded_randomness: 9 callbacks suppressed [ 753.063322] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=1 [ 754.122426] systemd-hiberna (1258) used greatest stack depth: 10576 bytes left [ 754.802614] systemd-rc-loca (1259) used greatest stack depth: 10544 bytes left [ 755.905219] random: systemd-cryptse: uninitialized urandom read (16 bytes read) [ 756.693267] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read) [ 757.781738] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read) [ 759.277264] systemd-sysv-ge (1263) used greatest stack depth: 10448 bytes left [ 759.581993] random: systemd: uninitialized urandom read (16 bytes read) [ 759.829702] random: systemd: uninitialized urandom read (16 bytes read) [ 759.834111] random: systemd: uninitialized urandom read (16 bytes read) [ 767.558468] systemd[1]: networking.service: Cannot add dependency job, ignoring: Unit networking.service is masked. [ 767.630199] random: get_random_bytes called from generate_random_uuid+0x20/0x50 with crng_init=1 [ 767.695578] systemd[1]: Listening on Syslog Socket. [ OK ] Listening on Syslog Socket. [ 767.761025] systemd[1]: Listening on udev Control Socket. [ OK ] Listening on udev Control Socket. [ 767.793796] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe. [ OK ] Listening on /dev/initctl Compatibility Named Pipe. [ 767.820341] systemd[1]: Listening on Journal Socket (/dev/log). [ OK ] Listening on Journal Socket (/dev/log). [ 767.910049] systemd[1]: Created slice System Slice. [ OK ] Created slice System Slice. [ 768.111118] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 768.214158] systemd[1]: Mounting Debug File System... Mounting Debug File System... [ 768.262350] systemd[1]: Reached target Slices. [ OK ] Reached target Slices. [ 768.848612] systemd[1]: Mounting POSIX Message Queue File System... [ 768.903131] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 768.904488] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 768.905196] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 Mounting POSIX Message Queue File System... [ 769.070302] systemd[1]: Created slice system-serial\x2dgetty.slice. [ OK ] Created slice system-serial\x2dgetty.slice. [ OK ] Listening on Journal Socket. [ 769.923312] _warn_unseeded_randomness: 8 callbacks suppressed [ 769.923499] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 769.931186] random: get_random_bytes called from create_elf_tables+0x10c/0xd18 with crng_init=1 [ 770.005355] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=1 Starting Load Kernel Modules... [ 771.090961] _warn_unseeded_randomness: 1 callbacks suppressed [ 771.091149] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 771.093101] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 771.093908] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 Mounting Huge Pages File System... [ 773.033472] systemd[1]: Created slice system-getty.slice. [ OK ] Created slice system-getty.slice. [ 773.413626] _warn_unseeded_randomness: 12 callbacks suppressed [ 773.413839] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 773.554308] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 773.555199] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 774.470804] _warn_unseeded_randomness: 3 callbacks suppressed [ 774.471000] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 774.805355] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 774.806302] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 775.385237] systemd[1]: Starting Remount Root and Kernel File Systems... Starting Remount Root and Kernel File Systems... [ 775.530008] _warn_unseeded_randomness: 5 callbacks suppressed [ 775.530212] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 775.650125] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 775.651142] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 775.656502] systemd[1]: Listening on udev Kernel Socket. [ OK ] Listening on udev Kernel Socket. [ 776.926252] _warn_unseeded_randomness: 3 callbacks suppressed [ 776.926446] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 776.927516] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 777.029463] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=1 [ 777.861842] systemd[1]: Starting Create Static Device Nodes in /dev... Starting Create Static Device Nodes in /dev... [ 778.078269] systemd[1]: Reached target Remote File Systems. [ OK ] Reached target Remote File Systems. [ 778.258674] systemd[1]: Starting of Arbitrary Executable File Formats File System Automount Point not supported. [UNSUPP] Starting of Arbitrary Executable Fi…tem Automount Point not supported. [ 778.980602] systemd[1]: Reached target Swap. [ OK ] Reached target Swap. [ 779.206286] _warn_unseeded_randomness: 4 callbacks suppressed [ 779.206473] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 779.207742] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 779.208999] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 779.276665] systemd[1]: Started Forward Password Requests to Wall Directory Watch. [ OK ] Started Forward Password Requests to Wall Directory Watch. [ 779.491598] systemd[1]: Listening on Journal Audit Socket. [ OK ] Listening on Journal Audit Socket. [ 779.592518] systemd[1]: Reached target Sockets. [ OK ] Reached target Sockets. [ 780.266654] _warn_unseeded_randomness: 10 callbacks suppressed [ 780.266851] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 780.268974] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 780.285653] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 780.950977] systemd[1]: Starting Journal Service... Starting Journal Service... [ 781.369878] systemd[1]: Started Dispatch Password Requests to Console Directory Watch. [ OK ] Started Dispatch Password Requests to Console Directory Watch. [ 781.513789] systemd[1]: Reached target Paths. [ OK ] Reached target Paths. [ 781.630853] systemd[1]: Reached target Encrypted Volumes. [ OK ] Reached target Encrypted Volumes. [ 783.550548] _warn_unseeded_randomness: 2 callbacks suppressed [ 783.550735] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 783.552454] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 783.553247] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 784.495376] systemd[1]: Mounted Debug File System. [ OK ] Mounted Debug File System. [ 784.561847] systemd[1]: Mounted Huge Pages File System. [ OK ] Mounted Huge Pages File System. [ 784.638280] systemd[1]: Mounted POSIX Message Queue File System. [ OK ] Mounted POSIX Message Queue File System. [ 785.442631] systemd[1]: Started Load Kernel Modules. [ OK ] Started Load Kernel Modules. [ 785.860854] _warn_unseeded_randomness: 2 callbacks suppressed [ 785.861049] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 786.034717] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 786.035633] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 786.378895] systemd[1]: Started Remount Root and Kernel File Systems. [ OK ] Started Remount Root and Kernel File Systems. [ 787.858240] _warn_unseeded_randomness: 3 callbacks suppressed [ 787.858435] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 788.432825] systemd[1]: Starting Load/Save Random Seed... Starting Load/Save Random Seed... [ 788.638166] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 788.639059] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 789.291127] _warn_unseeded_randomness: 2 callbacks suppressed [ 789.291352] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=1 [ 789.911765] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 790.072964] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 790.410717] systemd[1]: Starting udev Coldplug all Devices... Starting udev Coldplug all Devices... [ 790.682018] _warn_unseeded_randomness: 5 callbacks suppressed [ 790.682219] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=1 [ 791.550895] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 792.115621] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 792.117045] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 792.117810] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 792.262850] systemd[1]: Starting Apply Kernel Variables... Starting Apply Kernel Variables... [ 793.508957] _warn_unseeded_randomness: 4 callbacks suppressed [ 793.509156] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 793.908929] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 793.909878] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 794.067070] systemd-journald[1279]: /dev/kmsg buffer overrun, some messages lost. [ 794.124755] systemd[1]: Mounting Configuration File System... Mounting Configuration File System... [ 794.816775] _warn_unseeded_randomness: 5 callbacks suppressed [ 794.816973] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 795.017135] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 795.018094] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 797.199177] _warn_unseeded_randomness: 3 callbacks suppressed [ 797.199373] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 797.201100] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 797.307883] random: get_random_u32 called from shuffle_freelist+0x64/0x218 with crng_init=1 [ 798.691082] systemd[1]: Started Create Static Device Nodes in /dev. [ OK ] Started Create Static Device Nodes in /dev. [ 799.578815] _warn_unseeded_randomness: 3 callbacks suppressed [ 799.579013] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 799.737200] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 799.738112] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 800.182921] systemd[1]: Started Load/Save Random Seed. [ OK ] Started Load/Save Random Seed. [ 801.544824] systemd[1]: Started Apply Kernel Variables. [ OK ] Started Apply Kernel Variables. [ 802.884976] _warn_unseeded_randomness: 3 callbacks suppressed [ 802.885173] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 803.004479] systemd[1]: Mounted Configuration File System. [ 803.029052] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 803.030089] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ OK ] Mounted Configuration File System. [ 804.887027] _warn_unseeded_randomness: 3 callbacks suppressed [ 804.887225] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ 805.391196] systemd[1]: Starting udev Kernel Device Manager... Starting udev Kernel Device Manager... [ 805.585444] systemd[1]: Reached target Local File Systems (Pre). [ OK ] Reached target Local File Systems (Pre). [ 805.734966] systemd[1]: Reached target Local File Systems. [ OK ] Reached target Local File Systems. [ 807.502934] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 807.504442] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 807.505164] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [* ] (1 of 4) A start job is running for dev-ttyAMA0.device (43s / 30min) [** ] (1 of 4) A start job is running for dev-ttyAMA0.device (44s / 30min) [*** ] (1 of 4) A start job is running for dev-ttyAMA0.device (44s / 30min) [ *** ] (2 of 4) A start job is running for…l Device Manager (45s / 30min 37s) [ *** ] (2 of 4) A start job is running for…l Device Manager (45s / 30min 37s) [ ***] (2 of 4) A start job is running for…l Device Manager (46s / 30min 37s) [ **] (3 of 4) A start job is running for Journal Service (46s / 30min 12s) [ *] (3 of 4) A start job is running for Journal Service (47s / 30min 12s) [ **] (3 of 4) A start job is running for Journal Service (47s / 30min 12s) [ ***] (4 of 4) A start job is running for…dplug all Devices (48s / no limit) [ *** ] (4 of 4) A start job is running for…dplug all Devices (48s / no limit) [ *** ] (4 of 4) A start job is running for…dplug all Devices (49s / no limit) [*** ] (1 of 4) A start job is running for dev-ttyAMA0.device (49s / 30min) [** ] (1 of 4) A start job is running for dev-ttyAMA0.device (50s / 30min) [* ] (1 of 4) A start job is running for dev-ttyAMA0.device (50s / 30min) [** ] (2 of 4) A start job is running for…l Device Manager (51s / 30min 37s) [*** ] (2 of 4) A start job is running for…l Device Manager (51s / 30min 37s) [ *** ] (2 of 4) A start job is running for…l Device Manager (52s / 30min 37s) [ *** ] (3 of 4) A start job is running for Journal Service (52s / 30min 12s)[ 820.775033] systemd[1]: Started udev Kernel Device Manager. [ OK ] Started udev Kernel Device Manager. [ 825.651501] _warn_unseeded_randomness: 4 callbacks suppressed [ 825.651702] random: get_random_u64 called from dup_task_struct+0xdc/0x3c8 with crng_init=1 [ ***] (1 of 3) A start job is running for dev-ttyAMA0.device (58s / 30min) [ **] (1 of 3) A start job is running for dev-ttyAMA0.device (58s / 30min) [ *] (2 of 3) A start job is running for Journal Service (59s / 30min 12s) [ **] (2 of 3) A start job is running for Journal Service (59s / 30min 12s) [ ***] (2 of 3) A start job is running for Journal Service (1min / 30min 12s) [ *** ] (3 of 3) A start job is running for…plug all Devices (1min / no limit) [ *** ] (3 of 3) A start job is running for…g all Devices (1min 1s / no limit) [*** ] (3 of 3) A start job is running for…g all Devices (1min 1s / no limit) [** ] (1 of 3) A start job is running for…v-ttyAMA0.device (1min 2s / 30min) [* ] (1 of 3) A start job is running for…v-ttyAMA0.device (1min 2s / 30min) [** ] (1 of 3) A start job is running for…v-ttyAMA0.device (1min 3s / 30min) [*** ] (2 of 3) A start job is running for…rnal Service (1min 3s / 30min 12s) [ *** ] (2 of 3) A start job is running for…rnal Service (1min 4s / 30min 12s) [ *** ] (2 of 3) A start job is running for…rnal Service (1min 4s / 30min 12s) [ ***] (3 of 3) A start job is running for…g all Devices (1min 5s / no limit)[ 833.454670] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ 833.455582] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 833.456923] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ **] (3 of 3) A start job is running for…g all Devices (1min 6s / no limit) [ *] (3 of 3) A start job is running for…g all Devices (1min 7s / no limit) [ **] (1 of 3) A start job is running for…v-ttyAMA0.device (1min 7s / 30min)[ 835.462677] _warn_unseeded_randomness: 4 callbacks suppressed [ 835.462874] random: get_random_u64 called from randomize_stack_top+0x38/0x80 with crng_init=1 [ 835.464573] random: get_random_u32 called from arch_align_stack+0x40/0x60 with crng_init=1 [ 835.665857] random: get_random_u64 called from arch_mmap_rnd+0x98/0xb0 with crng_init=1 [ ***] (1 of 3) A start job is running for…v-ttyAMA0.device (1min 8s / 30min) [ *** ] (1 of 3) A start job is running for…v-ttyAMA0.device (1min 8s / 30min) [ *** ] (2 of 3) A start job is running for…rnal Service (1min 9s / 30min 12s) [*** ] (2 of 3) A start job is running for…rnal Service (1min 9s / 30min 12s) [** ] (2 of 3) A start job is running for…nal Service (1min 10s / 30min 12s) [* ] (3 of 3) A start job is running for… all Devices (1min 10s / no limit) [** ] (3 of 3) A start job is running for… all Devices (1min 11s / no limit) [*** ] (3 of 3) A start job is running for… all Devices (1min 11s / no limit) [ *** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 12s / 30min) [ *** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 12s / 30min) [ ***] (1 of 3) A start job is running for…-ttyAMA0.device (1min 13s / 30min) [ **] (2 of 3) A start job is running for…nal Service (1min 13s / 30min 12s) [ *] (2 of 3) A start job is running for…nal Service (1min 14s / 30min 12s) [ **] (2 of 3) A start job is running for…nal Service (1min 14s / 30min 12s) [ ***] (3 of 3) A start job is running for… all Devices (1min 15s / no limit)[ 843.104324] _warn_unseeded_randomness: 1 callbacks suppressed [ 843.104522] random: get_random_bytes called from __prandom_timer+0x30/0x98 with crng_init=1 [ *** ] (3 of 3) A start job is running for… all Devices (1min 15s / no limit) [ *** ] (3 of 3) A start job is running for… all Devices (1min 16s / no limit) [*** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 16s / 30min) [** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 17s / 30min) [* ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 17s / 30min) [** ] (2 of 3) A start job is running for…nal Service (1min 18s / 30min 12s) [*** ] (2 of 3) A start job is running for…nal Service (1min 18s / 30min 12s) [ *** ] (2 of 3) A start job is running for…nal Service (1min 19s / 30min 12s) [ *** ] (3 of 3) A start job is running for… all Devices (1min 19s / no limit) [ ***] (3 of 3) A start job is running for… all Devices (1min 20s / no limit) [ **] (3 of 3) A start job is running for… all Devices (1min 20s / no limit) [ *] (1 of 3) A start job is running for…-ttyAMA0.device (1min 21s / 30min) [ **] (1 of 3) A start job is running for…-ttyAMA0.device (1min 21s / 30min) [ ***] (1 of 3) A start job is running for…-ttyAMA0.device (1min 22s / 30min)[ 850.109466] random: crng init done [ *** ] (2 of 3) A start job is running for…nal Service (1min 22s / 30min 12s) [ *** ] (2 of 3) A start job is running for…nal Service (1min 23s / 30min 12s) [*** ] (2 of 3) A start job is running for…nal Service (1min 23s / 30min 12s) [** ] (3 of 3) A start job is running for… all Devices (1min 24s / no limit)[ 851.879380] systemd[1]: Started Journal Service. [ OK ] Started Journal Service. Starting Flush Journal to Persistent Storage... [* ] (3 of 3) A start job is running for… all Devices (1min 29s / no limit) [** ] (3 of 3) A start job is running for… all Devices (1min 30s / no limit)[ 857.966931] systemd-journald[1279]: Received request to flush runtime journal from PID 1 [*** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 30s / 30min) [ OK ] Started Flush Journal to Persistent Storage. Starting Create Volatile Files and Directories... [ *** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 36s / 30min) [ *** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 37s / 30min) [ ***] (2 of 3) A start job is running for… Directories (1min 37s / no limit) [ **] (2 of 3) A start job is running for… Directories (1min 38s / no limit) [ *] (2 of 3) A start job is running for… Directories (1min 38s / no limit) [ **] (3 of 3) A start job is running for… all Devices (1min 39s / no limit) [ ***] (3 of 3) A start job is running for… all Devices (1min 39s / no limit) [ *** ] (3 of 3) A start job is running for… all Devices (1min 40s / no limit) [ *** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 40s / 30min) [*** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 41s / 30min) [** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 41s / 30min) [* ] (2 of 3) A start job is running for… Directories (1min 42s / no limit) [** ] (2 of 3) A start job is running for… Directories (1min 42s / no limit) [*** ] (2 of 3) A start job is running for… Directories (1min 43s / no limit) [ *** ] (3 of 3) A start job is running for… all Devices (1min 43s / no limit) [ *** ] (3 of 3) A start job is running for… all Devices (1min 44s / no limit) [ ***] (3 of 3) A start job is running for… all Devices (1min 44s / no limit) [ **] (1 of 3) A start job is running for…-ttyAMA0.device (1min 45s / 30min) [ *] (1 of 3) A start job is running for…-ttyAMA0.device (1min 45s / 30min) [ **] (1 of 3) A start job is running for…-ttyAMA0.device (1min 46s / 30min) [ ***] (2 of 3) A start job is running for… Directories (1min 46s / no limit) [ *** ] (2 of 3) A start job is running for… Directories (1min 47s / no limit) [ *** ] (2 of 3) A start job is running for… Directories (1min 47s / no limit) [*** ] (3 of 3) A start job is running for… all Devices (1min 48s / no limit) [** ] (3 of 3) A start job is running for… all Devices (1min 48s / no limit) [* ] (3 of 3) A start job is running for… all Devices (1min 49s / no limit) [** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 49s / 30min) [*** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 50s / 30min) [ *** ] (1 of 3) A start job is running for…-ttyAMA0.device (1min 50s / 30min) [ *** ] (2 of 3) A start job is running for… Directories (1min 51s / no limit) [ ***] (2 of 3) A start job is running for… Directories (1min 51s / no limit) [ **] (2 of 3) A start job is running for… Directories (1min 52s / no limit) [ OK ] Started Create Volatile Files and Directories. Starting Update UTMP about System Boot/Shutdown... Starting Network Time Synchronization... [ *] (4 of 4) A start job is running for…hronization (1min 59s / 31min 57s) [ **] (4 of 4) A start job is running for…Synchronization (2min / 31min 57s) [ ***] (4 of 4) A start job is running for…Synchronization (2min / 31min 57s) [ *** ] (1 of 4) A start job is running for…v-ttyAMA0.device (2min 1s / 30min) [ *** ] (1 of 4) A start job is running for…v-ttyAMA0.device (2min 2s / 30min) [*** ] (1 of 4) A start job is running for…v-ttyAMA0.device (2min 2s / 30min) [ OK ] Started Update UTMP about System Boot/Shutdown. [** ] (2 of 3) A start job is running for…g all Devices (2min 8s / no limit) [* ] (2 of 3) A start job is running for…g all Devices (2min 9s / no limit) [** ] (2 of 3) A start job is running for…g all Devices (2min 9s / no limit) [*** ] (3 of 3) A start job is running for…hronization (2min 10s / 31min 57s) [ *** ] (3 of 3) A start job is running for…hronization (2min 10s / 31min 57s) [ *** ] (3 of 3) A start job is running for…hronization (2min 11s / 31min 57s) [ ***] (1 of 3) A start job is running for…-ttyAMA0.device (2min 11s / 30min) [ **] (1 of 3) A start job is running for…-ttyAMA0.device (2min 12s / 30min) [ *] (1 of 3) A start job is running for…-ttyAMA0.device (2min 12s / 30min) [ **] (2 of 3) A start job is running for… all Devices (2min 13s / no limit) [ ***] (2 of 3) A start job is running for… all Devices (2min 13s / no limit) [ *** ] (2 of 3) A start job is running for… all Devices (2min 14s / no limit) [ *** ] (3 of 3) A start job is running for…hronization (2min 14s / 31min 57s) [*** ] (3 of 3) A start job is running for…hronization (2min 15s / 31min 57s) [** ] (3 of 3) A start job is running for…hronization (2min 15s / 31min 57s) [* ] (1 of 3) A start job is running for…-ttyAMA0.device (2min 16s / 30min) [ OK ] Started Network Time Synchronization. [ OK ] Reached target System Time Synchronized. [** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 22s / 30min) [*** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 22s / 30min) [ *** ] (2 of 2) A start job is running for… all Devices (2min 23s / no limit) [ *** ] (2 of 2) A start job is running for… all Devices (2min 23s / no limit) [ ***] (2 of 2) A start job is running for… all Devices (2min 24s / no limit) [ **] (1 of 2) A start job is running for…-ttyAMA0.device (2min 24s / 30min) [ *] (1 of 2) A start job is running for…-ttyAMA0.device (2min 25s / 30min) [ **] (1 of 2) A start job is running for…-ttyAMA0.device (2min 25s / 30min) [ ***] (2 of 2) A start job is running for… all Devices (2min 26s / no limit) [ *** ] (2 of 2) A start job is running for… all Devices (2min 26s / no limit) [ *** ] (2 of 2) A start job is running for… all Devices (2min 27s / no limit) [*** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 27s / 30min) [** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 28s / 30min) [* ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 28s / 30min) [** ] (2 of 2) A start job is running for… all Devices (2min 29s / no limit) [*** ] (2 of 2) A start job is running for… all Devices (2min 29s / no limit) [ *** ] (2 of 2) A start job is running for… all Devices (2min 30s / no limit) [ *** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 30s / 30min) [ ***] (1 of 2) A start job is running for…-ttyAMA0.device (2min 31s / 30min) [ **] (1 of 2) A start job is running for…-ttyAMA0.device (2min 31s / 30min) [ *] (2 of 2) A start job is running for… all Devices (2min 32s / no limit) [ **] (2 of 2) A start job is running for… all Devices (2min 32s / no limit) [ ***] (2 of 2) A start job is running for… all Devices (2min 33s / no limit) [ *** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 33s / 30min) [ *** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 34s / 30min) [*** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 34s / 30min) [** ] (2 of 2) A start job is running for… all Devices (2min 35s / no limit) [* ] (2 of 2) A start job is running for… all Devices (2min 35s / no limit) [** ] (2 of 2) A start job is running for… all Devices (2min 36s / no limit) [*** ] (1 of 2) A start job is running for…-ttyAMA0.device (2min 36s / 30min) [ OK ] Found device /dev/ttyAMA0. [ 927.425467] virtio_net virtio0 enp0s1: renamed from eth0 [ *** ] A start job is running for udev Col… all Devices (2min 43s / no limit) [ *** ] A start job is running for udev Col… all Devices (2min 43s / no limit) [ ***] A start job is running for udev Col… all Devices (2min 44s / no limit) [ **] A start job is running for udev Col… all Devices (2min 44s / no limit) [ OK ] Started udev Coldplug all Devices. [ OK ] Reached target System Initialization. [ OK ] Reached target Basic System. Starting getty on tty2-tty6 if dbus and logind are not available... Starting System Logging Service... [ OK ] Started Daily apt upgrade and clean activities. Starting Permit User Sessions... [ OK ] Started Regular background program processing daemon. [ OK ] Started Daily Cleanup of Temporary Directories. [ OK ] Reached target Timers. [ OK ] Started System Logging Service. [ OK ] Started Permit User Sessions. [ *] A start job is running for getty on…ot available (3min 15s / no limit) [ **] A start job is running for getty on…ot available (3min 18s / no limit) [ ***] A start job is running for getty on…ot available (3min 22s / no limit) [ *** ] A start job is running for getty on…ot available (3min 24s / no limit) [ *** ] A start job is running for getty on…ot available (3min 27s / no limit) [*** ] A start job is running for getty on…ot available (3min 30s / no limit) [** ] A start job is running for getty on…ot available (3min 31s / no limit) [ OK ] Started Getty on tty6. [ OK ] Started Getty on tty5. [ OK ] Started Getty on tty4. [ OK ] Started Getty on tty3. [ OK ] Started Getty on tty1. [ OK ] Started Serial Getty on ttyAMA0. [ OK ] Started Getty on tty2. Starting Cleanup of Temporary Directories... [ OK ] Started getty on tty2-tty6 if dbus and logind are not available. Debian GNU/Linux 9 compilator ttyAMA0 compilator login: