2021-04-11 03:46:29

by Hao Sun

[permalink] [raw]
Subject: More KCSAN data-race Reports

Hi

Since the last KCSAN report[1], I found two more KCSAN reports that
Syzbot had not reported.
Not sure if they are valid bugs, I hope the stack information in
reports can help you locate the problem.
Kernel config can be found in the attachment.

Here is the detailed information:
commit: 3b9cdafb5358eb9f3790de2f728f765fef100731
version: linux 5.11
git tree: upstream

Report-1
==================================================================
BUG: KCSAN: data-race in ext4_mark_iloc_dirty / jbd2_journal_commit_transaction

read-write to 0xffff88804451d800 of 8 bytes by task 4821 on cpu 1:
jbd2_journal_commit_transaction+0x222/0x3200
kjournald2+0x253/0x470
kthread+0x1f0/0x220
ret_from_fork+0x1f/0x30

read to 0xffff88804451d800 of 8 bytes by task 8418 on cpu 0:
ext4_mark_iloc_dirty+0x14ec/0x16e0
__ext4_mark_inode_dirty+0x4d2/0x5d0
ext4_evict_inode+0xb9f/0xed0
evict+0x1a6/0x410
iput+0x3fc/0x510
do_unlinkat+0x2c9/0x4d0
__x64_sys_unlink+0x2c/0x30
do_syscall_64+0x39/0x80
entry_SYSCALL_64_after_hwframe+0x44/0xae

Report-2
==================================================================
BUG: KCSAN: data-race in __ext4_handle_dirty_metadata /
jbd2_journal_commit_transaction

read-write to 0xffff88800e142800 of 8 bytes by task 4823 on cpu 0:
jbd2_journal_commit_transaction+0x222/0x3200
kjournald2+0x253/0x470
kthread+0x1f0/0x220
ret_from_fork+0x1f/0x30

read to 0xffff88800e142800 of 8 bytes by task 7925 on cpu 1:
__ext4_handle_dirty_metadata+0x11a/0x590
ext4_mark_iloc_dirty+0x12dd/0x16e0
__ext4_mark_inode_dirty+0x4d2/0x5d0
ext4_dirty_inode+0x86/0xa0
__mark_inode_dirty+0x70/0x6b0
file_update_time+0x3ab/0x3f0
file_modified+0x62/0x80
ext4_buffered_write_iter+0x1f9/0x3d0
ext4_file_write_iter+0x45e/0x10d0
vfs_write+0x6db/0x7c0
ksys_write+0xce/0x180
__x64_sys_write+0x3e/0x50
do_syscall_64+0x39/0x80
entry_SYSCALL_64_after_hwframe+0x44/0xae


[1] https://lore.kernel.org/lkml/[email protected]om/


Attachments:
config (215.69 kB)

2021-04-12 09:07:20

by Jan Kara

[permalink] [raw]
Subject: Re: More KCSAN data-race Reports

Hello,

On Sun 11-04-21 11:42:05, Hao Sun wrote:
> Since the last KCSAN report[1], I found two more KCSAN reports that
> Syzbot had not reported.
> Not sure if they are valid bugs, I hope the stack information in
> reports can help you locate the problem.
> Kernel config can be found in the attachment.

Do we have symbolic decoding of the traces below? Because involved
functions are really big so it's difficult to guess what KCSAN is
complaining about... At least I wasn't able to guess it after looking into
the stacktraces for a while.

Honza

>
> Here is the detailed information:
> commit: 3b9cdafb5358eb9f3790de2f728f765fef100731
> version: linux 5.11
> git tree: upstream
>
> Report-1
> ==================================================================
> BUG: KCSAN: data-race in ext4_mark_iloc_dirty / jbd2_journal_commit_transaction
>
> read-write to 0xffff88804451d800 of 8 bytes by task 4821 on cpu 1:
> jbd2_journal_commit_transaction+0x222/0x3200
> kjournald2+0x253/0x470
> kthread+0x1f0/0x220
> ret_from_fork+0x1f/0x30
>
> read to 0xffff88804451d800 of 8 bytes by task 8418 on cpu 0:
> ext4_mark_iloc_dirty+0x14ec/0x16e0
> __ext4_mark_inode_dirty+0x4d2/0x5d0
> ext4_evict_inode+0xb9f/0xed0
> evict+0x1a6/0x410
> iput+0x3fc/0x510
> do_unlinkat+0x2c9/0x4d0
> __x64_sys_unlink+0x2c/0x30
> do_syscall_64+0x39/0x80
> entry_SYSCALL_64_after_hwframe+0x44/0xae
>
> Report-2
> ==================================================================
> BUG: KCSAN: data-race in __ext4_handle_dirty_metadata /
> jbd2_journal_commit_transaction
>
> read-write to 0xffff88800e142800 of 8 bytes by task 4823 on cpu 0:
> jbd2_journal_commit_transaction+0x222/0x3200
> kjournald2+0x253/0x470
> kthread+0x1f0/0x220
> ret_from_fork+0x1f/0x30
>
> read to 0xffff88800e142800 of 8 bytes by task 7925 on cpu 1:
> __ext4_handle_dirty_metadata+0x11a/0x590
> ext4_mark_iloc_dirty+0x12dd/0x16e0
> __ext4_mark_inode_dirty+0x4d2/0x5d0
> ext4_dirty_inode+0x86/0xa0
> __mark_inode_dirty+0x70/0x6b0
> file_update_time+0x3ab/0x3f0
> file_modified+0x62/0x80
> ext4_buffered_write_iter+0x1f9/0x3d0
> ext4_file_write_iter+0x45e/0x10d0
> vfs_write+0x6db/0x7c0
> ksys_write+0xce/0x180
> __x64_sys_write+0x3e/0x50
> do_syscall_64+0x39/0x80
> entry_SYSCALL_64_after_hwframe+0x44/0xae
>
>
> [1] https://lore.kernel.org/lkml/[email protected]om/


--
Jan Kara <[email protected]>
SUSE Labs, CR

2021-04-12 10:43:38

by Hao Sun

[permalink] [raw]
Subject: Re: More KCSAN data-race Reports

Jan Kara <[email protected]> 于2021年4月12日周一 下午5:02写道:
>
> Hello,
>
> On Sun 11-04-21 11:42:05, Hao Sun wrote:
> > Since the last KCSAN report[1], I found two more KCSAN reports that
> > Syzbot had not reported.
> > Not sure if they are valid bugs, I hope the stack information in
> > reports can help you locate the problem.
> > Kernel config can be found in the attachment.
>
> Do we have symbolic decoding of the traces below? Because involved
> functions are really big so it's difficult to guess what KCSAN is
> complaining about... At least I wasn't able to guess it after looking into
> the stacktraces for a while.
>
Sorry, the log processing module of Fuzzer still has some logic bugs,
only some of the symbolized reports are stored in the disk.
Interestingly, however, the read-write end that causes data racing in
both reports are in the same location (fs/jbd2/commit.c:443), and this
information should help locate the problem.

Partial symbolized report 1:
==================================================================
BUG: KCSAN: data-race in ext4_mark_iloc_dirty / jbd2_journal_commit_transaction
read-write to 0xffff88804451d800 of 8 bytes by task 4821 on cpu 1:
jbd2_journal_commit_transaction+0x222/0x3200 fs/jbd2/commit.c:443
kjournald2+0x253/0x470 fs/jbd2/journal.c:213
kthread+0x1f0/0x220 kernel/kthread.c:292
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294

Partial symbolized report 2:
==================================================================
BUG: KCSAN: data-race in __ext4_handle_dirty_metadata /
jbd2_journal_commit_transaction
read-write to 0xffff88800e142800 of 8 bytes by task 4823 on cpu 0:
jbd2_journal_commit_transaction+0x222/0x3200 fs/jbd2/commit.c:443
kjournald2+0x253/0x470 fs/jbd2/journal.c:213
kthread+0x1f0/0x220 kernel/kthread.c:292
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:294

>
> >
> > Here is the detailed information:
> > commit: 3b9cdafb5358eb9f3790de2f728f765fef100731
> > version: linux 5.11
> > git tree: upstream
> >
> > Report-1
> > ==================================================================
> > BUG: KCSAN: data-race in ext4_mark_iloc_dirty / jbd2_journal_commit_transaction
> >
> > read-write to 0xffff88804451d800 of 8 bytes by task 4821 on cpu 1:
> > jbd2_journal_commit_transaction+0x222/0x3200
> > kjournald2+0x253/0x470
> > kthread+0x1f0/0x220
> > ret_from_fork+0x1f/0x30
> >
> > read to 0xffff88804451d800 of 8 bytes by task 8418 on cpu 0:
> > ext4_mark_iloc_dirty+0x14ec/0x16e0
> > __ext4_mark_inode_dirty+0x4d2/0x5d0
> > ext4_evict_inode+0xb9f/0xed0
> > evict+0x1a6/0x410
> > iput+0x3fc/0x510
> > do_unlinkat+0x2c9/0x4d0
> > __x64_sys_unlink+0x2c/0x30
> > do_syscall_64+0x39/0x80
> > entry_SYSCALL_64_after_hwframe+0x44/0xae
> >
> > Report-2
> > ==================================================================
> > BUG: KCSAN: data-race in __ext4_handle_dirty_metadata /
> > jbd2_journal_commit_transaction
> >
> > read-write to 0xffff88800e142800 of 8 bytes by task 4823 on cpu 0:
> > jbd2_journal_commit_transaction+0x222/0x3200
> > kjournald2+0x253/0x470
> > kthread+0x1f0/0x220
> > ret_from_fork+0x1f/0x30
> >
> > read to 0xffff88800e142800 of 8 bytes by task 7925 on cpu 1:
> > __ext4_handle_dirty_metadata+0x11a/0x590
> > ext4_mark_iloc_dirty+0x12dd/0x16e0
> > __ext4_mark_inode_dirty+0x4d2/0x5d0
> > ext4_dirty_inode+0x86/0xa0
> > __mark_inode_dirty+0x70/0x6b0
> > file_update_time+0x3ab/0x3f0
> > file_modified+0x62/0x80
> > ext4_buffered_write_iter+0x1f9/0x3d0
> > ext4_file_write_iter+0x45e/0x10d0
> > vfs_write+0x6db/0x7c0
> > ksys_write+0xce/0x180
> > __x64_sys_write+0x3e/0x50
> > do_syscall_64+0x39/0x80
> > entry_SYSCALL_64_after_hwframe+0x44/0xae
> >
> >
> > [1] https://lore.kernel.org/lkml/[email protected]om/
>
>
> --
> Jan Kara <[email protected]>
> SUSE Labs, CR