Re: 9P change breaks bpftrace running in qemu+9p?

Re: 9P change breaks bpftrace running in qemu+9p?

[Alexei Starovoitov]

On Mon, Oct 20, 2025 at 11:49 PM Song Liu <song@kernel.org> wrote:
>
> Hi Tingmao,
>
> On Mon, Oct 20, 2025 at 5:54 PM Tingmao Wang <m@maowtm.org> wrote:
> >
> > On 10/20/25 22:52, Song Liu wrote:
> > > Hi Dominique,
> > >
> > > On Mon, Oct 20, 2025 at 2:32 PM Dominique Martinet
> > > <asmadeus@codewreck.org> wrote:
> > >>
> > >> Song Liu wrote on Mon, Oct 20, 2025 at 12:40:23PM -0700:
> > >>> I am running qemu 9.2.0 and bpftrace v0.24.0. I don't think anything is
> > >>> very special here.
> > >>
> > >> I don't reproduce either (qemu 9.2.4 and bpftrace v0.24.1, I even went
> > >> and installed vmtest to make sure), trying both my branch and a pristine
> > >> v6.18-rc2 kernel -- what's the exact commit you're testing and could you
> > >> attach your .config ?
> > >
> > > Attached, please find the config file.
> > >
> > > I tried to debug this, and found that the issue disappears when I remove
> > > v9fs_lookup_revalidate from v9fs_dentry_operations. But I couldn't figure
> > > out why d_revalidate() is causing such an issue.
> >
> > I've compiled qemu 9.2.0 and download the binary build of bpftrace v0.24.0
> > from GitHub [1], and compiled kernel with your config, but unfortunately I
> > still can't reproduce it...
>
> Thanks for running these tests.
>
> > I do now get this message sometimes (probably unrelated?):
> > bpftrace (148) used greatest stack depth: 11624 bytes left
> >
> > I don't really know how to proceed right now but I will have it run in a
> > loop and see if I can hit it by chance.
> >
> > If you can reproduce it frequently and can debug exactly what is returning
> > -EIO in v9fs_lookup_revalidate that would probably be very helpful, or if
> > you can enable 9p debug outputs and see what's happening around the time
> > of error (CONFIG_NET_9P_DEBUG=y and also debug=5 mount options - I'm not
> > sure how to get vmtest to use a custom mount option but if it's
> > reproducible in plain QEMU that's also an option) that might also be
> > informative I think?  I'm happy to take a deeper look (although I'm of
> > course less of an expert than Dominique so hopefully he can also give some
> > opinion).
> >
> > I'm also curious if this can happen with just a usual `stat` or other
> > operations (not necessarily caused by dentry revalidation, and thus not
> > necessarily to do with my patch)
>
> I used strace to compare the behavior before and after the change.
> It appears to me that bpftrace didn't get -EIO in the error case. Instead,
> it got 0 bytes for a read that was supposed to return data.
>
> Success case:
> ...
> openat(AT_FDCWD, "/tmp/bpftrace.Rl1Vkg",
> O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0600) = 3
> write(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\1\0\367\0\1\0\0\0\0\0\0\0\0\0\0\0"...,
> 4352) = 4352
> openat(AT_FDCWD, "/tmp/bpftrace.Rl1Vkg", O_RDONLY|O_CLOEXEC) = 4
> newfstatat(4, "", {st_mode=S_IFREG|0600, st_size=4352, ...}, AT_EMPTY_PATH) = 0
> read(4, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\1\0\367\0\1\0\0\0\0\0\0\0\0\0\0\0"...,
> 8192) = 4352
> close(4) = 0
> ...
>
> Failure case:
> ...
> openat(AT_FDCWD, "/tmp/bpftrace.LbbDxk",
> O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0600) = 3
> write(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\1\0\367\0\1\0\0\0\0\0\0\0\0\0\0\0"...,
> 4352) = 4352
> openat(AT_FDCWD, "/tmp/bpftrace.LbbDxk", O_RDONLY|O_CLOEXEC) = 4
> newfstatat(4, "", {st_mode=S_IFREG|0600, st_size=0, ...}, AT_EMPTY_PATH) = 0
> read(4, "", 8192) = 0
> ...
>
> So the failure case is basically:
> 1) open a file for write, and write something;
> 2) open the same file for read, and read() returns 0.
>
> I created a small program to reproduce this issue (attached below).
>
> Before [1], the program can read the data on the first read():
> [root@(none) ]# ./main xxx
> i: 0, read returns 4096
> i: 1, read returns 0
> i: 2, read returns 0
> i: 3, read returns 0
> i: 4, read returns 0
> i: 5, read returns 0
> i: 6, read returns 0
> i: 7, read returns 0
> i: 8, read returns 0
> i: 9, read returns 0
>
> After [1], the program cannot read the data, even after retry:
> [root@(none) ]# ./main yyy
> i: 0, read returns 0
> i: 1, read returns 0
> i: 2, read returns 0
> i: 3, read returns 0
> i: 4, read returns 0
> i: 5, read returns 0
> i: 6, read returns 0
> i: 7, read returns 0
> i: 8, read returns 0
> i: 9, read returns 0
>
> I am not sure what is the "right" behavior in this case. But this is
> clearly a change of behavior.
>
> Thanks,
> Song
>
> [1] https://lore.kernel.org/v9fs/cover.1743956147.git.m@maowtm.org/
>
>
>
> ================ reproducer ==================
>
> #include <fcntl.h>
> #include <stdio.h>
> #include <stdlib.h>
> #include <unistd.h>
>
> char buf[4096];
>
> int main(int argc, char *argv[])
> {
>         int ret, i;
>         int fdw, fdr;
>
>         if (argc < 2)
>                 return 1;
>
>         fdw = openat(AT_FDCWD, argv[1], O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0600);
>         if (fdw < 0) {
>                 fprintf(stderr, "cannot open fdw\n");
>                 return 1;
>         }
>         write(fdw, buf, sizeof(buf));
>
>         fdr = openat(AT_FDCWD, argv[1], O_RDONLY|O_CLOEXEC);
>
>         if (fdr < 0) {
>                 fprintf(stderr, "cannot open fdr\n");
>                 close(fdw);
>                 return 1;
>         }
>
>         for (i = 0; i < 10; i++) {
>                 ret = read(fdr, buf, sizeof(buf));
>                 fprintf(stderr, "i: %d, read returns %d\n", i, ret);
>         }
>
>         close(fdr);
>         close(fdw);
>         unlink(argv[1]);
>         return 0;
> }

Andrii reported the issue as well:
https://lore.kernel.org/bpf/CAEf4BzZbCE4tLoDZyUf_aASpgAGFj75QMfSXX4a4dLYixnOiLg@mail.gmail.com/

selftests/bpf was relying on the above behavior too
which we adjusted already, but
this looks to be a regression either in 9p or in vfs.

Re: 9P change breaks bpftrace running in qemu+9p?

[Dominique Martinet]

Alexei Starovoitov wrote on Tue, Oct 21, 2025 at 09:56:10AM -0700:
> > I am not sure what is the "right" behavior in this case. But this is
> > clearly a change of behavior.

That's definitely wrong, the resulting file was truncated.
Thanks for the repro!

I've sent a fix here:
https://lkml.kernel.org/r/20251022-mmap-regression-v1-1-980365ee524e@codewreck.org


Would be great if you could confirm it fixes your problems, and I'll get
it sent to Linus

> Andrii reported the issue as well:
> https://lore.kernel.org/bpf/CAEf4BzZbCE4tLoDZyUf_aASpgAGFj75QMfSXX4a4dLYixnOiLg@mail.gmail.com/
> 
> selftests/bpf was relying on the above behavior too
> which we adjusted already, but
> this looks to be a regression either in 9p or in vfs.

Looks like a 9p bug, sorry :(

-- 
Dominique Martinet | Asmadeus