| Message ID | 20220601063730.1726879-4-zlang@kernel.org (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | random fixes for fstests | expand |
On Wed, Jun 01, 2022 at 02:37:28PM +0800, Zorro Lang wrote: > In generic/591.out expects below output: > concurrent reader with O_DIRECT > concurrent reader with O_DIRECT <=== ??? > concurrent reader without O_DIRECT > concurrent reader without O_DIRECT <=== ??? > sequential reader with O_DIRECT > sequential reader without O_DIRECT > > The lines marked "???" are unbelievable, due to the src/splice-test.c > only calls printf to output that message once in main function. So > Why splice-test prints that message twice sometimes? It seems related > with the "-r" option, due to the test lines without "-r" option only > print one line each time running. > > A stanger thing is this "double output" issue only can be triggered by > running g/591, can't reproduce it by running splice-test manually. > > By checking the code of splice-test.c, I found a "fork()" in it, and > it'll be called if the '-r' option is specified. So I suspect the > redundant output come from the child process. By the help of strace > tool, I got: > > 10554 execve("/root/git/xfstests/src/splice-test", ["/root/git/xfstests/src/splice-te"..., "-r", "/mnt/test/a"], 0x7ffcabc2c0a8 /* 202 vars */) = 0 > ... > 10554 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f937f5d5a10) = 10555 > ... > 10555 read(4, "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"..., 512) = 512 > 10555 write(1, "concurrent reader with O_DIRECT\n", 32) = 32 > 10555 exit_group(0) = ? > 10555 +++ exited with 0 +++ > 10554 <... wait4 resumed>NULL, 0, NULL) = 10555 > 10554 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=10555, si_uid=0, si_status=0, si_utime=0, si_stime=1} --- > 10554 unlink("/mnt/test/a") = 0 > 10554 write(1, "concurrent reader with O_DIRECT\n", 32) = 32 > 10554 exit_group(0) = ? > 10554 +++ exited with 0 +++ > > We can see the "concurrent reader with O_DIRECT\n" be printed by > parent process 10554 and child process 10555 separately. > > Due to the stdout redirection that fstests does cause the stream > doesn't refer to a tty anymore, then the stdout become block > buffered, so the '\n' doesn't help to flush that printf message, > and the child print it again. > > So use setlinebuf(stdout) to force it line buffered, to avoid the > confused output to be golden image. Then correct the generic/591.out Eww, so the printf ends up in the output buffer, which is then duplicated in the forked child, so both parent and child emit the same message? Gross. Reviewed-by: Darrick J. Wong <djwong@kernel.org> --D > Signed-off-by: Zorro Lang <zlang@kernel.org> > --- > src/splice-test.c | 2 ++ > tests/generic/591.out | 2 -- > 2 files changed, 2 insertions(+), 2 deletions(-) > > diff --git a/src/splice-test.c b/src/splice-test.c > index 2f1ba2ba..dc41b0f5 100644 > --- a/src/splice-test.c > +++ b/src/splice-test.c > @@ -140,6 +140,8 @@ int main(int argc, char *argv[]) > usage(argv[0]); > filename = argv[optind]; > > + /* force below printf line buffered */ > + setlinebuf(stdout); > printf("%s reader %s O_DIRECT\n", > do_splice == do_splice1 ? "sequential" : "concurrent", > (open_flags & O_DIRECT) ? "with" : "without"); > diff --git a/tests/generic/591.out b/tests/generic/591.out > index d61811ee..e9fffd1d 100644 > --- a/tests/generic/591.out > +++ b/tests/generic/591.out > @@ -1,7 +1,5 @@ > QA output created by 591 > concurrent reader with O_DIRECT > -concurrent reader with O_DIRECT > -concurrent reader without O_DIRECT > concurrent reader without O_DIRECT > sequential reader with O_DIRECT > sequential reader without O_DIRECT > -- > 2.31.1 >
diff --git a/src/splice-test.c b/src/splice-test.c index 2f1ba2ba..dc41b0f5 100644 --- a/src/splice-test.c +++ b/src/splice-test.c @@ -140,6 +140,8 @@ int main(int argc, char *argv[]) usage(argv[0]); filename = argv[optind]; + /* force below printf line buffered */ + setlinebuf(stdout); printf("%s reader %s O_DIRECT\n", do_splice == do_splice1 ? "sequential" : "concurrent", (open_flags & O_DIRECT) ? "with" : "without"); diff --git a/tests/generic/591.out b/tests/generic/591.out index d61811ee..e9fffd1d 100644 --- a/tests/generic/591.out +++ b/tests/generic/591.out @@ -1,7 +1,5 @@ QA output created by 591 concurrent reader with O_DIRECT -concurrent reader with O_DIRECT -concurrent reader without O_DIRECT concurrent reader without O_DIRECT sequential reader with O_DIRECT sequential reader without O_DIRECT
In generic/591.out expects below output: concurrent reader with O_DIRECT concurrent reader with O_DIRECT <=== ??? concurrent reader without O_DIRECT concurrent reader without O_DIRECT <=== ??? sequential reader with O_DIRECT sequential reader without O_DIRECT The lines marked "???" are unbelievable, due to the src/splice-test.c only calls printf to output that message once in main function. So Why splice-test prints that message twice sometimes? It seems related with the "-r" option, due to the test lines without "-r" option only print one line each time running. A stanger thing is this "double output" issue only can be triggered by running g/591, can't reproduce it by running splice-test manually. By checking the code of splice-test.c, I found a "fork()" in it, and it'll be called if the '-r' option is specified. So I suspect the redundant output come from the child process. By the help of strace tool, I got: 10554 execve("/root/git/xfstests/src/splice-test", ["/root/git/xfstests/src/splice-te"..., "-r", "/mnt/test/a"], 0x7ffcabc2c0a8 /* 202 vars */) = 0 ... 10554 clone(child_stack=NULL, flags=CLONE_CHILD_CLEARTID|CLONE_CHILD_SETTID|SIGCHLD, child_tidptr=0x7f937f5d5a10) = 10555 ... 10555 read(4, "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"..., 512) = 512 10555 write(1, "concurrent reader with O_DIRECT\n", 32) = 32 10555 exit_group(0) = ? 10555 +++ exited with 0 +++ 10554 <... wait4 resumed>NULL, 0, NULL) = 10555 10554 --- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=10555, si_uid=0, si_status=0, si_utime=0, si_stime=1} --- 10554 unlink("/mnt/test/a") = 0 10554 write(1, "concurrent reader with O_DIRECT\n", 32) = 32 10554 exit_group(0) = ? 10554 +++ exited with 0 +++ We can see the "concurrent reader with O_DIRECT\n" be printed by parent process 10554 and child process 10555 separately. Due to the stdout redirection that fstests does cause the stream doesn't refer to a tty anymore, then the stdout become block buffered, so the '\n' doesn't help to flush that printf message, and the child print it again. So use setlinebuf(stdout) to force it line buffered, to avoid the confused output to be golden image. Then correct the generic/591.out Signed-off-by: Zorro Lang <zlang@kernel.org> --- src/splice-test.c | 2 ++ tests/generic/591.out | 2 -- 2 files changed, 2 insertions(+), 2 deletions(-)