2021-08-26 14:27:36

by kernel test robot

[permalink] [raw]
Subject: [mm] f9ce0be71d: BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page



Greeting,

FYI, we noticed the following commit (built with clang-14):

commit: f9ce0be71d1fbb038ada15ced83474b0e63f264d ("mm: Cleanup faultaround and finish_fault() codepaths")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master


in testcase: trinity
version:
with following parameters:

number: 99999
group: group-04

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+------------------------------------------------------------------------+-----------+------------+
| | v5.11-rc4 | f9ce0be71d |
+------------------------------------------------------------------------+-----------+------------+
| BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page | 0 | 19 |
| BUG:KCSAN:data-race_in_mark_page_accessed/next_uptodate_page | 0 | 17 |
| BUG:KCSAN:data-race_in_next_uptodate_page/page_memcg | 0 | 13 |
| BUG:KCSAN:data-race_in_next_uptodate_page/unlock_page | 0 | 13 |
+------------------------------------------------------------------------+-----------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <[email protected]>


[ 184.717904][ T1873] ==================================================================
[ 184.718938][ T1873] BUG: KCSAN: data-race in next_uptodate_page / unlock_page
[ 184.719828][ T1873]
[ 184.720103][ T1873] write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
[ 184.721024][ T1873] unlock_page+0x102/0x1b0
[ 184.721533][ T1873] filemap_map_pages+0x6c6/0x890
[ 184.722102][ T1873] handle_mm_fault+0x179c/0x27f0
[ 184.722672][ T1873] do_user_addr_fault+0x3fb/0x830
[ 184.723263][ T1873] exc_page_fault+0xc3/0x1a0
[ 184.723845][ T1873] asm_exc_page_fault+0x1e/0x30
[ 184.724427][ T1873]
[ 184.724720][ T1873] read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
[ 184.725575][ T1873] next_uptodate_page+0x456/0x830
[ 184.726161][ T1873] filemap_map_pages+0x728/0x890
[ 184.726747][ T1873] handle_mm_fault+0x179c/0x27f0
[ 184.727332][ T1873] do_user_addr_fault+0x3fb/0x830
[ 184.727905][ T1873] exc_page_fault+0xc3/0x1a0
[ 184.728440][ T1873] asm_exc_page_fault+0x1e/0x30
[ 184.729027][ T1873]
[ 184.729313][ T1873] Reported by Kernel Concurrency Sanitizer on:
[ 184.730019][ T1873] CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
[ 184.731103][ T1873] ==================================================================


To reproduce:

# build kernel
cd linux
cp config-5.11.0-rc4-00001-gf9ce0be71d1f .config
make HOSTCC=clang-14 CC=clang-14 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage

git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> job-script # job-script is attached in this email



---
0DAY/LKP+ Test Infrastructure Open Source Technology Center
https://lists.01.org/hyperkitty/list/[email protected] Intel Corporation

Thanks,
Oliver Sang


Attachments:
(No filename) (3.39 kB)
config-5.11.0-rc4-00001-gf9ce0be71d1f (150.60 kB)
job-script (4.29 kB)
dmesg.xz (19.75 kB)
Download all attachments

2021-08-27 15:45:00

by Kirill A. Shutemov

[permalink] [raw]
Subject: Re: [mm] f9ce0be71d: BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page

On Thu, Aug 26, 2021 at 10:41:57PM +0800, kernel test robot wrote:
>
>
> Greeting,
>
> FYI, we noticed the following commit (built with clang-14):
>
> commit: f9ce0be71d1fbb038ada15ced83474b0e63f264d ("mm: Cleanup faultaround and finish_fault() codepaths")
> https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
>
>
> in testcase: trinity
> version:
> with following parameters:
>
> number: 99999
> group: group-04
>
> test-description: Trinity is a linux system call fuzz tester.
> test-url: http://codemonkey.org.uk/projects/trinity/
>
>
> on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
>
> caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
>
>
> +------------------------------------------------------------------------+-----------+------------+
> | | v5.11-rc4 | f9ce0be71d |
> +------------------------------------------------------------------------+-----------+------------+
> | BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page | 0 | 19 |
> | BUG:KCSAN:data-race_in_mark_page_accessed/next_uptodate_page | 0 | 17 |
> | BUG:KCSAN:data-race_in_next_uptodate_page/page_memcg | 0 | 13 |
> | BUG:KCSAN:data-race_in_next_uptodate_page/unlock_page | 0 | 13 |
> +------------------------------------------------------------------------+-----------+------------+
>
>
> If you fix the issue, kindly add following tag
> Reported-by: kernel test robot <[email protected]>
>
>
> [ 184.717904][ T1873] ==================================================================
> [ 184.718938][ T1873] BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> [ 184.719828][ T1873]
> [ 184.720103][ T1873] write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> [ 184.721024][ T1873] unlock_page+0x102/0x1b0
> [ 184.721533][ T1873] filemap_map_pages+0x6c6/0x890
> [ 184.722102][ T1873] handle_mm_fault+0x179c/0x27f0
> [ 184.722672][ T1873] do_user_addr_fault+0x3fb/0x830
> [ 184.723263][ T1873] exc_page_fault+0xc3/0x1a0
> [ 184.723845][ T1873] asm_exc_page_fault+0x1e/0x30
> [ 184.724427][ T1873]
> [ 184.724720][ T1873] read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> [ 184.725575][ T1873] next_uptodate_page+0x456/0x830
> [ 184.726161][ T1873] filemap_map_pages+0x728/0x890
> [ 184.726747][ T1873] handle_mm_fault+0x179c/0x27f0
> [ 184.727332][ T1873] do_user_addr_fault+0x3fb/0x830
> [ 184.727905][ T1873] exc_page_fault+0xc3/0x1a0
> [ 184.728440][ T1873] asm_exc_page_fault+0x1e/0x30
> [ 184.729027][ T1873]
> [ 184.729313][ T1873] Reported by Kernel Concurrency Sanitizer on:
> [ 184.730019][ T1873] CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
> [ 184.731103][ T1873] ==================================================================

Line annotation would be helpful.

And I'm not very familiar with KCSAN. My guess it reports PageLock() vs.
clearing PG_locked. In this context it looks safe, unless I miss
something.

Do we need some annotation to help KCSAN?

--
Kirill A. Shutemov

2021-08-31 13:16:13

by Will Deacon

[permalink] [raw]
Subject: Re: [mm] f9ce0be71d: BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page

[+Marco]

On Fri, Aug 27, 2021 at 06:42:32PM +0300, Kirill A. Shutemov wrote:
> On Thu, Aug 26, 2021 at 10:41:57PM +0800, kernel test robot wrote:
> > commit: f9ce0be71d1fbb038ada15ced83474b0e63f264d ("mm: Cleanup faultaround and finish_fault() codepaths")
> > https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
> >
> > in testcase: trinity
> > version:
> > with following parameters:
> >
> > number: 99999
> > group: group-04
> >
> > test-description: Trinity is a linux system call fuzz tester.
> > test-url: http://codemonkey.org.uk/projects/trinity/
> >
> >
> > on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
> >
> > caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
> >
> > +------------------------------------------------------------------------+-----------+------------+
> > | | v5.11-rc4 | f9ce0be71d |
> > +------------------------------------------------------------------------+-----------+------------+
> > | BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page | 0 | 19 |
> > | BUG:KCSAN:data-race_in_mark_page_accessed/next_uptodate_page | 0 | 17 |
> > | BUG:KCSAN:data-race_in_next_uptodate_page/page_memcg | 0 | 13 |
> > | BUG:KCSAN:data-race_in_next_uptodate_page/unlock_page | 0 | 13 |
> > +------------------------------------------------------------------------+-----------+------------+
> >
> > [ 184.717904][ T1873] ==================================================================
> > [ 184.718938][ T1873] BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> > [ 184.719828][ T1873]
> > [ 184.720103][ T1873] write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> > [ 184.721024][ T1873] unlock_page+0x102/0x1b0
> > [ 184.721533][ T1873] filemap_map_pages+0x6c6/0x890
> > [ 184.722102][ T1873] handle_mm_fault+0x179c/0x27f0
> > [ 184.722672][ T1873] do_user_addr_fault+0x3fb/0x830
> > [ 184.723263][ T1873] exc_page_fault+0xc3/0x1a0
> > [ 184.723845][ T1873] asm_exc_page_fault+0x1e/0x30
> > [ 184.724427][ T1873]
> > [ 184.724720][ T1873] read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> > [ 184.725575][ T1873] next_uptodate_page+0x456/0x830
> > [ 184.726161][ T1873] filemap_map_pages+0x728/0x890
> > [ 184.726747][ T1873] handle_mm_fault+0x179c/0x27f0
> > [ 184.727332][ T1873] do_user_addr_fault+0x3fb/0x830
> > [ 184.727905][ T1873] exc_page_fault+0xc3/0x1a0
> > [ 184.728440][ T1873] asm_exc_page_fault+0x1e/0x30
> > [ 184.729027][ T1873]
> > [ 184.729313][ T1873] Reported by Kernel Concurrency Sanitizer on:
> > [ 184.730019][ T1873] CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
> > [ 184.731103][ T1873] ==================================================================
>
> Line annotation would be helpful.

Agreed.

> And I'm not very familiar with KCSAN. My guess it reports PageLock() vs.
> clearing PG_locked. In this context it looks safe, unless I miss
> something.

The access in clear_bit_unlock() is annotated as a full sizeof(long) atomic
write, so we could be racing with a non-atomic read of another bit in the
page flags but I can't spot where that happens before the trylock_page() in
next_uptodate_page().

> Do we need some annotation to help KCSAN?

clear_bit_unlock() is already instrumented and _most_ of the helpers in
page-flags.h look they should be as well by virtue of using test_bit().

Will

2021-08-31 13:40:41

by Marco Elver

[permalink] [raw]
Subject: Re: [mm] f9ce0be71d: BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page

On Tue, 31 Aug 2021 at 15:13, Will Deacon <[email protected]> wrote:
[...]
> > > +------------------------------------------------------------------------+-----------+------------+
> > > | | v5.11-rc4 | f9ce0be71d |
> > > +------------------------------------------------------------------------+-----------+------------+
> > > | BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page | 0 | 19 |
> > > | BUG:KCSAN:data-race_in_mark_page_accessed/next_uptodate_page | 0 | 17 |
> > > | BUG:KCSAN:data-race_in_next_uptodate_page/page_memcg | 0 | 13 |
> > > | BUG:KCSAN:data-race_in_next_uptodate_page/unlock_page | 0 | 13 |
> > > +------------------------------------------------------------------------+-----------+------------+
> > >
> > > [ 184.717904][ T1873] ==================================================================
> > > [ 184.718938][ T1873] BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> > > [ 184.719828][ T1873]
> > > [ 184.720103][ T1873] write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> > > [ 184.721024][ T1873] unlock_page+0x102/0x1b0
> > > [ 184.721533][ T1873] filemap_map_pages+0x6c6/0x890
> > > [ 184.722102][ T1873] handle_mm_fault+0x179c/0x27f0
> > > [ 184.722672][ T1873] do_user_addr_fault+0x3fb/0x830
> > > [ 184.723263][ T1873] exc_page_fault+0xc3/0x1a0
> > > [ 184.723845][ T1873] asm_exc_page_fault+0x1e/0x30
> > > [ 184.724427][ T1873]
> > > [ 184.724720][ T1873] read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> > > [ 184.725575][ T1873] next_uptodate_page+0x456/0x830
> > > [ 184.726161][ T1873] filemap_map_pages+0x728/0x890
> > > [ 184.726747][ T1873] handle_mm_fault+0x179c/0x27f0
> > > [ 184.727332][ T1873] do_user_addr_fault+0x3fb/0x830
> > > [ 184.727905][ T1873] exc_page_fault+0xc3/0x1a0
> > > [ 184.728440][ T1873] asm_exc_page_fault+0x1e/0x30
> > > [ 184.729027][ T1873]
> > > [ 184.729313][ T1873] Reported by Kernel Concurrency Sanitizer on:
> > > [ 184.730019][ T1873] CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
> > > [ 184.731103][ T1873] ==================================================================
> >
> > Line annotation would be helpful.
>
> Agreed.
>
> > And I'm not very familiar with KCSAN. My guess it reports PageLock() vs.
> > clearing PG_locked. In this context it looks safe, unless I miss
> > something.
>
> The access in clear_bit_unlock() is annotated as a full sizeof(long) atomic
> write, so we could be racing with a non-atomic read of another bit in the
> page flags but I can't spot where that happens before the trylock_page() in
> next_uptodate_page().
>
> > Do we need some annotation to help KCSAN?
>
> clear_bit_unlock() is already instrumented and _most_ of the helpers in
> page-flags.h look they should be as well by virtue of using test_bit().

Even though they're data races, if this is a "1-bit value change" data
race, then I'd leave it as-is for now (unless maintainer prefers
marking everything that can concurrently be accessed).

Bots wanting to enable KCSAN and races like this was the reason for
CONFIG_KCSAN_PERMISSIVE (ignoring those "1-bit value changes"):
https://lkml.kernel.org/r/[email protected] --
This series is supposed to land in this merge-window.

For syzbot, we do active moderation -- when we get the time, we look
at races, and try to analyze or fix (although I've not looked
recently), or unconditionally forward to some maintainers who
committed addressing all data races in their subsystems (RCU, some
parts of networking).

Without active moderation before kernel 5.15, I do not recommend
turning on KCSAN on bots unconditionally, simply because prioritizing
the severity of data races is still difficult (and maintainers only
have so much time). Ultimately, our goal is of course to eventually
address all data races, but I think it requires time and patience.

With 5.15, it may be possible to cautiously enable KCSAN on bots
without moderation if they set CONFIG_KCSAN_PERMISSIVE=y. If no
moderation is possible, an intermediate step may be:

-- sending everything to a separate mailing list by default, without
Cc (those interested, can subscribe)
-- maintainers who opt into KCSAN reports will get the reports as normal.

We could also make use of those opt-ins for syzbot. :-)

Thoughts?

(For completeness, longer discussion on developer/maintainer
strategies: https://lwn.net/Articles/816854/)

Thanks,
-- Marco

2021-08-31 14:11:01

by Will Deacon

[permalink] [raw]
Subject: Re: [mm] f9ce0be71d: BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page

On Tue, Aug 31, 2021 at 03:38:17PM +0200, Marco Elver wrote:
> On Tue, 31 Aug 2021 at 15:13, Will Deacon <[email protected]> wrote:
> > > > [ 184.717904][ T1873] ==================================================================
> > > > [ 184.718938][ T1873] BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> > > > [ 184.719828][ T1873]
> > > > [ 184.720103][ T1873] write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> > > > [ 184.721024][ T1873] unlock_page+0x102/0x1b0
> > > > [ 184.721533][ T1873] filemap_map_pages+0x6c6/0x890
> > > > [ 184.722102][ T1873] handle_mm_fault+0x179c/0x27f0
> > > > [ 184.722672][ T1873] do_user_addr_fault+0x3fb/0x830
> > > > [ 184.723263][ T1873] exc_page_fault+0xc3/0x1a0
> > > > [ 184.723845][ T1873] asm_exc_page_fault+0x1e/0x30
> > > > [ 184.724427][ T1873]
> > > > [ 184.724720][ T1873] read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> > > > [ 184.725575][ T1873] next_uptodate_page+0x456/0x830
> > > > [ 184.726161][ T1873] filemap_map_pages+0x728/0x890
> > > > [ 184.726747][ T1873] handle_mm_fault+0x179c/0x27f0
> > > > [ 184.727332][ T1873] do_user_addr_fault+0x3fb/0x830
> > > > [ 184.727905][ T1873] exc_page_fault+0xc3/0x1a0
> > > > [ 184.728440][ T1873] asm_exc_page_fault+0x1e/0x30
> > > > [ 184.729027][ T1873]
> > > > [ 184.729313][ T1873] Reported by Kernel Concurrency Sanitizer on:
> > > > [ 184.730019][ T1873] CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
> > > > [ 184.731103][ T1873] ==================================================================
> > >
> > > Line annotation would be helpful.
> >
> > Agreed.
> >
> > > And I'm not very familiar with KCSAN. My guess it reports PageLock() vs.
> > > clearing PG_locked. In this context it looks safe, unless I miss
> > > something.
> >
> > The access in clear_bit_unlock() is annotated as a full sizeof(long) atomic
> > write, so we could be racing with a non-atomic read of another bit in the
> > page flags but I can't spot where that happens before the trylock_page() in
> > next_uptodate_page().
> >
> > > Do we need some annotation to help KCSAN?
> >
> > clear_bit_unlock() is already instrumented and _most_ of the helpers in
> > page-flags.h look they should be as well by virtue of using test_bit().
>
> Even though they're data races, if this is a "1-bit value change" data
> race, then I'd leave it as-is for now (unless maintainer prefers
> marking everything that can concurrently be accessed).
>
> Bots wanting to enable KCSAN and races like this was the reason for
> CONFIG_KCSAN_PERMISSIVE (ignoring those "1-bit value changes"):
> https://lkml.kernel.org/r/[email protected] --
> This series is supposed to land in this merge-window.
>
> For syzbot, we do active moderation -- when we get the time, we look
> at races, and try to analyze or fix (although I've not looked
> recently), or unconditionally forward to some maintainers who
> committed addressing all data races in their subsystems (RCU, some
> parts of networking).
>
> Without active moderation before kernel 5.15, I do not recommend
> turning on KCSAN on bots unconditionally, simply because prioritizing
> the severity of data races is still difficult (and maintainers only
> have so much time). Ultimately, our goal is of course to eventually
> address all data races, but I think it requires time and patience.

(sounds like the 0day folks should disable KCSAN for now then)

> With 5.15, it may be possible to cautiously enable KCSAN on bots
> without moderation if they set CONFIG_KCSAN_PERMISSIVE=y. If no
> moderation is possible, an intermediate step may be:
>
> -- sending everything to a separate mailing list by default, without
> Cc (those interested, can subscribe)
> -- maintainers who opt into KCSAN reports will get the reports as normal.
>
> We could also make use of those opt-ins for syzbot. :-)
>
> Thoughts?

I wasn't complaining about the report! It's more that without line numbers
we're struggling a bit to figure out where the race is. All the page-flag
tests on the reader side should be using test_bit(), but the report above
doesn't seem to think that the read is marked. Given your series adding
CONFIG_KCSAN_PERMISSIVE and the fact that you try to triage these things, I
thought maybe you've seen this before and might be able to point at the race
(which is hopefully benign, but it's annoying when you can't spot it!).

Will

2021-08-31 15:53:49

by Marco Elver

[permalink] [raw]
Subject: Re: [mm] f9ce0be71d: BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page

On Tue, Aug 31, 2021 at 03:07PM +0100, Will Deacon wrote:
> On Tue, Aug 31, 2021 at 03:38:17PM +0200, Marco Elver wrote:
> > On Tue, 31 Aug 2021 at 15:13, Will Deacon <[email protected]> wrote:
> > > > > [ 184.717904][ T1873] ==================================================================
> > > > > [ 184.718938][ T1873] BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> > > > > [ 184.719828][ T1873]
> > > > > [ 184.720103][ T1873] write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> > > > > [ 184.721024][ T1873] unlock_page+0x102/0x1b0
> > > > > [ 184.721533][ T1873] filemap_map_pages+0x6c6/0x890
> > > > > [ 184.722102][ T1873] handle_mm_fault+0x179c/0x27f0
> > > > > [ 184.722672][ T1873] do_user_addr_fault+0x3fb/0x830
> > > > > [ 184.723263][ T1873] exc_page_fault+0xc3/0x1a0
> > > > > [ 184.723845][ T1873] asm_exc_page_fault+0x1e/0x30
> > > > > [ 184.724427][ T1873]
> > > > > [ 184.724720][ T1873] read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> > > > > [ 184.725575][ T1873] next_uptodate_page+0x456/0x830
> > > > > [ 184.726161][ T1873] filemap_map_pages+0x728/0x890
> > > > > [ 184.726747][ T1873] handle_mm_fault+0x179c/0x27f0
> > > > > [ 184.727332][ T1873] do_user_addr_fault+0x3fb/0x830
> > > > > [ 184.727905][ T1873] exc_page_fault+0xc3/0x1a0
> > > > > [ 184.728440][ T1873] asm_exc_page_fault+0x1e/0x30
> > > > > [ 184.729027][ T1873]
> > > > > [ 184.729313][ T1873] Reported by Kernel Concurrency Sanitizer on:
> > > > > [ 184.730019][ T1873] CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
> > > > > [ 184.731103][ T1873] ==================================================================
> > > >
> > > > Line annotation would be helpful.
[...]
> > Thoughts?
>
> I wasn't complaining about the report! It's more that without line numbers
> we're struggling a bit to figure out where the race is. All the page-flag
> tests on the reader side should be using test_bit(), but the report above
> doesn't seem to think that the read is marked. Given your series adding
> CONFIG_KCSAN_PERMISSIVE and the fact that you try to triage these things, I
> thought maybe you've seen this before and might be able to point at the race
> (which is hopefully benign, but it's annoying when you can't spot it!).

Hmm, I was sure I could find it in either closed or still open syzbot
reports, but sadly I couldn't find anything. :-/

The next best thing was to take the same kernel version, same Clang
version, and same config in the hopes the generated functions of
interest are identical. If I take the report and symbolize it with what
I've built, I get:

| ==================================================================
| BUG: KCSAN: data-race in next_uptodate_page / unlock_page
|
| write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
| instrument_atomic_write include/linux/instrumented.h:87 [inline]
| clear_bit_unlock_is_negative_byte include/asm-generic/bitops/instrumented-lock.h:74 [inline]
| unlock_page+0x102/0x1b0 mm/filemap.c:1465
| filemap_map_pages+0x6c6/0x890 mm/filemap.c:3057
| do_fault_around mm/memory.c:3904 [inline]
| do_read_fault mm/memory.c:3918 [inline]
| do_fault mm/memory.c:4051 [inline]
| handle_pte_fault mm/memory.c:4302 [inline]
| __handle_mm_fault mm/memory.c:4437 [inline]
| handle_mm_fault+0x179c/0x27f0 mm/memory.c:4535
| do_user_addr_fault+0x3fb/0x830 arch/x86/mm/fault.c:1393
| handle_page_fault arch/x86/mm/fault.c:1450 [inline]
| exc_page_fault+0xc3/0x1a0 arch/x86/mm/fault.c:1506
| asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:580
|
| read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
| PagePoisoned include/linux/page-flags.h:204 [inline]
| PageReadahead include/linux/page-flags.h:382 [inline]
| next_uptodate_page+0x456/0x830 mm/filemap.c:2975
| next_map_page mm/filemap.c:3010 [inline]
| filemap_map_pages+0x728/0x890 mm/filemap.c:3066
| do_fault_around mm/memory.c:3904 [inline]
| do_read_fault mm/memory.c:3918 [inline]
| do_fault mm/memory.c:4051 [inline]
| handle_pte_fault mm/memory.c:4302 [inline]
| __handle_mm_fault mm/memory.c:4437 [inline]
| handle_mm_fault+0x179c/0x27f0 mm/memory.c:4535
| do_user_addr_fault+0x3fb/0x830 arch/x86/mm/fault.c:1393
| handle_page_fault arch/x86/mm/fault.c:1450 [inline]
| exc_page_fault+0xc3/0x1a0 arch/x86/mm/fault.c:1506
| asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:580
|
| Reported by Kernel Concurrency Sanitizer on:
| CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
| ==================================================================

And looking at the preprocessed source, this makes sense, because
PageReadahead clearly includes a call to PagePoisoned with the given
config.

My guess is that the below patch would be appropriate here?

(LKP folks: I'd still like bots to enable CONFIG_KCSAN_PERMISSIVE=y,
just to keep the volume of reports down for now.)

Thanks,
-- Marco

------ >8 ------

From: Marco Elver <[email protected]>
Date: Tue, 31 Aug 2021 17:27:27 +0200
Subject: [PATCH] mm: fix data race in PagePoisoned()

PagePoisoned() accesses page->flags which can be updated concurrently:

| BUG: KCSAN: data-race in next_uptodate_page / unlock_page
|
| write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
| instrument_atomic_write include/linux/instrumented.h:87 [inline]
| clear_bit_unlock_is_negative_byte include/asm-generic/bitops/instrumented-lock.h:74 [inline]
| unlock_page+0x102/0x1b0 mm/filemap.c:1465
| filemap_map_pages+0x6c6/0x890 mm/filemap.c:3057
| ...
| read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
| PagePoisoned include/linux/page-flags.h:204 [inline]
| PageReadahead include/linux/page-flags.h:382 [inline]
| next_uptodate_page+0x456/0x830 mm/filemap.c:2975
| ...
| CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1

To avoid the compiler tearing or otherwise optimizing the access, use
READ_ONCE() to access flags.

Reported-by: kernel test robot <[email protected]>
Signed-off-by: Marco Elver <[email protected]>
---
include/linux/page-flags.h | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/include/linux/page-flags.h b/include/linux/page-flags.h
index a68af80649a4..70bf0ec29ee3 100644
--- a/include/linux/page-flags.h
+++ b/include/linux/page-flags.h
@@ -236,7 +236,7 @@ static __always_inline int PageCompound(struct page *page)
#define PAGE_POISON_PATTERN -1l
static inline int PagePoisoned(const struct page *page)
{
- return page->flags == PAGE_POISON_PATTERN;
+ return READ_ONCE(page->flags) == PAGE_POISON_PATTERN;
}

#ifdef CONFIG_DEBUG_VM
--
2.33.0.259.gc128427fd7-goog

2021-09-01 02:30:16

by kernel test robot

[permalink] [raw]
Subject: Re: [mm] f9ce0be71d: BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page

hi Will,

On Tue, Aug 31, 2021 at 02:13:14PM +0100, Will Deacon wrote:
> [+Marco]
>
> On Fri, Aug 27, 2021 at 06:42:32PM +0300, Kirill A. Shutemov wrote:
> > On Thu, Aug 26, 2021 at 10:41:57PM +0800, kernel test robot wrote:
> > > commit: f9ce0be71d1fbb038ada15ced83474b0e63f264d ("mm: Cleanup faultaround and finish_fault() codepaths")
> > > https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master
> > >
> > > in testcase: trinity
> > > version:
> > > with following parameters:
> > >
> > > number: 99999
> > > group: group-04
> > >
> > > test-description: Trinity is a linux system call fuzz tester.
> > > test-url: http://codemonkey.org.uk/projects/trinity/
> > >
> > >
> > > on test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G
> > >
> > > caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
> > >
> > > +------------------------------------------------------------------------+-----------+------------+
> > > | | v5.11-rc4 | f9ce0be71d |
> > > +------------------------------------------------------------------------+-----------+------------+
> > > | BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page | 0 | 19 |
> > > | BUG:KCSAN:data-race_in_mark_page_accessed/next_uptodate_page | 0 | 17 |
> > > | BUG:KCSAN:data-race_in_next_uptodate_page/page_memcg | 0 | 13 |
> > > | BUG:KCSAN:data-race_in_next_uptodate_page/unlock_page | 0 | 13 |
> > > +------------------------------------------------------------------------+-----------+------------+
> > >
> > > [ 184.717904][ T1873] ==================================================================
> > > [ 184.718938][ T1873] BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> > > [ 184.719828][ T1873]
> > > [ 184.720103][ T1873] write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> > > [ 184.721024][ T1873] unlock_page+0x102/0x1b0
> > > [ 184.721533][ T1873] filemap_map_pages+0x6c6/0x890
> > > [ 184.722102][ T1873] handle_mm_fault+0x179c/0x27f0
> > > [ 184.722672][ T1873] do_user_addr_fault+0x3fb/0x830
> > > [ 184.723263][ T1873] exc_page_fault+0xc3/0x1a0
> > > [ 184.723845][ T1873] asm_exc_page_fault+0x1e/0x30
> > > [ 184.724427][ T1873]
> > > [ 184.724720][ T1873] read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> > > [ 184.725575][ T1873] next_uptodate_page+0x456/0x830
> > > [ 184.726161][ T1873] filemap_map_pages+0x728/0x890
> > > [ 184.726747][ T1873] handle_mm_fault+0x179c/0x27f0
> > > [ 184.727332][ T1873] do_user_addr_fault+0x3fb/0x830
> > > [ 184.727905][ T1873] exc_page_fault+0xc3/0x1a0
> > > [ 184.728440][ T1873] asm_exc_page_fault+0x1e/0x30
> > > [ 184.729027][ T1873]
> > > [ 184.729313][ T1873] Reported by Kernel Concurrency Sanitizer on:
> > > [ 184.730019][ T1873] CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
> > > [ 184.731103][ T1873] ==================================================================
> >
> > Line annotation would be helpful.
>
> Agreed.

Thanks a lot for suggestion! we will add line annotation.

>
> > And I'm not very familiar with KCSAN. My guess it reports PageLock() vs.
> > clearing PG_locked. In this context it looks safe, unless I miss
> > something.
>
> The access in clear_bit_unlock() is annotated as a full sizeof(long) atomic
> write, so we could be racing with a non-atomic read of another bit in the
> page flags but I can't spot where that happens before the trylock_page() in
> next_uptodate_page().
>
> > Do we need some annotation to help KCSAN?
>
> clear_bit_unlock() is already instrumented and _most_ of the helpers in
> page-flags.h look they should be as well by virtue of using test_bit().
>
> Will

2021-09-01 02:37:12

by kernel test robot

[permalink] [raw]
Subject: Re: [mm] f9ce0be71d: BUG:KCSAN:data-race_in_next_uptodate_page/next_uptodate_page

Hi Marco,

On Tue, Aug 31, 2021 at 05:47:37PM +0200, Marco Elver wrote:
> On Tue, Aug 31, 2021 at 03:07PM +0100, Will Deacon wrote:
> > On Tue, Aug 31, 2021 at 03:38:17PM +0200, Marco Elver wrote:
> > > On Tue, 31 Aug 2021 at 15:13, Will Deacon <[email protected]> wrote:
> > > > > > [ 184.717904][ T1873] ==================================================================
> > > > > > [ 184.718938][ T1873] BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> > > > > > [ 184.719828][ T1873]
> > > > > > [ 184.720103][ T1873] write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> > > > > > [ 184.721024][ T1873] unlock_page+0x102/0x1b0
> > > > > > [ 184.721533][ T1873] filemap_map_pages+0x6c6/0x890
> > > > > > [ 184.722102][ T1873] handle_mm_fault+0x179c/0x27f0
> > > > > > [ 184.722672][ T1873] do_user_addr_fault+0x3fb/0x830
> > > > > > [ 184.723263][ T1873] exc_page_fault+0xc3/0x1a0
> > > > > > [ 184.723845][ T1873] asm_exc_page_fault+0x1e/0x30
> > > > > > [ 184.724427][ T1873]
> > > > > > [ 184.724720][ T1873] read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> > > > > > [ 184.725575][ T1873] next_uptodate_page+0x456/0x830
> > > > > > [ 184.726161][ T1873] filemap_map_pages+0x728/0x890
> > > > > > [ 184.726747][ T1873] handle_mm_fault+0x179c/0x27f0
> > > > > > [ 184.727332][ T1873] do_user_addr_fault+0x3fb/0x830
> > > > > > [ 184.727905][ T1873] exc_page_fault+0xc3/0x1a0
> > > > > > [ 184.728440][ T1873] asm_exc_page_fault+0x1e/0x30
> > > > > > [ 184.729027][ T1873]
> > > > > > [ 184.729313][ T1873] Reported by Kernel Concurrency Sanitizer on:
> > > > > > [ 184.730019][ T1873] CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
> > > > > > [ 184.731103][ T1873] ==================================================================
> > > > >
> > > > > Line annotation would be helpful.
> [...]
> > > Thoughts?
> >
> > I wasn't complaining about the report! It's more that without line numbers
> > we're struggling a bit to figure out where the race is. All the page-flag
> > tests on the reader side should be using test_bit(), but the report above
> > doesn't seem to think that the read is marked. Given your series adding
> > CONFIG_KCSAN_PERMISSIVE and the fact that you try to triage these things, I
> > thought maybe you've seen this before and might be able to point at the race
> > (which is hopefully benign, but it's annoying when you can't spot it!).
>
> Hmm, I was sure I could find it in either closed or still open syzbot
> reports, but sadly I couldn't find anything. :-/
>
> The next best thing was to take the same kernel version, same Clang
> version, and same config in the hopes the generated functions of
> interest are identical. If I take the report and symbolize it with what
> I've built, I get:
>
> | ==================================================================
> | BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> |
> | write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> | instrument_atomic_write include/linux/instrumented.h:87 [inline]
> | clear_bit_unlock_is_negative_byte include/asm-generic/bitops/instrumented-lock.h:74 [inline]
> | unlock_page+0x102/0x1b0 mm/filemap.c:1465
> | filemap_map_pages+0x6c6/0x890 mm/filemap.c:3057
> | do_fault_around mm/memory.c:3904 [inline]
> | do_read_fault mm/memory.c:3918 [inline]
> | do_fault mm/memory.c:4051 [inline]
> | handle_pte_fault mm/memory.c:4302 [inline]
> | __handle_mm_fault mm/memory.c:4437 [inline]
> | handle_mm_fault+0x179c/0x27f0 mm/memory.c:4535
> | do_user_addr_fault+0x3fb/0x830 arch/x86/mm/fault.c:1393
> | handle_page_fault arch/x86/mm/fault.c:1450 [inline]
> | exc_page_fault+0xc3/0x1a0 arch/x86/mm/fault.c:1506
> | asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:580
> |
> | read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> | PagePoisoned include/linux/page-flags.h:204 [inline]
> | PageReadahead include/linux/page-flags.h:382 [inline]
> | next_uptodate_page+0x456/0x830 mm/filemap.c:2975
> | next_map_page mm/filemap.c:3010 [inline]
> | filemap_map_pages+0x728/0x890 mm/filemap.c:3066
> | do_fault_around mm/memory.c:3904 [inline]
> | do_read_fault mm/memory.c:3918 [inline]
> | do_fault mm/memory.c:4051 [inline]
> | handle_pte_fault mm/memory.c:4302 [inline]
> | __handle_mm_fault mm/memory.c:4437 [inline]
> | handle_mm_fault+0x179c/0x27f0 mm/memory.c:4535
> | do_user_addr_fault+0x3fb/0x830 arch/x86/mm/fault.c:1393
> | handle_page_fault arch/x86/mm/fault.c:1450 [inline]
> | exc_page_fault+0xc3/0x1a0 arch/x86/mm/fault.c:1506
> | asm_exc_page_fault+0x1e/0x30 arch/x86/include/asm/idtentry.h:580
> |
> | Reported by Kernel Concurrency Sanitizer on:
> | CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
> | ==================================================================
>
> And looking at the preprocessed source, this makes sense, because
> PageReadahead clearly includes a call to PagePoisoned with the given
> config.
>
> My guess is that the below patch would be appropriate here?
>
> (LKP folks: I'd still like bots to enable CONFIG_KCSAN_PERMISSIVE=y,
> just to keep the volume of reports down for now.)

Thanks a lot for all information so far and suggestions!

currently, we do human check and only when the parent is very clean
and the KCSAN issue is very clearly related with code change, we will
send out the report.

And we will follow up to enable CONFIG_KCSAN_PERMISSIVE=y

>
> Thanks,
> -- Marco
>
> ------ >8 ------
>
> From: Marco Elver <[email protected]>
> Date: Tue, 31 Aug 2021 17:27:27 +0200
> Subject: [PATCH] mm: fix data race in PagePoisoned()
>
> PagePoisoned() accesses page->flags which can be updated concurrently:
>
> | BUG: KCSAN: data-race in next_uptodate_page / unlock_page
> |
> | write (marked) to 0xffffea00050f37c0 of 8 bytes by task 1872 on cpu 1:
> | instrument_atomic_write include/linux/instrumented.h:87 [inline]
> | clear_bit_unlock_is_negative_byte include/asm-generic/bitops/instrumented-lock.h:74 [inline]
> | unlock_page+0x102/0x1b0 mm/filemap.c:1465
> | filemap_map_pages+0x6c6/0x890 mm/filemap.c:3057
> | ...
> | read to 0xffffea00050f37c0 of 8 bytes by task 1873 on cpu 0:
> | PagePoisoned include/linux/page-flags.h:204 [inline]
> | PageReadahead include/linux/page-flags.h:382 [inline]
> | next_uptodate_page+0x456/0x830 mm/filemap.c:2975
> | ...
> | CPU: 0 PID: 1873 Comm: systemd-udevd Not tainted 5.11.0-rc4-00001-gf9ce0be71d1f #1
>
> To avoid the compiler tearing or otherwise optimizing the access, use
> READ_ONCE() to access flags.
>
> Reported-by: kernel test robot <[email protected]>
> Signed-off-by: Marco Elver <[email protected]>
> ---
> include/linux/page-flags.h | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/include/linux/page-flags.h b/include/linux/page-flags.h
> index a68af80649a4..70bf0ec29ee3 100644
> --- a/include/linux/page-flags.h
> +++ b/include/linux/page-flags.h
> @@ -236,7 +236,7 @@ static __always_inline int PageCompound(struct page *page)
> #define PAGE_POISON_PATTERN -1l
> static inline int PagePoisoned(const struct page *page)
> {
> - return page->flags == PAGE_POISON_PATTERN;
> + return READ_ONCE(page->flags) == PAGE_POISON_PATTERN;
> }
>
> #ifdef CONFIG_DEBUG_VM
> --
> 2.33.0.259.gc128427fd7-goog
>