]> granicus.if.org Git - strace/commitdiff
Stage output for -z and -Z options
authorPaul Chaignon <paul.chaignon@gmail.com>
Sat, 15 Jun 2019 05:21:44 +0000 (07:21 +0200)
committerDmitry V. Levin <ldv@altlinux.org>
Wed, 10 Jul 2019 16:12:44 +0000 (16:12 +0000)
-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 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 <burkhard.kohl@intel.com>
Signed-off-by: Paul Chaignon <paul.chaignon@gmail.com>
Makefile.am
NEWS
configure.ac
defs.h
stage_output.c [new file with mode: 0644]
strace.1.in
strace.c
syscall.c

index dfd798921cc399e800832f9d871fa4345c2fb13b..0fa7f25d857a5126dec4d9400894d015d1134e4d 100644 (file)
@@ -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 ddca2b2b288f9bebba9b6e59251eb8a57d5458b7..67656ea4d98e82c28934bdfd47f1de8f36e66f3a 100644 (file)
--- 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.
index 399c0e0ac54dbd9d4254a308a1a1f456756df530..a973c2b27f3c2680418873618348f9505e65a741 100644 (file)
@@ -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 ca458d40faf68b2bd19f0e9afd02d202a826b4a3..b9b394ec8a030727e2335b26d58df455a1b2daea 100644 (file)
--- 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 (file)
index 0000000..971714b
--- /dev/null
@@ -0,0 +1,64 @@
+/*
+ * Copyright (c) 2017 Intel Corporation
+ * Copyright (c) 2019 Paul Chaignon <paul.chaignon@gmail.com>
+ * 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
+}
index 76a74119268114b0012328d540cdbbe15eb66d2b..e1090a0f1de3a966924e84ac84055e1cffa68e08 100644 (file)
@@ -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
index 27027a305b362b6911f87eab02f420f9b440a7e7..22f30684adf30fe51da43c7ab00edecb2343a2e6 100644 (file)
--- 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, " <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) */
        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;
index e73e427495057311671c49717a2b429549e52743..65f00d2d7547d47a474c66558c56b4fc7da3da03 100644 (file)
--- 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 <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)))
-                       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();