-----Original Message----- From: Kohl, Burkhard Sent: Thursday, June 8, 2017 13:02 To: strace-devel@lists.sourceforge.net Cc: Kohl, Burkhard <burkhard.k...@intel.com> Subject: [PATCH v1] Implement output staging for failed/successful syscalls
With flags not_failing_only/failing_only, syscall output is written to tcp->memf and either dropped or published at strace_syscall_exiting * stage_out.c strace_openmemstream(), drop_staged_out(), publish_staged_out(). * defs.h added flags stage_out, failing only struct tcb: new members memf, memfptr, memfloc. * syscall.c print output depending on flags and outcome. * strace.c add options -z/-Z +help modified tvprintf(), tprints(), newoutf() set stage_output flag in main(). * Makefile.am new: stage_out.c * configure.ac (AC_CHECK_FUNCS): open_memstream * strace.1 -z/-Z: description added --- Makefile.am | 1 + configure.ac | 1 + defs.h | 16 ++++++++ stage_out.c | 128 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ strace.1 | 8 +++- strace.c | 112 ++++++++++++++++++++++++++++++++++++++++++++++++--- syscall.c | 21 +++++++++- 7 files changed, 280 insertions(+), 7 deletions(-) create mode 100644 stage_out.c diff --git a/Makefile.am b/Makefile.am index 3d6eba1..e3c2d5c 100644 --- a/Makefile.am +++ b/Makefile.am @@ -232,6 +232,7 @@ strace_SOURCES = \ sockaddr.c \ socketutils.c \ sram_alloc.c \ + stage_out.c \ stat.c \ stat.h \ stat64.c \ diff --git a/configure.ac b/configure.ac index 0d4679e..f8a06d7 100644 --- a/configure.ac +++ b/configure.ac @@ -286,6 +286,7 @@ AC_CHECK_FUNCS(m4_normalize([ strsignal sync_file_range utimensat + open_memstream ])) AC_CHECK_TYPES([sig_atomic_t, struct sigcontext],,, [#include <signal.h>]) diff --git a/defs.h b/defs.h index f731fa8..343e2e8 100644 --- a/defs.h +++ b/defs.h @@ -223,6 +223,11 @@ 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 */ +#if HAVE_OPEN_MEMSTREAM + FILE *memf; /* Staged output file for this process */ + char *memfptr; + size_t memfloc; +#endif /* if HAVE_OPEN_MEMSTREAM */ 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 */ @@ -370,6 +375,10 @@ extern bool iflag; extern bool count_wallclock; extern unsigned int qflag; extern bool not_failing_only; +#if HAVE_OPEN_MEMSTREAM +extern bool failing_only; +extern bool stage_output; /* allows dropping of failed/successful syscalls output */ +#endif /* if HAVE_OPEN_MEMSTREAM */ extern unsigned int show_fd_path; /* are we filtering traces based on paths? */ extern const char **paths_selected; @@ -752,6 +761,13 @@ 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 -z/-Z (not_failing_only/failing_only) */ extern +FILE *strace_openmemstream(struct tcb *tcp); extern void +drop_staged_out(struct tcb *tcp); extern void publish_staged_out(struct +tcb *tcp); + #if SUPPORTED_PERSONALITIES > 1 extern void set_personality(int personality); extern unsigned current_personality; diff --git a/stage_out.c b/stage_out.c new file mode 100644 index 0000000..34cd0cf --- /dev/null +++ b/stage_out.c @@ -0,0 +1,128 @@ +/* + * Copyright (C) 2016-2017 Intel Deutschland GmbH + + * All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * 3. The name of the author may not be used to endorse or promote products + * derived from this software without specific prior written permission. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR ``AS IS'' AND ANY EXPRESS OR + * IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE IMPLIED + WARRANTIES + * OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE ARE DISCLAIMED. + * IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR ANY DIRECT, INDIRECT, + * INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, + BUT + * NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF + USE, + * DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON + ANY + * THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT + * (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE + USE OF + * THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE. + */ + +/* + * 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 + * + * 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" +#if HAVE_OPEN_MEMSTREAM + +FILE * +strace_openmemstream(struct tcb *tcp) +{ + FILE *fp = NULL; // to be returned + + if(debug_flag) { + ; /* error_msg("stage_openmemstream working on tcp %p", tcp); */ + } + if (NULL != tcp) { + tcp->memfptr = NULL; + fp = open_memstream(&(tcp->memfptr), &(tcp->memfloc)); + if (NULL == fp) + perror_msg_and_die("error during open_memstream"); + else + /* call to fflush required to update tcp->memfptr, see open_memstream man page */ + fflush(fp); + tcp->memf = fp; +#if DEBUG_STAGEOUT + if(debug_flag) { + error_msg("stage_openmemstream for tcp: %p (opened memf: %p, memfptr: %p, size: %zu)", tcp, tcp->memf, tcp->memfptr, tcp->memfloc); + } +#endif + } + + return fp; +} + +void +drop_staged_out(struct tcb *tcp) +{ + if (NULL != tcp->memf) { +#if DEBUG_STAGEOUT + if(debug_flag) { + error_msg("drop_stage_out (before flcose): for tcp: %p (opened memf: %p, memfptr: %p, size: %zu)", tcp, tcp->memf, tcp->memfptr, tcp->memfloc); + } +#endif + + if (fclose(tcp->memf)) { + perror_msg("flose on tcp->memf"); + } + if (NULL != tcp->memfptr) { + if(debug_flag) { + error_msg("syscall output dropped: %s ...", tcp->memfptr); + } + + free(tcp->memfptr); + tcp->memfptr = NULL; + } + + /* reopen tcp->memf for subsequent use */ + strace_openmemstream(tcp); + } +} + +void +publish_staged_out(struct tcb *tcp) +{ + if (NULL != tcp->memf) { +#if DEBUG_STAGEOUT + if(debug_flag) { + error_msg("publish_staged_out (before fclose): for tcp: %p (opened memf: %p, memfptr: %p, size: %zu)", tcp, tcp->memf, tcp->memfptr, tcp->memfloc); + } +#endif + + if (fclose(tcp->memf)) { + perror_msg("flose on tcp->memf"); + } + if (NULL != tcp->memfptr) { + if (0 > fprintf(tcp->outf, "%s", tcp->memfptr)) { + /* ToDo: print suitable error msg */ + } + +#if DEBUG_STAGEOUT + if (debug_flag) { + error_msg("publish_staged_out (after free): for tcp: %p (opened memf: %p, memfptr: %p, size: %zu)", tcp, tcp->memf, tcp->memfptr, tcp->memfloc); + } +#endif + + free(tcp->memfptr); + tcp->memfptr = NULL; + } + + /* reopen tcp->memf for subsequent use */ + strace_openmemstream(tcp); + } +} +#endif /* if HAVE_OPEN_MEMSTREAM */ diff --git a/strace.1 b/strace.1 index 869da08..b900029 100644 --- a/strace.1 +++ b/strace.1 @@ -45,7 +45,7 @@ strace \- trace system calls and signals .SH SYNOPSIS .B strace -[\fB-CdffhikqrtttTvVxxy\fR] +[\fB-CdffhikqrtttTvVxxyzZ\fR] [\fB-I\fIn\fR] [\fB-b\fIexecve\fR] [\fB-e\fIexpr\fR]... @@ -660,6 +660,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 successful syscalls only. +.TP +.BI "\-Z " +Print failed syscalls only. (Although not very useful, -z/-Z options +may be combined) .SS Tracing .TP 12 .BI "\-b " syscall diff --git a/strace.c b/strace.c index 42650ab..32f0399 100644 --- a/strace.c +++ b/strace.c @@ -123,7 +123,11 @@ static int post_attach_sigstop = TCB_IGNORE_ONE_SIGSTOP; #endif /* Sometimes we want to print only succeeding syscalls. */ -bool not_failing_only = 0; +bool not_failing_only = false; +#if HAVE_OPEN_MEMSTREAM +bool failing_only = false; +bool stage_output = false; +#endif /* #if HAVE_OPEN_MEMSTREAM */ /* Show path associated with fd arguments */ unsigned int show_fd_path = 0; @@ -200,10 +204,21 @@ print_version(void) static void usage(void) { - printf("\ + printf( +#if HAVE_OPEN_MEMSTREAM +"\ +usage: strace [-CdffhiqrtttTvVwxxyzZ] [-I n] [-e expr]...\n\ + [-a column] [-o file] [-s strsize] [-P path]...\n\ + -p pid... / [-D] [-E var=val]... [-u username] PROG +[ARGS]\n\ " +#else +"\ usage: strace [-CdffhiqrtttTvVwxxy] [-I n] [-e expr]...\n\ [-a column] [-o file] [-s strsize] [-P path]...\n\ -p pid... / [-D] [-E var=val]... [-u username] PROG [ARGS]\n\ +" +#endif +"\ or: strace -c[dfw] [-I n] [-e expr]... [-O overhead] [-S sortby]\n\ -p pid... / [-D] [-E var=val]... [-u username] PROG [ARGS]\n\ \n\ @@ -240,7 +255,15 @@ Filtering:\n\ -e expr a qualifying expression: option=[!]all or option=[!]val1[,val2]...\n\ options: trace, abbrev, verbose, raw, signal, read, write, fault\n\ -P path trace accesses to path\n\ -\n\ +" +#if HAVE_OPEN_MEMSTREAM +"\ + -z print only succeeding syscalls\n\ + -Z print only failing syscalls\n\ + (although not very useful, both options may be +combined)\n\ " +#endif /* #if HAVE_OPEN_MEMSTREAM */ +"\n\ Tracing:\n\ -b execve detach on execve syscall\n\ -D run tracer process as a detached grandchild, not as parent\n\ @@ -268,9 +291,11 @@ Miscellaneous:\n\ /* ancient, no one should use it -F -- attempt to follow vforks (deprecated, use -f)\n\ */ +#if HAVE_OPEN_MEMSTREAM == 0 /* this is broken, so don't document it -z -- print only succeeding syscalls\n\ */ +#endif /* #if HAVE_OPEN_MEMSTREAM == 0 */ , DEFAULT_ACOLUMN, DEFAULT_STRLEN, DEFAULT_SORTBY); exit(0); } @@ -574,14 +599,40 @@ ATTRIBUTE_FORMAT((printf, 1, 0)) static void tvprintf(const char *const fmt, va_list args) { + int n = 0; + +#if HAVE_OPEN_MEMSTREAM if (current_tcp) { - int n = vfprintf(current_tcp->outf, fmt, args); + if (stage_output) { + if (NULL == current_tcp->memf) { + error_msg("tprintf: No file opened for current_tcp->memf\n"); + return; + } + n = vfprintf(current_tcp->memf, fmt, args); + if (n < 0) { + perror_msg("printing to memf"); + } + } else { + n = vfprintf(current_tcp->outf, fmt, args); + if (n < 0) { + if (current_tcp->outf != stderr) + perror_msg("%s", outfname); + } + } + } + if (n >= 0) { + current_tcp->curcol += n; + } +#else + if (current_tcp) { + n = vfprintf(current_tcp->outf, fmt, args); if (n < 0) { if (current_tcp->outf != stderr) perror_msg("%s", outfname); } else current_tcp->curcol += n; } +#endif /* #if HAVE_OPEN_MEMSTREAM */ } void @@ -601,7 +652,20 @@ void tprints(const char *str) { if (current_tcp) { - int n = fputs_unlocked(str, current_tcp->outf); + int n; +#if HAVE_OPEN_MEMSTREAM + if (stage_output) { + if (NULL == current_tcp->memf) { + error_msg("tprints: No file opened for current_tcp->memf\n"); + return; + } + n = fputs_unlocked(str, current_tcp->memf); + } else { + n = fputs_unlocked(str, current_tcp->outf); + } +#else + n = fputs_unlocked(str, current_tcp->outf); #endif /* #if +HAVE_OPEN_MEMSTREAM */ if (n >= 0) { current_tcp->curcol += strlen(str); return; @@ -728,6 +792,11 @@ newoutf(struct tcb *tcp) sprintf(name, "%.512s.%u", outfname, tcp->pid); tcp->outf = strace_fopen(name); } +#if HAVE_OPEN_MEMSTREAM + if (not_failing_only || failing_only) { + strace_openmemstream(tcp); + } +#endif /* #if HAVE_OPEN_MEMSTREAM */ } static void @@ -1641,7 +1710,11 @@ init(int argc, char *argv[]) #endif qualify("signal=all"); while ((c = getopt(argc, argv, +#if HAVE_OPEN_MEMSTREAM + "+b:cCdfFhiqrtTvVwxyzZ" +#else "+b:cCdfFhiqrtTvVwxyz" +#endif /* HAVE_OPEN_MEMSTREAM */ #ifdef USE_LIBUNWIND "k" #endif @@ -1712,9 +1785,14 @@ init(int argc, char *argv[]) print_version(); exit(0); break; +#if HAVE_OPEN_MEMSTREAM case 'z': not_failing_only = 1; break; + case 'Z': + failing_only = 1; + break; +#endif /* HAVE_OPEN_MEMSTREAM */ case 'a': acolumn = string_to_uint(optarg); if (acolumn < 0) @@ -2161,6 +2239,10 @@ print_signalled(struct tcb *tcp, const int pid, int status) static void print_exited(struct tcb *tcp, const int pid, int status) { +#if HAVE_OPEN_MEMSTREAM + bool saved_stage_output_flag = stage_output; + stage_output = false; +#endif /* #if HAVE_OPEN_MEMSTREAM */ if (pid == strace_child) { exit_code = WEXITSTATUS(status); strace_child = 0; @@ -2172,11 +2254,18 @@ print_exited(struct tcb *tcp, const int pid, int status) tprintf("+++ exited with %d +++\n", WEXITSTATUS(status)); line_ended(); } +#if HAVE_OPEN_MEMSTREAM + stage_output = saved_stage_output_flag; #endif /* #if +HAVE_OPEN_MEMSTREAM */ } static void print_stopped(struct tcb *tcp, const siginfo_t *si, const unsigned int sig) { +#if HAVE_OPEN_MEMSTREAM + bool saved_stage_output_flag = stage_output; + stage_output = false; +#endif /* #if HAVE_OPEN_MEMSTREAM */ if (cflag != CFLAG_ONLY_STATS && !hide_log(tcp) && is_number_in_set(sig, &signal_set)) { @@ -2189,6 +2278,9 @@ print_stopped(struct tcb *tcp, const siginfo_t *si, const unsigned int sig) tprintf("--- stopped by %s ---\n", signame(sig)); line_ended(); } +#if HAVE_OPEN_MEMSTREAM + stage_output = saved_stage_output_flag; #endif /* #if +HAVE_OPEN_MEMSTREAM */ } static void @@ -2519,13 +2611,23 @@ extern void __gcov_flush(); int main(int argc, char *argv[]) { +#if HAVE_OPEN_MEMSTREAM + stage_output = false; +#endif /* #if HAVE_OPEN_MEMSTREAM */ init(argc, argv); exit_code = !nprocs; +#if HAVE_OPEN_MEMSTREAM + stage_output = not_failing_only || failing_only; #endif /* #if +HAVE_OPEN_MEMSTREAM */ while (trace()) ; +#if HAVE_OPEN_MEMSTREAM + /* during cleanup and shutdown don't print to internal memf stream */ + stage_output = false; +#endif /* #if HAVE_OPEN_MEMSTREAM */ cleanup(); fflush(NULL); if (shared_log != stderr) diff --git a/syscall.c b/syscall.c index a34f640..b63f245 100644 --- a/syscall.c +++ b/syscall.c @@ -764,6 +764,7 @@ static int trace_syscall_exiting(struct tcb *tcp) { struct timeval tv; + int res; /* Measure the exit time as early as possible to avoid errors. */ if ((Tflag || cflag) && !(filtered(tcp) || hide_log(tcp))) @@ -783,7 +784,9 @@ trace_syscall_exiting(struct tcb *tcp) #if SUPPORTED_PERSONALITIES > 1 update_personality(tcp, tcp->currpers); #endif - int res = (get_regs_error ? -1 : get_syscall_result(tcp)); + res = (get_regs_error ? -1 : get_syscall_result(tcp)); + if (filtered(tcp) || hide_log(tcp)) + goto ret; if (syserror(tcp) && syscall_tampered(tcp)) tamper_with_syscall_exiting(tcp); @@ -829,6 +832,16 @@ trace_syscall_exiting(struct tcb *tcp) if (tcp->qual_flg & QUAL_RAW) { /* sys_res = printargs(tcp); - but it's nop on sysexit */ } else { +#if HAVE_OPEN_MEMSTREAM + if (stage_output) { + if ( (not_failing_only && syserror(tcp) ) || (failing_only && !syserror(tcp)) ) { + drop_staged_out(tcp); + line_ended(); + goto ret; /* ignore failed/successful syscalls */ + } + } else { + } +#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: @@ -839,6 +852,7 @@ trace_syscall_exiting(struct tcb *tcp) */ if (not_failing_only && tcp->u_error) goto ret; /* ignore failed syscalls */ +#endif /* #if HAVE_OPEN_MEMSTREAM */ if (tcp->sys_func_rval & RVAL_DECODED) sys_res = tcp->sys_func_rval; else @@ -989,6 +1003,11 @@ trace_syscall_exiting(struct tcb *tcp) } tprints("\n"); dumpio(tcp); +#if HAVE_OPEN_MEMSTREAM + if (stage_output) { + publish_staged_out(tcp); + } +#endif /* #if HAVE_OPEN_MEMSTREAM */ line_ended(); #ifdef USE_LIBUNWIND -- 1.9.1 Intel Deutschland GmbH Registered Address: Am Campeon 10-12, 85579 Neubiberg, Germany Tel: +49 89 99 8853-0, www.intel.de Managing Directors: Christin Eisenschmid, Christian Lamprechter Chairperson of the Supervisory Board: Nicole Lau Registered Office: Munich Commercial Register: Amtsgericht Muenchen HRB 186928 ------------------------------------------------------------------------------ Check out the vibrant tech community on one of the world's most engaging tech sites, Slashdot.org! http://sdm.link/slashdot _______________________________________________ Strace-devel mailing list Strace-devel@lists.sourceforge.net https://lists.sourceforge.net/lists/listinfo/strace-devel