BUG: KCSAN: data-race in ext4_fill_raw_inode / setattr_copy

From: Paul Menzel
Date: Mon Feb 07 2022 - 14:17:09 EST

Dear Linux folks,


Running Linux 5.17-rc2+ in QEMU 6.2.0, while running `apt install bluez bluez-obexd bash-completion` in the VM the Kernel Concurrency Sanitizer reports the race below.

qemu-system-x86_64 -cpu host -smp cpus=3 -m 2G -enable-kvm -usb -device usb-host,vendorid=0x8087,productid=0x0a2a -drive file=/dev/shm/debian-64.img,format=raw,if=virtio -net nic -net user,hostfwd=tcp::22223-:22 -kernel /dev/shm/bzImage -append "root=/dev/vda1 rw quiet"

```
[ 283.432792] ==================================================================
[ 283.433607] BUG: KCSAN: data-race in ext4_fill_raw_inode / setattr_copy

[ 283.434585] read to 0xffffa07f951c9c50 of 8 bytes by task 7 on cpu 1:
[ 283.435145] ext4_fill_raw_inode+0x2d9/0xa40
[ 283.435161] ext4_mark_iloc_dirty+0x25b/0xbf0
[ 283.435177] __ext4_mark_inode_dirty+0xb3/0x3a0
[ 283.435194] __ext4_ext_dirty+0x115/0x130
[ 283.435212] ext4_ext_map_blocks+0x1a12/0x2740
[ 283.435230] ext4_map_blocks+0x2e1/0x9e0
[ 283.435245] ext4_convert_unwritten_extents+0x210/0x320
[ 283.435265] ext4_convert_unwritten_io_end_vec+0xad/0x130
[ 283.435283] ext4_end_io_rsv_work+0x180/0x310
[ 283.435296] process_one_work+0x477/0x7d0
[ 283.435304] worker_thread+0x2ec/0x810
[ 283.435312] kthread+0x16d/0x1a0
[ 283.435322] ret_from_fork+0x22/0x30

[ 283.435599] write to 0xffffa07f951c9c50 of 16 bytes by task 1509 on cpu 0:
[ 283.436138] setattr_copy+0x94/0x160
[ 283.436156] ext4_setattr+0x30f/0xf20
[ 283.436170] notify_change+0x34d/0x640
[ 283.436187] vfs_utimes+0x225/0x3d0
[ 283.436205] do_utimes+0xab/0x110
[ 283.436221] __x64_sys_utimensat+0xa9/0x100
[ 283.436240] do_syscall_64+0x39/0x80
[ 283.436257] entry_SYSCALL_64_after_hwframe+0x44/0xae

[ 283.436634] Reported by Kernel Concurrency Sanitizer on:
[ 283.437154] CPU: 0 PID: 1509 Comm: dpkg Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 283.437173] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 283.437184] ==================================================================
```

Please find the output of `dmesg` attached.


Kind regards,

Paul[ 0.000000] Linux version 5.17.0-rc3-00369-gc67afd79c7ba (pmenzel@xxxxxxxxxxxxxxxxxxxxx) (gcc (GCC) 11.1.0, GNU ld (GNU Binutils) 2.37) #35 SMP PREEMPT Mon Feb 7 19:15:32 CET 2022
[ 0.000000] Command line: root=/dev/vda1 rw quiet
[ 0.000000] x86/fpu: Supporting XSAVE feature 0x001: 'x87 floating point registers'
[ 0.000000] x86/fpu: Supporting XSAVE feature 0x002: 'SSE registers'
[ 0.000000] x86/fpu: Supporting XSAVE feature 0x004: 'AVX registers'
[ 0.000000] x86/fpu: xstate_offset[2]: 576, xstate_sizes[2]: 256
[ 0.000000] x86/fpu: Enabled xstate features 0x7, context size is 832 bytes, using 'standard' format.
[ 0.000000] signal: max sigframe size: 1776
[ 0.000000] BIOS-provided physical RAM map:
[ 0.000000] BIOS-e820: [mem 0x0000000000000000-0x000000000009fbff] usable
[ 0.000000] BIOS-e820: [mem 0x000000000009fc00-0x000000000009ffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000000f0000-0x00000000000fffff] reserved
[ 0.000000] BIOS-e820: [mem 0x0000000000100000-0x000000007ffdafff] usable
[ 0.000000] BIOS-e820: [mem 0x000000007ffdb000-0x000000007fffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000feffc000-0x00000000feffffff] reserved
[ 0.000000] BIOS-e820: [mem 0x00000000fffc0000-0x00000000ffffffff] reserved
[ 0.000000] NX (Execute Disable) protection: active
[ 0.000000] SMBIOS 2.8 present.
[ 0.000000] DMI: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 0.000000] tsc: Fast TSC calibration using PIT
[ 0.000000] tsc: Detected 2594.006 MHz processor
[ 0.004348] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[ 0.004372] e820: remove [mem 0x000a0000-0x000fffff] usable
[ 0.004388] last_pfn = 0x7ffdb max_arch_pfn = 0x400000000
[ 0.004442] x86/PAT: Configuration [0-7]: WB WC UC- UC WB WP UC- WT
[ 0.012572] found SMP MP-table at [mem 0x000f5b90-0x000f5b9f]
[ 0.012704] Using GB pages for direct mapping
[ 0.012929] ACPI: Early table checksum verification disabled
[ 0.012960] ACPI: RSDP 0x00000000000F59D0 000014 (v00 BOCHS )
[ 0.012978] ACPI: RSDT 0x000000007FFE19C5 000034 (v01 BOCHS BXPC 00000001 BXPC 00000001)
[ 0.013005] ACPI: FACP 0x000000007FFE1869 000074 (v01 BOCHS BXPC 00000001 BXPC 00000001)
[ 0.013025] ACPI: DSDT 0x000000007FFE0040 001829 (v01 BOCHS BXPC 00000001 BXPC 00000001)
[ 0.013041] ACPI: FACS 0x000000007FFE0000 000040
[ 0.013054] ACPI: APIC 0x000000007FFE18DD 000088 (v01 BOCHS BXPC 00000001 BXPC 00000001)
[ 0.013070] ACPI: HPET 0x000000007FFE1965 000038 (v01 BOCHS BXPC 00000001 BXPC 00000001)
[ 0.013086] ACPI: WAET 0x000000007FFE199D 000028 (v01 BOCHS BXPC 00000001 BXPC 00000001)
[ 0.013101] ACPI: Reserving FACP table memory at [mem 0x7ffe1869-0x7ffe18dc]
[ 0.013107] ACPI: Reserving DSDT table memory at [mem 0x7ffe0040-0x7ffe1868]
[ 0.013114] ACPI: Reserving FACS table memory at [mem 0x7ffe0000-0x7ffe003f]
[ 0.013120] ACPI: Reserving APIC table memory at [mem 0x7ffe18dd-0x7ffe1964]
[ 0.013126] ACPI: Reserving HPET table memory at [mem 0x7ffe1965-0x7ffe199c]
[ 0.013132] ACPI: Reserving WAET table memory at [mem 0x7ffe199d-0x7ffe19c4]
[ 0.013218] ACPI: CEDT not present
[ 0.013442] No NUMA configuration found
[ 0.013446] Faking a node at [mem 0x0000000000000000-0x000000007ffdafff]
[ 0.013457] NODE_DATA(0) allocated [mem 0x7ffd7000-0x7ffdafff]
[ 0.013495] Zone ranges:
[ 0.013498] DMA [mem 0x0000000000001000-0x0000000000ffffff]
[ 0.013506] DMA32 [mem 0x0000000001000000-0x000000007ffdafff]
[ 0.013514] Normal empty
[ 0.013519] Movable zone start for each node
[ 0.013522] Early memory node ranges
[ 0.013525] node 0: [mem 0x0000000000001000-0x000000000009efff]
[ 0.013532] node 0: [mem 0x0000000000100000-0x000000007ffdafff]
[ 0.013540] Initmem setup node 0 [mem 0x0000000000001000-0x000000007ffdafff]
[ 0.013849] On node 0, zone DMA: 1 pages in unavailable ranges
[ 0.013870] On node 0, zone DMA: 97 pages in unavailable ranges
[ 0.020928] On node 0, zone DMA32: 37 pages in unavailable ranges
[ 0.021880] ACPI: PM-Timer IO Port: 0x608
[ 0.021911] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
[ 0.021974] IOAPIC[0]: apic_id 0, version 17, address 0xfec00000, GSI 0-23
[ 0.021986] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
[ 0.021995] ACPI: INT_SRC_OVR (bus 0 bus_irq 5 global_irq 5 high level)
[ 0.022006] ACPI: INT_SRC_OVR (bus 0 bus_irq 9 global_irq 9 high level)
[ 0.022023] ACPI: INT_SRC_OVR (bus 0 bus_irq 10 global_irq 10 high level)
[ 0.022035] ACPI: INT_SRC_OVR (bus 0 bus_irq 11 global_irq 11 high level)
[ 0.022086] ACPI: Using ACPI (MADT) for SMP configuration information
[ 0.022095] ACPI: HPET id: 0x8086a201 base: 0xfed00000
[ 0.022118] TSC deadline timer available
[ 0.022138] smpboot: Allowing 3 CPUs, 0 hotplug CPUs
[ 0.022214] PM: hibernation: Registered nosave memory: [mem 0x00000000-0x00000fff]
[ 0.022229] PM: hibernation: Registered nosave memory: [mem 0x0009f000-0x0009ffff]
[ 0.022238] PM: hibernation: Registered nosave memory: [mem 0x000a0000-0x000effff]
[ 0.022247] PM: hibernation: Registered nosave memory: [mem 0x000f0000-0x000fffff]
[ 0.022259] [mem 0x80000000-0xfeffbfff] available for PCI devices
[ 0.022287] clocksource: refined-jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1910969940391419 ns
[ 0.030292] setup_percpu: NR_CPUS:64 nr_cpumask_bits:64 nr_cpu_ids:3 nr_node_ids:1
[ 0.030724] percpu: Embedded 53 pages/cpu s177048 r8192 d31848 u524288
[ 0.030755] pcpu-alloc: s177048 r8192 d31848 u524288 alloc=1*2097152
[ 0.030767] pcpu-alloc: [0] 0 1 2 -
[ 0.030869] Fallback order for Node 0: 0
[ 0.030879] Built 1 zonelists, mobility grouping on. Total pages: 515803
[ 0.030885] Policy zone: DMA32
[ 0.030892] Kernel command line: root=/dev/vda1 rw quiet
[ 0.031357] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[ 0.031442] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.031539] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.037606] Memory: 2014056K/2096612K available (24588K kernel code, 2637K rwdata, 5136K rodata, 1444K init, 1372K bss, 82296K reserved, 0K cma-reserved)
[ 0.037845] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=3, Nodes=1
[ 0.037891] Kernel/User page tables isolation: enabled
[ 0.041580] Dynamic Preempt: voluntary
[ 0.042044] rcu: Preemptible hierarchical RCU implementation.
[ 0.042049] rcu: RCU event tracing is enabled.
[ 0.042054] rcu: RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=3.
[ 0.042060] Trampoline variant of Tasks RCU enabled.
[ 0.042064] Rude variant of Tasks RCU enabled.
[ 0.042067] Tracing variant of Tasks RCU enabled.
[ 0.042074] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
[ 0.042079] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=3
[ 0.047559] NR_IRQS: 4352, nr_irqs: 448, preallocated irqs: 16
[ 0.047979] random: get_random_bytes called from start_kernel+0x57c/0x82a with crng_init=0
[ 0.055672] Console: colour VGA+ 80x25
[ 0.055761] printk: console [tty0] enabled
[ 0.055813] ACPI: Core revision 20211217
[ 0.056092] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[ 0.056236] APIC: Switch to symmetric I/O mode setup
[ 0.057734] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[ 0.062235] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x25641dc4a8e, max_idle_ns: 440795265595 ns
[ 0.062262] Calibrating delay loop (skipped), value calculated using timer frequency.. 5188.01 BogoMIPS (lpj=2594006)
[ 0.062275] pid_max: default: 32768 minimum: 301
[ 0.062321] LSM: Security Framework initializing
[ 0.062340] SELinux: Initializing.
[ 0.062390] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.062400] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.063094] x86/cpu: User Mode Instruction Prevention (UMIP) activated
[ 0.063277] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[ 0.063285] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 0.063319] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[ 0.063326] Spectre V2 : Mitigation: Full generic retpoline
[ 0.063330] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[ 0.063336] Spectre V2 : Enabling Restricted Speculation for firmware calls
[ 0.063342] Spectre V2 : mitigation: Enabling conditional Indirect Branch Prediction Barrier
[ 0.063348] Speculative Store Bypass: Mitigation: Speculative Store Bypass disabled via prctl
[ 0.063359] TAA: Mitigation: Clear CPU buffers
[ 0.063364] SRBDS: Unknown: Dependent on hypervisor status
[ 0.063368] MDS: Mitigation: Clear CPU buffers
[ 0.077973] Freeing SMP alternatives memory: 44K
[ 0.078024] kcsan: enabled early
[ 0.078028] kcsan: non-strict mode configured - use CONFIG_KCSAN_STRICT=y to see all data races
[ 0.078252] smpboot: CPU0: Intel(R) Core(TM) i7-5600U CPU @ 2.60GHz (family: 0x6, model: 0x3d, stepping: 0x4)
[ 0.078252] cblist_init_generic: Setting adjustable number of callback queues.
[ 0.078252] cblist_init_generic: Setting shift to 2 and lim to 1.
[ 0.078252] cblist_init_generic: Setting shift to 2 and lim to 1.
[ 0.078252] cblist_init_generic: Setting shift to 2 and lim to 1.
[ 0.078252] Performance Events: Broadwell events, full-width counters, Intel PMU driver.
[ 0.078252] ... version: 2
[ 0.078252] ... bit width: 48
[ 0.078252] ... generic registers: 4
[ 0.078252] ... value mask: 0000ffffffffffff
[ 0.078252] ... max period: 00007fffffffffff
[ 0.078252] ... fixed-purpose events: 3
[ 0.078252] ... event mask: 000000070000000f
[ 0.078252] rcu: Hierarchical SRCU implementation.
[ 0.080344] smp: Bringing up secondary CPUs ...
[ 0.080904] x86: Booting SMP configuration:
[ 0.080909] .... node #0, CPUs: #1 #2
[ 0.082720] smp: Brought up 1 node, 3 CPUs
[ 0.082720] smpboot: Max logical packages: 1
[ 0.082720] smpboot: Total of 3 processors activated (15564.03 BogoMIPS)
[ 0.083855] devtmpfs: initialized
[ 0.086739] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275000 ns
[ 0.086758] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.087261] PM: RTC time: 18:27:46, date: 2022-02-07
[ 0.087877] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 0.088844] audit: initializing netlink subsys (disabled)
[ 0.088899] audit: type=2000 audit(1644258466.031:1): state=initialized audit_enabled=0 res=1
[ 0.089503] thermal_sys: Registered thermal governor 'step_wise'
[ 0.089520] thermal_sys: Registered thermal governor 'user_space'
[ 0.089589] cpuidle: using governor menu
[ 0.090774] PCI: Using configuration type 1 for base access
[ 0.129534] kprobes: kprobe jump-optimization is enabled. All kprobes are optimized if possible.
[ 0.130436] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[ 0.131414] ACPI: Added _OSI(Module Device)
[ 0.131427] ACPI: Added _OSI(Processor Device)
[ 0.131451] ACPI: Added _OSI(3.0 _SCP Extensions)
[ 0.131468] ACPI: Added _OSI(Processor Aggregator Device)
[ 0.131478] ACPI: Added _OSI(Linux-Dell-Video)
[ 0.131489] ACPI: Added _OSI(Linux-Lenovo-NV-HDMI-Audio)
[ 0.131500] ACPI: Added _OSI(Linux-HPI-Hybrid-Graphics)
[ 0.137766] ACPI: 1 ACPI AML tables successfully acquired and loaded
[ 0.142179] ACPI: Interpreter enabled
[ 0.142299] ACPI: PM: (supports S0 S3 S4 S5)
[ 0.142304] ACPI: Using IOAPIC for interrupt routing
[ 0.142405] PCI: Using host bridge windows from ACPI; if necessary, use "pci=nocrs" and report a bug
[ 0.143288] ACPI: Enabled 2 GPEs in block 00 to 0F
[ 0.163914] ACPI: PCI Root Bridge [PCI0] (domain 0000 [bus 00-ff])
[ 0.164019] acpi PNP0A03:00: _OSC: OS supports [ASPM ClockPM Segments MSI HPX-Type3]
[ 0.164106] acpi PNP0A03:00: _OSC: not requesting OS control; OS requires [ExtendedConfig ASPM ClockPM MSI]
[ 0.164220] acpi PNP0A03:00: fail to add MMCONFIG information, can't access extended PCI configuration space under this bridge.
[ 0.164669] PCI host bridge to bus 0000:00
[ 0.164684] pci_bus 0000:00: root bus resource [io 0x0000-0x0cf7 window]
[ 0.164703] pci_bus 0000:00: root bus resource [io 0x0d00-0xffff window]
[ 0.164721] pci_bus 0000:00: root bus resource [mem 0x000a0000-0x000bffff window]
[ 0.164787] pci_bus 0000:00: root bus resource [mem 0x80000000-0xfebfffff window]
[ 0.164804] pci_bus 0000:00: root bus resource [mem 0x100000000-0x17fffffff window]
[ 0.164824] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.165022] pci 0000:00:00.0: [8086:1237] type 00 class 0x060000
[ 0.168188] pci 0000:00:01.0: [8086:7000] type 00 class 0x060100
[ 0.169079] pci 0000:00:01.1: [8086:7010] type 00 class 0x010180
[ 0.171259] pci 0000:00:01.1: reg 0x20: [io 0xc0e0-0xc0ef]
[ 0.172170] pci 0000:00:01.1: legacy IDE quirk: reg 0x10: [io 0x01f0-0x01f7]
[ 0.172180] pci 0000:00:01.1: legacy IDE quirk: reg 0x14: [io 0x03f6]
[ 0.172187] pci 0000:00:01.1: legacy IDE quirk: reg 0x18: [io 0x0170-0x0177]
[ 0.172194] pci 0000:00:01.1: legacy IDE quirk: reg 0x1c: [io 0x0376]
[ 0.172572] pci 0000:00:01.2: [8086:7020] type 00 class 0x0c0300
[ 0.174868] pci 0000:00:01.2: reg 0x20: [io 0xc0c0-0xc0df]
[ 0.176152] pci 0000:00:01.3: [8086:7113] type 00 class 0x068000
[ 0.176662] pci 0000:00:01.3: quirk: [io 0x0600-0x063f] claimed by PIIX4 ACPI
[ 0.176740] pci 0000:00:01.3: quirk: [io 0x0700-0x070f] claimed by PIIX4 SMB
[ 0.177181] pci 0000:00:02.0: [1234:1111] type 00 class 0x030000
[ 0.178866] pci 0000:00:02.0: reg 0x10: [mem 0xfd000000-0xfdffffff pref]
[ 0.182675] pci 0000:00:02.0: reg 0x18: [mem 0xfebf0000-0xfebf0fff]
[ 0.185627] pci 0000:00:02.0: reg 0x30: [mem 0xfebe0000-0xfebeffff pref]
[ 0.185919] pci 0000:00:02.0: Video device with shadowed ROM at [mem 0x000c0000-0x000dffff]
[ 0.188405] pci 0000:00:03.0: [8086:100e] type 00 class 0x020000
[ 0.189259] pci 0000:00:03.0: reg 0x10: [mem 0xfebc0000-0xfebdffff]
[ 0.189834] pci 0000:00:03.0: reg 0x14: [io 0xc080-0xc0bf]
[ 0.192260] pci 0000:00:03.0: reg 0x30: [mem 0xfeb80000-0xfebbffff pref]
[ 0.196114] pci 0000:00:04.0: [1af4:1001] type 00 class 0x010000
[ 0.198260] pci 0000:00:04.0: reg 0x10: [io 0xc000-0xc07f]
[ 0.199829] pci 0000:00:04.0: reg 0x14: [mem 0xfebf1000-0xfebf1fff]
[ 0.201859] pci 0000:00:04.0: reg 0x20: [mem 0xfe000000-0xfe003fff 64bit pref]
[ 0.208393] ACPI: PCI: Interrupt link LNKA configured for IRQ 10
[ 0.209114] ACPI: PCI: Interrupt link LNKB configured for IRQ 10
[ 0.209528] ACPI: PCI: Interrupt link LNKC configured for IRQ 11
[ 0.210095] ACPI: PCI: Interrupt link LNKD configured for IRQ 11
[ 0.210338] ACPI: PCI: Interrupt link LNKS configured for IRQ 9
[ 0.212674] iommu: Default domain type: Translated
[ 0.212682] iommu: DMA domain TLB invalidation policy: lazy mode
[ 0.213347] pci 0000:00:02.0: vgaarb: setting as boot VGA device
[ 0.213417] pci 0000:00:02.0: vgaarb: VGA device added: decodes=io+mem,owns=io+mem,locks=none
[ 0.213427] pci 0000:00:02.0: vgaarb: bridge control possible
[ 0.213433] vgaarb: loaded
[ 0.213579] SCSI subsystem initialized
[ 0.214394] libata version 3.00 loaded.
[ 0.214561] ACPI: bus type USB registered
[ 0.214561] usbcore: registered new interface driver usbfs
[ 0.214561] usbcore: registered new interface driver hub
[ 0.214561] usbcore: registered new device driver usb
[ 0.214620] pps_core: LinuxPPS API ver. 1 registered
[ 0.214627] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@xxxxxxxx>
[ 0.214721] PTP clock support registered
[ 0.215447] Advanced Linux Sound Architecture Driver Initialized.
[ 0.216171] Bluetooth: Core ver 2.22
[ 0.216199] NET: Registered PF_BLUETOOTH protocol family
[ 0.216203] Bluetooth: HCI device and connection manager initialized
[ 0.216214] Bluetooth: HCI socket layer initialized
[ 0.216219] Bluetooth: L2CAP socket layer initialized
[ 0.216234] Bluetooth: SCO socket layer initialized
[ 0.216262] NetLabel: Initializing
[ 0.216300] NetLabel: domain hash size = 128
[ 0.216304] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
[ 0.216516] NetLabel: unlabeled traffic allowed by default
[ 0.217290] PCI: Using ACPI for IRQ routing
[ 0.217297] PCI: pci_cache_line_size set to 64 bytes
[ 0.217430] e820: reserve RAM buffer [mem 0x0009fc00-0x0009ffff]
[ 0.217495] e820: reserve RAM buffer [mem 0x7ffdb000-0x7fffffff]
[ 0.217495] hpet0: at MMIO 0xfed00000, IRQs 2, 8, 0
[ 0.217495] hpet0: 3 comparators, 64-bit 100.000000 MHz counter
[ 0.223417] clocksource: Switched to clocksource tsc-early
[ 0.301725] VFS: Disk quotas dquot_6.6.0
[ 0.301831] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 0.302021] pnp: PnP ACPI init
[ 0.302779] pnp 00:02: [dma 2]
[ 0.304622] pnp: PnP ACPI: found 6 devices
[ 0.327653] clocksource: acpi_pm: mask: 0xffffff max_cycles: 0xffffff, max_idle_ns: 2085701024 ns
[ 0.327987] NET: Registered PF_INET protocol family
[ 0.328173] IP idents hash table entries: 32768 (order: 6, 262144 bytes, linear)
[ 0.334700] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)
[ 0.334823] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 0.336012] TCP bind hash table entries: 16384 (order: 6, 262144 bytes, linear)
[ 0.337834] TCP: Hash tables configured (established 16384 bind 16384)
[ 0.337920] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)
[ 0.338314] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)
[ 0.338642] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 0.339248] RPC: Registered named UNIX socket transport module.
[ 0.339283] RPC: Registered udp transport module.
[ 0.339290] RPC: Registered tcp transport module.
[ 0.339295] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.343934] pci_bus 0000:00: resource 4 [io 0x0000-0x0cf7 window]
[ 0.343952] pci_bus 0000:00: resource 5 [io 0x0d00-0xffff window]
[ 0.344018] pci_bus 0000:00: resource 6 [mem 0x000a0000-0x000bffff window]
[ 0.344033] pci_bus 0000:00: resource 7 [mem 0x80000000-0xfebfffff window]
[ 0.344048] pci_bus 0000:00: resource 8 [mem 0x100000000-0x17fffffff window]
[ 0.344844] pci 0000:00:01.0: PIIX3: Enabling Passive Release
[ 0.345126] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[ 0.345190] pci 0000:00:01.0: Activating ISA DMA hang workarounds
[ 0.536957] ACPI: \_SB_.LNKD: Enabled at IRQ 11
[ 0.930821] pci 0000:00:01.2: quirk_usb_early_handoff+0x0/0x7e0 took 571691 usecs
[ 0.931189] PCI: CLS 0 bytes, default 64
[ 2.064726] RAPL PMU: API unit is 2^-32 Joules, 0 fixed counters, 10737418240 ms ovfl timer
[ 2.067527] rcu-torture:--- Start of test: nreaders=2 nfakewriters=4 stat_interval=60 verbose=1 test_no_idle_hz=1 shuffle_interval=3 stutter=5 irqreader=1 fqs_duration=0 fqs_holdoff=0 fqs_stutter=3 test_boost=1/0 test_boost_interval=7 test_boost_duration=4 shutdown_secs=0 stall_cpu=0 stall_cpu_holdoff=10 stall_cpu_irqsoff=0 stall_cpu_block=0 n_barrier_cbs=0 onoff_interval=0 onoff_holdoff=0 read_exit_delay=13 read_exit_burst=16 nocbs_nthreads=0 nocbs_toggle=1000
[ 2.069617] rcu: Start-test grace-period state: g-1143 f0x0
[ 2.069975] rcu_torture_write_types: Testing conditional GPs.
[ 2.069979] rcu_torture_write_types: Testing expedited GPs.
[ 2.069983] rcu_torture_write_types: Testing asynchronous GPs.
[ 2.070013] rcu_torture_write_types: Testing polling GPs.
[ 2.070016] rcu_torture_write_types: Testing normal GPs.
[ 2.070020] rcu-torture: Creating rcu_torture_writer task
[ 2.070745] rcu-torture: Creating rcu_torture_fakewriter task
[ 2.070774] rcu-torture: rcu_torture_writer task started
[ 2.071454] rcu-torture: Creating rcu_torture_fakewriter task
[ 2.071506] rcu-torture: rcu_torture_fakewriter task started
[ 2.071768] rcu-torture: GP expediting controlled from boot/sysfs for rcu.
[ 2.072430] rcu-torture: Creating rcu_torture_fakewriter task
[ 2.072476] rcu-torture: rcu_torture_fakewriter task started
[ 2.074086] rcu-torture: Creating rcu_torture_fakewriter task
[ 2.074120] rcu-torture: rcu_torture_fakewriter task started
[ 2.074653] rcu-torture: Creating rcu_torture_reader task
[ 2.075405] rcu-torture: rcu_torture_fakewriter task started
[ 2.075632] rcu-torture: Creating rcu_torture_reader task
[ 2.075681] rcu-torture: rcu_torture_reader task started
[ 2.077381] rcu-torture: Creating rcu_torture_stats task
[ 2.077410] rcu-torture: rcu_torture_reader task started
[ 2.078766] rcu-torture: Creating torture_shuffle task
[ 2.079021] rcu-torture: rcu_torture_stats task started
[ 2.080054] rcu-torture: Creating torture_stutter task
[ 2.080060] rcu-torture: torture_shuffle task started
[ 2.081341] rcu-torture: Creating rcu_torture_fwd_prog task
[ 2.081979] rcu-torture: torture_stutter task started
[ 2.082368] rcu-torture: Creating rcu_torture_read_exit task
[ 2.083062] rcu-torture: rcu_torture_fwd_progress task started
[ 2.083212] torture_init_begin: Refusing rcu init: rcu running.
[ 2.083219] rcu-torture: rcu_torture_read_exit: Start of test
[ 2.083886] rcu_torture_rea (57) used greatest stack depth: 15168 bytes left
[ 2.084088] torture_init_begin: One torture test at a time!
[ 2.084103] torture_init_begin: Refusing rcu init: rcu running.
[ 2.085727] torture_init_begin: One torture test at a time!
[ 2.087771] Initialise system trusted keyrings
[ 2.088032] workingset: timestamp_bits=56 max_order=19 bucket_order=0
[ 2.106602] NFS: Registering the id_resolver key type
[ 2.106618] Key type id_resolver registered
[ 2.106622] Key type id_legacy registered
[ 2.119092] Key type asymmetric registered
[ 2.119104] Asymmetric key parser 'x509' registered
[ 2.119146] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[ 2.119153] io scheduler mq-deadline registered
[ 2.119158] io scheduler kyber registered
[ 2.119700] input: Power Button as /devices/LNXSYSTM:00/LNXPWRBN:00/input/input0
[ 2.119810] ACPI: button: Power Button [PWRF]
[ 2.200532] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[ 2.200741] 00:04: ttyS0 at I/O 0x3f8 (irq = 4, base_baud = 115200) is a 16550A
[ 2.202297] Non-volatile memory driver v1.3
[ 2.202492] Linux agpgart interface v0.103
[ 2.202673] ACPI: bus type drm_connector registered
[ 2.213992] loop: module loaded
[ 2.215619] virtio_blk virtio0: [vda] 6291456 512-byte logical blocks (3.22 GB/3.00 GiB)
[ 2.217625] vda: vda1
[ 2.218736] ata_piix 0000:00:01.1: version 2.13
[ 2.220865] scsi host0: ata_piix
[ 2.221637] scsi host1: ata_piix
[ 2.221932] ata1: PATA max MWDMA2 cmd 0x1f0 ctl 0x3f6 bmdma 0xc0e0 irq 14
[ 2.221939] ata2: PATA max MWDMA2 cmd 0x170 ctl 0x376 bmdma 0xc0e8 irq 15
[ 2.224044] e100: Intel(R) PRO/100 Network Driver
[ 2.224049] e100: Copyright(c) 1999-2006 Intel Corporation
[ 2.224214] e1000: Intel(R) PRO/1000 Network Driver
[ 2.224218] e1000: Copyright (c) 1999-2006 Intel Corporation.
[ 2.376737] ata2: found unknown device (class 0)
[ 2.378515] ata2.00: ATAPI: QEMU DVD-ROM, 2.5+, max UDMA/100
[ 2.380217] scsi 1:0:0:0: CD-ROM QEMU QEMU DVD-ROM 2.5+ PQ: 0 ANSI: 5
[ 2.397470] sr 1:0:0:0: [sr0] scsi3-mmc drive: 4x/4x cd/rw xa/form2 tray
[ 2.397490] cdrom: Uniform CD-ROM driver Revision: 3.20
[ 2.412969] ACPI: \_SB_.LNKC: Enabled at IRQ 10
[ 2.414020] sr 1:0:0:0: Attached scsi CD-ROM sr0
[ 2.414383] sr 1:0:0:0: Attached scsi generic sg0 type 5
[ 2.743750] e1000 0000:00:03.0 eth0: (PCI:33MHz:32-bit) 52:54:00:12:34:56
[ 2.743774] e1000 0000:00:03.0 eth0: Intel(R) PRO/1000 Network Connection
[ 2.743979] e1000e: Intel(R) PRO/1000 Network Driver
[ 2.743984] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[ 2.744241] sky2: driver version 1.30
[ 2.745116] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 2.745125] ehci-pci: EHCI PCI platform driver
[ 2.745202] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 2.745217] ohci-pci: OHCI PCI platform driver
[ 2.745327] uhci_hcd: USB Universal Host Controller Interface driver
[ 2.932744] uhci_hcd 0000:00:01.2: UHCI Host Controller
[ 2.933214] uhci_hcd 0000:00:01.2: new USB bus registered, assigned bus number 1
[ 2.933507] uhci_hcd 0000:00:01.2: irq 11, io port 0x0000c0c0
[ 2.933709] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.17
[ 2.933762] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 2.933779] usb usb1: Product: UHCI Host Controller
[ 2.933786] usb usb1: Manufacturer: Linux 5.17.0-rc3-00369-gc67afd79c7ba uhci_hcd
[ 2.933792] usb usb1: SerialNumber: 0000:00:01.2
[ 2.934481] hub 1-0:1.0: USB hub found
[ 2.934540] hub 1-0:1.0: 2 ports detected
[ 2.935496] usbcore: registered new interface driver usblp
[ 2.935598] usbcore: registered new interface driver usb-storage
[ 2.935863] i8042: PNP: PS/2 Controller [PNP0303:KBD,PNP0f13:MOU] at 0x60,0x64 irq 1,12
[ 2.936819] serio: i8042 KBD port at 0x60,0x64 irq 1
[ 2.936891] serio: i8042 AUX port at 0x60,0x64 irq 12
[ 2.938375] input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/input1
[ 2.938525] rtc_cmos 00:05: RTC can wake from S4
[ 2.941035] rtc_cmos 00:05: registered as rtc0
[ 2.941402] rtc_cmos 00:05: alarms up to one day, y3k, 242 bytes nvram, hpet irqs
[ 2.943359] device-mapper: ioctl: 4.45.0-ioctl (2021-03-22) initialised: dm-devel@xxxxxxxxxx
[ 2.943387] Bluetooth: HCI UART driver ver 2.3
[ 2.943448] Bluetooth: HCI UART protocol H4 registered
[ 2.943735] usbcore: registered new interface driver btusb
[ 2.943894] intel_pstate: CPU model not supported
[ 2.944149] hid: raw HID events driver (C) Jiri Kosina
[ 2.945664] usbcore: registered new interface driver usbhid
[ 2.945672] usbhid: USB HID core driver
[ 2.948563] Initializing XFRM netlink socket
[ 2.949334] NET: Registered PF_INET6 protocol family
[ 2.951827] Segment Routing with IPv6
[ 2.951847] In-situ OAM (IOAM) with IPv6
[ 2.952247] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[ 2.953358] NET: Registered PF_PACKET protocol family
[ 2.953606] Bluetooth: RFCOMM socket layer initialized
[ 2.953628] Bluetooth: RFCOMM ver 1.11
[ 2.953719] Key type dns_resolver registered
[ 2.954987] IPI shorthand broadcast: enabled
[ 2.955031] sched_clock: Marking stable (2945325211, 9408919)->(2963070265, -8336135)
[ 2.955591] registered taskstats version 1
[ 2.955601] Loading compiled-in X.509 certificates
[ 2.962181] PM: Magic number: 10:336:493
[ 2.962345] printk: console [netcon0] enabled
[ 2.962412] netconsole: network logging started
[ 2.962912] Bluetooth: Starting self testing
[ 3.076393] Bluetooth: ECDH test passed in 110814 usecs
[ 3.076940] kworker/u6:2 (96) used greatest stack depth: 14432 bytes left
[ 3.077584] kworker/u6:2 (97) used greatest stack depth: 13912 bytes left
[ 3.097017] tsc: Refined TSC clocksource calibration: 2593.966 MHz
[ 3.097054] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x2563f7e18a7, max_idle_ns: 440795265594 ns
[ 3.097222] clocksource: Switched to clocksource tsc
[ 3.116842] Bluetooth: SMP test passed in 37562 usecs
[ 3.116867] Bluetooth: Finished self testing
[ 3.116960] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[ 3.121681] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[ 3.121772] platform regulatory.0: Direct firmware load for regulatory.db failed with error -2
[ 3.121787] cfg80211: failed to load regulatory.db
[ 3.121904] ALSA device list:
[ 3.121958] No soundcards found.
[ 3.154321] usb 1-1: new full-speed USB device number 2 using uhci_hcd
[ 3.302900] usb 1-1: New USB device found, idVendor=8087, idProduct=0a2a, bcdDevice= 0.01
[ 3.302916] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[ 3.324840] Bluetooth: hci0: Legacy ROM 2.5 revision 1.0 build 3 week 17 2014
[ 3.324856] Bluetooth: hci0: Intel device is already patched. patch num: 32
[ 3.564118] input: ImExPS/2 Generic Explorer Mouse as /devices/platform/i8042/serio1/input/input3
[ 3.564632] md: Waiting for all devices to be available before autodetect
[ 3.564640] md: If you don't use raid, use raid=noautodetect
[ 3.564651] md: Autodetecting RAID arrays.
[ 3.564656] md: autorun ...
[ 3.564660] md: ... autorun DONE.
[ 3.568780] EXT4-fs (vda1): mounted filesystem with ordered data mode. Quota mode: none.
[ 3.568819] VFS: Mounted root (ext4 filesystem) on device 253:1.
[ 3.569327] devtmpfs: mounted
[ 3.571314] Freeing unused kernel image (initmem) memory: 1444K
[ 3.573421] Write protecting the kernel read-only data: 32768k
[ 3.579067] Freeing unused kernel image (text/rodata gap) memory: 2032K
[ 3.580732] Freeing unused kernel image (rodata/data gap) memory: 1008K
[ 3.581079] Run /sbin/init as init process
[ 3.581085] with arguments:
[ 3.581088] /sbin/init
[ 3.581091] with environment:
[ 3.581094] HOME=/
[ 3.581098] TERM=linux
[ 3.605611] random: fast init done
[ 3.666548] systemd[1]: systemd 250.3-2 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT +GNUTLS -OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)
[ 3.667336] systemd[1]: Detected virtualization kvm.
[ 3.667361] systemd[1]: Detected architecture x86-64.
[ 3.667647] systemd[1]: Detected first boot.
[ 3.667969] systemd[1]: Hostname set to <ersatz>.
[ 3.670451] systemd[1]: Initializing machine ID from D-Bus machine ID.
[ 3.765766] systemd-fstab-g (118) used greatest stack depth: 13144 bytes left
[ 3.765881] mkdir (124) used greatest stack depth: 12816 bytes left
[ 3.838633] random: lvmconfig: uninitialized urandom read (4 bytes read)
[ 4.541101] systemd[1]: Populated /etc with preset unit settings.
[ 4.647734] systemd[1]: Queued start job for default target Graphical Interface.
[ 4.649064] systemd[1]: Created slice Slice /system/getty.
[ 4.649850] systemd[1]: Created slice Slice /system/modprobe.
[ 4.650479] systemd[1]: Created slice Slice /system/postfix.
[ 4.650987] systemd[1]: Created slice User and Session Slice.
[ 4.651254] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[ 4.651582] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ 4.652028] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[ 4.652104] systemd[1]: Reached target Local Encrypted Volumes.
[ 4.652125] systemd[1]: Reached target Local Integrity Protected Volumes.
[ 4.652168] systemd[1]: Reached target Remote Encrypted Volumes.
[ 4.652183] systemd[1]: Reached target Remote File Systems.
[ 4.652198] systemd[1]: Reached target Remote Verity Protected Volumes.
[ 4.652216] systemd[1]: Reached target Slice Units.
[ 4.652236] systemd[1]: Reached target Swaps.
[ 4.652298] systemd[1]: Reached target Local Verity Protected Volumes.
[ 4.652584] systemd[1]: Listening on Device-mapper event daemon FIFOs.
[ 4.653056] systemd[1]: Listening on LVM2 poll daemon socket.
[ 4.653495] systemd[1]: Listening on Syslog Socket.
[ 4.653730] systemd[1]: Listening on fsck to fsckd communication Socket.
[ 4.654090] systemd[1]: Listening on initctl Compatibility Named Pipe.
[ 4.654609] systemd[1]: Listening on Journal Audit Socket.
[ 4.654887] systemd[1]: Listening on Journal Socket (/dev/log).
[ 4.655365] systemd[1]: Listening on Journal Socket.
[ 4.655944] systemd[1]: Listening on Network Service Netlink Socket.
[ 4.656501] systemd[1]: Listening on udev Control Socket.
[ 4.656823] systemd[1]: Listening on udev Kernel Socket.
[ 4.659207] systemd[1]: Mounting Huge Pages File System...
[ 4.662616] systemd[1]: Mounting POSIX Message Queue File System...
[ 4.666090] systemd[1]: Mounting Kernel Debug File System...
[ 4.669965] systemd[1]: Mounting Kernel Trace File System...
[ 4.670540] systemd[1]: Finished Availability of block devices.
[ 4.674719] systemd[1]: Starting Wait for network to be configured by ifupdown...
[ 4.676321] systemd[1]: Create List of Static Device Nodes was skipped because of a failed condition check (ConditionFileNotEmpty=/lib/modules/5.17.0-rc3-00369-gc67afd79c7ba/modules.devname).
[ 4.680007] systemd[1]: Starting Monitoring of LVM2 mirrors, snapshots etc. using dmeventd or progress polling...
[ 4.684429] systemd[1]: Starting Load Kernel Module configfs...
[ 4.688146] systemd[1]: Starting Load Kernel Module drm...
[ 4.691770] systemd[1]: Starting Load Kernel Module fuse...
[ 4.695315] systemd[1]: Starting nftables...
[ 4.695644] systemd[1]: File System Check on Root Device was skipped because of a failed condition check (ConditionPathIsReadWrite=!/).
[ 4.696232] systemd[1]: systemd-journald.service: unit configures an IP firewall, but the local system does not support BPF/cgroup firewalling.
[ 4.696250] systemd[1]: (This warning is only shown for the first unit using IP firewalling.)
[ 4.699395] systemd[1]: Starting Journal Service...
[ 4.710854] systemd[1]: Starting Load Kernel Modules...
[ 4.719597] systemd[1]: Starting Generate network units from Kernel command line...
[ 4.725904] systemd[1]: Starting Remount Root and Kernel File Systems...
[ 4.726128] random: lvm: uninitialized urandom read (4 bytes read)
[ 4.726221] systemd[1]: Repartition Root Disk was skipped because all trigger condition checks failed.
[ 4.729670] systemd[1]: Starting Coldplug All udev Devices...
[ 4.735624] systemd[1]: Mounted Huge Pages File System.
[ 4.735968] systemd[1]: Mounted POSIX Message Queue File System.
[ 4.736309] systemd[1]: Mounted Kernel Debug File System.
[ 4.736559] systemd[1]: Mounted Kernel Trace File System.
[ 4.737557] systemd[1]: modprobe@configfs.service: Deactivated successfully.
[ 4.738130] systemd[1]: Finished Load Kernel Module configfs.
[ 4.739359] systemd[1]: modprobe@drm.service: Deactivated successfully.
[ 4.739854] systemd[1]: Finished Load Kernel Module drm.
[ 4.741092] systemd[1]: modprobe@fuse.service: Deactivated successfully.
[ 4.741607] systemd[1]: Finished Load Kernel Module fuse.
[ 4.742405] systemd[1]: FUSE Control File System was skipped because of a failed condition check (ConditionPathExists=/sys/fs/fuse/connections).
[ 4.742754] systemd[1]: Kernel Configuration File System was skipped because of a failed condition check (ConditionPathExists=/sys/kernel/config).
[ 4.766135] systemd[1]: Finished Load Kernel Modules.
[ 4.768888] systemd[1]: Starting Apply Kernel Variables...
[ 4.776752] systemd[1]: Finished Generate network units from Kernel command line.
[ 4.813693] EXT4-fs (vda1): re-mounted. Quota mode: none.
[ 4.825401] systemd[1]: Finished Apply Kernel Variables.
[ 4.839997] systemd[1]: Finished Remount Root and Kernel File Systems.
[ 4.840359] systemd[1]: Platform Persistent Storage Archival was skipped because of a failed condition check (ConditionDirectoryNotEmpty=/sys/fs/pstore).
[ 4.843675] systemd[1]: Starting Load/Save Random Seed...
[ 4.851517] systemd[1]: Starting Create System Users...
[ 4.931717] systemd-sysuser (158) used greatest stack depth: 12504 bytes left
[ 4.932764] systemd[1]: Finished Create System Users.
[ 4.936631] systemd[1]: Starting Create Static Device Nodes in /dev...
[ 4.975612] systemd[1]: nftables.service: Main process exited, code=exited, status=1/FAILURE
[ 4.976633] systemd[1]: nftables.service: Failed with result 'exit-code'.
[ 4.977494] systemd[1]: Failed to start nftables.
[ 4.993676] systemd[1]: Finished Create Static Device Nodes in /dev.
[ 4.999813] systemd[1]: Starting Rule-based Manager for Device Events and Files...
[ 5.094522] systemd[1]: Finished Coldplug All udev Devices.
[ 5.098119] systemd[1]: Starting Helper to synchronize boot up for ifupdown...
[ 5.098593] systemd[1]: Started Journal Service.
[ 5.129930] systemd-journald[143]: Received client request to flush runtime journal.
[ 5.458050] e1000 0000:00:03.0 enp0s3: renamed from eth0
[ 5.833189] systemd-update- (209) used greatest stack depth: 12328 bytes left
[ 5.912099] random: dbus-daemon: uninitialized urandom read (12 bytes read)
[ 5.931407] random: dbus-daemon: uninitialized urandom read (12 bytes read)
[ 6.327306] random: crng init done
[ 6.448050] e2scrub_all (230) used greatest stack depth: 12304 bytes left
[ 7.112319] rcu-torture: rcu_torture_read_exit: End of episode
[ 20.440304] rcu-torture: rcu_torture_read_exit: Start of episode
[ 20.471407] rcu-torture: rcu_torture_read_exit: End of episode
[ 29.553511] ==================================================================
[ 29.554105] BUG: KCSAN: data-race in tick_nohz_idle_stop_tick / tick_nohz_next_event

[ 29.554974] write to 0xffffffff8748abf0 of 4 bytes by task 0 on cpu 1:
[ 29.555371] tick_nohz_idle_stop_tick+0x39c/0x490
[ 29.555382] do_idle+0x1e4/0x250
[ 29.555391] cpu_startup_entry+0x14/0x20
[ 29.555401] secondary_startup_64_no_verify+0xd5/0xdb

[ 29.555634] read to 0xffffffff8748abf0 of 4 bytes by task 0 on cpu 2:
[ 29.555995] tick_nohz_next_event+0xfd/0x220
[ 29.556003] tick_nohz_idle_stop_tick+0x298/0x490
[ 29.556011] do_idle+0x1e4/0x250
[ 29.556020] cpu_startup_entry+0x14/0x20
[ 29.556030] secondary_startup_64_no_verify+0xd5/0xdb

[ 29.556254] value changed: 0x00000001 -> 0xffffffff

[ 29.556792] Reported by Kernel Concurrency Sanitizer on:
[ 29.557124] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 29.557134] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 29.557139] ==================================================================
[ 33.882420] rcu-torture: rcu_torture_read_exit: Start of episode
[ 33.915300] rcu-torture: rcu_torture_read_exit: End of episode
[ 47.386351] rcu-torture: rcu_torture_read_exit: Start of episode
[ 47.415553] rcu-torture: rcu_torture_read_exit: End of episode
[ 60.760718] rcu-torture: rcu_torture_read_exit: Start of episode
[ 60.790539] rcu-torture: rcu_torture_read_exit: End of episode
[ 62.488377] rcu-torture:
[ 62.488397] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 62.488391] rtc: 00000000b0b4c7f1 ver: 4910 tfle: 0 rta: 4911 rtaf: 0 rtf: 4900 rtmbe: 0 rtmbkf: 0/3627 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 38327 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 84 nocb-toggles: 0:0
[ 62.489342] rcu-torture: Reader Pipe: 9700605 4601 0 0 0 0 0 0 0 0 0
[ 62.489896] rcu-torture: Reader Batch: 9690051 15155 0 0 0 0 0 0 0 0 0
[ 62.490514] rcu-torture: Free-Block Circulation: 4910 4909 4908 4907 4906 4905 4904 4903 4902 4901 0
[ 62.535472] rcu_torture_fwd_prog_cr Duration 29 barrier: 13 pending 3505 n_launders: 11227 n_launders_sa: 3505 n_max_gps: 100 n_max_cbs: 7271 cver 5 gps 12
[ 62.536422] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 43 jiffies): 1s/10: 18498:14
[ 71.753270] rcu_torture_fwd_prog_nr: 0 Duration 8166 cver 694 gps 1335
[ 74.136314] rcu-torture: rcu_torture_read_exit: Start of episode
[ 74.175192] rcu-torture: rcu_torture_read_exit: End of episode
[ 83.065990] clocksource: timekeeping watchdog on CPU0: hpet wd-wd read-back delay of 165680ns
[ 83.066278] clocksource: wd-tsc-wd read-back delay of 155780ns, clock-skew test skipped!
[ 87.576282] rcu-torture: rcu_torture_read_exit: Start of episode
[ 87.583839] rcu-torture: rcu_torture_read_exit: End of episode
[ 101.336351] rcu-torture: rcu_torture_read_exit: Start of episode
[ 101.343918] rcu-torture: rcu_torture_read_exit: End of episode
[ 108.809021] e1000: enp0s3 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
[ 108.815421] IPv6: ADDRCONF(NETDEV_CHANGE): enp0s3: link becomes ready
[ 108.815419] ip (704) used greatest stack depth: 12232 bytes left
[ 114.648923] rcu-torture: rcu_torture_read_exit: Start of episode
[ 114.688337] rcu-torture: rcu_torture_read_exit: End of episode
[ 123.928337] rcu-torture: rtc: 00000000d57b163c ver: 10354 tfle: 0 rta: 10355 rtaf: 0 rtf: 10345 rtmbe: 0 rtmbkf: 0/7563 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 80769 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 152 nocb-toggles: 0:0
[ 123.930198] rcu-torture: Reader Pipe: 20217603 9989 0 0 0 0 0 0 0 0 0
[ 123.930919] rcu-torture: Reader Batch: 20196648 30944 0 0 0 0 0 0 0 0 0
[ 123.931612] rcu-torture: Free-Block Circulation: 10354 10353 10352 10351 10350 10349 10348 10347 10346 10345 0
[ 128.025071] rcu-torture: rcu_torture_read_exit: Start of episode
[ 128.060519] rcu-torture: rcu_torture_read_exit: End of episode
[ 132.120356] rcu_torture_fwd_prog n_max_cbs: 7271
[ 132.120758] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 132.171077] rcu_torture_fwd_prog_cr Duration 31 barrier: 11 pending 6865 n_launders: 19124 n_launders_sa: 14076 n_max_gps: 100 n_max_cbs: 13976 cver 0 gps 10
[ 132.171795] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 43 jiffies): 1s/10: 33100:12
[ 141.401269] rcu-torture: rcu_torture_read_exit: Start of episode
[ 141.453423] rcu-torture: rcu_torture_read_exit: End of episode
[ 146.805260] rcu_torture_fwd_prog_nr: 0 Duration 13591 cver 979 gps 1869
[ 154.776313] rcu-torture: rcu_torture_read_exit: Start of episode
[ 154.805457] rcu-torture: rcu_torture_read_exit: End of episode
[ 159.066429] clocksource: timekeeping watchdog on CPU2: hpet wd-wd read-back delay of 90140ns
[ 159.066488] clocksource: wd-tsc-wd read-back delay of 1551350ns, clock-skew test skipped!
[ 168.153267] rcu-torture: rcu_torture_read_exit: Start of episode
[ 168.186651] rcu-torture: rcu_torture_read_exit: End of episode
[ 181.529297] rcu-torture: rcu_torture_read_exit: Start of episode
[ 181.568672] rcu-torture: rcu_torture_read_exit: End of episode
[ 185.368582] rcu-torture: rtc: 0000000023cf0f82 ver: 15614 tfle: 0 rta: 15614 rtaf: 0 rtf: 15605 rtmbe: 0 rtmbkf: 0/11247 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 121238 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 237 nocb-toggles: 0:0
[ 185.373833] rcu-torture: Reader Pipe: 30151818 14665 0 0 0 0 0 0 0 0 0
[ 185.375835] rcu-torture: Reader Batch: 30120588 45895 0 0 0 0 0 0 0 0 0
[ 185.377351] rcu-torture: Free-Block Circulation: 15613 15613 15612 15611 15610 15609 15608 15607 15606 15605 0
[ 194.904858] rcu-torture: rcu_torture_read_exit: Start of episode
[ 194.938345] rcu-torture: rcu_torture_read_exit: End of episode
[ 208.280400] rcu-torture: rcu_torture_read_exit: Start of episode
[ 208.285828] rcu-torture: rcu_torture_read_exit: End of episode
[ 209.944273] rcu_torture_fwd_prog n_max_cbs: 13976
[ 209.944825] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 209.999316] rcu_torture_fwd_prog_cr Duration 27 barrier: 18 pending 4524 n_launders: 11093 n_launders_sa: 4523 n_max_gps: 100 n_max_cbs: 6638 cver 3 gps 10
[ 210.000450] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 46 jiffies): 1s/10: 17731:12
[ 221.593267] rcu-torture: rcu_torture_read_exit: Start of episode
[ 221.632994] rcu-torture: rcu_torture_read_exit: End of episode
[ 228.666266] rcu_torture_fwd_prog_nr: 0 Duration 17628 cver 1292 gps 2512
[ 235.096396] rcu-torture: rcu_torture_read_exit: Start of episode
[ 235.126504] rcu-torture: rcu_torture_read_exit: End of episode
[ 246.808380] rcu-torture: rtc: 000000007fbaa228 ver: 20742 tfle: 0 rta: 20743 rtaf: 0 rtf: 20732 rtmbe: 0 rtmbkf: 0/14808 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 159642 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 305 nocb-toggles: 0:0
[ 246.809860] rcu-torture: Reader Pipe: 39510716 19291 0 0 0 0 0 0 0 0 0
[ 246.810603] rcu-torture: Reader Batch: 39470471 59536 0 0 0 0 0 0 0 0 0
[ 246.811395] rcu-torture: Free-Block Circulation: 20742 20741 20740 20739 20738 20737 20736 20735 20734 20732 0
[ 248.473271] rcu-torture: rcu_torture_read_exit: Start of episode
[ 248.483472] rcu-torture: rcu_torture_read_exit: End of episode
[ 257.568984] clocksource: timekeeping watchdog on CPU1: hpet wd-wd read-back delay of 94060ns
[ 257.569037] clocksource: wd-tsc-wd read-back delay of 483690ns, clock-skew test skipped!
[ 261.913385] rcu-torture: rcu_torture_read_exit: Start of episode
[ 261.942270] rcu-torture: rcu_torture_read_exit: End of episode
[ 273.080405] ==================================================================
[ 273.081267] BUG: KCSAN: data-race in virtqueue_kick_prepare+0x105/0x190

[ 273.082298] race at unknown origin, with read to 0xffffa07f813a5a44 of 2 bytes by task 7 on cpu 0:
[ 273.082886] virtqueue_kick_prepare+0x105/0x190
[ 273.082898] virtio_queue_rq+0x633/0x9e0
[ 273.082907] __blk_mq_try_issue_directly+0x26d/0x310
[ 273.082917] blk_mq_plug_issue_direct.constprop.0+0xca/0x1f0
[ 273.082927] blk_mq_flush_plug_list+0x4c6/0x5f0
[ 273.082936] blk_mq_submit_bio+0x9bc/0xc20
[ 273.082944] __submit_bio+0x188/0x2b0
[ 273.082952] submit_bio_noacct+0x4d4/0x540
[ 273.082961] submit_bio+0x4d/0x120
[ 273.082968] ext4_io_submit+0xb5/0xd0
[ 273.082980] ext4_writepages+0x9fc/0x1c10
[ 273.082990] do_writepages+0x9d/0x2c0
[ 273.083000] __writeback_single_inode+0x63/0x550
[ 273.083011] writeback_sb_inodes+0x427/0x870
[ 273.083021] __writeback_inodes_wb+0x65/0x120
[ 273.083031] wb_writeback+0x39b/0x400
[ 273.083041] wb_workfn+0x498/0x830
[ 273.083051] process_one_work+0x477/0x7d0
[ 273.083059] worker_thread+0x2ec/0x810
[ 273.083067] kthread+0x16d/0x1a0
[ 273.083078] ret_from_fork+0x22/0x30

[ 273.083355] value changed: 0x0414 -> 0x0416

[ 273.083964] Reported by Kernel Concurrency Sanitizer on:
[ 273.084342] CPU: 0 PID: 7 Comm: kworker/u6:0 Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 273.084356] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 273.084364] Workqueue: writeback wb_workfn (flush-253:0)
[ 273.084379] ==================================================================
[ 275.289420] rcu-torture: rcu_torture_read_exit: Start of episode
[ 275.296353] rcu-torture: rcu_torture_read_exit: End of episode
[ 280.576951] http (1490) used greatest stack depth: 12008 bytes left
[ 283.432792] ==================================================================
[ 283.433607] BUG: KCSAN: data-race in ext4_fill_raw_inode / setattr_copy

[ 283.434585] read to 0xffffa07f951c9c50 of 8 bytes by task 7 on cpu 1:
[ 283.435145] ext4_fill_raw_inode+0x2d9/0xa40
[ 283.435161] ext4_mark_iloc_dirty+0x25b/0xbf0
[ 283.435177] __ext4_mark_inode_dirty+0xb3/0x3a0
[ 283.435194] __ext4_ext_dirty+0x115/0x130
[ 283.435212] ext4_ext_map_blocks+0x1a12/0x2740
[ 283.435230] ext4_map_blocks+0x2e1/0x9e0
[ 283.435245] ext4_convert_unwritten_extents+0x210/0x320
[ 283.435265] ext4_convert_unwritten_io_end_vec+0xad/0x130
[ 283.435283] ext4_end_io_rsv_work+0x180/0x310
[ 283.435296] process_one_work+0x477/0x7d0
[ 283.435304] worker_thread+0x2ec/0x810
[ 283.435312] kthread+0x16d/0x1a0
[ 283.435322] ret_from_fork+0x22/0x30

[ 283.435599] write to 0xffffa07f951c9c50 of 16 bytes by task 1509 on cpu 0:
[ 283.436138] setattr_copy+0x94/0x160
[ 283.436156] ext4_setattr+0x30f/0xf20
[ 283.436170] notify_change+0x34d/0x640
[ 283.436187] vfs_utimes+0x225/0x3d0
[ 283.436205] do_utimes+0xab/0x110
[ 283.436221] __x64_sys_utimensat+0xa9/0x100
[ 283.436240] do_syscall_64+0x39/0x80
[ 283.436257] entry_SYSCALL_64_after_hwframe+0x44/0xae

[ 283.436634] Reported by Kernel Concurrency Sanitizer on:
[ 283.437154] CPU: 0 PID: 1509 Comm: dpkg Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 283.437173] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 283.437184] ==================================================================
[ 285.678455] ==================================================================
[ 285.679039] BUG: KCSAN: data-race in _mix_pool_bytes+0x5d/0x1c0

[ 285.680046] race at unknown origin, with read to 0xffffa07f853d6f0a of 1 bytes by task 1509 on cpu 2:
[ 285.680842] _mix_pool_bytes+0x5d/0x1c0
[ 285.680864] add_device_randomness+0x97/0x290
[ 285.680877] release_task+0x231/0xb20
[ 285.680895] wait_consider_task+0x883/0x17d0
[ 285.680918] do_wait+0x2b4/0x4d0
[ 285.680935] kernel_wait4+0xdb/0x180
[ 285.680953] __do_sys_wait4+0x85/0x90
[ 285.680970] __x64_sys_wait4+0x49/0x50
[ 285.680988] do_syscall_64+0x39/0x80
[ 285.681002] entry_SYSCALL_64_after_hwframe+0x44/0xae

[ 285.681372] value changed: 0xa0 -> 0xa1

[ 285.682159] Reported by Kernel Concurrency Sanitizer on:
[ 285.682659] CPU: 2 PID: 1509 Comm: dpkg Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 285.682676] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 285.682685] ==================================================================
[ 288.601361] rcu-torture: rcu_torture_read_exit: Start of episode
[ 291.865376] rcu_torture_fwd_prog n_max_cbs: 6638
[ 291.865767] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 291.904131] rcu_torture_fwd_prog_cr Duration 23 barrier: 8 pending 4210 n_launders: 14267 n_launders_sa: 13075 n_max_gps: 100 n_max_cbs: 8488 cver 0 gps 9
[ 291.904953] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 32 jiffies): 1s/10: 22755:11
[ 293.104894] rcu-torture: rcu_torture_read_exit: End of episode
[ 306.319280] rcu_torture_fwd_prog_nr: 0 Duration 13357 cver 1370 gps 2637
[ 306.457256] rcu-torture: rcu_torture_read_exit: Start of episode
[ 306.498279] rcu-torture: rcu_torture_read_exit: End of episode
[ 308.248333] rcu-torture: rtc: 000000008d70020e ver: 26469 tfle: 0 rta: 26470 rtaf: 0 rtf: 26458 rtmbe: 0 rtmbkf: 0/18787 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 200953 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 390 nocb-toggles: 0:0
[ 308.249754] rcu-torture: Reader Pipe: 49242928 24066 0 0 0 0 0 0 0 0 0
[ 308.250370] rcu-torture: Reader Batch: 49192867 74127 0 0 0 0 0 0 0 0 0
[ 308.250979] rcu-torture: Free-Block Circulation: 26469 26468 26467 26466 26464 26463 26462 26461 26459 26458 0
[ 319.832313] rcu-torture: rcu_torture_read_exit: Start of episode
[ 319.862802] rcu-torture: rcu_torture_read_exit: End of episode
[ 333.208283] rcu-torture: rcu_torture_read_exit: Start of episode
[ 333.229480] rcu-torture: rcu_torture_read_exit: End of episode
[ 346.589280] rcu-torture: rcu_torture_read_exit: Start of episode
[ 346.622607] rcu-torture: rcu_torture_read_exit: End of episode
[ 360.345548] rcu-torture: rcu_torture_read_exit: Start of episode
[ 360.376263] rcu-torture: rcu_torture_read_exit: End of episode
[ 366.829376] ==================================================================
[ 366.829999] BUG: KCSAN: data-race in tick_nohz_idle_stop_tick / tick_nohz_idle_stop_tick

[ 366.840795] write to 0xffffffff8748abf0 of 4 bytes by task 0 on cpu 1:
[ 366.841164] tick_nohz_idle_stop_tick+0x39c/0x490
[ 366.841175] do_idle+0x1e4/0x250
[ 366.841185] cpu_startup_entry+0x14/0x20
[ 366.841195] secondary_startup_64_no_verify+0xd5/0xdb

[ 366.841471] read to 0xffffffff8748abf0 of 4 bytes by task 0 on cpu 2:
[ 366.841875] tick_nohz_idle_stop_tick+0x127/0x490
[ 366.841887] do_idle+0x1e4/0x250
[ 366.841899] cpu_startup_entry+0x14/0x20
[ 366.841911] secondary_startup_64_no_verify+0xd5/0xdb

[ 366.842227] value changed: 0x00000001 -> 0xffffffff

[ 366.844306] Reported by Kernel Concurrency Sanitizer on:
[ 366.844709] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 366.844721] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 366.844728] ==================================================================
[ 369.688270] rcu_torture_fwd_prog n_max_cbs: 8488
[ 369.688402] rcu-torture:
[ 369.688710] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 369.688711] rtc: 00000000aa795463 ver: 32028 tfle: 0 rta: 32028 rtaf: 0 rtf: 32019 rtmbe: 0 rtmbkf: 0/22764 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 242154 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 458 nocb-toggles: 0:0
[ 369.689571] rcu-torture: Reader Pipe: 59471686 29042 0 0 0 0 0 0 0 0 0
[ 369.690034] rcu-torture: Reader Batch: 59410176 90552 0 0 0 0 0 0 0 0 0
[ 369.690580] rcu-torture: Free-Block Circulation: 32027 32027 32026 32025 32024 32023 32022 32021 32020 32019 0
[ 369.739189] rcu_torture_fwd_prog_cr Duration 34 barrier: 11 pending 5044 n_launders: 12249 n_launders_sa: 937 n_max_gps: 100 n_max_cbs: 20417 cver 0 gps 10
[ 369.739980] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 46 jiffies): 1s/10: 32666:12
[ 373.912525] rcu-torture: rcu_torture_read_exit: Start of episode
[ 373.966262] rcu-torture: rcu_torture_read_exit: End of episode
[ 384.996253] rcu_torture_fwd_prog_nr: 0 Duration 14214 cver 1203 gps 2331
[ 387.288328] rcu-torture: rcu_torture_read_exit: Start of episode
[ 387.310597] rcu-torture: rcu_torture_read_exit: End of episode
[ 400.664730] rcu-torture: rcu_torture_read_exit: Start of episode
[ 400.673639] rcu-torture: rcu_torture_read_exit: End of episode
[ 413.976599] rcu-torture: rcu_torture_read_exit: Start of episode
[ 413.980345] rcu-torture: rcu_torture_read_exit: End of episode
[ 419.251437] ==================================================================
[ 419.252075] BUG: KCSAN: data-race in tick_nohz_idle_stop_tick / tick_nohz_next_event

[ 419.252915] write to 0xffffffff8748abf0 of 4 bytes by task 0 on cpu 0:
[ 419.253414] tick_nohz_idle_stop_tick+0x39c/0x490
[ 419.253426] do_idle+0x1e4/0x250
[ 419.253435] cpu_startup_entry+0x14/0x20
[ 419.253445] rest_init+0xf2/0x100
[ 419.253454] arch_call_rest_init+0x5/0x7
[ 419.253462] start_kernel+0x805/0x82a
[ 419.253495] secondary_startup_64_no_verify+0xd5/0xdb

[ 419.253849] read to 0xffffffff8748abf0 of 4 bytes by task 0 on cpu 2:
[ 419.254953] tick_nohz_next_event+0xfd/0x220
[ 419.254984] tick_nohz_idle_stop_tick+0x298/0x490
[ 419.255002] do_idle+0x1e4/0x250
[ 419.255017] cpu_startup_entry+0x14/0x20
[ 419.255030] secondary_startup_64_no_verify+0xd5/0xdb

[ 419.255424] value changed: 0x00000000 -> 0xffffffff

[ 419.256105] Reported by Kernel Concurrency Sanitizer on:
[ 419.256444] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 419.256455] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 419.256461] ==================================================================
[ 427.288306] rcu-torture: rcu_torture_read_exit: Start of episode
[ 427.315380] rcu-torture: rcu_torture_read_exit: End of episode
[ 431.128367] rcu-torture: rtc: 000000007636a9e8 ver: 37020 tfle: 0 rta: 37021 rtaf: 0 rtf: 37009 rtmbe: 0 rtmbkf: 0/26233 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 282028 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 543 nocb-toggles: 0:0
[ 431.130705] rcu-torture: Reader Pipe: 69183925 33766 0 0 0 0 0 0 0 0 0
[ 431.131552] rcu-torture: Reader Batch: 69112946 104745 0 0 0 0 0 0 0 0 0
[ 431.133579] rcu-torture: Free-Block Circulation: 37020 37019 37018 37016 37015 37014 37013 37011 37010 37009 0
[ 440.728468] rcu-torture: rcu_torture_read_exit: Start of episode
[ 440.762267] rcu-torture: rcu_torture_read_exit: End of episode
[ 447.512649] rcu_torture_fwd_prog n_max_cbs: 20417
[ 447.516146] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 447.563108] rcu_torture_fwd_prog_cr Duration 24 barrier: 16 pending 2844 n_launders: 4705 n_launders_sa: 3359 n_max_gps: 100 n_max_cbs: 3259 cver 0 gps 8
[ 447.565869] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 43 jiffies): 1s/10: 7964:11
[ 454.105687] rcu-torture: rcu_torture_read_exit: Start of episode
[ 454.161551] rcu-torture: rcu_torture_read_exit: End of episode
[ 466.424242] rcu_torture_fwd_prog_nr: 0 Duration 17818 cver 1353 gps 2586
[ 467.545088] rcu-torture: rcu_torture_read_exit: Start of episode
[ 467.585267] rcu-torture: rcu_torture_read_exit: End of episode
[ 480.920343] rcu-torture: rcu_torture_read_exit: Start of episode
[ 480.944800] rcu-torture: rcu_torture_read_exit: End of episode
[ 492.588839] rcu-torture: rtc: 000000005c76f12c ver: 41689 tfle: 0 rta: 41690 rtaf: 0 rtf: 41680 rtmbe: 0 rtmbkf: 0/29530 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 322236 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 611 nocb-toggles: 0:0
[ 492.590079] rcu-torture: Reader Pipe: 79429157 37585 0 0 0 0 0 0 0 0 0
[ 492.590734] rcu-torture: Reader Batch: 79348919 117823 0 0 0 0 0 0 0 0 0
[ 492.591181] rcu-torture: Free-Block Circulation: 41689 41688 41687 41686 41685 41684 41683 41682 41681 41680 0
[ 494.296370] rcu-torture: rcu_torture_read_exit: Start of episode
[ 494.328479] rcu-torture: rcu_torture_read_exit: End of episode
[ 496.161416] ==================================================================
[ 496.162044] BUG: KCSAN: data-race in cpumask_next_wrap+0x52/0x80

[ 496.162739] race at unknown origin, with read to 0xffffffff87cc5140 of 8 bytes by interrupt on cpu 2:
[ 496.163278] cpumask_next_wrap+0x52/0x80
[ 496.163295] _nohz_idle_balance.constprop.0.isra.0+0x68/0x250
[ 496.163305] __do_softirq+0xe4/0x2d9
[ 496.163314] irq_exit_rcu+0xb6/0x100
[ 496.163321] sysvec_call_function_single+0x8e/0xc0
[ 496.163330] asm_sysvec_call_function_single+0x12/0x20
[ 496.163338] default_idle+0xb/0x10
[ 496.163344] default_idle_call+0x28/0xd0
[ 496.163351] do_idle+0x1e9/0x250
[ 496.163360] cpu_startup_entry+0x14/0x20
[ 496.163377] secondary_startup_64_no_verify+0xd5/0xdb

[ 496.163610] value changed: 0x0000000000000004 -> 0x0000000000000006

[ 496.164209] Reported by Kernel Concurrency Sanitizer on:
[ 496.164571] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 496.164581] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 496.164586] ==================================================================
[ 497.663531] ==================================================================
[ 497.665744] BUG: KCSAN: data-race in tick_nohz_idle_stop_tick / tick_nohz_idle_stop_tick

[ 497.669785] write to 0xffffffff8748abf0 of 4 bytes by task 0 on cpu 2:
[ 497.671978] tick_nohz_idle_stop_tick+0x39c/0x490
[ 497.672025] do_idle+0x1e4/0x250
[ 497.672064] cpu_startup_entry+0x14/0x20
[ 497.672103] secondary_startup_64_no_verify+0xd5/0xdb

[ 497.673146] read to 0xffffffff8748abf0 of 4 bytes by task 0 on cpu 1:
[ 497.678656] tick_nohz_idle_stop_tick+0x127/0x490
[ 497.678732] do_idle+0x1e4/0x250
[ 497.678797] cpu_startup_entry+0x14/0x20
[ 497.678864] secondary_startup_64_no_verify+0xd5/0xdb

[ 497.680429] value changed: 0x00000002 -> 0xffffffff

[ 497.684307] Reported by Kernel Concurrency Sanitizer on:
[ 497.685638] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.17.0-rc3-00369-gc67afd79c7ba #35
[ 497.685679] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014
[ 497.685700] ==================================================================
[ 507.736696] rcu-torture: rcu_torture_read_exit: Start of episode
[ 507.763719] rcu-torture: rcu_torture_read_exit: End of episode
[ 521.113290] rcu-torture: rcu_torture_read_exit: Start of episode
[ 521.143533] rcu-torture: rcu_torture_read_exit: End of episode
[ 527.065512] clocksource: timekeeping watchdog on CPU0: hpet wd-wd read-back delay of 175730ns
[ 527.065820] clocksource: wd-tsc-wd read-back delay of 130870ns, clock-skew test skipped!
[ 529.433291] rcu_torture_fwd_prog n_max_cbs: 3259
[ 529.433687] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 529.494537] rcu_torture_fwd_prog_cr Duration 37 barrier: 16 pending 5516 n_launders: 17853 n_launders_sa: 14102 n_max_gps: 100 n_max_cbs: 14003 cver 5 gps 10
[ 529.495552] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 54 jiffies): 1s/10: 31856:13
[ 534.489240] rcu-torture: rcu_torture_read_exit: Start of episode
[ 534.529357] rcu-torture: rcu_torture_read_exit: End of episode
[ 541.039291] rcu_torture_fwd_prog_nr: 0 Duration 10509 cver 902 gps 1724
[ 547.865253] rcu-torture: rcu_torture_read_exit: Start of episode
[ 547.870037] rcu-torture: rcu_torture_read_exit: End of episode
[ 554.008284] rcu-torture: rtc: 00000000cb05dc5d ver: 46684 tfle: 0 rta: 46685 rtaf: 0 rtf: 46675 rtmbe: 0 rtmbkf: 0/32994 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 360595 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 696 nocb-toggles: 0:0
[ 554.010019] rcu-torture: Reader Pipe: 89237498 41839 0 0 0 0 0 0 0 0 0
[ 554.010776] rcu-torture: Reader Batch: 89147309 132028 0 0 0 0 0 0 0 0 0
[ 554.011397] rcu-torture: Free-Block Circulation: 46684 46684 46683 46682 46681 46680 46679 46678 46677 46676 0
[ 561.176339] rcu-torture: rcu_torture_read_exit: Start of episode
[ 561.207247] rcu-torture: rcu_torture_read_exit: End of episode
[ 574.552464] rcu-torture: rcu_torture_read_exit: Start of episode
[ 579.179289] rcu-torture: rcu_torture_read_exit: End of episode
[ 590.872613] kworker/dying (151) used greatest stack depth: 11928 bytes left
[ 592.737242] rcu-torture: rcu_torture_read_exit: Start of episode
[ 592.770271] rcu-torture: rcu_torture_read_exit: End of episode
[ 603.160497] rcu_torture_fwd_prog n_max_cbs: 14003
[ 603.162492] rcu_torture_fwd_prog: Starting forward-progress test 0
[ 603.215421] rcu_torture_fwd_prog_cr Duration 28 barrier: 13 pending 3102 n_launders: 5235 n_launders_sa: 816 n_max_gps: 100 n_max_cbs: 3881 cver 0 gps 9
[ 603.218311] rcu_torture_fwd_cb_hist: Callback-invocation histogram 0 (duration 44 jiffies): 1s/10: 9116:11
[ 606.553242] rcu-torture: rcu_torture_read_exit: Start of episode
[ 606.581255] rcu-torture: rcu_torture_read_exit: End of episode
[ 615.448277] rcu-torture: rtc: 00000000aa795463 ver: 52127 tfle: 0 rta: 52128 rtaf: 0 rtf: 52117 rtmbe: 0 rtmbkf: 0/36880 rtbe: 0 rtbke: 0 rtbre: 0 rtbf: 0 rtb: 0 nt: 403387 onoff: 0/0:0/0 -1,0:-1,0 0:0 (HZ=1000) barrier: 0/0:0 read-exits: 764 nocb-toggles: 0:0
[ 615.450316] rcu-torture: Reader Pipe: 100296269 46965 0 0 0 0 0 0 0 0 0
[ 615.450788] rcu-torture: Reader Batch: 100195586 147648 0 0 0 0 0 0 0 0 0
[ 615.451293] rcu-torture: Free-Block Circulation: 52127 52126 52124 52123 52122 52121 52120 52119 52118 52117 0