[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20201115214125.GA317@Ryzen-9-3900X.localdomain>
Date: Sun, 15 Nov 2020 14:41:25 -0700
From: Nathan Chancellor <natechancellor@...il.com>
To: Al Viro <viro@...iv.linux.org.uk>
Cc: Linus Torvalds <torvalds@...ux-foundation.org>,
Christoph Hellwig <hch@....de>,
Greg KH <gregkh@...uxfoundation.org>,
Alexey Dobriyan <adobriyan@...il.com>,
linux-fsdevel <linux-fsdevel@...r.kernel.org>,
Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
kys@...rosoft.com, haiyangz@...rosoft.com, sthemmin@...rosoft.com,
wei.liu@...nel.org, linux-hyperv@...r.kernel.org
Subject: Re: [PATCH 1/6] seq_file: add seq_read_iter
Hi Al,
Apologies for the delay.
On Sun, Nov 15, 2020 at 03:53:55PM +0000, Al Viro wrote:
> On Sat, Nov 14, 2020 at 08:50:00PM +0000, Al Viro wrote:
>
> OK, I think I understand what's going on. Could you check if
> reverting the variant in -next and applying the following instead
> fixes what you are seeing?
The below diff on top of d4d50710a8b46082224376ef119a4dbb75b25c56 does
not fix my issue unfortunately.
> diff --git a/fs/seq_file.c b/fs/seq_file.c
> index 3b20e21604e7..35667112bbd1 100644
> --- a/fs/seq_file.c
> +++ b/fs/seq_file.c
> @@ -168,7 +168,6 @@ EXPORT_SYMBOL(seq_read);
> ssize_t seq_read_iter(struct kiocb *iocb, struct iov_iter *iter)
> {
> struct seq_file *m = iocb->ki_filp->private_data;
> - size_t size = iov_iter_count(iter);
> size_t copied = 0;
> size_t n;
> void *p;
> @@ -208,16 +207,15 @@ ssize_t seq_read_iter(struct kiocb *iocb, struct iov_iter *iter)
> }
> /* if not empty - flush it first */
> if (m->count) {
> - n = min(m->count, size);
> - if (copy_to_iter(m->buf + m->from, n, iter) != n)
> - goto Efault;
> + n = copy_to_iter(m->buf + m->from, m->count, iter);
> m->count -= n;
> m->from += n;
> - size -= n;
> copied += n;
> - if (!size)
> - goto Done;
> + if (m->count)
> + goto Efault;
> }
> + if (!iov_iter_count(iter))
> + goto Done;
> /* we need at least one record in buffer */
> m->from = 0;
> p = m->op->start(m, &m->index);
> @@ -249,6 +247,7 @@ ssize_t seq_read_iter(struct kiocb *iocb, struct iov_iter *iter)
> goto Done;
> Fill:
> /* they want more? let's try to get some more */
> + /* m->count is positive and there's space left in iter */
> while (1) {
> size_t offs = m->count;
> loff_t pos = m->index;
> @@ -263,7 +262,7 @@ ssize_t seq_read_iter(struct kiocb *iocb, struct iov_iter *iter)
> err = PTR_ERR(p);
> break;
> }
> - if (m->count >= size)
> + if (m->count >= iov_iter_count(iter))
> break;
> err = m->op->show(m, p);
> if (seq_has_overflowed(m) || err) {
> @@ -273,12 +272,12 @@ ssize_t seq_read_iter(struct kiocb *iocb, struct iov_iter *iter)
> }
> }
> m->op->stop(m, p);
> - n = min(m->count, size);
> - if (copy_to_iter(m->buf, n, iter) != n)
> - goto Efault;
> + n = copy_to_iter(m->buf, m->count, iter);
> copied += n;
> - m->count -= n;
> m->from = n;
> + m->count -= n;
> + if (m->count)
> + goto Efault;
> Done:
> if (!copied)
> copied = err;
>
Replying to your two other messages here:
> FWIW, just to make sure:
> 1) does reverting just that commit recover the desired behaviour?
Yes, d4d50710a8b46082224376ef119a4dbb75b25c56 is fine,
6a9f696d1627bacc91d1cebcfb177f474484e8ba is broken.
$ uname -r
5.10.0-rc2-microsoft-00001-gd4d50710a8b4
$ echo $PATH
/home/nathan/usr/bin:/home/nathan/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/mnt/c/Windows/system32:...
$ uname -r
5.10.0-rc2-microsoft-00002-g6a9f696d1627
$ echo $PATH
/home/nathan/usr/bin:/home/nathan/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games
> 2) could you verify that your latest tests had been done with
> the incremental I'd posted (shifting the if (....) goto Done; out of the if
> body)?
> 3) does the build with that commit reverted produce any warnings
> related to mountinfo?
d4d50710a8b46082224376ef119a4dbb75b25c56:
$ dmesg -l err
[ 0.064825] PCI: Fatal: No config space access function found
[ 0.077436] kvm: no hardware support
[ 0.077438] kvm: no hardware support
[ 0.108227] hv_utils: cannot register PTP clock: 0
[ 2.518229] FS-Cache: Duplicate cookie detected
[ 2.518232] FS-Cache: O-cookie c=000000005d51d0cd [p=000000006bb17fa6 fl=222 nc=0 na=1]
[ 2.518232] FS-Cache: O-cookie d=0000000021f3f873 n=000000002fb0c46e
[ 2.518233] FS-Cache: O-key=[10] '34323934393337353435'
[ 2.518236] FS-Cache: N-cookie c=000000002e0fa15c [p=000000006bb17fa6 fl=2 nc=0 na=1]
[ 2.518236] FS-Cache: N-cookie d=0000000021f3f873 n=00000000a3943d77
[ 2.518236] FS-Cache: N-key=[10] '34323934393337353435'
6a9f696d1627bacc91d1cebcfb177f474484e8ba:
$ dmesg -l err
[ 0.064266] PCI: Fatal: No config space access function found
[ 0.077833] kvm: no hardware support
[ 0.077835] kvm: no hardware support
[ 0.107284] hv_utils: cannot register PTP clock: 0
[ 0.221703] init: (235) ERROR: LogException:36: LOCALHOST: Could not start localhost port scanner.
[ 2.428629] FS-Cache: Duplicate cookie detected
[ 2.428631] FS-Cache: O-cookie c=000000008dc18c92 [p=00000000e8a82afe fl=222 nc=0 na=1]
[ 2.428631] FS-Cache: O-cookie d=000000007254ca01 n=0000000009bd1860
[ 2.428632] FS-Cache: O-key=[10] '34323934393337353336'
[ 2.428635] FS-Cache: N-cookie c=000000005941e9ee [p=00000000e8a82afe fl=2 nc=0 na=1]
[ 2.428635] FS-Cache: N-cookie d=000000007254ca01 n=0000000095ef7a9f
[ 2.428636] FS-Cache: N-key=[10] '34323934393337353336'
[ 2.438529] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.438535] init: (9) ERROR: CreateProcessParseCommon:849: Failed to translate C:\Users\natec
[ 2.438550] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.438552] init: (9) ERROR: UtilTranslatePathList:2373: Failed to translate C:\Windows\system32
[ 2.438558] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.438559] init: (9) ERROR: UtilTranslatePathList:2373: Failed to translate C:\Windows
[ 2.438565] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
6a9f696d1627bacc91d1cebcfb177f474484e8ba + shifting the if (....) goto Done; out of the if body:
$ echo $PATH
/home/nathan/usr/bin:/home/nathan/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games
$ dmesg -l err
[ 0.059315] PCI: Fatal: No config space access function found
[ 0.077335] kvm: no hardware support
[ 0.077336] kvm: no hardware support
[ 0.107422] hv_utils: cannot register PTP clock: 0
[ 2.437321] FS-Cache: Duplicate cookie detected
[ 2.437323] FS-Cache: O-cookie c=0000000061ae161f [p=000000005e0c26a4 fl=222 nc=0 na=1]
[ 2.437323] FS-Cache: O-cookie d=000000006e487749 n=00000000d6f2b7cc
[ 2.437324] FS-Cache: O-key=[10] '34323934393337353337'
[ 2.437327] FS-Cache: N-cookie c=00000000c08b3ba9 [p=000000005e0c26a4 fl=2 nc=0 na=1]
[ 2.437327] FS-Cache: N-cookie d=000000006e487749 n=0000000026c46bbc
[ 2.437328] FS-Cache: N-key=[10] '34323934393337353337'
[ 2.447874] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.447878] init: (9) ERROR: CreateProcessParseCommon:849: Failed to translate C:\Users\natec
[ 2.447905] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.447906] init: (9) ERROR: UtilTranslatePathList:2373: Failed to translate C:\Windows\system32
[ 2.447923] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.447924] init: (9) ERROR: UtilTranslatePathList:2373: Failed to translate C:\Windows
[ 2.447940] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
Your latest diff on top of d4d50710a8b46082224376ef119a4dbb75b25c56:
$ echo $PATH
/home/nathan/usr/bin:/home/nathan/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games
$ dmesg -l err
[ 0.064514] PCI: Fatal: No config space access function found
[ 0.078288] kvm: no hardware support
[ 0.078290] kvm: no hardware support
[ 0.108100] hv_utils: cannot register PTP clock: 0
[ 2.428126] FS-Cache: Duplicate cookie detected
[ 2.428128] FS-Cache: O-cookie c=00000000f90a28fc [p=000000008eaf59d5 fl=222 nc=0 na=1]
[ 2.428128] FS-Cache: O-cookie d=00000000e1e04d39 n=00000000109665e8
[ 2.428129] FS-Cache: O-key=[10] '34323934393337353336'
[ 2.428132] FS-Cache: N-cookie c=00000000c32f0eb9 [p=000000008eaf59d5 fl=2 nc=0 na=1]
[ 2.428132] FS-Cache: N-cookie d=00000000e1e04d39 n=000000003fef461f
[ 2.428132] FS-Cache: N-key=[10] '34323934393337353336'
[ 2.439541] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.439545] init: (9) ERROR: CreateProcessParseCommon:849: Failed to translate C:\Users\natec
[ 2.439571] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.439573] init: (9) ERROR: UtilTranslatePathList:2373: Failed to translate C:\Windows\system32
[ 2.439590] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
[ 2.439591] init: (9) ERROR: UtilTranslatePathList:2373: Failed to translate C:\Windows
[ 2.439607] init: (9) ERROR: UtilFindMount:700: Invalid mountinfo line 14
> 4) your posted log with WARN_ON unfortunately starts *after*
> the mountinfo accesses; could you check which process had been doing those?
> The Comm: ... part in there, that is.
init it looks like. Attached is the output of
---
diff --git a/fs/read_write.c b/fs/read_write.c
index 75f764b43418..37708555cb8d 100644
--- a/fs/read_write.c
+++ b/fs/read_write.c
@@ -757,6 +757,10 @@ static ssize_t do_loop_readv_writev(struct file *filp, struct iov_iter *iter,
struct iovec iovec = iov_iter_iovec(iter);
ssize_t nr;
+ if (unlikely(!memcmp(filp->f_path.dentry->d_name.name, "mountinfo", 10)) &&
+ WARN_ON(!iovec.iov_len))
+ printk(KERN_ERR "odd readv on %pd4\n", filp);
+
if (type == READ) {
nr = filp->f_op->read(filp, iovec.iov_base,
iovec.iov_len, ppos);
---
against your latest diff on top of d4d50710a8b46082224376ef119a4dbb75b25c56.
> 5) in the "I don't believe that could happen, but let's make sure"
> department: turn the
> /* m->count is positive and there's space left in iter */
> comment in seq_read_iter() into an outright
> BUG_ON(!m->count || !iov_iter_count(iter));
Does not look like it triggers against your latest diff.
> OK, so let's do this: fix in seq_read_iter() + in do_loop_readv_writev()
> (on entry) the following (racy as hell, but will do for debugging):
>
> bool weird = false;
>
> if (unlikely(memcmp(file->f_path.dentry->d_name.name, "mountinfo", 10))) {
> int i;
>
> for (i = 0; i < iter->nr_segs; i++)
> if (!iter->iov[i].iov_len)
> weird = true;
> if (weird) {
> printk(KERN_ERR "[%s]: weird readv on %p4D (%ld) ",
> current->comm, filp, (long)filp->f_pos);
> for (i = 0; i < iter->nr_segs; i++)
> printk(KERN_CONT "%c%zd", i ? ':' : '<',
> iter->iov[i].iov_len);
> printk(KERN_CONT "> ");
> }
> }
> and in the end (just before return)
> if (weird)
> printk(KERN_CONT "-> %zd\n", ret);
>
> Preferably along with the results of cat /proc/<whatever it is>/mountinfo both
> on that and on the working kernel...
I applied this against your latest diff, attached as weird_readv.
Good (d4d50710a8b46082224376ef119a4dbb75b25c56):
$ cat /proc/9/mountinfo
29 21 8:0 / / rw,relatime - ext4 /dev/sda rw,discard,no_fc,errors=remount-ro,data=ordered
30 29 0:15 / /mnt/wsl rw,relatime shared:1 - tmpfs tmpfs rw
31 29 0:16 /init /init ro,relatime - 9p tools ro,dirsync,aname=tools;fmask=022,loose,access=client,trans=fd,rfd=6,wfd=6
32 29 0:5 / /dev rw,nosuid,relatime - devtmpfs none rw,size=8176740k,nr_inodes=2044185,mode=755
33 29 0:14 / /sys rw,nosuid,nodev,noexec,noatime - sysfs sysfs rw
34 29 0:19 / /proc rw,nosuid,nodev,noexec,noatime - proc proc rw
35 32 0:20 / /dev/pts rw,nosuid,noexec,noatime - devpts devpts rw,gid=5,mode=620,ptmxmode=000
36 29 0:21 / /run rw,nosuid,noexec,noatime - tmpfs none rw,mode=755
37 36 0:22 / /run/lock rw,nosuid,nodev,noexec,noatime - tmpfs none rw
38 36 0:23 / /run/shm rw,nosuid,nodev,noatime - tmpfs none rw
39 36 0:24 / /run/user rw,nosuid,nodev,noexec,noatime - tmpfs none rw,mode=755
40 34 0:17 / /proc/sys/fs/binfmt_misc rw,relatime - binfmt_misc binfmt_misc rw
41 33 0:25 / /sys/fs/cgroup rw,nosuid,nodev,noexec,relatime - tmpfs tmpfs rw,mode=755
42 41 0:26 / /sys/fs/cgroup/unified rw,nosuid,nodev,noexec,relatime - cgroup2 cgroup2 rw,nsdelegate
43 41 0:27 / /sys/fs/cgroup/cpuset rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,cpuset
44 41 0:28 / /sys/fs/cgroup/cpu rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,cpu
45 41 0:29 / /sys/fs/cgroup/cpuacct rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,cpuacct
46 41 0:30 / /sys/fs/cgroup/blkio rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,blkio
47 41 0:31 / /sys/fs/cgroup/memory rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,memory
48 41 0:32 / /sys/fs/cgroup/devices rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,devices
49 41 0:33 / /sys/fs/cgroup/freezer rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,freezer
50 41 0:34 / /sys/fs/cgroup/net_cls rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,net_cls
51 41 0:35 / /sys/fs/cgroup/perf_event rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,perf_event
52 41 0:36 / /sys/fs/cgroup/net_prio rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,net_prio
53 41 0:37 / /sys/fs/cgroup/hugetlb rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,hugetlb
54 41 0:38 / /sys/fs/cgroup/pids rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,pids
55 41 0:39 / /sys/fs/cgroup/rdma rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,rdma
90 29 0:40 / /mnt/c rw,noatime - 9p C:\134 rw,dirsync,aname=drvfs;path=C:\;uid=1000;gid=1000;symlinkroot=/mnt/,mmap,access=client,msize=65536,trans=fd,rfd=8,wfd=8
91 29 0:41 / /mnt/d rw,noatime - 9p D:\134 rw,dirsync,aname=drvfs;path=D:\;uid=1000;gid=1000;symlinkroot=/mnt/,mmap,access=client,msize=65536,trans=fd,rfd=8,wfd=8
Bad (your latest diff on top of d4d50710a8b46082224376ef119a4dbb75b25c56
$ cat /proc/9/mountinfo
29 21 8:0 / / rw,relatime - ext4 /dev/sda rw,discard,no_fc,errors=remount-ro,data=ordered
30 29 0:15 / /mnt/wsl rw,relatime shared:1 - tmpfs tmpfs rw
31 29 0:16 /init /init ro,relatime - 9p tools ro,dirsync,aname=tools;fmask=022,loose,access=client,trans=fd,rfd=6,wfd=6
32 29 0:5 / /dev rw,nosuid,relatime - devtmpfs none rw,size=8176740k,nr_inodes=2044185,mode=755
33 29 0:14 / /sys rw,nosuid,nodev,noexec,noatime - sysfs sysfs rw
34 29 0:19 / /proc rw,nosuid,nodev,noexec,noatime - proc proc rw
35 32 0:20 / /dev/pts rw,nosuid,noexec,noatime - devpts devpts rw,gid=5,mode=620,ptmxmode=000
36 29 0:21 / /run rw,nosuid,noexec,noatime - tmpfs none rw,mode=755
37 36 0:22 / /run/lock rw,nosuid,nodev,noexec,noatime - tmpfs none rw
38 36 0:23 / /run/shm rw,nosuid,nodev,noatime - tmpfs none rw
39 36 0:24 / /run/user rw,nosuid,nodev,noexec,noatime - tmpfs none rw,mode=755
40 34 0:17 / /proc/sys/fs/binfmt_misc rw,relatime - binfmt_misc binfmt_misc rw
41 33 0:25 / /sys/fs/cgroup rw,nosuid,nodev,noexec,relatime - tmpfs tmpfs rw,mode=755
42 41 0:26 / /sys/fs/cgroup/unified rw,nosuid,nodev,noexec,relatime - cgroup2 cgroup2 rw,nsdelegate
43 41 0:27 / /sys/fs/cgroup/cpuset rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,cpuset
44 41 0:28 / /sys/fs/cgroup/cpu rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,cpu
45 41 0:29 / /sys/fs/cgroup/cpuacct rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,cpuacct
46 41 0:30 / /sys/fs/cgroup/blkio rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,blkio
47 41 0:31 / /sys/fs/cgroup/memory rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,memory
48 41 0:32 / /sys/fs/cgroup/devices rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,devices
49 41 0:33 / /sys/fs/cgroup/freezer rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,freezer
50 41 0:34 / /sys/fs/cgroup/net_cls rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,net_cls
51 41 0:35 / /sys/fs/cgroup/perf_event rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,perf_event
52 41 0:36 / /sys/fs/cgroup/net_prio rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,net_prio
53 41 0:37 / /sys/fs/cgroup/hugetlb rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,hugetlb
54 41 0:38 / /sys/fs/cgroup/pids rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,pids
55 41 0:39 / /sys/fs/cgroup/rdma rw,nosuid,nodev,noexec,relatime - cgroup cgroup rw,rdma
90 29 0:40 / /mnt/c rw,noatime - 9p C:\134 rw,dirsync,aname=drvfs;path=C:\;uid=1000;gid=1000;symlinkroot=/mnt/,mmap,access=client,msize=65536,trans=fd,rfd=8,wfd=8
91 29 0:41 / /mnt/d rw,noatime - 9p D:\134 rw,dirsync,aname=drvfs;path=D:\;uid=1000;gid=1000;symlinkroot=/mnt/,mmap,access=client,msize=65536,trans=fd,rfd=8,wfd=8
If you need any more information, please let me know!
Cheers,
Nathan
View attachment "dmesg_warn_on_mountinfo_filtered.txt" of type "text/plain" (131712 bytes)
View attachment "dmesg_weird_readv.txt" of type "text/plain" (22281 bytes)
Powered by blists - more mailing lists