| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <202405312203.a36824e7-lkp@intel.com>
Date: Fri, 31 May 2024 22:41:09 +0800
From: kernel test robot <oliver.sang@...el.com>
To: Adrian Hunter <adrian.hunter@...el.com>
CC: <oe-lkp@...ts.linux.dev>, <lkp@...el.com>, <linux-kernel@...r.kernel.org>,
Thomas Gleixner <tglx@...utronix.de>, <oliver.sang@...el.com>
Subject: [linus:master] [timekeeping] fcf190c369:
BUG:KCSAN:data-race_in_timekeeping_advance/timekeeping_debug_get_ns
Hello,
kernel test robot noticed "BUG:KCSAN:data-race_in_timekeeping_advance/timekeeping_debug_get_ns" on:
commit: fcf190c369149c3b04539797cedf28741eb14164 ("timekeeping: Make delta calculation overflow safe")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
[test failed on linus/master 4a4be1ad3a6efea16c56615f31117590fd881358]
[test failed on linux-next/master 9d99040b1bc8dbf385a8aa535e9efcdf94466e19]
in testcase: boot
compiler: gcc-13
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
(please refer to attached dmesg/kmsg for entire log/backtrace)
since we don't have enough knowledge to investigate KCSAN issues deeply, we
just run more times to make sure the issue is persistent on the commit and
clean on parent. for this one, below just FYI.
e809a80aa0bcf802 fcf190c369149c3b04539797ced
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
17:50 -34% :50 dmesg.BUG:KCSAN:data-race_in_ktime_get/timekeeping_advance
14:50 -28% :50 dmesg.BUG:KCSAN:data-race_in_ktime_get_update_offsets_now/timekeeping_advance
13:50 10% 18:50 dmesg.BUG:KCSAN:data-race_in_rb_get_reader_page/rb_move_tail
50:50 0% 50:50 dmesg.BUG:KCSAN:data-race_in_rb_get_reader_page/ring_buffer_unlock_commit
:50 6% 3:50 dmesg.BUG:KCSAN:data-race_in_rb_move_tail/ring_buffer_read_page
:50 60% 30:50 dmesg.BUG:KCSAN:data-race_in_timekeeping_advance/timekeeping_debug_get_ns
If you fix the issue in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@...el.com>
| Closes: https://lore.kernel.org/oe-lkp/202405312203.a36824e7-lkp@intel.com
[ 7.317452][ C1] BUG: KCSAN: data-race in timekeeping_advance / timekeeping_debug_get_ns
[ 7.319202][ C1]
[ 7.319379][ C1] write to 0xffffffffaaa638b8 of 296 bytes by interrupt on cpu 0:
[ 7.320781][ C1] timekeeping_advance (kernel/time/timekeeping.c:2224 (discriminator 1))
[ 7.320781][ C1] update_wall_time (kernel/time/timekeeping.c:2239 (discriminator 1))
[ 7.320781][ C1] tick_periodic (kernel/time/tick-common.c:97)
[ 7.320781][ C1] tick_handle_periodic (include/linux/clockchips.h:152 kernel/time/tick-common.c:122)
[ 7.324712][ C1] __sysvec_apic_timer_interrupt (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 arch/x86/include/asm/trace/irq_vectors.h:41 arch/x86/kernel/apic/apic.c:1050)
[ 7.324712][ C1] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1043 (discriminator 47) arch/x86/kernel/apic/apic.c:1043 (discriminator 47))
[ 7.324712][ C1] asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:702)
[ 7.328793][ C1] _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:699 arch/x86/include/asm/irqflags.h:135 include/linux/spinlock_api_smp.h:151 kernel/locking/spinlock.c:194)
[ 7.328793][ C1] prepare_to_swait_event (kernel/sched/swait.c:122)
[ 7.328793][ C1] rcu_gp_fqs_loop (kernel/rcu/tree.c:1577 kernel/rcu/tree.c:1663)
[ 7.328793][ C1] rcu_gp_kthread (kernel/rcu/tree.c:1865 (discriminator 2))
[ 7.332714][ C1] kthread (kernel/kthread.c:388)
[ 7.332714][ C1] ret_from_fork (arch/x86/kernel/process.c:153)
[ 7.332714][ C1] ret_from_fork_asm (arch/x86/entry/entry_64.S:256)
[ 7.332714][ C1]
[ 7.336781][ C1] read to 0xffffffffaaa638d8 of 8 bytes by interrupt on cpu 1:
[ 7.336781][ C1] timekeeping_debug_get_ns (kernel/time/timekeeping.c:389 (discriminator 1) kernel/time/timekeeping.c:372 (discriminator 1) kernel/time/timekeeping.c:280 (discriminator 1))
[ 7.340722][ C1] ktime_get (kernel/time/timekeeping.c:406 kernel/time/timekeeping.c:855)
[ 7.340722][ C1] sched_clock_tick (kernel/sched/clock.c:98 (discriminator 1) kernel/sched/clock.c:424 (discriminator 1) kernel/sched/clock.c:412 (discriminator 1))
[ 7.340722][ C1] scheduler_tick (kernel/sched/sched.h:1385 kernel/sched/sched.h:1699 kernel/sched/core.c:5679)
[ 7.344805][ C1] update_process_times (kernel/time/timer.c:2493)
[ 7.344805][ C1] tick_periodic (kernel/time/tick-common.c:101)
[ 7.344805][ C1] tick_handle_periodic (kernel/time/tick-common.c:129)
[ 7.344805][ C1] __sysvec_apic_timer_interrupt (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 arch/x86/include/asm/trace/irq_vectors.h:41 arch/x86/kernel/apic/apic.c:1050)
[ 7.348718][ C1] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1043 (discriminator 2) arch/x86/kernel/apic/apic.c:1043 (discriminator 2))
[ 7.348718][ C1] asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:702)
[ 7.348718][ C1] _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:699 arch/x86/include/asm/irqflags.h:135 include/linux/spinlock_api_smp.h:151 kernel/locking/spinlock.c:194)
[ 7.352782][ C1] swake_up_one_online (kernel/rcu/tree.c:1046)
[ 7.352782][ C1] rcu_gp_kthread_wake (kernel/rcu/tree.c:1073)
[ 7.352782][ C1] rcu_report_qs_rsp (kernel/rcu/tree.c:1889)
[ 7.352782][ C1] rcu_report_qs_rnp (kernel/rcu/tree.c:1960)
[ 7.356725][ C1] rcu_report_qs_rdp (kernel/rcu/tree.c:2062)
[ 7.356725][ C1] rcu_core (kernel/rcu/rcu.h:138 (discriminator 2) kernel/rcu/tree.c:227 (discriminator 2) kernel/rcu/tree.c:2458 (discriminator 2))
[ 7.356725][ C1] rcu_core_si (kernel/rcu/tree.c:2489)
[ 7.356725][ C1] __do_softirq (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/trace/events/irq.h:142 kernel/softirq.c:555)
[ 7.360772][ C1] irq_exit_rcu (kernel/softirq.c:647 (discriminator 38))
[ 7.360772][ C1] sysvec_apic_timer_interrupt (arch/x86/kernel/apic/apic.c:1043 (discriminator 47) arch/x86/kernel/apic/apic.c:1043 (discriminator 47))
[ 7.360772][ C1] asm_sysvec_apic_timer_interrupt (arch/x86/include/asm/idtentry.h:702)
[ 7.364706][ C1] _raw_spin_unlock_irqrestore (arch/x86/include/asm/paravirt.h:699 arch/x86/include/asm/irqflags.h:135 include/linux/spinlock_api_smp.h:151 kernel/locking/spinlock.c:194)
[ 7.364706][ C1] __delete_object (mm/kmemleak.c:798)
[ 7.364706][ C1] kmem_cache_free (include/linux/kmemleak.h:48 mm/slub.c:2072 mm/slub.c:4280 mm/slub.c:4344)
[ 7.364706][ C1] putname (fs/namei.c:274)
[ 7.368775][ C1] kern_path (fs/namei.c:2627)
[ 7.368775][ C1] init_stat (fs/init.c:133)
[ 7.368775][ C1] clean_path (init/initramfs.c:334 (discriminator 1))
[ 7.368775][ C1] do_name (init/initramfs.c:367)
[ 7.368775][ C1] flush_buffer (init/initramfs.c:452 (discriminator 1) init/initramfs.c:464 (discriminator 1))
[ 7.372705][ C1] __gunzip+0x36d/0x4d0
[ 7.372705][ C1] gunzip (lib/decompress_inflate.c:207 (discriminator 1))
[ 7.372705][ C1] unpack_to_rootfs (init/initramfs.c:522)
[ 7.372705][ C1] do_populate_rootfs (init/initramfs.c:714)
[ 7.376757][ C1] async_run_entry_fn (kernel/async.c:136 (discriminator 1))
[ 7.376757][ C1] process_one_work (kernel/workqueue.c:3259)
[ 7.376757][ C1] worker_thread (kernel/workqueue.c:3329 (discriminator 2) kernel/workqueue.c:3416 (discriminator 2))
[ 7.376757][ C1] kthread (kernel/kthread.c:388)
[ 7.380720][ C1] ret_from_fork (arch/x86/kernel/process.c:153)
[ 7.380720][ C1] ret_from_fork_asm (arch/x86/entry/entry_64.S:256)
[ 7.380720][ C1]
[ 7.380720][ C1] value changed: 0x000a914d14000000 -> 0x000ace5614000000
[ 7.384767][ C1]
[ 7.384767][ C1] Reported by Kernel Concurrency Sanitizer on:
[ 7.384767][ C1] CPU: 1 PID: 30 Comm: kworker/u9:1 Not tainted 6.9.0-rc3-00018-gfcf190c36914 #2
[ 7.388715][ C1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 7.388715][ C1] Workqueue: async async_run_entry_fn
[ 7.388715][ C1] ==================================================================
[ 46.680358][ T30] Freeing initrd memory: 107964K
[ 46.682005][ T1] PCI-DMA: Using software bounce buffering for IO (SWIOTLB)
[ 46.683699][ T1] software IO TLB: mapped [mem 0x00000000b5671000-0x00000000b9671000] (64MB)
[ 46.705499][ T1] clocksource: tsc: mask: 0xffffffffffffffff max_cycles: 0x1fa3704c1a9, max_idle_ns: 440795296692 ns
[ 46.711289][ T1] AVX2 or AES-NI instructions are not detected.
[ 46.750407][ T1] Initialise system trusted keyrings
[ 46.752155][ T1] Key type blacklist registered
[ 46.754665][ T1] workingset: timestamp_bits=62 max_order=22 bucket_order=0
[ 46.772327][ T1] debugfs: Directory 'file_lock_cache' with parent 'slab' already present!
[ 46.818173][ T1] ntfs3: Max link count 4000
[ 46.819226][ T1] ntfs3: Warning: Activated 64 bits per cluster. Windows does not support this
[ 46.821239][ T1] ntfs3: Read-only LZX/Xpress compression included
[ 46.827627][ T1] efs: 1.0a - http://aeschi.ch.eu.org/efs/
[ 46.830338][ T1] JFS: nTxBlock = 8192, nTxLock = 65536
[ 46.848621][ T1] NILFS version 2 loaded
[ 46.849689][ T1] befs: version: 0.9.3
[ 46.855836][ T1] gfs2: GFS2 installed
[ 46.860723][ T1] Key type asymmetric registered
[ 46.861970][ T1] Asymmetric key parser 'x509' registered
[ 46.864644][ T1] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
[ 46.867540][ T1] io scheduler mq-deadline registered
[ 46.868771][ T1] io scheduler kyber registered
[ 46.870314][ T1] io scheduler bfq registered
[ 47.359071][ T49] ==================================================================
[ 47.360665][ T49] BUG: KCSAN: data-race in rb_get_reader_page / ring_buffer_unlock_commit
[ 47.360665][ T49]
[ 47.360665][ T49] write to 0xffff8881093584a8 of 8 bytes by task 48 on cpu 0:
[ 47.360665][ T49] rb_get_reader_page (kernel/trace/ring_buffer.c:4598)
[ 47.360665][ T49] rb_buffer_peek (kernel/trace/ring_buffer.c:4729)
[ 47.360665][ T49] ring_buffer_consume (kernel/trace/ring_buffer.c:5013)
[ 47.360665][ T49] ring_buffer_consumer (kernel/trace/ring_buffer_benchmark.c:91 kernel/trace/ring_buffer_benchmark.c:205)
[ 47.360665][ T49] ring_buffer_consumer_thread (kernel/trace/ring_buffer_benchmark.c:390 (discriminator 3))
[ 47.360665][ T49] kthread (kernel/kthread.c:388)
[ 47.360665][ T49] ret_from_fork (arch/x86/kernel/process.c:153)
[ 47.360665][ T49] ret_from_fork_asm (arch/x86/entry/entry_64.S:256)
[ 47.372689][ T49]
[ 47.372689][ T49] read to 0xffff8881093584a8 of 8 bytes by task 49 on cpu 1:
[ 47.372689][ T49] ring_buffer_unlock_commit (kernel/trace/ring_buffer.c:3067 kernel/trace/ring_buffer.c:3253)
[ 47.372689][ T49] ring_buffer_producer (kernel/trace/ring_buffer_benchmark.c:255 (discriminator 1))
[ 47.372689][ T49] ring_buffer_producer_thread (kernel/trace/ring_buffer_benchmark.c:82 kernel/trace/ring_buffer_benchmark.c:414)
[ 47.372689][ T49] kthread (kernel/kthread.c:388)
[ 47.372689][ T49] ret_from_fork (arch/x86/kernel/process.c:153)
[ 47.372689][ T49] ret_from_fork_asm (arch/x86/entry/entry_64.S:256)
[ 47.372689][ T49]
[ 47.372689][ T49] value changed: 0xffff888141aa3c40 -> 0xffff888141aa3b40
[ 47.372689][ T49]
[ 47.372689][ T49] Reported by Kernel Concurrency Sanitizer on:
[ 47.372689][ T49] CPU: 1 PID: 49 Comm: rb_producer Not tainted 6.9.0-rc3-00018-gfcf190c36914 #2
[ 47.372689][ T49] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 47.372689][ T49] ==================================================================
[ 51.025622][ T49] ==================================================================
[ 51.027409][ T49] BUG: KCSAN: data-race in rb_get_reader_page / ring_buffer_unlock_commit
[ 51.028657][ T49]
[ 51.028657][ T49] write to 0xffff8881093584a8 of 8 bytes by task 48 on cpu 0:
[ 51.028657][ T49] rb_get_reader_page (kernel/trace/ring_buffer.c:4598)
[ 51.028657][ T49] rb_buffer_peek (kernel/trace/ring_buffer.c:4729)
[ 51.028657][ T49] ring_buffer_consume (kernel/trace/ring_buffer.c:5013)
[ 51.028657][ T49] ring_buffer_consumer (kernel/trace/ring_buffer_benchmark.c:91 kernel/trace/ring_buffer_benchmark.c:205)
[ 51.028657][ T49] ring_buffer_consumer_thread (kernel/trace/ring_buffer_benchmark.c:390 (discriminator 3))
[ 51.028657][ T49] kthread (kernel/kthread.c:388)
[ 51.028657][ T49] ret_from_fork (arch/x86/kernel/process.c:153)
[ 51.028657][ T49] ret_from_fork_asm (arch/x86/entry/entry_64.S:256)
[ 51.028657][ T49]
[ 51.028657][ T49] read to 0xffff8881093584a8 of 8 bytes by task 49 on cpu 1:
[ 51.028657][ T49] ring_buffer_unlock_commit (kernel/trace/ring_buffer.c:3067 kernel/trace/ring_buffer.c:3253)
[ 51.028657][ T49] ring_buffer_producer (kernel/trace/ring_buffer_benchmark.c:255 (discriminator 1))
[ 51.028657][ T49] ring_buffer_producer_thread (kernel/trace/ring_buffer_benchmark.c:82 kernel/trace/ring_buffer_benchmark.c:414)
[ 51.028657][ T49] kthread (kernel/kthread.c:388)
[ 51.028657][ T49] ret_from_fork (arch/x86/kernel/process.c:153)
[ 51.028657][ T49] ret_from_fork_asm (arch/x86/entry/entry_64.S:256)
[ 51.028657][ T49]
[ 51.028657][ T49] value changed: 0xffff888141aa3b40 -> 0xffff888141aa3d40
[ 51.028657][ T49]
[ 51.028657][ T49] Reported by Kernel Concurrency Sanitizer on:
[ 51.028657][ T49] CPU: 1 PID: 49 Comm: rb_producer Not tainted 6.9.0-rc3-00018-gfcf190c36914 #2
[ 51.028657][ T49] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 51.028657][ T49] ==================================================================
[ 54.411601][ T49] ==================================================================
[ 54.412673][ T49] BUG: KCSAN: data-race in rb_get_reader_page / ring_buffer_unlock_commit
[ 54.412673][ T49]
[ 54.412673][ T49] write to 0xffff8881093584a8 of 8 bytes by task 48 on cpu 0:
[ 54.412673][ T49] rb_get_reader_page (kernel/trace/ring_buffer.c:4598)
[ 54.412673][ T49] rb_buffer_peek (kernel/trace/ring_buffer.c:4729)
[ 54.412673][ T49] ring_buffer_consume (kernel/trace/ring_buffer.c:5013)
[ 54.412673][ T49] ring_buffer_consumer (kernel/trace/ring_buffer_benchmark.c:91 kernel/trace/ring_buffer_benchmark.c:205)
[ 54.412673][ T49] ring_buffer_consumer_thread (kernel/trace/ring_buffer_benchmark.c:390 (discriminator 3))
[ 54.412673][ T49] kthread (kernel/kthread.c:388)
[ 54.412673][ T49] ret_from_fork (arch/x86/kernel/process.c:153)
[ 54.412673][ T49] ret_from_fork_asm (arch/x86/entry/entry_64.S:256)
[ 54.412673][ T49]
[ 54.412673][ T49] read to 0xffff8881093584a8 of 8 bytes by task 49 on cpu 1:
[ 54.412673][ T49] ring_buffer_unlock_commit (kernel/trace/ring_buffer.c:3067 kernel/trace/ring_buffer.c:3253)
[ 54.412673][ T49] ring_buffer_producer (kernel/trace/ring_buffer_benchmark.c:255 (discriminator 1))
[ 54.412673][ T49] ring_buffer_producer_thread (kernel/trace/ring_buffer_benchmark.c:82 kernel/trace/ring_buffer_benchmark.c:414)
[ 54.412673][ T49] kthread (kernel/kthread.c:388)
[ 54.412673][ T49] ret_from_fork (arch/x86/kernel/process.c:153)
[ 54.412673][ T49] ret_from_fork_asm (arch/x86/entry/entry_64.S:256)
[ 54.412673][ T49]
[ 54.412673][ T49] value changed: 0xffff888141a4ed40 -> 0xffff888141a5f340
[ 54.412673][ T49]
[ 54.412673][ T49] Reported by Kernel Concurrency Sanitizer on:
[ 54.412673][ T49] CPU: 1 PID: 49 Comm: rb_producer Not tainted 6.9.0-rc3-00018-gfcf190c36914 #2
[ 54.412673][ T49] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 54.412673][ T49] ==================================================================
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240531/202405312203.a36824e7-lkp@intel.com
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
Powered by blists - more mailing lists