From: Paul Chaignon Date: Sat, 15 Jun 2019 05:21:44 +0000 (+0200) Subject: Stage output for -z and -Z options X-Git-Tag: v5.2~7 X-Git-Url: https://granicus.if.org/sourcecode?a=commitdiff_plain;h=35dbe6803f35d47403b186d66db25c574b7637d7;p=strace Stage output for -z and -Z options -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 whereas the intended result is that the open(...) line is not shown at all. This change 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. Document -z and -Z options as new features since they have never worked properly before and were undocumented since commit v4.4.95~21. * stage_output.c: New file. * Makefile.am (strace_SOURCES): Add it. * configure.ac (AC_CHECK_FUNCS): Add open_memstream. * defs.h (struct tcb): Add real_outf, memfptr, and memfloc fields for memstream. (strace_open_memstream, strace_close_memstream): New prototypes. * strace.1.in: Document -z and -Z options. * strace.c (usage): Mention -z and -Z options. (init): Error on -z and -Z options if open_memstream if unavailable. (maybe_switch_tcbs): Handle switch of memstream between tcbs. (printleader): Avoid marking staged syscalls as unfinished. * syscall.c (syscall_entering_trace): Open memstream. (syscall_exiting_trace): Filter failed syscalls if failing_only is set, handle raw(tcp) case. (print_syscall_resume): Avoid marking staged syscalls as resumed. * NEWS: Mention this change. Resolves: https://github.com/strace/strace/issues/49 Resolves: https://github.com/strace/strace/issues/50 Co-Authored-by: Burkhard Kohl Signed-off-by: Paul Chaignon --- diff --git a/Makefile.am b/Makefile.am index dfd79892..0fa7f25d 100644 --- a/Makefile.am +++ b/Makefile.am @@ -315,6 +315,7 @@ strace_SOURCES = \ socketutils.c \ sparc.c \ sram_alloc.c \ + stage_output.c \ stat.c \ stat.h \ stat64.c \ diff --git a/NEWS b/NEWS index ddca2b2b..67656ea4 100644 --- a/NEWS +++ b/NEWS @@ -6,6 +6,7 @@ Noteworthy changes in release ?.? (????-??-??) PTRACE_GET_SYSCALL_INFO is in use. * Improvements + * Implemented syscall return status filtering options: -z, -Z. * Implemented decoding of open_tree, move_mount, fsopen, fsconfig, fsmount, and fspick syscalls. * Enhanced decoding of bpf, clone, mbind, and set_mempolicy syscalls. diff --git a/configure.ac b/configure.ac index 399c0e0a..a973c2b2 100644 --- a/configure.ac +++ b/configure.ac @@ -262,6 +262,7 @@ AC_CHECK_FUNCS(m4_normalize([ iconv_open if_indextoname open64 + open_memstream prctl preadv process_vm_readv diff --git a/defs.h b/defs.h index ca458d40..b9b394ec 100644 --- a/defs.h +++ b/defs.h @@ -204,6 +204,10 @@ struct tcb { int sys_func_rval; /* Syscall entry parser's return value */ int curcol; /* Output column for this process */ FILE *outf; /* Output file for this process */ + FILE *real_outf; /* Backup for real outf while staging */ + char *memfptr; + size_t memfloc; + const char *auxstr; /* Auxiliary info from syscall (see RVAL_STR) */ void *_priv_data; /* Private data for syscall decoding functions */ void (*_free_priv_data)(void *); /* Callback for freeing priv_data */ @@ -1196,6 +1200,12 @@ extern void tprints(const char *str); extern void tprintf_comment(const char *fmt, ...) ATTRIBUTE_FORMAT((printf, 1, 2)); extern void tprints_comment(const char *str); +/* + * Staging output for status qualifier. + */ +extern FILE *strace_open_memstream(struct tcb *tcp); +extern void strace_close_memstream(struct tcb *tcp, bool publish); + static inline void printaddr_comment(const kernel_ulong_t addr) { diff --git a/stage_output.c b/stage_output.c new file mode 100644 index 00000000..971714b7 --- /dev/null +++ b/stage_output.c @@ -0,0 +1,64 @@ +/* + * Copyright (c) 2017 Intel Corporation + * Copyright (c) 2019 Paul Chaignon + * All rights reserved. + * + * SPDX-License-Identifier: LGPL-2.1-or-later + */ + +/* + * 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. + */ + fflush(fp); + + /* Store the FILE pointer for later restauration. */ + tcp->real_outf = tcp->outf; + tcp->outf = fp; +#endif + + return fp; +} + +void +strace_close_memstream(struct tcb *tcp, bool publish) +{ +#if HAVE_OPEN_MEMSTREAM + if (!tcp->real_outf) { + debug_msg("memstream already closed"); + return; + } + + if (fclose(tcp->outf)) + perror_msg("fclose(tcp->outf)"); + + tcp->outf = tcp->real_outf; + tcp->real_outf = NULL; + if (tcp->memfptr) { + if (publish) + fputs_unlocked(tcp->memfptr, tcp->outf); + else + debug_msg("syscall output dropped: %s", tcp->memfptr); + free(tcp->memfptr); + tcp->memfptr = NULL; + } +#endif +} diff --git a/strace.1.in b/strace.1.in index 76a74119..e1090a0f 100644 --- a/strace.1.in +++ b/strace.1.in @@ -771,6 +771,12 @@ Print unabbreviated versions of environment, stat, termios, etc. calls. These structures are very common in calls and so the default behavior displays a reasonable subset of structure members. Use this option to get all of the gory details. +.TP +.B \-z +Print only syscalls that returned without an error code. +.TP +.B \-Z +Print only syscalls that returned with an error code. .SS Tracing .TP 12 .BI "\-b " syscall diff --git a/strace.c b/strace.c index 27027a30..22f30684 100644 --- 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); } @@ -611,7 +609,8 @@ printleader(struct tcb *tcp) if (printing_tcp) { set_current_tcp(printing_tcp); - if (printing_tcp->curcol != 0 && (followfork < 2 || printing_tcp == tcp)) { + if (tcp->real_outf == NULL && printing_tcp->curcol != 0 && + (followfork < 2 || printing_tcp == tcp)) { /* * case 1: we have a shared log (i.e. not -ff), and last line * wasn't finished (same or different tcb, doesn't matter). @@ -1765,6 +1764,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'; @@ -2076,10 +2080,25 @@ maybe_switch_tcbs(struct tcb *tcp, const int pid) fprintf(execve_thread->outf, " \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) */ FILE *fp = execve_thread->outf; execve_thread->outf = tcp->outf; tcp->outf = fp; + if (execve_thread->real_outf || tcp->real_outf) { + char *memfptr; + size_t memfloc; + + 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; diff --git a/syscall.c b/syscall.c index e73e4274..65f00d2d 100644 --- a/syscall.c +++ b/syscall.c @@ -650,6 +650,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); @@ -712,7 +715,7 @@ print_syscall_resume(struct tcb *tcp) * "strace -ff -oLOG test/threaded_execve" corner case. * It's the only case when -ff mode needs reprinting. */ - if ((followfork < 2 && printing_tcp != tcp) + if ((followfork < 2 && printing_tcp != tcp && tcp->real_outf == NULL) || (tcp->flags & TCB_REPRINT)) { tcp->flags &= ~TCB_REPRINT; printleader(tcp); @@ -751,24 +754,22 @@ 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 - * {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))) - return 0; /* ignore failed/successful - * syscalls */ if (tcp->sys_func_rval & RVAL_DECODED) sys_res = tcp->sys_func_rval; else sys_res = tcp_sysent(tcp)->sys_func(tcp); } + if ((not_failing_only && syserror(tcp)) || + (failing_only && !syserror(tcp))) { + strace_close_memstream(tcp, false); + line_ended(); + return 0; /* ignore failed/successful + * syscalls */ + } else if (not_failing_only || failing_only) { + strace_close_memstream(tcp, true); + } + tprints(") "); tabto();