[PATCH v4 2/4] Stage output for -z and -Z options

Dmitry V. Levin ldv at altlinux.org
Mon Jun 17 23:21:27 UTC 2019


On Sat, Jun 15, 2019 at 07:31:24PM +0200, Paul Chaignon wrote:
> -z and -Z options print only successful and failing syscalls respectively.
> However, failure of syscall is only known after syscall return.  Thus, we end
> up with something like this on, e.g., ENOENT:
> 
>   open("does_not_exist", O_RDONLY <unfinished ...>
> 
> whereas the intended result is that the open(...) line is not shown at all.
> 
> This patch fixes this issue using open_memstream.  When either the -z or the -Z
> option is used, the output is staged in memory (using open_memstream) until we
> know the syscall return status.
> If the open_memstream function is not available, these new options error out.
> 
> Signed-off-by: Paul Chaignon <paul.chaignon at gmail.com>
> Co-Authored-by: Burkhard Kohl <burkhard.kohl at intel.com>
> ---
>  Makefile.am    |  1 +
>  configure.ac   |  1 +
>  defs.h         | 10 ++++++++
>  stage_output.c | 66 ++++++++++++++++++++++++++++++++++++++++++++++++++
>  strace.1.in    |  6 +++++
>  strace.c       | 31 ++++++++++++++++++++----
>  syscall.c      | 18 +++++++-------
>  7 files changed, 119 insertions(+), 14 deletions(-)
>  create mode 100644 stage_output.c

Looks good, thanks.
There are a few minor issues that should be addressed, see below.

> diff --git a/Makefile.am b/Makefile.am
> index a8ace321..b53d795c 100644
> --- a/Makefile.am
> +++ b/Makefile.am
> @@ -307,6 +307,7 @@ strace_SOURCES =	\
>  	sock.c		\
>  	sockaddr.c	\
>  	socketutils.c	\
> +	stage_output.c	\
>  	sparc.c		\
>  	sram_alloc.c	\
>  	stat.c		\

Please keep this list sorted.

[...]
> --- /dev/null
> +++ b/stage_output.c
> @@ -0,0 +1,66 @@
> +/*
> + * Copyright (c) 2017 Intel Corporation
> + * Copyright (c) 2019 Paul Chaignon <paul.chaignon at gmail.com>
> + * All rights reserved.
> + *
> + * SPDX-License-Identifier: LGPL-2.1-or-later
> + */
> +
> +/*
> + *  Output staging is based on the "open_memstream()" function, see:
> + *  http://man7.org/linux/man-pages/man3/open_memstream.3.html
> + *  Requires glibc version 2.7 mininal

"mininal" is not a word.
I think the whole sentence can be omitted as open_memstream(3) already
describes this glibc bug in detail.

> + *
> + *  open_memstream returns a FILE stream that allows writing to a
> + *  dynamically growing buffer, that can be either copied to
> + *  tcp->outf (syscall successful) or dropped (syscall failed)
> + */
> +
> +#include "defs.h"
> +
> +FILE *
> +strace_open_memstream(struct tcb *tcp)
> +{
> +	FILE *fp = NULL;
> +
> +#if HAVE_OPEN_MEMSTREAM
> +	tcp->memfptr = NULL;
> +	fp = open_memstream(&tcp->memfptr, &tcp->memfloc);
> +	if (!fp)
> +		perror_msg_and_die("open_memstream");
> +	/* Call to fflush required to update tcp->memfptr, see open_memstream
> +	 * man page. */

We prefer a slightly different style for multi-line comments.

[...]
> --- a/strace.c
> +++ b/strace.c
> @@ -275,6 +275,8 @@ Filtering:\n\
>    -e expr        a qualifying expression: option=[!]all or option=[!]val1[,val2]...\n\
>       options:    trace, abbrev, verbose, raw, signal, read, write, fault, inject, kvm\n\
>    -P path        trace accesses to path\n\
> +  -z             print only syscalls that returned without an error code\n\
> +  -Z             print only syscalls that returned with an error code\n\
>  \n\
>  Tracing:\n\
>    -b execve      detach on execve syscall\n\
> @@ -303,10 +305,6 @@ Miscellaneous:\n\
>  /* ancient, no one should use it
>  -F -- attempt to follow vforks (deprecated, use -f)\n\
>   */
> -/* this is broken, so don't document it
> --z -- print only succeeding syscalls\n\
> --Z -- print only failing syscalls\n\
> - */
>  , DEFAULT_ACOLUMN, DEFAULT_STRLEN, DEFAULT_SORTBY);
>  	exit(0);
>  }
> @@ -1771,6 +1769,11 @@ init(int argc, char *argv[])
>  			error_msg("-%c has no effect with -c", 'y');
>  	}
>  
> +#ifndef HAVE_OPEN_MEMSTREAM
> +	if (not_failing_only || failing_only)
> +		error_msg_and_help("open_memstream is required to use -z or -Z");
> +#endif
> +
>  	acolumn_spaces = xmalloc(acolumn + 1);
>  	memset(acolumn_spaces, ' ', acolumn);
>  	acolumn_spaces[acolumn] = '\0';
> @@ -2044,6 +2047,8 @@ static struct tcb *
>  maybe_switch_tcbs(struct tcb *tcp, const int pid)
>  {
>  	FILE *fp;
> +	char *memfptr;
> +	size_t memfloc;

I think definitions of these variables could be moved to the block where
they are used.

>  	struct tcb *execve_thread;
>  	long old_pid = tcb_wait_tab[tcp->wait_data_idx].msg;
>  
> @@ -2065,10 +2070,22 @@ maybe_switch_tcbs(struct tcb *tcp, const int pid)
>  		fprintf(execve_thread->outf, " <pid changed to %d ...>\n", pid);
>  		/*execve_thread->curcol = 0; - no need, see code below */
>  	}
> -	/* Swap output FILEs (needed for -ff) */
> +	/* Swap output FILEs and memstream (needed for -ff) */
>  	fp = execve_thread->outf;
>  	execve_thread->outf = tcp->outf;
>  	tcp->outf = fp;
> +	if (execve_thread->real_outf || tcp->real_outf) {
> +		fp = execve_thread->real_outf;
> +		execve_thread->real_outf = tcp->real_outf;
> +		tcp->real_outf = fp;
> +		memfptr = execve_thread->memfptr;
> +		execve_thread->memfptr = tcp->memfptr;
> +		tcp->memfptr = memfptr;
> +		memfloc = execve_thread->memfloc;
> +		execve_thread->memfloc = tcp->memfloc;
> +		tcp->memfloc = memfloc;
> +	}
> +
>  	/* And their column positions */
>  	execve_thread->curcol = tcp->curcol;
>  	tcp->curcol = 0;
> @@ -2081,6 +2098,10 @@ maybe_switch_tcbs(struct tcb *tcp, const int pid)
>  		printleader(tcp);
>  		tprintf("+++ superseded by execve in pid %lu +++\n", old_pid);
>  		line_ended();
> +		/* Need to reopen memstream for thread
> +		 * as we closed it in droptcb. */

This patch does not change droptcb, it is done by the subsequent patch
in the series.

Looks like this patch is somewhat incomplete as it leaks memory e.g.
for each exit/exit_group syscall when staging output is enabled.

Again, we prefer a slightly different style for multi-line comments.

> +		if (failing_only || not_failing_only)
> +			strace_open_memstream(tcp);
>  		tcp->flags |= TCB_REPRINT;
>  	}
>  
> diff --git a/syscall.c b/syscall.c
> index 29dfb7a7..2a471711 100644
> --- a/syscall.c
> +++ b/syscall.c
> @@ -656,6 +656,9 @@ syscall_entering_trace(struct tcb *tcp, unsigned int *sig)
>  	}
>  #endif
>  
> +	if (not_failing_only || failing_only)
> +		strace_open_memstream(tcp);
> +
>  	printleader(tcp);
>  	tprintf("%s(", tcp_sysent(tcp)->sys_name);
>  	int res = raw(tcp) ? printargs(tcp) : tcp_sysent(tcp)->sys_func(tcp);
> @@ -757,18 +760,13 @@ syscall_exiting_trace(struct tcb *tcp, struct timespec *ts, int res)
>  	if (raw(tcp)) {
>  		/* sys_res = printargs(tcp); - but it's nop on sysexit */
>  	} else {
> -	/* FIXME: not_failing_only (IOW, option -z) is broken:
> -	 * failure of syscall is known only after syscall return.
> -	 * Thus we end up with something like this on, say, ENOENT:
> -	 *     open("does_not_exist", O_RDONLY <unfinished ...>
> -	 *     {next syscall decode}
> -	 * whereas the intended result is that open(...) line
> -	 * is not shown at all.
> -	 */
>  		if ((not_failing_only && syserror(tcp)) ||
> -		    (failing_only && !syserror(tcp)))
> +		    (failing_only && !syserror(tcp))) {
> +			strace_close_memstream(tcp, false);
> +			line_ended();
>  			return 0;	/* ignore failed/successful
>  					 * syscalls */
> +		}
>  		if (tcp->sys_func_rval & RVAL_DECODED)
>  			sys_res = tcp->sys_func_rval;
>  		else
> @@ -904,6 +902,8 @@ syscall_exiting_trace(struct tcb *tcp, struct timespec *ts, int res)
>  	}
>  	tprints("\n");
>  	dumpio(tcp);
> +	if (not_failing_only || failing_only)
> +		strace_close_memstream(tcp, true);
>  	line_ended();
>  
>  #ifdef ENABLE_STACKTRACE

Is there any particular reason to stage the output of dumpio?


-- 
ldv
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 801 bytes
Desc: not available
URL: <http://lists.strace.io/pipermail/strace-devel/attachments/20190618/72905d73/attachment.bin>


More information about the Strace-devel mailing list