Hello,
kernel test robot noticed "BUG:KCSAN:data-race_in_atime_needs_update/inode_update_timestamps" on:
commit: 541d4c798a598854fcce7326d947cbcbd35701d6 ("fs: drop the timespec64 arg from generic_update_time")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
in testcase: trinity
version: trinity-i386-abe9de86-1_20230429
with following parameters:
runtime: 300s
group: group-04
nr_groups: 5
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)
we noticed this issue does not always happen, and parent has similar ones.
we don't know if these issues are expected, just report what we found in our
tests FYI.
0d72b92883c651a1 541d4c798a598854fcce7326d94
---------------- ---------------------------
fail:runs %reproduction fail:runs
| | |
8:202 -4% :202 dmesg.BUG:KCSAN:data-race_in_atime_needs_update/generic_update_time
:202 11% 22:202 dmesg.BUG:KCSAN:data-race_in_atime_needs_update/inode_update_timestamps
48:202 -24% :202 dmesg.BUG:KCSAN:data-race_in_atime_needs_update/touch_atime
:202 7% 14:202 dmesg.BUG:KCSAN:data-race_in_generic_fillattr/inode_update_timestamps
21:202 -10% :202 dmesg.BUG:KCSAN:data-race_in_generic_fillattr/touch_atime
:202 12% 24:202 dmesg.BUG:KCSAN:data-race_in_inode_update_timestamps/inode_update_timestamps
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 <[email protected]>
| Closes: https://lore.kernel.org/oe-lkp/[email protected]
[ 179.356355][ T3221] BUG: KCSAN: data-race in atime_needs_update / inode_update_timestamps
[ 179.363113][ T3221]
[ 179.363323][ T3221] write to 0xffffa34c4c66f600 of 8 bytes by task 3222 on cpu 0:
[ 179.363951][ T3221] inode_update_timestamps (fs/inode.c:1923)
[ 179.364410][ T3221] generic_update_time (fs/inode.c:1948)
[ 179.364823][ T3221] touch_atime (fs/inode.c:1966 fs/inode.c:2038)
[ 179.365207][ T3221] generic_file_mmap (include/linux/fs.h:2245 mm/filemap.c:3616)
[ 179.365721][ T3221] mmap_region (mm/mmap.c:2751)
[ 179.366104][ T3221] do_mmap (mm/mmap.c:1362)
[ 179.366448][ T3221] vm_mmap_pgoff (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/linux/mmap_lock.h:41 include/linux/mmap_lock.h:127 mm/util.c:545)
[ 179.366840][ T3221] vm_mmap (mm/util.c:562)
[ 179.367181][ T3221] elf_map (fs/binfmt_elf.c:378)
[ 179.367586][ T3221] load_elf_binary (fs/binfmt_elf.c:1187)
[ 179.367996][ T3221] search_binary_handler (fs/exec.c:1740)
[ 179.368434][ T3221] exec_binprm (fs/exec.c:1781)
[ 179.368813][ T3221] bprm_execve (fs/exec.c:279 fs/exec.c:383 fs/exec.c:1533)
[ 179.369251][ T3221] bprm_execve (fs/exec.c:1885)
[ 179.369784][ T3221] kernel_execve (fs/exec.c:2023)
[ 179.370172][ T3221] call_usermodehelper_exec_async (kernel/umh.c:114)
[ 179.370673][ T3221] ret_from_fork (arch/x86/entry/entry_64.S:314)
[ 179.371043][ T3221]
[ 179.371253][ T3221] read to 0xffffa34c4c66f600 of 8 bytes by task 3221 on cpu 1:
[ 179.371864][ T3221] atime_needs_update (include/linux/time64.h:49 (discriminator 1) fs/inode.c:2008 (discriminator 1))
[ 179.372294][ T3221] touch_atime (fs/inode.c:2020 (discriminator 1))
[ 179.372669][ T3221] generic_file_mmap (include/linux/fs.h:2245 mm/filemap.c:3616)
[ 179.373163][ T3221] mmap_region (mm/mmap.c:2751)
[ 179.373533][ T3221] do_mmap (mm/mmap.c:1362)
[ 179.373950][ T3221] vm_mmap_pgoff (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/linux/mmap_lock.h:41 include/linux/mmap_lock.h:127 mm/util.c:545)
[ 179.374338][ T3221] vm_mmap (mm/util.c:562)
[ 179.374673][ T3221] elf_map (fs/binfmt_elf.c:378)
[ 179.375070][ T3221] load_elf_binary (fs/binfmt_elf.c:1187)
[ 179.375498][ T3221] search_binary_handler (fs/exec.c:1740)
[ 179.375941][ T3221] exec_binprm (fs/exec.c:1781)
[ 179.376294][ T3221] bprm_execve (fs/exec.c:279 fs/exec.c:383 fs/exec.c:1533)
[ 179.376712][ T3221] bprm_execve (fs/exec.c:1885)
[ 179.377063][ T3221] kernel_execve (fs/exec.c:2023)
[ 179.377452][ T3221] call_usermodehelper_exec_async (kernel/umh.c:114)
[ 179.378061][ T3221] ret_from_fork (arch/x86/entry/entry_64.S:314)
[ 179.378434][ T3221]
[ 179.378635][ T3221] value changed: 0x000000000402a3d1 -> 0x000000000411e611
[ 179.379219][ T3221]
[ 179.379411][ T3221] Reported by Kernel Concurrency Sanitizer on:
[ 179.379920][ T3221] CPU: 1 PID: 3221 Comm: modprobe Tainted: G N 6.5.0-rc1-00096-g541d4c798a59 #1
[ 179.380804][ T3221] ==================================================================
The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240408/[email protected]
--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests/wiki
On Mon, 2024-04-08 at 11:04 +0800, kernel test robot wrote:
>
> Hello,
>
> kernel test robot noticed "BUG:KCSAN:data-race_in_atime_needs_update/inode_update_timestamps" on:
>
> commit: 541d4c798a598854fcce7326d947cbcbd35701d6 ("fs: drop the timespec64 arg from generic_update_time")
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
>
> in testcase: trinity
> version: trinity-i386-abe9de86-1_20230429
> with following parameters:
>
> runtime: 300s
> group: group-04
> nr_groups: 5
>
>
>
> 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)
>
>
> we noticed this issue does not always happen, and parent has similar ones.
> we don't know if these issues are expected, just report what we found in our
> tests FYI.
>
>
> 0d72b92883c651a1 541d4c798a598854fcce7326d94
> ---------------- ---------------------------
> fail:runs %reproduction fail:runs
> | | |
> 8:202 -4% :202 dmesg.BUG:KCSAN:data-race_in_atime_needs_update/generic_update_time
> :202 11% 22:202 dmesg.BUG:KCSAN:data-race_in_atime_needs_update/inode_update_timestamps
> 48:202 -24% :202 dmesg.BUG:KCSAN:data-race_in_atime_needs_update/touch_atime
> :202 7% 14:202 dmesg.BUG:KCSAN:data-race_in_generic_fillattr/inode_update_timestamps
> 21:202 -10% :202 dmesg.BUG:KCSAN:data-race_in_generic_fillattr/touch_atime
> :202 12% 24:202 dmesg.BUG:KCSAN:data-race_in_inode_update_timestamps/inode_update_timestamps
>
>
> 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 <[email protected]>
> > Closes: https://lore.kernel.org/oe-lkp/[email protected]
>
>
> [ 179.356355][ T3221] BUG: KCSAN: data-race in atime_needs_update / inode_update_timestamps
> [ 179.363113][ T3221]
> [ 179.363323][ T3221] write to 0xffffa34c4c66f600 of 8 bytes by task 3222 on cpu 0:
> [ 179.363951][ T3221] inode_update_timestamps (fs/inode.c:1923)
> [ 179.364410][ T3221] generic_update_time (fs/inode.c:1948)
> [ 179.364823][ T3221] touch_atime (fs/inode.c:1966 fs/inode.c:2038)
> [ 179.365207][ T3221] generic_file_mmap (include/linux/fs.h:2245 mm/filemap.c:3616)
> [ 179.365721][ T3221] mmap_region (mm/mmap.c:2751)
> [ 179.366104][ T3221] do_mmap (mm/mmap.c:1362)
> [ 179.366448][ T3221] vm_mmap_pgoff (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/linux/mmap_lock.h:41 include/linux/mmap_lock.h:127 mm/util.c:545)
> [ 179.366840][ T3221] vm_mmap (mm/util.c:562)
> [ 179.367181][ T3221] elf_map (fs/binfmt_elf.c:378)
> [ 179.367586][ T3221] load_elf_binary (fs/binfmt_elf.c:1187)
> [ 179.367996][ T3221] search_binary_handler (fs/exec.c:1740)
> [ 179.368434][ T3221] exec_binprm (fs/exec.c:1781)
> [ 179.368813][ T3221] bprm_execve (fs/exec.c:279 fs/exec.c:383 fs/exec.c:1533)
> [ 179.369251][ T3221] bprm_execve (fs/exec.c:1885)
> [ 179.369784][ T3221] kernel_execve (fs/exec.c:2023)
> [ 179.370172][ T3221] call_usermodehelper_exec_async (kernel/umh.c:114)
> [ 179.370673][ T3221] ret_from_fork (arch/x86/entry/entry_64.S:314)
> [ 179.371043][ T3221]
> [ 179.371253][ T3221] read to 0xffffa34c4c66f600 of 8 bytes by task 3221 on cpu 1:
> [ 179.371864][ T3221] atime_needs_update (include/linux/time64.h:49 (discriminator 1) fs/inode.c:2008 (discriminator 1))
> [ 179.372294][ T3221] touch_atime (fs/inode.c:2020 (discriminator 1))
> [ 179.372669][ T3221] generic_file_mmap (include/linux/fs.h:2245 mm/filemap.c:3616)
> [ 179.373163][ T3221] mmap_region (mm/mmap.c:2751)
> [ 179.373533][ T3221] do_mmap (mm/mmap.c:1362)
> [ 179.373950][ T3221] vm_mmap_pgoff (arch/x86/include/asm/jump_label.h:27 include/linux/jump_label.h:207 include/linux/mmap_lock.h:41 include/linux/mmap_lock.h:127 mm/util.c:545)
> [ 179.374338][ T3221] vm_mmap (mm/util.c:562)
> [ 179.374673][ T3221] elf_map (fs/binfmt_elf.c:378)
> [ 179.375070][ T3221] load_elf_binary (fs/binfmt_elf.c:1187)
> [ 179.375498][ T3221] search_binary_handler (fs/exec.c:1740)
> [ 179.375941][ T3221] exec_binprm (fs/exec.c:1781)
> [ 179.376294][ T3221] bprm_execve (fs/exec.c:279 fs/exec.c:383 fs/exec.c:1533)
> [ 179.376712][ T3221] bprm_execve (fs/exec.c:1885)
> [ 179.377063][ T3221] kernel_execve (fs/exec.c:2023)
> [ 179.377452][ T3221] call_usermodehelper_exec_async (kernel/umh.c:114)
> [ 179.378061][ T3221] ret_from_fork (arch/x86/entry/entry_64.S:314)
> [ 179.378434][ T3221]
> [ 179.378635][ T3221] value changed: 0x000000000402a3d1 -> 0x000000000411e611
> [ 179.379219][ T3221]
> [ 179.379411][ T3221] Reported by Kernel Concurrency Sanitizer on:
> [ 179.379920][ T3221] CPU: 1 PID: 3221 Comm: modprobe Tainted: G N 6.5.0-rc1-00096-g541d4c798a59 #1
> [ 179.380804][ T3221] ==================================================================
>
>
>
> The kernel config and materials to reproduce are available at:
> https://download.01.org/0day-ci/archive/20240408/[email protected]
>
>
>
Timestamp updates in Linux have always been a bit racy. The changelog
for this patch mentions that there is a potential race condition with
this change:
"This change means that an update_time could fetch a different timestamp
than was seen in inode_needs_update_time. update_time is only ever
called with one of two flag combinations: Either S_ATIME is set, or
S_MTIME|S_CTIME|S_VERSION are set.
With this change we now treat the flags argument as an indicator that
some value needed to be updated when last checked, rather than an
indication to update specific timestamps."
I think that race condition is benign, and when it happens it we're no
worse off than before. Let me know if I'm misinterpreting this report
though. If there is potential for harm with this race, then I'm happy to
take another look.
--
Jeff Layton <[email protected]>