Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
On Wed, May 15, 2019 at 08:20:35AM -0700, Matthew Wilcox wrote: > On Wed, May 15, 2019 at 05:04:06PM +0200, Greg Kroah-Hartman wrote: > > > Greg, can you consider 6daef95b8c914866a46247232a048447fff97279 for > > > backporting to stable? Nobody realised it was a bugfix at the time it > > > went in. I suspect there aren't too many of us running HIGHMEM kernels > > > any more. > > > > > > > Sure, what kernel version(s) should this go to? 4.19 and newer? > > Looks like the problem was introduced with commit > a90bcb86ae700c12432446c4aa1819e7b8e172ec so 4.14 and newer, I think. Thanks, now queued up. greg k-h
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
W dniu 15.05.2019 o 17:18, Matthew Wilcox pisze: > On Wed, May 15, 2019 at 08:02:17AM -0700, Eric Dumazet wrote: >> On Wed, May 15, 2019 at 7:43 AM Matthew Wilcox wrote: >>> You're seeing a race between page_address(page) being called twice. >>> Between those two calls, something has caused the page to be removed from >>> the page_address_map() list. Eric's patch avoids calling page_address(), >>> so apply it and be happy. >> Hmm... wont the kmap_atomic() done later, after page_copy_sane() would >> suffer from the race ? >> >> It seems there is a real bug somewhere to fix. > No. page_address() called before the kmap_atomic() will look through > the list of mappings and see if that page is mapped somewhere. We unmap > lazily, so all it takes to trigger this race is that the page _has_ > been mapped before, and its mapping gets torn down during this call. > > While the page is kmapped, its mapping cannot be torn down. And that's the answer I'm really glad to hear. In the meantime I've set up a test run with CONFIG_HIGHMEM disabled to be extra sure, however quite expectedly it robs the system of 256MiB of accessible memory. Unfortunatly, looking through defconfigs for 32-bit ARM, CONFIG_HIGHMEM is enabled in quite a few of them, i.MX included. I'll pick up the patch then and drop it when it gets included in 4.19.y. Thanks! -- With kind regards, Lech
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
On Wed, May 15, 2019 at 08:20:35AM -0700, Matthew Wilcox wrote: > On Wed, May 15, 2019 at 05:04:06PM +0200, Greg Kroah-Hartman wrote: > > > Greg, can you consider 6daef95b8c914866a46247232a048447fff97279 for > > > backporting to stable? Nobody realised it was a bugfix at the time it > > > went in. I suspect there aren't too many of us running HIGHMEM kernels > > > any more. > > > > > > > Sure, what kernel version(s) should this go to? 4.19 and newer? > > Looks like the problem was introduced with commit > a90bcb86ae700c12432446c4aa1819e7b8e172ec so 4.14 and newer, I think. Ok, I'll look into it after this round of stable kernels are released, thanks. greg k-h
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
On Wed, May 15, 2019 at 05:04:06PM +0200, Greg Kroah-Hartman wrote: > > Greg, can you consider 6daef95b8c914866a46247232a048447fff97279 for > > backporting to stable? Nobody realised it was a bugfix at the time it > > went in. I suspect there aren't too many of us running HIGHMEM kernels > > any more. > > > > Sure, what kernel version(s) should this go to? 4.19 and newer? Looks like the problem was introduced with commit a90bcb86ae700c12432446c4aa1819e7b8e172ec so 4.14 and newer, I think.
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
On Wed, May 15, 2019 at 08:02:17AM -0700, Eric Dumazet wrote: > On Wed, May 15, 2019 at 7:43 AM Matthew Wilcox wrote: > > You're seeing a race between page_address(page) being called twice. > > Between those two calls, something has caused the page to be removed from > > the page_address_map() list. Eric's patch avoids calling page_address(), > > so apply it and be happy. > > Hmm... wont the kmap_atomic() done later, after page_copy_sane() would > suffer from the race ? > > It seems there is a real bug somewhere to fix. No. page_address() called before the kmap_atomic() will look through the list of mappings and see if that page is mapped somewhere. We unmap lazily, so all it takes to trigger this race is that the page _has_ been mapped before, and its mapping gets torn down during this call. While the page is kmapped, its mapping cannot be torn down.
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
On Wed, May 15, 2019 at 07:43:52AM -0700, Matthew Wilcox wrote: > > > W dniu 25.04.2019 o 11:25, Lech Perczak pisze: > > >> Some time ago, after upgrading the Kernel on our i.MX6Q-based boards to > > >> mainline 4.18, and now to LTS 4.19 line, during stress tests we started > > >> noticing strange warnings coming from 'read' syscall, when > > >> page_copy_sane() check failed. Typical reproducibility is up to ~4 > > >> events per 24h. Warnings origin from different processes, mostly > > >> involved with the stress tests, but not necessarily with block devices > > >> we're stressing. If the warning appeared in process relating to block > > >> device stress test, it would be accompanied by corrupted data, as the > > >> read operation gets aborted. > > >> > > >> When I started debugging the issue, I noticed that in all cases we're > > >> dealing with highmem zero-order pages. In this case, page_head(page) == > > >> page, so page_address(page) should be equal to page_address(head). > > >> However, it isn't the case, as page_address(head) in each case returns > > >> zero, causing the value of "v" to explode, and the check to fail. > > You're seeing a race between page_address(page) being called twice. > Between those two calls, something has caused the page to be removed from > the page_address_map() list. Eric's patch avoids calling page_address(), > so apply it and be happy. > > Greg, can you consider 6daef95b8c914866a46247232a048447fff97279 for > backporting to stable? Nobody realised it was a bugfix at the time it > went in. I suspect there aren't too many of us running HIGHMEM kernels > any more. > Sure, what kernel version(s) should this go to? 4.19 and newer? thanks, greg k-h
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
On Wed, May 15, 2019 at 7:43 AM Matthew Wilcox wrote: > > > > W dniu 25.04.2019 o 11:25, Lech Perczak pisze: > > >> Some time ago, after upgrading the Kernel on our i.MX6Q-based boards to > > >> mainline 4.18, and now to LTS 4.19 line, during stress tests we started > > >> noticing strange warnings coming from 'read' syscall, when > > >> page_copy_sane() check failed. Typical reproducibility is up to ~4 > > >> events per 24h. Warnings origin from different processes, mostly > > >> involved with the stress tests, but not necessarily with block devices > > >> we're stressing. If the warning appeared in process relating to block > > >> device stress test, it would be accompanied by corrupted data, as the > > >> read operation gets aborted. > > >> > > >> When I started debugging the issue, I noticed that in all cases we're > > >> dealing with highmem zero-order pages. In this case, page_head(page) == > > >> page, so page_address(page) should be equal to page_address(head). > > >> However, it isn't the case, as page_address(head) in each case returns > > >> zero, causing the value of "v" to explode, and the check to fail. > > You're seeing a race between page_address(page) being called twice. > Between those two calls, something has caused the page to be removed from > the page_address_map() list. Eric's patch avoids calling page_address(), > so apply it and be happy. Hmm... wont the kmap_atomic() done later, after page_copy_sane() would suffer from the race ? It seems there is a real bug somewhere to fix. > > Greg, can you consider 6daef95b8c914866a46247232a048447fff97279 for > backporting to stable? Nobody realised it was a bugfix at the time it > went in. I suspect there aren't too many of us running HIGHMEM kernels > any more. >
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
> > W dniu 25.04.2019 o 11:25, Lech Perczak pisze: > >> Some time ago, after upgrading the Kernel on our i.MX6Q-based boards to > >> mainline 4.18, and now to LTS 4.19 line, during stress tests we started > >> noticing strange warnings coming from 'read' syscall, when > >> page_copy_sane() check failed. Typical reproducibility is up to ~4 events > >> per 24h. Warnings origin from different processes, mostly involved with > >> the stress tests, but not necessarily with block devices we're stressing. > >> If the warning appeared in process relating to block device stress test, > >> it would be accompanied by corrupted data, as the read operation gets > >> aborted. > >> > >> When I started debugging the issue, I noticed that in all cases we're > >> dealing with highmem zero-order pages. In this case, page_head(page) == > >> page, so page_address(page) should be equal to page_address(head). > >> However, it isn't the case, as page_address(head) in each case returns > >> zero, causing the value of "v" to explode, and the check to fail. You're seeing a race between page_address(page) being called twice. Between those two calls, something has caused the page to be removed from the page_address_map() list. Eric's patch avoids calling page_address(), so apply it and be happy. Greg, can you consider 6daef95b8c914866a46247232a048447fff97279 for backporting to stable? Nobody realised it was a bugfix at the time it went in. I suspect there aren't too many of us running HIGHMEM kernels any more.
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
Hi,
W dniu 26.04.2019 o 10:42, Lech Perczak pisze:
> Cc linux...@kvack.org
>
> W dniu 25.04.2019 o 11:25, Lech Perczak pisze:
>> Hello,
>>
>> Some time ago, after upgrading the Kernel on our i.MX6Q-based boards to
>> mainline 4.18, and now to LTS 4.19 line, during stress tests we started
>> noticing strange warnings coming from 'read' syscall, when page_copy_sane()
>> check failed. Typical reproducibility is up to ~4 events per 24h. Warnings
>> origin from different processes, mostly involved with the stress tests, but
>> not necessarily with block devices we're stressing. If the warning appeared
>> in process relating to block device stress test, it would be accompanied by
>> corrupted data, as the read operation gets aborted.
>> Our reason for dropping caches is to ensure that the actual block device
>> gets accessed during the test without resorting to O_DIRECT.
>> When dropping caches was disabled in the tests, the issue would also
>> disappear, at least in a single-week run.
>>
>> Example processes caught in the last run (grepped from stacktraces):
>> [38128.430694] CPU: 2 PID: 32735 Comm: glmark2 Not tainted
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>> [44168.081821] CPU: 2 PID: 21555 Comm: cat Tainted: G W
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>> [75879.424076] CPU: 3 PID: 1478 Comm: flashcp Tainted: G W
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>> [117060.951333] CPU: 1 PID: 14150 Comm: cat Tainted: G W
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>> [201668.438219] CPU: 1 PID: 14370 Comm: glmark2 Tainted: G W
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>> [214332.212960] CPU: 0 PID: 25633 Comm: cp Tainted: G W
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>> [283484.619058] CPU: 0 PID: 5091 Comm: glmark2 Tainted: G W
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>> [330256.709124] CPU: 2 PID: 4565 Comm: sensors Tainted: G W
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>> [337685.549556] CPU: 2 PID: 30132 Comm: sensors Tainted: G W
>> 4.19.32-devboardimx6q+g0a64e3717985 #1
>>
>> When I started debugging the issue, I noticed that in all cases we're
>> dealing with highmem zero-order pages. In this case, page_head(page) ==
>> page, so page_address(page) should be equal to page_address(head).
>> However, it isn't the case, as page_address(head) in each case returns zero,
>> causing the value of "v" to explode, and the check to fail.
>>
>> At first I thought, that it could be caused by modification of struct page
>> itself, but it turned out to not be the case - sometimes struct page would
>> be unmodified during duration of the check. With lowmem pages, this wouldn't
>> also happen, because page_address is derived directly from struct page
>> pointer itself.
>>
>> Finally, after gathering a few traces with added debug logs I decided to
>> trigger a panic on the warning and capture a vmcore.
>> When analyzing the vmcore, I confirmed that the struct page_address_slot
>> corresponding to the struct page had an empty list of mappings, explaining
>> NULL returned from page_address(head) in page_copy_sane().
>> Yeah, I had to manually calculate hash of struct page pointer ;)
>>
>> In the meantime I noticed a patch by Eric Dumazet ("iov_iter: optimize
>> page_copy_sane()") [1]. Applying this patch silenced the warnings, at least
>> for test run going for over a week. This is quite expected, as with this
>> change 'page' isn't dereferenced at all, nor is page_address() called. Here
>> I suspect that applying this patch may only hide a real issue I'm facing,
>> and might be missing the case of highmem pages as well.
>>
>> An example stacktrace I captured, with added debug logs and copy of struct
>> page before and after the check in page_copy_sane:
>>
>> This last one shows no changes to struct page over the call to
>> page_copy_sane(), where first call to page_address(page) returns a valid
>> page address (page_address=2146996224) and second call returns 0
>> (head_address=0). Subsequent calls to page_address inside WARN() argument
>> list also return 0. The same was true for the occurence I captured vmcore
>> for.
>>
>> (For your reference, a patch containing my debug prints is at the end of the
>> message)
>>
>> [337685.344204] [ cut here ]
>> [337685.356870] WARNING: CPU: 0 PID: 30132 at
>> /mnt/work/git/platforms-manifest/build_devboardimx6q/tmp/work-shared/devboardimx6q/kernel-source/lib/iov_iter.c:834
>> page_copy_sane+0x13c/0x178
>> [337685.420706] page_copy_sane: page=7721123e, offset=0, n=4096,
>> v=2147000320, head=7721123e, page_address=2146996224, head_address=0,
>> compound_order(head)=0, page_address(page)=0, page_address(head)=0
>> page_address(page_copy)=0,
>> flags(page)=referenced|uptodate|lru|active|arch_1,
>> flags(page_copy)=referenced|uptodate|lru|active|arch_1
>> [337685.494736] Modules linked in: xt_nat
Re: Recurring warning in page_copy_sane (inside copy_page_to_iter) when running stress tests involving drop_caches
Cc linux...@kvack.org
W dniu 25.04.2019 o 11:25, Lech Perczak pisze:
> Hello,
>
> Some time ago, after upgrading the Kernel on our i.MX6Q-based boards to
> mainline 4.18, and now to LTS 4.19 line, during stress tests we started
> noticing strange warnings coming from 'read' syscall, when page_copy_sane()
> check failed. Typical reproducibility is up to ~4 events per 24h. Warnings
> origin from different processes, mostly involved with the stress tests, but
> not necessarily with block devices we're stressing. If the warning appeared
> in process relating to block device stress test, it would be accompanied by
> corrupted data, as the read operation gets aborted.
> Our reason for dropping caches is to ensure that the actual block device gets
> accessed during the test without resorting to O_DIRECT.
> When dropping caches was disabled in the tests, the issue would also
> disappear, at least in a single-week run.
>
> Example processes caught in the last run (grepped from stacktraces):
> [38128.430694] CPU: 2 PID: 32735 Comm: glmark2 Not tainted
> 4.19.32-devboardimx6q+g0a64e3717985 #1
> [44168.081821] CPU: 2 PID: 21555 Comm: cat Tainted: G W
> 4.19.32-devboardimx6q+g0a64e3717985 #1
> [75879.424076] CPU: 3 PID: 1478 Comm: flashcp Tainted: G W
> 4.19.32-devboardimx6q+g0a64e3717985 #1
> [117060.951333] CPU: 1 PID: 14150 Comm: cat Tainted: G W
> 4.19.32-devboardimx6q+g0a64e3717985 #1
> [201668.438219] CPU: 1 PID: 14370 Comm: glmark2 Tainted: G W
> 4.19.32-devboardimx6q+g0a64e3717985 #1
> [214332.212960] CPU: 0 PID: 25633 Comm: cp Tainted: G W
> 4.19.32-devboardimx6q+g0a64e3717985 #1
> [283484.619058] CPU: 0 PID: 5091 Comm: glmark2 Tainted: G W
> 4.19.32-devboardimx6q+g0a64e3717985 #1
> [330256.709124] CPU: 2 PID: 4565 Comm: sensors Tainted: G W
> 4.19.32-devboardimx6q+g0a64e3717985 #1
> [337685.549556] CPU: 2 PID: 30132 Comm: sensors Tainted: G W
> 4.19.32-devboardimx6q+g0a64e3717985 #1
>
> When I started debugging the issue, I noticed that in all cases we're dealing
> with highmem zero-order pages. In this case, page_head(page) == page, so
> page_address(page) should be equal to page_address(head).
> However, it isn't the case, as page_address(head) in each case returns zero,
> causing the value of "v" to explode, and the check to fail.
>
> At first I thought, that it could be caused by modification of struct page
> itself, but it turned out to not be the case - sometimes struct page would be
> unmodified during duration of the check. With lowmem pages, this wouldn't
> also happen, because page_address is derived directly from struct page
> pointer itself.
>
> Finally, after gathering a few traces with added debug logs I decided to
> trigger a panic on the warning and capture a vmcore.
> When analyzing the vmcore, I confirmed that the struct page_address_slot
> corresponding to the struct page had an empty list of mappings, explaining
> NULL returned from page_address(head) in page_copy_sane().
> Yeah, I had to manually calculate hash of struct page pointer ;)
>
> In the meantime I noticed a patch by Eric Dumazet ("iov_iter: optimize
> page_copy_sane()") [1]. Applying this patch silenced the warnings, at least
> for test run going for over a week. This is quite expected, as with this
> change 'page' isn't dereferenced at all, nor is page_address() called. Here I
> suspect that applying this patch may only hide a real issue I'm facing, and
> might be missing the case of highmem pages as well.
>
> An example stacktrace I captured, with added debug logs and copy of struct
> page before and after the check in page_copy_sane:
>
> This last one shows no changes to struct page over the call to
> page_copy_sane(), where first call to page_address(page) returns a valid page
> address (page_address=2146996224) and second call returns 0 (head_address=0).
> Subsequent calls to page_address inside WARN() argument list also return 0.
> The same was true for the occurence I captured vmcore for.
>
> (For your reference, a patch containing my debug prints is at the end of the
> message)
>
> [337685.344204] [ cut here ]
> [337685.356870] WARNING: CPU: 0 PID: 30132 at
> /mnt/work/git/platforms-manifest/build_devboardimx6q/tmp/work-shared/devboardimx6q/kernel-source/lib/iov_iter.c:834
> page_copy_sane+0x13c/0x178
> [337685.420706] page_copy_sane: page=7721123e, offset=0, n=4096,
> v=2147000320, head=7721123e, page_address=2146996224, head_address=0,
> compound_order(head)=0, page_address(page)=0, page_address(head)=0
> page_address(page_copy)=0, flags(page)=referenced|uptodate|lru|active|arch_1,
> flags(page_copy)=referenced|uptodate|lru|active|arch_1
> [337685.494736] Modules linked in: xt_nat iptable_nat nf_nat_ipv4 nf_nat
> nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip_tables x_tables
> usb_f_mass_storage usb_f_rndis u_ether ci_hdrc_imx
