[PATCH v2] Implement output staging for failed/successful syscalls

Kohl, Burkhard burkhard.kohl at intel.com
Tue Mar 7 12:34:00 UTC 2017


Hello All,

I had submitted below patch back 18th of  January (https://sourceforge.net/p/strace/mailman/message/35611809/). Don't see that it was merged nor did I receive any feedback so far.
Was my submission just missed - or is the implemented feature (-z/-Z: filter for successful/failed syscalls) considered not useful for the project?

Regards,
Burkhard 

-----Original Message-----
From: Kohl, Burkhard 
Sent: Wednesday, January 18, 2017 18:13
To: strace-devel at lists.sourceforge.net
Cc: Kohl, Burkhard <burkhard.kohl at intel.com>
Subject: [PATCH v2] Implement output staging for failed/successful syscalls

  With not_failing_only/failing_only flags, 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 option -Z +help
              modified tprintf, tprints
              set stage_output 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       |  18 +++++++++
 stage_out.c  | 120 +++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
 strace.1     |   6 +++
 strace.c     | 107 +++++++++++++++++++++++++++++++++++++++++++++++++---
 syscall.c    |  18 +++++++++
 7 files changed, 266 insertions(+), 5 deletions(-)  create mode 100644 stage_out.c

diff --git a/Makefile.am b/Makefile.am
index afc3dd2..4550ff2 100644
--- a/Makefile.am
+++ b/Makefile.am
@@ -226,6 +226,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 793d74e..5a4212a 100644
--- a/configure.ac
+++ b/configure.ac
@@ -285,6 +285,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 09c0a5f..7494e54 100644
--- a/defs.h
+++ b/defs.h
@@ -2,6 +2,7 @@
  * Copyright (c) 1991, 1992 Paul Kranenburg <pk at cs.few.eur.nl>
  * Copyright (c) 1993 Branko Lankester <branko at hacktic.nl>
  * Copyright (c) 1993, 1994, 1995, 1996 Rick Sladkey <jrs at world.std.com>
+ * Copyright (C) 2016-2017 Intel Deutschland GmbH
  * All rights reserved.
  *
  * Redistribution and use in source and binary forms, with or without @@ -219,6 +220,12 @@ 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 */ @@ -363,6 +370,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; @@ -736,6 +747,13 @@ extern void tabto(void);  extern void tprintf(const char *fmt, ...) ATTRIBUTE_FORMAT((printf, 1, 2));  extern void tprints(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..88af3b8
--- /dev/null
+++ b/stage_out.c
@@ -0,0 +1,120 @@
+/*
+ * 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_flag) {
+            ; /* error_msg("stage_openmemstream for tcp: %p (opened memf: %p, memfptr: %p, size: %zu)", tcp, tcp->memf, tcp->memfptr, tcp->memfloc); */
+        }
+	}
+
+	return fp;
+}
+
+void
+drop_staged_out(struct tcb *tcp)
+{
+	if (NULL != tcp->memf) {
+		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); */
+        }
+
+		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_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); */
+        }
+
+		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_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); */
+            }
+
+			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 0356c2d..08739c0 100644
--- a/strace.1
+++ b/strace.1
@@ -581,6 +581,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
+.B \-Z
+Print failed syscalls only.
 .SS Tracing
 .TP 12
 .TP
diff --git a/strace.c b/strace.c
index da6b165..78fcffe 100644
--- a/strace.c
+++ b/strace.c
@@ -3,6 +3,7 @@
  * Copyright (c) 1993 Branko Lankester <branko at hacktic.nl>
  * Copyright (c) 1993, 1994, 1995, 1996 Rick Sladkey <jrs at world.std.com>
  * Copyright (c) 1996-1999 Wichert Akkerman <wichert at cistron.nl>
+ * Copyright (C) 2016-2017 Intel Deutschland GmbH
  * All rights reserved.
  *
  * Redistribution and use in source and binary forms, with or without @@ -121,8 +122,12 @@ static int post_attach_sigstop = TCB_IGNORE_ONE_SIGSTOP;  # define use_seize 0  #endif
 
-/* Sometimes we want to print only succeeding syscalls. */ -bool not_failing_only = 0;
+/* Sometimes we want to print succeeding/failing syscalls only. */ 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; @@ -239,7 +244,13 @@ 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\
+"
+#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\
@@ -267,9 +278,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 */
 , DEFAULT_ACOLUMN, DEFAULT_STRLEN, DEFAULT_SORTBY);
 	exit(0);
 }
@@ -573,16 +586,43 @@ void
 tprintf(const char *fmt, ...)
 {
 	va_list args;
+	int n = 0;
 
 	va_start(args, fmt);
+#if HAVE_OPEN_MEMSTREAM
+	if (current_tcp) {
+		if (stage_output) {
+			if (NULL == current_tcp->memf) {
+				error_msg("tprintf: No file opened for current_tcp->memf\n");
+				goto ret;
+			}
+			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;
+	}
+ret:
+#else
 	if (current_tcp) {
-		int n = vfprintf(current_tcp->outf, fmt, args);
+		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 */
 	va_end(args);
 }
 
@@ -594,7 +634,21 @@ 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;
@@ -700,6 +754,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
@@ -1606,7 +1665,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
@@ -1680,6 +1743,11 @@ init(int argc, char *argv[])
 		case 'z':
 			not_failing_only = 1;
 			break;
+#if HAVE_OPEN_MEMSTREAM
+		case 'Z':
+			failing_only = 1;
+			break;
+#endif /* HAVE_OPEN_MEMSTREAM */
 		case 'a':
 			acolumn = string_to_uint(optarg);
 			if (acolumn < 0)
@@ -2132,6 +2200,11 @@ 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;
@@ -2143,11 +2216,19 @@ 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)) { @@ -2160,6 +2241,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
@@ -2488,13 +2572,26 @@ restart_tracee:
 int
 main(int argc, char *argv[])
 {
+#if HAVE_OPEN_MEMSTREAM
+
+	/* during init don't print to internal memf stream */
+	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 9de3056..a9be536 100644
--- a/syscall.c
+++ b/syscall.c
@@ -6,6 +6,7 @@
  * Copyright (c) 1999 IBM Deutschland Entwicklung GmbH, IBM Corporation
  *                     Linux for s390 port by D.J. Barrow
  *                    <barrow_dj at mail.yahoo.com,djbarrow at de.ibm.com>
+ * Copyright (C) 2016-2017 Intel Deutschland GmbH
  * All rights reserved.
  *
  * Redistribution and use in source and binary forms, with or without @@ -796,6 +797,17 @@ 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 {
+			/* publish staged output later */
+		}
+#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:
@@ -806,6 +818,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
@@ -952,6 +965,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