FW: [PATCH v1] Implement output staging for failed/successful syscalls
Kohl, Burkhard
burkhard.kohl at intel.com
Thu Jun 8 15:42:17 UTC 2017
-----Original Message-----
From: Kohl, Burkhard
Sent: Thursday, June 8, 2017 13:02
To: strace-devel at lists.sourceforge.net
Cc: Kohl, Burkhard <burkhard.kohl at 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
More information about the Strace-devel
mailing list