[PATCH v1 1/2] Enhance output to match suspend-resume syscalls pairs

[Sahil Siddiq]

Introduce an identifier that is mapped to each suspend-resume
syscall pair in the output. This makes it easy to fetch such
pairs using utilities like grep.

* src/defs.h (struct tcb): Add resume_id field.
* src/strace.c (resume_id): New variable.
  (update_resume_id): New function.
  (printleader): Use new function/field.
  (alloctcb): Likewise.
  (maybe_switch_tcbs): Likewise.
  (print_event_exit): Likewise. Also, add new comment.
* src/syscall.c (print_syscall_resume): Use new field.

Closes: https://github.com/strace/strace/issues/152
Suggested-by: Masatake YAMATO <yamato at redhat.com>
Signed-off-by: Sahil Siddiq <sahilcdq0 at gmail.com>
---
 src/defs.h    |  3 +++
 src/strace.c  | 22 +++++++++++++++++++---
 src/syscall.c |  4 +++-
 3 files changed, 25 insertions(+), 4 deletions(-)

diff --git a/src/defs.h b/src/defs.h
index 9376d8f30..886857f45 100644
--- a/src/defs.h
+++ b/src/defs.h
@@ -271,6 +271,9 @@ struct tcb {
 # if SUPPORTED_PERSONALITIES > 1
 	unsigned int currpers;	/* Personality at the time of scno update */
 # endif
+	unsigned long resume_id;/* Resumption ID used to keep track of interrupted
+				 * and resumed syscalls.
+				 */
 	unsigned long u_error;	/* Error code */
 	kernel_ulong_t scno;	/* System call number */
 	kernel_ulong_t true_scno;	/* Same, but without subcall decoding and shuffling */
diff --git a/src/strace.c b/src/strace.c
index f22b54a7f..df900df7f 100644
--- a/src/strace.c
+++ b/src/strace.c
@@ -168,6 +168,7 @@ static bool open_append;
 
 struct tcb *printing_tcp;
 static struct tcb *current_tcp;
+static unsigned long resume_id;
 
 struct tcb_wait_data {
 	enum trace_event te; /**< Event passed to dispatch_event() */
@@ -826,6 +827,15 @@ line_ended(void)
 	}
 }
 
+static unsigned long
+update_resume_id(struct tcb *tcp)
+{
+	if (!tcp->resume_id)
+		tcp->resume_id = ++resume_id;
+
+	return tcp->resume_id;
+}
+
 static void
 set_current_tcp(const struct tcb *tcp)
 {
@@ -869,7 +879,7 @@ printleader(struct tcb *tcp)
 			 */
 			set_current_tcp(printing_tcp);
 			tprint_space();
-			tprints_string("<unfinished ...>");
+			tprintf_string("<unfinished #%lu ...>", update_resume_id(printing_tcp));
 			tprint_newline();
 			printing_tcp->curcol = 0;
 		}
@@ -1057,6 +1067,7 @@ alloctcb(int pid)
 			memset(tcp, 0, sizeof(*tcp));
 			list_init(&tcp->wait_list);
 			tcp->pid = pid;
+			tcp->resume_id = 0;
 			maybe_load_task_comm(tcp);
 #if SUPPORTED_PERSONALITIES > 1
 			tcp->currpers = current_personality;
@@ -3401,7 +3412,8 @@ maybe_switch_tcbs(struct tcb *tcp, const int pid)
 		 * Another case is demonstrated by
 		 * tests/maybe_switch_current_tcp.c
 		 */
-		fprintf(execve_thread->outf, " <pid changed to %d ...>\n", pid);
+		fprintf(execve_thread->outf, " <pid changed to %d ... (#%lu)>\n",
+			pid, update_resume_id(execve_thread));
 		/*execve_thread->curcol = 0; - no need, see code below */
 	}
 	/* Swap output FILEs and memstream (needed for -ff) */
@@ -3560,7 +3572,7 @@ print_event_exit(struct tcb *tcp)
 	    && printing_tcp->curcol != 0 && !printing_tcp->staged_output_data) {
 		set_current_tcp(printing_tcp);
 		tprint_space();
-		tprints_string("<unfinished ...>");
+		tprintf_string("<unfinished #%lu ...>", update_resume_id(printing_tcp));
 		tprint_newline();
 		flush_tcp_output(printing_tcp);
 		printing_tcp->curcol = 0;
@@ -3575,6 +3587,10 @@ print_event_exit(struct tcb *tcp)
 		 * on exiting syscall which is not going to happen.
 		 */
 		tprint_space();
+		/*
+		 * resume_id does not have to be printed here since this
+		 * syscall does not require resumption.
+		 */
 		tprints_string("<unfinished ...>");
 	}
 
diff --git a/src/syscall.c b/src/syscall.c
index 1f4d86dc1..19a92775e 100644
--- a/src/syscall.c
+++ b/src/syscall.c
@@ -756,7 +756,9 @@ print_syscall_resume(struct tcb *tcp)
 	    || (tcp->flags & TCB_REPRINT)) {
 		tcp->flags &= ~TCB_REPRINT;
 		printleader(tcp);
-		tprintf_string("<... %s resumed>", tcp_sysent(tcp)->sys_name);
+		tprintf_string("<... %s resumed #%lu>", tcp_sysent(tcp)->sys_name, tcp->resume_id);
+		/* Reset resumption ID for this TCB */
+		tcp->resume_id = 0;
 	}
 	printing_tcp = tcp;
 }
-- 
2.52.0