fuse: trying to steal weird page

DISCUSSION Nikolaus Rath 3 participants 17 messages Dec 26, 2018 – Mar 18, 2019 1 message not in the archive

Subsystems (3)

Memory management VFS FUSE filesystem core

lore

Share & tools

lore

Nikolaus Rath

author

2018-12-26 21:43 UTC #0 lore raw

Hi,

I am seeing relatively regular occurences of

$ sudo dmesg | tail
[21929.138815] fuse: trying to steal weird page
[21929.138821]   page=00000000a7dd2617 index=64 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)
[21930.647338] fuse: trying to steal weird page
[21930.647345]   page=00000000a07f32af index=2848 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)
[21932.338873] fuse: trying to steal weird page
[21932.338879]   page=0000000067e3a012 index=64 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)
[21933.930703] fuse: trying to steal weird page
[21933.930710]   page=00000000046feb25 index=845 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)
[21936.163174] fuse: trying to steal weird page
[21936.163180]   page=00000000fb80fe27 index=0 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)

They do not seem to correlate with userspace errors.

(I am debugging a mysterious EBADF error that I get from an nftw() walk and that disappears when running under strace(), but it its occurence does not correlate).

What are the implications of the above kernel message? Is there a way to provide more debugging information?

$ uname -a
Linux vostro.rath.org 4.18.0-0.bpo.1-amd64 #1 SMP Debian 4.18.6-1~bpo9+1 (2018-09-13) x86_64 GNU/Linux

Best,
-Nikolaus

Signature · 3 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«

Miklos Szeredi

maintainer

2019-01-07 08:28 UTC #1 lore raw

Quoted 5 lines · Nikolaus Rath

Hi,
I am seeing relatively regular occurences of

Quoted 11 lines

$ sudo dmesg | tail
[21929.138815] fuse: trying to steal weird page
[21929.138821]   page=00000000a7dd2617 index=64 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)
[21930.647338] fuse: trying to steal weird page
[21930.647345]   page=00000000a07f32af index=2848 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)
[21932.338873] fuse: trying to steal weird page
[21932.338879]   page=0000000067e3a012 index=64 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)
[21933.930703] fuse: trying to steal weird page
[21933.930710]   page=00000000046feb25 index=845 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)
[21936.163174] fuse: trying to steal weird page
[21936.163180]   page=00000000fb80fe27 index=0 flags=17fffc0000000ad, count=1, mapcount=0, mapping=          (null)

The page has the PG_dity and PG_waiters flags set which are incompatible with stealing. page_cache_pipe_buf_steal() does apparently filter out dirty ones, so it's not a regular file that we are trying to streal the page from. So the question is: what is the source of the splice()?

Thanks,
Miklos

Quoted 26 lines

They do not seem to correlate with userspace errors.
(I am debugging a mysterious EBADF error that I get from an nftw() walk and that disappears when running under strace(), but it its occurence does not correlate).
What are the implications of the above kernel message? Is there a way to provide more debugging information?
$ uname -a
Linux vostro.rath.org 4.18.0-0.bpo.1-amd64 #1 SMP Debian 4.18.6-1~bpo9+1 (2018-09-13) x86_64 GNU/Linux
Best,
-Nikolaus
--
GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F
»Time flies like an arrow, fruit flies like a Banana.«
--
fuse-devel mailing list
To unsubscribe or subscribe, visit https://lists.sourceforge.net/lists/listinfo/fuse-devel

Nikolaus Rath

author

2019-01-07 21:05 UTC #2 lore raw

Quoted 23 lines · Miklos Szeredi

Quoted 5 lines · Nikolaus Rath

Hi,
I am seeing relatively regular occurences of

Quoted 16 lines

$ sudo dmesg | tail
[21929.138815] fuse: trying to steal weird page
[21929.138821] page=00000000a7dd2617 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21930.647338] fuse: trying to steal weird page
[21930.647345] page=00000000a07f32af index=2848
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21932.338873] fuse: trying to steal weird page
[21932.338879] page=0000000067e3a012 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21933.930703] fuse: trying to steal weird page
[21933.930710] page=00000000046feb25 index=845
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21936.163174] fuse: trying to steal weird page
[21936.163180] page=00000000fb80fe27 index=0 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)

Quoted 5 lines

The page has the PG_dity and PG_waiters flags set which are incompatible with stealing. page_cache_pipe_buf_steal() does apparently filter out dirty ones, so it's not a regular file that we are trying to streal the page from. So the question is: what is the source of the splice()?

Hmm. I think it has to be a regular file. But as I mentioned in my other email, I did have a race condition where fd's were closed incorrectly. Is it possible that this also triggered the above, i.e. that the fd was closed sometime during splice?

Best,
-Nikolaus

Signature · 3 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«

Miklos Szeredi

maintainer

2019-01-08 08:27 UTC #3 lore raw

Quoted 31 lines · Nikolaus Rath

Quoted 23 lines · Miklos Szeredi
Quoted 5 lines · Nikolaus Rath
Hi,
I am seeing relatively regular occurences of
Quoted 16 lines
$ sudo dmesg | tail
[21929.138815] fuse: trying to steal weird page
[21929.138821] page=00000000a7dd2617 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21930.647338] fuse: trying to steal weird page
[21930.647345] page=00000000a07f32af index=2848
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21932.338873] fuse: trying to steal weird page
[21932.338879] page=0000000067e3a012 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21933.930703] fuse: trying to steal weird page
[21933.930710] page=00000000046feb25 index=845
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21936.163174] fuse: trying to steal weird page
[21936.163180] page=00000000fb80fe27 index=0 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
Quoted 5 lines
The page has the PG_dity and PG_waiters flags set which are incompatible with stealing. page_cache_pipe_buf_steal() does apparently filter out dirty ones, so it's not a regular file that we are trying to streal the page from. So the question is: what is the source of the splice()?

Quoted 4 lines

Hmm. I think it has to be a regular file. But as I mentioned in my other email, I did have a race condition where fd's were closed incorrectly. Is it possible that this also triggered the above, i.e. that the fd was closed sometime during splice?

Close during a syscall that uses the fd is not an issue, because a ref to the file is acquired. So the race is between the close() and the internal fget(); if the close() wins then fget() will fail and the syscall will return EBADF. If the fget() wins, then the syscall can run normally despite the fact that the fd was closed.

Can you tell me what filesystem is the regular file (the one being spliced into fuse) is on?

It actually has to be a regular file, since AFAIK nothing else has
dirty pages. It could be using something other than
page_cache_pipe_buf_steal(), or there's some other mechanism that lets the page be dirtied after being unmapped, though that looks impossible...

Thanks,
Miklos

Nikolaus Rath

author

2019-01-08 10:35 UTC #4 lore raw

Quoted 37 lines · Miklos Szeredi

Quoted 31 lines · Nikolaus Rath
Quoted 23 lines · Miklos Szeredi
Quoted 5 lines · Nikolaus Rath
Hi,
I am seeing relatively regular occurences of
Quoted 16 lines
$ sudo dmesg | tail
[21929.138815] fuse: trying to steal weird page
[21929.138821] page=00000000a7dd2617 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21930.647338] fuse: trying to steal weird page
[21930.647345] page=00000000a07f32af index=2848
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21932.338873] fuse: trying to steal weird page
[21932.338879] page=0000000067e3a012 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21933.930703] fuse: trying to steal weird page
[21933.930710] page=00000000046feb25 index=845
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21936.163174] fuse: trying to steal weird page
[21936.163180] page=00000000fb80fe27 index=0 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
Quoted 5 lines
The page has the PG_dity and PG_waiters flags set which are incompatible with stealing. page_cache_pipe_buf_steal() does apparently filter out dirty ones, so it's not a regular file that we are trying to streal the page from. So the question is: what is the source of the splice()?
Quoted 4 lines
Hmm. I think it has to be a regular file. But as I mentioned in my other email, I did have a race condition where fd's were closed incorrectly. Is it possible that this also triggered the above, i.e. that the fd was closed sometime during splice?

Quoted 8 lines

Close during a syscall that uses the fd is not an issue, because a ref to the file is acquired. So the race is between the close() and the internal fget(); if the close() wins then fget() will fail and the syscall will return EBADF. If the fget() wins, then the syscall can run normally despite the fact that the fd was closed.
Can you tell me what filesystem is the regular file (the one being spliced into fuse) is on?

It's ext4.

Quoted 5 lines

It actually has to be a regular file, since AFAIK nothing else has
dirty pages. It could be using something other than
page_cache_pipe_buf_steal(), or there's some other mechanism that lets the page be dirtied after being unmapped, though that looks impossible...

I can't meaningfully comment on that, sorry...

Best,
-Nikolaus

Signature · 3 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«

Miklos Szeredi

maintainer

2019-01-09 08:07 UTC #5 lore raw

Quoted 45 lines · Nikolaus Rath

Quoted 43 lines · Miklos Szeredi
Quoted 31 lines · Nikolaus Rath
Quoted 23 lines · Miklos Szeredi
Quoted 5 lines · Nikolaus Rath
Hi,
I am seeing relatively regular occurences of
Quoted 16 lines
$ sudo dmesg | tail
[21929.138815] fuse: trying to steal weird page
[21929.138821] page=00000000a7dd2617 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21930.647338] fuse: trying to steal weird page
[21930.647345] page=00000000a07f32af index=2848
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21932.338873] fuse: trying to steal weird page
[21932.338879] page=0000000067e3a012 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21933.930703] fuse: trying to steal weird page
[21933.930710] page=00000000046feb25 index=845
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21936.163174] fuse: trying to steal weird page
[21936.163180] page=00000000fb80fe27 index=0 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
Quoted 5 lines
The page has the PG_dity and PG_waiters flags set which are incompatible with stealing. page_cache_pipe_buf_steal() does apparently filter out dirty ones, so it's not a regular file that we are trying to streal the page from. So the question is: what is the source of the splice()?
Quoted 4 lines
Hmm. I think it has to be a regular file. But as I mentioned in my other email, I did have a race condition where fd's were closed incorrectly. Is it possible that this also triggered the above, i.e. that the fd was closed sometime during splice?
Close during a syscall that uses the fd is not an issue, because a ref to the file is acquired. So the race is between the close() and the internal fget(); if the close() wins then fget() will fail and the syscall will return EBADF. If the fget() wins, then the syscall can run normally despite the fact that the fd was closed.

Quoted 4 lines

Quoted 2 lines
Can you tell me what filesystem is the regular file (the one being spliced into fuse) is on?
It's ext4.

Next question: is file opened with O_DIRECT or is filesystem mounted with DAX, or anything fancy?

Thanks,
Miklos

A message that is not in the archive (sent off-list or not yet received): CAJfpegtiXDgSBWN8MRubpAdJFxy95X21nO_yycCZhpvKLVePRA-JsoAwUIsXosN+BqQ9rBEUg@public.gmane.org

Nikolaus Rath

2019-01-11 15:39 UTC #7 lore raw

Quoted 46 lines · Miklos Szeredi

Quoted 45 lines · Nikolaus Rath
Quoted 43 lines · Miklos Szeredi
Quoted 31 lines · Nikolaus Rath
Quoted 23 lines · Miklos Szeredi
Quoted 5 lines · Nikolaus Rath
Hi,
I am seeing relatively regular occurences of
Quoted 16 lines
$ sudo dmesg | tail
[21929.138815] fuse: trying to steal weird page
[21929.138821] page=00000000a7dd2617 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21930.647338] fuse: trying to steal weird page
[21930.647345] page=00000000a07f32af index=2848
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21932.338873] fuse: trying to steal weird page
[21932.338879] page=0000000067e3a012 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21933.930703] fuse: trying to steal weird page
[21933.930710] page=00000000046feb25 index=845
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21936.163174] fuse: trying to steal weird page
[21936.163180] page=00000000fb80fe27 index=0 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
Quoted 5 lines
The page has the PG_dity and PG_waiters flags set which are incompatible with stealing. page_cache_pipe_buf_steal() does apparently filter out dirty ones, so it's not a regular file that we are trying to streal the page from. So the question is: what is the source of the splice()?
Quoted 4 lines
Hmm. I think it has to be a regular file. But as I mentioned in my other email, I did have a race condition where fd's were closed incorrectly. Is it possible that this also triggered the above, i.e. that the fd was closed sometime during splice?
Close during a syscall that uses the fd is not an issue, because a ref to the file is acquired. So the race is between the close() and the internal fget(); if the close() wins then fget() will fail and the syscall will return EBADF. If the fget() wins, then the syscall can run normally despite the fact that the fd was closed.

Quoted 7 lines

Quoted 4 lines
Quoted 2 lines
Can you tell me what filesystem is the regular file (the one being spliced into fuse) is on?
It's ext4.
Next question: is file opened with O_DIRECT or is filesystem mounted with DAX, or anything fancy?

Neither. But thinking about this, I guess that (because of the race) the fd could have been closed and re-opened before the ref was acquired. So it may have turned into a directory fd.

To be honest, I don't think it's worth investigating this unless I see it happen again now that the race in my code is fixed.

Best,
-Nikolaus

Signature · 8 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«


-- 
fuse-devel mailing list
To unsubscribe or subscribe, visit https://lists.sourceforge.net/lists/listinfo/fuse-devel

Nikolaus Rath

author

2019-02-10 22:05 UTC #8 lore raw

Quoted 55 lines · Nikolaus Rath

Quoted 46 lines · Miklos Szeredi
Quoted 45 lines · Nikolaus Rath
Quoted 43 lines · Miklos Szeredi
Quoted 31 lines · Nikolaus Rath
Quoted 23 lines · Miklos Szeredi
Quoted 5 lines · Nikolaus Rath
Hi,
I am seeing relatively regular occurences of
Quoted 16 lines
$ sudo dmesg | tail
[21929.138815] fuse: trying to steal weird page
[21929.138821] page=00000000a7dd2617 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21930.647338] fuse: trying to steal weird page
[21930.647345] page=00000000a07f32af index=2848
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21932.338873] fuse: trying to steal weird page
[21932.338879] page=0000000067e3a012 index=64 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
[21933.930703] fuse: trying to steal weird page
[21933.930710] page=00000000046feb25 index=845
flags=17fffc0000000ad, count=1, mapcount=0, mapping= (null)
[21936.163174] fuse: trying to steal weird page
[21936.163180] page=00000000fb80fe27 index=0 flags=17fffc0000000ad,
count=1, mapcount=0, mapping= (null)
Quoted 5 lines
The page has the PG_dity and PG_waiters flags set which are incompatible with stealing. page_cache_pipe_buf_steal() does apparently filter out dirty ones, so it's not a regular file that we are trying to streal the page from. So the question is: what is the source of the splice()?
Quoted 4 lines
Hmm. I think it has to be a regular file. But as I mentioned in my other email, I did have a race condition where fd's were closed incorrectly. Is it possible that this also triggered the above, i.e. that the fd was closed sometime during splice?
Close during a syscall that uses the fd is not an issue, because a ref to the file is acquired. So the race is between the close() and the internal fget(); if the close() wins then fget() will fail and the syscall will return EBADF. If the fget() wins, then the syscall can run normally despite the fact that the fd was closed.
Quoted 7 lines
Quoted 4 lines
Quoted 2 lines
Can you tell me what filesystem is the regular file (the one being spliced into fuse) is on?
It's ext4.
Next question: is file opened with O_DIRECT or is filesystem mounted with DAX, or anything fancy?

Quoted 6 lines

Neither. But thinking about this, I guess that (because of the race) the fd could have been closed and re-opened before the ref was acquired. So it may have turned into a directory fd.
To be honest, I don't think it's worth investigating this unless I see it happen again now that the race in my code is fixed.

Bad news. I can now reliably reproduce the issue again.

I have no clue why it disappeared for a while. This is exactly the same filesystem code, but I can't rule out that there has been some routine upgrade in the base system (compiler or kernel).

Any suggestions for debugging this?

As I said before, splice() source is a regular file on ext4, opened without O_DIRECT or DAX. If I disable FUSE_CAP_SPLICE_WRITE, the error message no longer occurs.

Best,
-Nikolaus

Signature · 3 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«

Miklos Szeredi

maintainer

2019-02-12 14:57 UTC #9 lore raw

Quoted 1 line · Nikolaus Rath

Bad news. I can now reliably reproduce the issue again.

A reliable reproducer is always good news. Are the messages exactly
the same as last time (value of flags, etc)?

Thanks,
Miklos

Nikolaus Rath

author

2019-02-12 21:28 UTC #10 lore raw

Quoted 6 lines · Miklos Szeredi

Quoted 1 line · Nikolaus Rath
Bad news. I can now reliably reproduce the issue again.
A reliable reproducer is always good news. Are the messages exactly
the same as last time (value of flags, etc)?

The flags, count, mapcount and mapping values are always the same. The page and index is varying. So the general format is:

[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187]   page=<something> index=<something> flags=17ffffc00000ad, count=1, mapcount=0, mapping=          (null)

Best,
-Nikolaus

Signature · 3 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«

Nikolaus Rath

author

2019-02-25 21:41 UTC #11 lore raw

Quoted 8 lines · Nikolaus Rath

Quoted 6 lines · Miklos Szeredi
Quoted 1 line · Nikolaus Rath
Bad news. I can now reliably reproduce the issue again.
A reliable reproducer is always good news. Are the messages exactly
the same as last time (value of flags, etc)?

Quoted 6 lines

The flags, count, mapcount and mapping values are always the same. The page and index is varying. So the general format is:
[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something>
flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)

Is there anything else I can do to help debugging this?

Best,
-Nikolaus

Signature · 3 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«

Miklos Szeredi

maintainer

2019-02-26 12:57 UTC #12 lore raw

Quoted 10 lines · Nikolaus Rath

Quoted 8 lines · Nikolaus Rath
Quoted 6 lines · Miklos Szeredi
Quoted 1 line · Nikolaus Rath
Bad news. I can now reliably reproduce the issue again.
A reliable reproducer is always good news. Are the messages exactly
the same as last time (value of flags, etc)?

Quoted 8 lines

Quoted 6 lines
The flags, count, mapcount and mapping values are always the same. The page and index is varying. So the general format is:
[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something>
flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)
Is there anything else I can do to help debugging this?

Could you please try the attached patch?

Thanks,
Miklos

fs/splice.c +1 -1

index de2ede048473..07c5c77abc45 100644
@@ -73,7 +73,7 @@ static int page_cache_pipe_buf_steal(struct pipe_inode_info *pipe,
 		 * If we succeeded in removing the mapping, set LRU flag
 		 * and return good.
 		 */
-		if (remove_mapping(mapping, page)) {
+		if (remove_mapping(mapping, page) && page_count(page) == 1) {
 			buf->flags |= PIPE_BUF_FLAG_LRU;
 			return 0;
 		}

Miklos Szeredi

maintainer

2019-02-26 13:30 UTC #13 lore raw

Quoted 15 lines · Miklos Szeredi

Quoted 13 lines · Nikolaus Rath
Quoted 11 lines · Nikolaus Rath
Quoted 6 lines · Miklos Szeredi
Quoted 1 line · Nikolaus Rath
Bad news. I can now reliably reproduce the issue again.
A reliable reproducer is always good news. Are the messages exactly
the same as last time (value of flags, etc)?
The flags, count, mapcount and mapping values are always the same. The page and index is varying. So the general format is:

Quoted 7 lines

Quoted 5 lines
Quoted 3 lines
[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something>
flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)
Is there anything else I can do to help debugging this?
Could you please try the attached patch?

Looking more, it's very unlikely to help. remove_mapping() should already ensure that the page count is 1.

I think this bug report needs to be forwarded to the <[email protected]> mailing list as this appears to be a race somewhere in the memory management subsystem and fuse is only making it visible due to its sanity checking in the page stealing code.

Thanks,
Miklos

Nikolaus Rath

author

2019-02-26 20:35 UTC #14 lore raw

[ Moving fuse-devel and linux-fsdevel to Bcc ]

Hello linux-mm people,

I am posting this here as advised by Miklos (see below). In short, I have a workload that reliably produces kernel messages of the form:

[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something> flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)

What are the implications of this message? Is something activelly going wrong (aka do I need to worry about data integrity)?

Is there something I can do to help debugging (and hopefully fixing) this?

This is with kernel 4.18 (from Ubuntu cosmic).

Best,
-Nikolaus

Quoted 39 lines · Miklos Szeredi

Quoted 15 lines · Miklos Szeredi
Quoted 13 lines · Nikolaus Rath
Quoted 11 lines · Nikolaus Rath
Quoted 6 lines · Miklos Szeredi
Quoted 1 line · Nikolaus Rath
Bad news. I can now reliably reproduce the issue again.
A reliable reproducer is always good news. Are the messages exactly
the same as last time (value of flags, etc)?
The flags, count, mapcount and mapping values are always the same. The page and index is varying. So the general format is:
Quoted 7 lines
Quoted 5 lines
Quoted 3 lines
[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something>
flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)
Is there anything else I can do to help debugging this?
Could you please try the attached patch?
Looking more, it's very unlikely to help. remove_mapping() should already ensure that the page count is 1.
I think this bug report needs to be forwarded to the <[email protected]> mailing list as this appears to be a race somewhere in the memory management subsystem and fuse is only making it visible due to its sanity checking in the page stealing code.
Thanks,
Miklos
Signature · 2 lines
fuse-devel mailing list
To unsubscribe or subscribe, visit https://lists.sourceforge.net/lists/listinfo/fuse-devel

Signature · 3 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«

Miklos Szeredi

maintainer

2019-02-26 20:57 UTC #15 lore raw

Quoted 5 lines · Nikolaus Rath

[ Moving fuse-devel and linux-fsdevel to Bcc ]
Hello linux-mm people,

Quoted 8 lines

I am posting this here as advised by Miklos (see below). In short, I have a workload that reliably produces kernel messages of the form:
[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something> flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)
What are the implications of this message? Is something activelly going wrong (aka do I need to worry about data integrity)?

Fuse is careful and basically just falls back on page copy, so it definitely shouldn't affect data integrity.

The more interesting question is: how can page_cache_pipe_buf_steal() return a dirty page? The logic in remove_mapping() should prevent that, but something is apparently slipping through...

Quoted 5 lines

Is there something I can do to help debugging (and hopefully fixing) this?
This is with kernel 4.18 (from Ubuntu cosmic).

One thought: have you tried reproducing with a recent vanilla (non-ubuntu) kernel?

Thanks,
Miklos

Quoted 51 lines

Best,
-Nikolaus
Quoted 32 lines · Miklos Szeredi
Quoted 15 lines · Miklos Szeredi
Quoted 13 lines · Nikolaus Rath
Quoted 11 lines · Nikolaus Rath
Quoted 6 lines · Miklos Szeredi
Quoted 1 line · Nikolaus Rath
Bad news. I can now reliably reproduce the issue again.
A reliable reproducer is always good news. Are the messages exactly
the same as last time (value of flags, etc)?
The flags, count, mapcount and mapping values are always the same. The page and index is varying. So the general format is:
Quoted 7 lines
Quoted 5 lines
Quoted 3 lines
[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something>
flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)
Is there anything else I can do to help debugging this?
Could you please try the attached patch?
Looking more, it's very unlikely to help. remove_mapping() should already ensure that the page count is 1.
I think this bug report needs to be forwarded to the <[email protected]> mailing list as this appears to be a race somewhere in the memory management subsystem and fuse is only making it visible due to its sanity checking in the page stealing code.
Quoted 7 lines
Thanks,
Miklos
--
fuse-devel mailing list
To unsubscribe or subscribe, visit https://lists.sourceforge.net/lists/listinfo/fuse-devel
--
GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F
»Time flies like an arrow, fruit flies like a Banana.«

Nikolaus Rath

author

2019-03-01 20:40 UTC #16 lore raw

Quoted 23 lines · Miklos Szeredi

Quoted 5 lines · Nikolaus Rath
[ Moving fuse-devel and linux-fsdevel to Bcc ]
Hello linux-mm people,
Quoted 8 lines
I am posting this here as advised by Miklos (see below). In short, I have a workload that reliably produces kernel messages of the form:
[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something> flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)
What are the implications of this message? Is something activelly going wrong (aka do I need to worry about data integrity)?
Fuse is careful and basically just falls back on page copy, so it definitely shouldn't affect data integrity.
The more interesting question is: how can page_cache_pipe_buf_steal() return a dirty page? The logic in remove_mapping() should prevent that, but something is apparently slipping through...
Quoted 1 line

Quoted 7 lines

Quoted 4 lines
Is there something I can do to help debugging (and hopefully fixing) this?
This is with kernel 4.18 (from Ubuntu cosmic).
One thought: have you tried reproducing with a recent vanilla (non-ubuntu) kernel?

Yes, I can reproduce with e.g. 5.0.0-050000rc8 (from
https://kernel.ubuntu.com/~kernel-ppa/mainline/v5.0-rc8/). However, here the flag value is different:

[  278.183571] fuse: trying to steal weird page
[  278.183576]   page=000000000aab208c index=14944 flags=17ffffc0000097, count=1, mapcount=0, mapping=          (null)

(but still the same across all messages observed with this kernel so far).

Best,
-Nikolaus

Signature · 3 lines

GPG Fingerprint: ED31 791B 2C5C 1613 AF38 8B8A D113 FCAC 3C4E 599F

             »Time flies like an arrow, fruit flies like a Banana.«

Miklos Szeredi

maintainer

2019-03-18 11:28 UTC #17 lore raw

Quoted 37 lines · Nikolaus Rath

Quoted 23 lines · Miklos Szeredi
Quoted 5 lines · Nikolaus Rath
[ Moving fuse-devel and linux-fsdevel to Bcc ]
Hello linux-mm people,
Quoted 8 lines
I am posting this here as advised by Miklos (see below). In short, I have a workload that reliably produces kernel messages of the form:
[ 2562.773181] fuse: trying to steal weird page
[ 2562.773187] page=<something> index=<something> flags=17ffffc00000ad, count=1, mapcount=0, mapping= (null)
What are the implications of this message? Is something activelly going wrong (aka do I need to worry about data integrity)?
Fuse is careful and basically just falls back on page copy, so it definitely shouldn't affect data integrity.
The more interesting question is: how can page_cache_pipe_buf_steal() return a dirty page? The logic in remove_mapping() should prevent that, but something is apparently slipping through...
Quoted 1 line
Quoted 7 lines
Quoted 4 lines
Is there something I can do to help debugging (and hopefully fixing) this?
This is with kernel 4.18 (from Ubuntu cosmic).
One thought: have you tried reproducing with a recent vanilla (non-ubuntu) kernel?
Yes, I can reproduce with e.g. 5.0.0-050000rc8 (from
https://kernel.ubuntu.com/~kernel-ppa/mainline/v5.0-rc8/). However, here the flag value is different:

Quoted 5 lines

[  278.183571] fuse: trying to steal weird page
[  278.183576]   page=000000000aab208c index=14944 flags=17ffffc0000097, count=1, mapcount=0, mapping=          (null)
(but still the same across all messages observed with this kernel so far).

Ah, so it's just the PG_waiters flag that is triggering the "weird
page" message. And it looks like it's okay if PG_waiters remains
set, at least that's what I infer from the comments in wake_up_page_bit(). Patch attached.

I'm not sure about the Ubuntu one, you should try filing a bug report with them, I think.

Thanks,
Miklos

fs/fuse/dev.c +1 -0

index 8a63e52785e9..769605cdf2bd 100644
@@ -905,6 +905,7 @@ static int fuse_check_page(struct page *page)
 	       1 << PG_uptodate |
 	       1 << PG_lru |
 	       1 << PG_active |
+	       1 << PG_waiters |
 	       1 << PG_reclaim))) {
 		printk(KERN_WARNING "fuse: trying to steal weird page\n");
 		printk(KERN_WARNING "  page=%p index=%li flags=%08lx, count=%i, mapcount=%i, mapping=%p\n", page, page->index, page->flags, page_count(page), page_mapcount(page), page->mapping);