Re: reproduce data race

[Dmitry Vyukov]

On Wed, Feb 10, 2021 at 6:20 AM Jin Huang <andy.j...@gmail.com> wrote:
>
> Hi, my name is Jin Huang, a graduate student at TAMU.
>
> After running syzkaller to fuzz the Linux Kernel through some syscalls I set up, I got some KCSAN data race report, and I tried to reproduce the data race myself.
>
> First I tried ./syz-repro -config my.cfg crashlog
> It was running for about half a hour, and reported some KCSAN data race, and stopped. And these data race are also different from the one I got running syzkaller.
>
> Then I tried tools/syz-execprog on the crashlog on vm.
> And it is still running, and report some data race as well.
>
> I think there should be some way for me to get the corresponding input for the syscalls fuzzing I set up, so that I can reproduce the data race reported, or as the document suggests, I could just get the source code through the syzkaller tools to reproduce the data race?

+syzkaller mailing list

Hi Jin,

syz-mananger extract reproducers for bugs automatically. You don't
need to do anything at all.
But note it does not always work and, yes, it may extract a reproducer
for a different bug. That's due to non-determinism everywhere,
concurrency, accumulated state, too many bugs in the kernel and for
KCSAN additionally
samping nature.

[Jin Huang]

Oh, I see. Thank you for your explanation.

Now I want to reproduce the data race myself based on the syzkaller log information.

Since I can not get the reproduce source code from syzkaller tools, like syz-repro, syz-execprog, I want to write the C program to reproduce the data race myself.

The crash log file generated by syzkaller already shows the syscalls triggering the data race, but all the input parameters are numbers, like fd, and other parameters, hard for me to recognize. Do you have any suggestions if I want to get the inputs. In the end, I can just write the program like yours, https://groups.google.com/g/syzkaller/c/fHZ42YrQM-Y/m/Z4Xf-BbUDgAJ?pli=1

Maybe I am still not so clear about how to use syz-execprog. As described here, https://github.com/google/syzkaller/blob/master/docs/reproducing_crashes.md, I can run syz-execprog with the crash-log, and it will run to produce the data race but seems it will not stop, always resuming the programs and stuff. As I understand, it should produce some output file so that I can further use syz-prog2c to get the C source reproduce program, right?

Thank You

Best

Jin Huang

[Dmitry Vyukov]

On Wed, Feb 10, 2021 at 7:23 PM Jin Huang <andy.j...@gmail.com> wrote:
>
> Oh, I see. Thank you for your explanation.
>
> Now I want to reproduce the data race myself based on the syzkaller log information.
> Since I can not get the reproduce source code from syzkaller tools, like syz-repro, syz-execprog, I want to write the C program to reproduce the data race myself.
>
> The crash log file generated by syzkaller already shows the syscalls triggering the data race, but all the input parameters are numbers, like fd, and other parameters, hard for me to recognize. Do you have any suggestions if I want to get the inputs. In the end, I can just write the program like yours, https://groups.google.com/g/syzkaller/c/fHZ42YrQM-Y/m/Z4Xf-BbUDgAJ?pli=1
>
> Maybe I am still not so clear about how to use syz-execprog. As described here, https://github.com/google/syzkaller/blob/master/docs/reproducing_crashes.md, I can run syz-execprog with the crash-log, and it will run to produce the data race but seems it will not stop, always resuming the programs and stuff. As I understand, it should produce some output file so that I can further use syz-prog2c to get the C source reproduce program, right?

Yes, syz-execprog is intended for just running the program or a set of
programs, it does not do anything else.
Yes, syz-prog2c converts syzkaller programs in the log to
corresponding C programs.
If you see what program in the crash log caused the race, you need to
save it to a separate file and then invoke syz-prog2c on that file. It
will give you a C program.

[Jin Huang]

“If you see what program in the crash log caused the race, you need to save it to a separate file and then invoke syz-prog2c on that file. It will give you a C program.”

For example, a segment of the log file is:

08:55:49 executing program 6:
r0 = epoll_create(0x800)
syz_io_uring_setup(0x472e, &(0x7f0000000100), &(0x7f0000ffe000/0x1000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
epoll_wait(r0, &(0x7f0000000000)=[{}], 0x1, 0x0)

08:55:49 executing program 4:
r0 = epoll_create1(0x0)
r1 = epoll_create1(0x0)
r2 = syz_io_uring_setup(0x472e, &(0x7f0000000100), &(0x7f0000ffe000/0x1000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
epoll_ctl$EPOLL_CTL_ADD(r1, 0x1, r2, 0x0)
epoll_ctl$EPOLL_CTL_ADD(r0, 0x1, r1, &(0x7f0000000080)={0x6})

[  932.291530] ==================================================================
[  932.292332] BUG: KCSAN: data-race in start_this_handle / start_this_handle

Do you mean I can just copy this part:

r0 = epoll_create1(0x0)

r1 = epoll_create1(0x0)
r2 = syz_io_uring_setup(0x472e, &(0x7f0000000100), &(0x7f0000ffe000/0x1000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
epoll_ctl$EPOLL_CTL_ADD(r1, 0x1, r2, 0x0)
epoll_ctl$EPOLL_CTL_ADD(r0, 0x1, r1, &(0x7f0000000080)={0x6})

into a separate file, example, and the syz-proc2c running on it will generate a corresponding C program?

But then I try syz-proc2c -prog example, it does not work, with this information:

panic: bad slowdown 0

goroutine 1 [running]:
github.com/google/syzkaller/sys/targets.(*Target).Timeouts(0xc000332e00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
        /home/jin/syzkaller_space/gopath/src/github.com/google/syzkaller/sys/targets/targets.go:682 +0x239
github.com/google/syzkaller/pkg/csource.Write(0xc000e8eb00, 0x0, 0x1, 0x1, 0x0, 0x0, 0x0, 0x0, 0xffffffffffffffff, 0x0, ...)
        /home/jin/syzkaller_space/gopath/src/github.com/google/syzkaller/pkg/csource/csource.go:97 +0xae0
main.main()
        /home/jin/syzkaller_space/gopath/src/github.com/google/syzkaller/tools/syz-prog2c/prog2c.go:101 +0x816

Do I miss something?

Thank You

Best

Jin Huang

[Jin Huang]

Hi, Dmitry

Still a question , for example the log I select is:

08:55:49 executing program 1:

r0 = epoll_create(0x800)
syz_io_uring_setup(0x472e, &(0x7f0000000100), &(0x7f0000ffe000/0x1000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
epoll_wait(r0, &(0x7f0000000000)=[{}], 0x1, 0x0)

08:55:49 executing program 2:
r0 = syz_io_uring_setup(0x61a1, &(0x7f0000000000)={0x0, 0x4ff, 0x1, 0x0, 0x32a}, &(0x7f0000ffc000/0x2000)=nil, &(0x7f0000ffc000/0x2000)=nil, &(0x7f0000000080), &(0x7f00000000c0))
syz_io_uring_setup(0x3243, &(0x7f0000000100)={0x0, 0xd02d, 0x20, 0x3, 0x16e, 0x0, r0}, &(0x7f0000ffc000/0x3000)=nil, &(0x7f0000ffc000/0x4000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
clone(0x22102000, 0x0, 0x0, 0x0, 0x0)
syz_io_uring_setup(0x2fa8, &(0x7f0000000200)={0x0, 0xd1a6, 0x0, 0x1, 0xf6, 0x0, r0}, &(0x7f0000ffc000/0x2000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000280), &(0x7f00000002c0))

Could I generate the C program to run program1 and program2 on different threads? Or I need to generate for program1 and program2 separately and merge the program source code myself?

Since I see the -threaded option for syz-prog2c, but not sure the effect.

Thank You

Best

Jin Huang

On Thu, Feb 11, 2021 at 4:11 AM Jin Huang <andy.j...@gmail.com> wrote:

Amazing!

It works!

Thank You

Best

Jin Huang

On Thu, Feb 11, 2021 at 3:48 AM Dmitry Vyukov <dvy...@google.com> wrote:

On Thu, Feb 11, 2021 at 9:45 AM Jin Huang <andy.j...@gmail.com> wrote:
>
> “If you see what program in the crash log caused the race, you need to save it to a separate file and then invoke syz-prog2c on that file. It will give you a C program.”
>
> For example, a segment of the log file is:
> 08:55:49 executing program 6:
> r0 = epoll_create(0x800)
> syz_io_uring_setup(0x472e, &(0x7f0000000100), &(0x7f0000ffe000/0x1000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
> epoll_wait(r0, &(0x7f0000000000)=[{}], 0x1, 0x0)
>
> 08:55:49 executing program 4:
> r0 = epoll_create1(0x0)
> r1 = epoll_create1(0x0)
> r2 = syz_io_uring_setup(0x472e, &(0x7f0000000100), &(0x7f0000ffe000/0x1000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
> epoll_ctl$EPOLL_CTL_ADD(r1, 0x1, r2, 0x0)
> epoll_ctl$EPOLL_CTL_ADD(r0, 0x1, r1, &(0x7f0000000080)={0x6})
>
> [  932.291530] ==================================================================
> [  932.292332] BUG: KCSAN: data-race in start_this_handle / start_this_handle
>
>
> Do you mean I can just copy this part:
>
> r0 = epoll_create1(0x0)
> r1 = epoll_create1(0x0)
> r2 = syz_io_uring_setup(0x472e, &(0x7f0000000100), &(0x7f0000ffe000/0x1000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
> epoll_ctl$EPOLL_CTL_ADD(r1, 0x1, r2, 0x0)
> epoll_ctl$EPOLL_CTL_ADD(r0, 0x1, r1, &(0x7f0000000080)={0x6})
>
> into a separate file, example, and the syz-proc2c running on it will generate a corresponding C program?

Yes.

Please sync to HEAD to pick up this commit:
https://github.com/google/syzkaller/commit/50068b628237c3793bf1df02bd207b713ff17b8b
It should fix the crash.

> But then I try syz-proc2c -prog example, it does not work, with this information:
> panic: bad slowdown 0
>
> goroutine 1 [running]:
> github.com/google/syzkaller/sys/targets.(*Target).Timeouts(0xc000332e00, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0)
>         /home/jin/syzkaller_space/gopath/src/github.com/google/syzkaller/sys/targets/targets.go:682 +0x239
> github.com/google/syzkaller/pkg/csource.Write(0xc000e8eb00, 0x0, 0x1, 0x1, 0x0, 0x0, 0x0, 0x0, 0xffffffffffffffff, 0x0, ...)
>         /home/jin/syzkaller_space/gopath/src/github.com/google/syzkaller/pkg/csource/csource.go:97 +0xae0
> main.main()
>         /home/jin/syzkaller_space/gopath/src/github.com/google/syzkaller/tools/syz-prog2c/prog2c.go:101 +0x816
>
> Do I miss something?
>
>
>
>

> Thank You
> Best
> Jin Huang
>
>

[Dmitry Vyukov]

On Thu, Feb 11, 2021 at 10:49 AM Jin Huang <andy.j...@gmail.com> wrote:
>
> Hi, Dmitry
> Still a question , for example the log I select is:
> 08:55:49 executing program 1:
> r0 = epoll_create(0x800)
> syz_io_uring_setup(0x472e, &(0x7f0000000100), &(0x7f0000ffe000/0x1000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
> epoll_wait(r0, &(0x7f0000000000)=[{}], 0x1, 0x0)
>
> 08:55:49 executing program 2:
> r0 = syz_io_uring_setup(0x61a1, &(0x7f0000000000)={0x0, 0x4ff, 0x1, 0x0, 0x32a}, &(0x7f0000ffc000/0x2000)=nil, &(0x7f0000ffc000/0x2000)=nil, &(0x7f0000000080), &(0x7f00000000c0))
> syz_io_uring_setup(0x3243, &(0x7f0000000100)={0x0, 0xd02d, 0x20, 0x3, 0x16e, 0x0, r0}, &(0x7f0000ffc000/0x3000)=nil, &(0x7f0000ffc000/0x4000)=nil, &(0x7f0000000180), &(0x7f00000001c0))
> clone(0x22102000, 0x0, 0x0, 0x0, 0x0)
> syz_io_uring_setup(0x2fa8, &(0x7f0000000200)={0x0, 0xd1a6, 0x0, 0x1, 0xf6, 0x0, r0}, &(0x7f0000ffc000/0x2000)=nil, &(0x7f0000ffc000/0x1000)=nil, &(0x7f0000000280), &(0x7f00000002c0))
>
> Could I generate the C program to run program1 and program2 on different threads? Or I need to generate for program1 and program2 separately and merge the program source code myself?
> Since I see the -threaded option for syz-prog2c, but not sure the effect.

Such functionality does not exist now. If you need exactly that, you
need to merge yourself.

[Hunter J]

Hi, Dmitry

I found it is hard for me to first select the potential program exceptions that could trigger data race.

For example, the KCSAN data race report in the crash log is:

BUG: KCSAN: data-race in step_into / vfs_unlink
write to 0xffff9af42962b270 of 4 bytes by task 15262 on cpu 0:
vfs_unlink+0x27a/0x3c0
do_unlinkat+0x211/0x4c0
__x64_sys_unlink+0x2c/0x30
do_syscall_64+0x37/0x50
entry_SYSCALL_64_after_hwframe+0x44/0xa9

read to 0xffff9af42962b270 of 4 bytes by task 110 on cpu 1:
step_into+0x159/0xfb0
walk_component+0x1a5/0x380
path_lookupat+0x11d/0x560
filename_lookup+0xf2/0x380
user_path_at_empty+0x3b/0x50
do_readlinkat+0x87/0x200
__x64_sys_readlink+0x43/0x50
do_syscall_64+0x37/0x50
entry_SYSCALL_64_after_hwframe+0x44/0xa9

I even did not find any readlink syscall in the crash log file. Did I miss something?

Thank You

Best

Jin Huang

[Dmitry Vyukov]

On Mon, Feb 15, 2021 at 11:06 AM Hunter J <andy.j...@gmail.com> wrote:
>
> Hi, Dmitry
> I found it is hard for me to first select the potential program exceptions that could trigger data race.
> For example, the KCSAN data race report in the crash log is:
> BUG: KCSAN: data-race in step_into / vfs_unlink
> write to 0xffff9af42962b270 of 4 bytes by task 15262 on cpu 0:
> vfs_unlink+0x27a/0x3c0
> do_unlinkat+0x211/0x4c0
> __x64_sys_unlink+0x2c/0x30
> do_syscall_64+0x37/0x50
> entry_SYSCALL_64_after_hwframe+0x44/0xa9
>
> read to 0xffff9af42962b270 of 4 bytes by task 110 on cpu 1:
> step_into+0x159/0xfb0
> walk_component+0x1a5/0x380
> path_lookupat+0x11d/0x560
> filename_lookup+0xf2/0x380
> user_path_at_empty+0x3b/0x50
> do_readlinkat+0x87/0x200
> __x64_sys_readlink+0x43/0x50
> do_syscall_64+0x37/0x50
> entry_SYSCALL_64_after_hwframe+0x44/0xa9
>
> I even did not find any readlink syscall in the crash log file. Did I miss something?

Hi Jin,

Some syscalls may be executed by the syz-executor binary itself. It
needs to allocate some memory, etc, that's also syscalls.
Some syscalls may be executed by the syz-fuzzer binary.
Some syscalls may be executed by other processes in your user-space
system that are not related to syzkaller.

[Dmitry Vyukov]

On Thu, Feb 18, 2021 at 10:25 AM Hunter J <andy.j...@gmail.com> wrote:
>
> Hi, Dmitry

> When I try to run syz-kaller to reproduce this data race, syscalls of sendfile64 and write, https://lore.kernel.org/lkml/0000000000000c...@google.com/.
> But when I set them in my .cfg file like this:
>
> {
> "target": "linux/amd64",
> "http": "127.0.0.1:56741",
> "workdir": "workdir",
> "kernel_obj": "linux-5.11",
> "image": "stretch.img",
> "sshkey": "stretch.id_rsa",
> "syzkaller": "gopath/src/github.com/google/syzkaller",
> "procs": 4,
> "type": "qemu",
> "vm": {
> "count": 8,
> "kernel": "/home/jin/syzkaller_space/linux-5.11/arch/x86/boot/bzImage",
> "cpu": 2,
> "mem": 4096
> },
> "enable_syscalls" : ["open", "sendfile64", "write"]
> }
>
> Then syz-manager complains 'unknown enabled syscall: sendfile64', but I actually find sendfile64 in syzkaller/sys/linux/sys.txt:
> sendfile64(fdout fd, fdin fd, off ptr[inout, fileoff[int64], opt], count intptr)

>
> Did I miss something?

Hi Jin,

THis syscall only seems to be present on arm32 architecture:

sys/linux/sys.txt.const:__NR_sendfile64 = 239,
amd64:arm64:mips64le:ppc64le:riscv64:s390x:???