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@xxxxxxxxxx>
--D
> Signed-off-by: Zorro Lang <zlang@xxxxxxxxxx>
> ---
> 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
>
