Re: [PATCH] exec: Fix a deadlock in ptrace

[Bernd Edlinger <bernd.edlinger@hotmail.de>]

[-- Attachment #1: Type: text/plain, Size: 4335 bytes --]

Hi Aleksa,

On 3/1/20 4:13 PM, Aleksa Sarai wrote:
> On 2020-03-01, Bernd Edlinger <bernd.edlinger@hotmail.de> wrote:
>> This fixes a deadlock in the tracer when tracing a multi-threaded
>> application that calls execve while more than one thread are running.
>>
>> I observed that when running strace on the gcc test suite, it always
>> blocks after a while, when expect calls execve, because other threads
>> have to be terminated.  They send ptrace events, but the strace is no
>> longer able to respond, since it is blocked in vm_access.
>>
>> The deadlock is always happening when strace needs to access the
>> tracees process mmap, while another thread in the tracee starts to
>> execve a child process, but that cannot continue until the
>> PTRACE_EVENT_EXIT is handled and the WIFEXITED event is received:
>>
>> strace          D    0 30614  30584 0x00000000
>> Call Trace:
>> __schedule+0x3ce/0x6e0
>> schedule+0x5c/0xd0
>> schedule_preempt_disabled+0x15/0x20
>> __mutex_lock.isra.13+0x1ec/0x520
>> __mutex_lock_killable_slowpath+0x13/0x20
>> mutex_lock_killable+0x28/0x30
>> mm_access+0x27/0xa0
>> process_vm_rw_core.isra.3+0xff/0x550
>> process_vm_rw+0xdd/0xf0
>> __x64_sys_process_vm_readv+0x31/0x40
>> do_syscall_64+0x64/0x220
>> entry_SYSCALL_64_after_hwframe+0x44/0xa9
>>
>> expect          D    0 31933  30876 0x80004003
>> Call Trace:
>> __schedule+0x3ce/0x6e0
>> schedule+0x5c/0xd0
>> flush_old_exec+0xc4/0x770
>> load_elf_binary+0x35a/0x16c0
>> search_binary_handler+0x97/0x1d0
>> __do_execve_file.isra.40+0x5d4/0x8a0
>> __x64_sys_execve+0x49/0x60
>> do_syscall_64+0x64/0x220
>> entry_SYSCALL_64_after_hwframe+0x44/0xa9
>>
>> The proposed solution is to have a second mutex that is
>> used in mm_access, so it is allowed to continue while the
>> dying threads are not yet terminated.
>>
>> I also took the opportunity to improve the documentation
>> of prepare_creds, which is obviously out of sync.
>>
>> Signed-off-by: Bernd Edlinger <bernd.edlinger@hotmail.de>
> 
> I can't comment on the validity of the patch, but I also found and
> reported this issue in 2016[1] and the discussion quickly veered into
> the problem being more complicated (and uglier) than it seems at first
> glance.
> 
> You should probably also Cc stable, given this has been a long-standing
> issue and your patch doesn't look (too) invasive.
> 

I am fully aware that this patch won't fix the case then PTRACE_ACCESS is racing
with de_thread.  But I don't see a problem with allowing vm access based on the
current credentials as they are still the same until de_thread is done with it's
job.  And in a practical way this fixes 99% of the real problem here, as it only
happens since strace is currently tracing something and needs access to the parameters
in the tracee's vm space.
Of course you could fork the strace process to do any PTRACE_ACCESS when necessary,
and, well, maybe that would fix the remaining problem here...

However before I considered changing the kernel for this I tried to fix this
within strace.  First I tried to wait in the signal handler.  See attached
strace-patch-1.diff, but that did not work, BUT I think it is possible that your
patch you proposed previously would actually make it work.

I tried then another approach, using a worker thread to wait for the childs,
but it did only work when I remove PTRACE_O_TRACEEXIT from the ptrace options,
because the ptrace(PTRACE_SYSCALL, pid, 0L, 0L) does not work in the worker thread,
rv = -1, errno = 3 there, and unfortunately the main thread is blocked and unable
to do the ptrace call, that makes the thread continue.
So I consider that second patch really ugly, and wouldn't propose something like
that seriously.


@@ -69,7 +71,7 @@
 cflag_t cflag = CFLAG_NONE;
 unsigned int followfork;
 unsigned int ptrace_setoptions = PTRACE_O_TRACESYSGOOD | PTRACE_O_TRACEEXEC
-                                | PTRACE_O_TRACEEXIT;
+                                ;//| PTRACE_O_TRACEEXIT;
 unsigned int xflag;
 bool debug_flag;
 bool Tflag;

so it only works because of this line, without that it is not able to make the
thread continue after the PTRACE_EVENT_EXIT. 


Thanks
Bernd.

> [1]: https://lore.kernel.org/lkml/20160921152946.GA24210@dhcp22.suse.cz/
> 

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: strace-patch-1.diff --]
[-- Type: text/x-patch; name="strace-patch-1.diff", Size: 7652 bytes --]

diff -ur strace-5.5/delay.h strace-5.5.x/delay.h
--- strace-5.5/delay.h	2019-08-06 15:38:20.000000000 +0200
+++ strace-5.5.x/delay.h	2020-02-29 12:39:51.563110827 +0100
@@ -14,5 +14,6 @@
 void delay_timer_expired(void);
 void arm_delay_timer(const struct tcb *);
 void delay_tcb(struct tcb *, uint16_t delay_idx, bool isenter);
+int my_waitpid(int, int*, int);
 
 #endif /* !STRACE_DELAY_H */
diff -ur strace-5.5/filter_seccomp.c strace-5.5.x/filter_seccomp.c
--- strace-5.5/filter_seccomp.c	2020-02-06 16:16:17.000000000 +0100
+++ strace-5.5.x/filter_seccomp.c	2020-02-29 12:42:43.184120263 +0100
@@ -19,6 +19,7 @@
 #include "number_set.h"
 #include "syscall.h"
 #include "scno.h"
+#include "delay.h"
 
 bool seccomp_filtering;
 bool seccomp_before_sysentry;
@@ -136,7 +137,7 @@
 		int status;
 
 		for (;;) {
-			long rc = waitpid(pid, &status, 0);
+			long rc = my_waitpid(pid, &status, 0);
 			if (rc < 0 && errno == EINTR)
 				continue;
 			if (rc == pid)
@@ -272,7 +273,7 @@
 	if (pid) {
 		kill(pid, SIGKILL);
 		for (;;) {
-			long rc = waitpid(pid, NULL, 0);
+			long rc = my_waitpid(pid, NULL, 0);
 			if (rc < 0 && errno == EINTR)
 				continue;
 			break;
diff -ur strace-5.5/Makefile.am strace-5.5.x/Makefile.am
--- strace-5.5/Makefile.am	2020-02-06 16:16:17.000000000 +0100
+++ strace-5.5.x/Makefile.am	2020-02-29 10:28:04.515676065 +0100
@@ -45,7 +45,7 @@
 strace_CPPFLAGS = $(AM_CPPFLAGS)
 strace_CFLAGS = $(AM_CFLAGS)
 strace_LDFLAGS =
-strace_LDADD = libstrace.a $(clock_LIBS) $(timer_LIBS)
+strace_LDADD = libstrace.a -lpthread $(clock_LIBS) $(timer_LIBS)
 noinst_LIBRARIES = libstrace.a
 
 libstrace_a_CPPFLAGS = $(strace_CPPFLAGS)
diff -ur strace-5.5/Makefile.in strace-5.5.x/Makefile.in
--- strace-5.5/Makefile.in	2020-02-06 17:23:35.000000000 +0100
+++ strace-5.5.x/Makefile.in	2020-02-29 10:28:28.833677402 +0100
@@ -1631,7 +1631,7 @@
 	$(am__append_11) $(CODE_COVERAGE_CPPFLAGS)
 strace_CFLAGS = $(AM_CFLAGS) $(am__append_4) $(CODE_COVERAGE_CFLAGS)
 strace_LDFLAGS = $(am__append_5) $(am__append_9) $(am__append_12)
-strace_LDADD = libstrace.a $(clock_LIBS) $(timer_LIBS) $(am__append_6) \
+strace_LDADD = libstrace.a -lpthread $(clock_LIBS) $(timer_LIBS) $(am__append_6) \
 	$(am__append_10) $(am__append_13) $(CODE_COVERAGE_LIBS) \
 	$(am__append_14) $(am__append_18)
 noinst_LIBRARIES = libstrace.a $(am__append_15) $(am__append_19)
diff -ur strace-5.5/ptrace_syscall_info.c strace-5.5.x/ptrace_syscall_info.c
--- strace-5.5/ptrace_syscall_info.c	2020-02-06 16:16:17.000000000 +0100
+++ strace-5.5.x/ptrace_syscall_info.c	2020-02-29 12:41:44.565117040 +0100
@@ -12,6 +12,7 @@
 #include "ptrace.h"
 #include "ptrace_syscall_info.h"
 #include "scno.h"
+#include "delay.h"
 
 #include <signal.h>
 #include <sys/wait.h>
@@ -118,7 +119,7 @@
 		};
 		const size_t size = sizeof(info);
 		int status;
-		long rc = waitpid(pid, &status, 0);
+		long rc = my_waitpid(pid, &status, 0);
 		if (rc != pid) {
 			/* cannot happen */
 			kill_tracee(pid);
@@ -247,7 +248,7 @@
 done:
 	if (pid) {
 		kill_tracee(pid);
-		waitpid(pid, NULL, 0);
+		my_waitpid(pid, NULL, 0);
 		ptrace_stop = -1U;
 	}
 
diff -ur strace-5.5/strace.c strace-5.5.x/strace.c
--- strace-5.5/strace.c	2020-02-06 16:16:17.000000000 +0100
+++ strace-5.5.x/strace.c	2020-03-01 07:53:27.028407698 +0100
@@ -15,6 +15,7 @@
 #include <fcntl.h>
 #include "ptrace.h"
 #include <signal.h>
+#include <semaphore.h>
 #include <sys/resource.h>
 #include <sys/stat.h>
 #ifdef HAVE_PATHS_H
@@ -1002,7 +1003,7 @@
 	 */
 	for (;;) {
 		unsigned int sig;
-		if (waitpid(tcp->pid, &status, __WALL) < 0) {
+		if (my_waitpid(tcp->pid, &status, __WALL) < 0) {
 			if (errno == EINTR)
 				continue;
 			/*
@@ -1615,7 +1616,7 @@
 		int status, tracee_pid;
 
 		errno = 0;
-		tracee_pid = waitpid(pid, &status, 0);
+		tracee_pid = my_waitpid(pid, &status, 0);
 		if (tracee_pid <= 0) {
 			if (errno == EINTR)
 				continue;
@@ -1663,6 +1664,69 @@
 	sigaction(signo, &sa, oldact);
 }
 
+#define MAX_WAITIDX 65536
+static unsigned short in_idx = 0, out_idx = 0;
+static sem_t wait_sem;
+static int wait_pid[MAX_WAITIDX];
+static int wait_status[MAX_WAITIDX];
+static struct rusage wait_rusage[MAX_WAITIDX];
+
+static void
+child_sighandler(int sig)
+{
+	int old_errno = errno;
+	int status;
+	struct rusage ru;
+	int pid = wait4(-1, &status, __WALL | WNOHANG, (cflag ? &ru : NULL));
+
+	if (pid > 0) {
+		if (WIFSTOPPED(status) && (status >> 16) == PTRACE_EVENT_EXIT)
+			ptrace(PTRACE_SYSCALL, pid, 0L, 0L);
+		wait_pid[in_idx] = pid;
+		wait_status[in_idx] = status;
+		if (cflag)
+			wait_rusage[in_idx] = ru;
+		in_idx++;
+		if (in_idx == out_idx || sem_post(&wait_sem) == -1)
+		{
+			const char *msg = "fatal error in child_sighandler\n"; 
+			status = write(STDERR_FILENO, msg, strlen(msg));
+			_exit(2);
+		}
+	}
+
+	errno = old_errno; 
+}
+
+int my_waitpid(int pid, int *status, int options)
+{
+	int skip = 0;
+	unsigned short idx = out_idx;
+	for (;;) {
+		while (sem_wait(&wait_sem) == -1 && errno == EINTR)
+			;
+		if (wait_pid[idx] == pid)
+			break;
+		idx++;
+		skip++;
+	}
+	*status = wait_status[idx];
+	while (skip > 0) {
+		unsigned short idx1 = idx;
+		idx1--;
+		wait_status[idx] = wait_status[idx1];
+		wait_pid[idx] = wait_pid[idx1];
+		if (cflag)
+			wait_rusage[idx] = wait_rusage[idx1];
+		if (sem_post(&wait_sem) == -1)
+			error_msg_and_die("fatal error in my_waitpid"); 
+		skip--;
+		idx--;
+	}
+	out_idx++;
+	return pid;
+}
+
 /*
  * Initialization part of main() was eating much stack (~0.5k),
  * which was unused after init.
@@ -2015,7 +2079,9 @@
 	memset(acolumn_spaces, ' ', acolumn);
 	acolumn_spaces[acolumn] = '\0';
 
-	set_sighandler(SIGCHLD, SIG_DFL, &params_for_tracee.child_sa);
+	if (sem_init(&wait_sem, 0, 0) == -1)
+		perror_msg_and_die("Unable to initialize signal wait sema");
+	set_sighandler(SIGCHLD, child_sighandler, &params_for_tracee.child_sa);
 
 #ifdef ENABLE_STACKTRACE
 	if (stack_trace_enabled)
@@ -2607,10 +2673,28 @@
 	 * then the system call will be interrupted and
 	 * the expiration will be handled by the signal handler.
 	 */
-	int status;
+	int status = 0;
 	struct rusage ru;
-	int pid = wait4(-1, &status, __WALL, (cflag ? &ru : NULL));
-	int wait_errno = errno;
+	int pid = 0;
+	int wait_errno = 0;
+	if (in_idx == out_idx) {
+		pid = wait4(-1, &status, __WALL | WNOHANG, (cflag ? &ru : NULL));
+		wait_errno = errno;
+		if (pid > 0 && WIFSTOPPED(status) && (status >> 16) == PTRACE_EVENT_EXIT)
+			ptrace(PTRACE_SYSCALL, pid, 0L, 0L);
+	}
+	if (pid == 0) {
+		while (sem_wait(&wait_sem) == -1 && errno == EINTR)
+			;
+
+		if (in_idx == out_idx)
+			error_msg_and_die("wait queue error");
+		pid = wait_pid[out_idx];
+		status = wait_status[out_idx];
+		if (cflag)
+			ru = wait_rusage[out_idx];
+		out_idx++;
+	}
 
 	/*
 	 * The window of opportunity to handle expirations
@@ -2791,8 +2875,17 @@
 			break;
 
 next_event_wait_next:
-		pid = wait4(-1, &status, __WALL | WNOHANG, (cflag ? &ru : NULL));
-		wait_errno = errno;
+		pid = 0;
+		if (in_idx != out_idx) {
+			while (sem_wait(&wait_sem) == -1 && errno == EINTR)
+				;
+
+			pid = wait_pid[out_idx];
+			status = wait_status[out_idx];
+			if (cflag)
+				ru = wait_rusage[out_idx];
+			out_idx++;
+		}
 		wait_nohang = true;
 	}
 
@@ -3019,7 +3112,7 @@
 
 	case TE_STOP_BEFORE_EXIT:
 		print_event_exit(current_tcp);
-		break;
+		return true;
 	}
 
 	/* We handled quick cases, we are permitted to interrupt now. */
@@ -3138,7 +3231,7 @@
 	if (shared_log != stderr)
 		fclose(shared_log);
 	if (popen_pid) {
-		while (waitpid(popen_pid, NULL, 0) < 0 && errno == EINTR)
+		while (my_waitpid(popen_pid, NULL, 0) < 0 && errno == EINTR)
 			;
 	}
 	if (sig) {

[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #3: strace-patch-2.diff --]
[-- Type: text/x-patch; name="strace-patch-2.diff", Size: 7878 bytes --]

diff -ur strace-5.5/delay.h strace-5.5.y/delay.h
--- strace-5.5/delay.h	2019-08-06 15:38:20.000000000 +0200
+++ strace-5.5.y/delay.h	2020-02-29 12:39:51.563110827 +0100
@@ -14,5 +14,6 @@
 void delay_timer_expired(void);
 void arm_delay_timer(const struct tcb *);
 void delay_tcb(struct tcb *, uint16_t delay_idx, bool isenter);
+int my_waitpid(int, int*, int);
 
 #endif /* !STRACE_DELAY_H */
diff -ur strace-5.5/filter_seccomp.c strace-5.5.y/filter_seccomp.c
--- strace-5.5/filter_seccomp.c	2020-02-06 16:16:17.000000000 +0100
+++ strace-5.5.y/filter_seccomp.c	2020-02-29 12:42:43.184120263 +0100
@@ -19,6 +19,7 @@
 #include "number_set.h"
 #include "syscall.h"
 #include "scno.h"
+#include "delay.h"
 
 bool seccomp_filtering;
 bool seccomp_before_sysentry;
@@ -136,7 +137,7 @@
 		int status;
 
 		for (;;) {
-			long rc = waitpid(pid, &status, 0);
+			long rc = my_waitpid(pid, &status, 0);
 			if (rc < 0 && errno == EINTR)
 				continue;
 			if (rc == pid)
@@ -272,7 +273,7 @@
 	if (pid) {
 		kill(pid, SIGKILL);
 		for (;;) {
-			long rc = waitpid(pid, NULL, 0);
+			long rc = my_waitpid(pid, NULL, 0);
 			if (rc < 0 && errno == EINTR)
 				continue;
 			break;
diff -ur strace-5.5/Makefile.am strace-5.5.y/Makefile.am
--- strace-5.5/Makefile.am	2020-02-06 16:16:17.000000000 +0100
+++ strace-5.5.y/Makefile.am	2020-02-29 10:28:04.515676065 +0100
@@ -45,7 +45,7 @@
 strace_CPPFLAGS = $(AM_CPPFLAGS)
 strace_CFLAGS = $(AM_CFLAGS)
 strace_LDFLAGS =
-strace_LDADD = libstrace.a $(clock_LIBS) $(timer_LIBS)
+strace_LDADD = libstrace.a -lpthread $(clock_LIBS) $(timer_LIBS)
 noinst_LIBRARIES = libstrace.a
 
 libstrace_a_CPPFLAGS = $(strace_CPPFLAGS)
diff -ur strace-5.5/Makefile.in strace-5.5.y/Makefile.in
--- strace-5.5/Makefile.in	2020-02-06 17:23:35.000000000 +0100
+++ strace-5.5.y/Makefile.in	2020-02-29 10:28:28.833677402 +0100
@@ -1631,7 +1631,7 @@
 	$(am__append_11) $(CODE_COVERAGE_CPPFLAGS)
 strace_CFLAGS = $(AM_CFLAGS) $(am__append_4) $(CODE_COVERAGE_CFLAGS)
 strace_LDFLAGS = $(am__append_5) $(am__append_9) $(am__append_12)
-strace_LDADD = libstrace.a $(clock_LIBS) $(timer_LIBS) $(am__append_6) \
+strace_LDADD = libstrace.a -lpthread $(clock_LIBS) $(timer_LIBS) $(am__append_6) \
 	$(am__append_10) $(am__append_13) $(CODE_COVERAGE_LIBS) \
 	$(am__append_14) $(am__append_18)
 noinst_LIBRARIES = libstrace.a $(am__append_15) $(am__append_19)
diff -ur strace-5.5/strace.c strace-5.5.y/strace.c
--- strace-5.5/strace.c	2020-02-06 16:16:17.000000000 +0100
+++ strace-5.5.y/strace.c	2020-03-01 07:59:55.586429063 +0100
@@ -15,6 +15,8 @@
 #include <fcntl.h>
 #include "ptrace.h"
 #include <signal.h>
+#include <semaphore.h>
+#include <pthread.h>
 #include <sys/resource.h>
 #include <sys/stat.h>
 #ifdef HAVE_PATHS_H
@@ -69,7 +71,7 @@
 cflag_t cflag = CFLAG_NONE;
 unsigned int followfork;
 unsigned int ptrace_setoptions = PTRACE_O_TRACESYSGOOD | PTRACE_O_TRACEEXEC
-				 | PTRACE_O_TRACEEXIT;
+				 ;//| PTRACE_O_TRACEEXIT;
 unsigned int xflag;
 bool debug_flag;
 bool Tflag;
@@ -1002,7 +1004,7 @@
 	 */
 	for (;;) {
 		unsigned int sig;
-		if (waitpid(tcp->pid, &status, __WALL) < 0) {
+		if (my_waitpid(tcp->pid, &status, __WALL) < 0) {
 			if (errno == EINTR)
 				continue;
 			/*
@@ -1663,6 +1665,83 @@
 	sigaction(signo, &sa, oldact);
 }
 
+#define MAX_WAITIDX 65536
+static unsigned short in_idx = 0, out_idx = 0;
+static sem_t wait_sem;
+static pthread_t wait_thread;
+static int wait_pid[MAX_WAITIDX];
+static int wait_status[MAX_WAITIDX];
+static struct rusage wait_rusage[MAX_WAITIDX];
+
+static void*
+child_sighandler(void *arg)
+{
+	int status;
+	struct rusage ru;
+	int pid;
+	for (;;) {
+		pid = wait4(-1, &status, __WALL, (cflag ? &ru : NULL));
+		if (pid < 0 && errno == EINTR)
+			continue;
+
+		if (pid < 0)
+			pid = -errno;
+
+		if (pid > 0 && WIFSTOPPED(status) && (status >> 16) == PTRACE_EVENT_EXIT) {
+			int i = ptrace(PTRACE_SYSCALL, pid, 0L, 0L);
+			fprintf(stderr, "in thread: ptrace(PTRACE_SYSCALL, %d, 0L, 0L)=%d errno=%d\n", pid, i, errno);
+		}
+		wait_pid[in_idx] = pid;
+		wait_status[in_idx] = status;
+		if (cflag)
+			wait_rusage[in_idx] = ru;
+		in_idx++;
+		if (in_idx == out_idx || sem_post(&wait_sem) == -1)
+			error_msg_and_die("fatal error in child_sighandler"); 
+		if (pid < 0)
+			break;
+	}
+
+	return NULL;
+}
+
+int my_waitpid(int pid, int *status, int options)
+{
+	int skip = 0;
+	unsigned short idx = out_idx;
+	for (;;) {
+		while (sem_wait(&wait_sem) == -1 && errno == EINTR)
+			;
+		if (wait_pid[idx] < 0) {
+			while (skip-- >= 0)
+				sem_post(&wait_sem);
+			errno = -wait_pid[idx];
+			return -1;
+		}
+		if (wait_pid[idx] == pid)
+			break;
+		idx++;
+		skip++;
+	}
+	*status = wait_status[idx];
+	while (skip > 0) {
+		unsigned short idx1 = idx;
+		idx1--;
+		wait_status[idx] = wait_status[idx1];
+		wait_pid[idx] = wait_pid[idx1];
+		if (cflag)
+			wait_rusage[idx] = wait_rusage[idx1];
+		if (sem_post(&wait_sem) == -1)
+			error_msg_and_die("fatal error in my_waitpid"); 
+		skip--;
+		idx--;
+	}
+	out_idx++;
+	if (pid < 0)
+		errno = -pid;
+	return pid < 0 ? -1 : pid;
+}
+
 /*
  * Initialization part of main() was eating much stack (~0.5k),
  * which was unused after init.
@@ -2124,6 +2203,9 @@
 		startup_child(argv);
 	}
 
+	if (sem_init(&wait_sem, 0, 0) == -1)
+		perror_msg_and_die("Unable to initialize signal wait sema");
+
 	set_sighandler(SIGTTOU, SIG_IGN, NULL);
 	set_sighandler(SIGTTIN, SIG_IGN, NULL);
 	if (opt_intr != INTR_ANYWHERE) {
@@ -2150,6 +2232,7 @@
 	if (nprocs != 0 || daemonized_tracer)
 		startup_attach();
 
+	pthread_create(&wait_thread, NULL, child_sighandler, NULL);
 	/* Do we want pids printed in our -o OUTFILE?
 	 * -ff: no (every pid has its own file); or
 	 * -f: yes (there can be more pids in the future); or
@@ -2607,10 +2690,28 @@
 	 * then the system call will be interrupted and
 	 * the expiration will be handled by the signal handler.
 	 */
-	int status;
+	int status = 0;
 	struct rusage ru;
-	int pid = wait4(-1, &status, __WALL, (cflag ? &ru : NULL));
-	int wait_errno = errno;
+	int pid = 0;
+	int wait_errno = 0;
+	while (sem_wait(&wait_sem) == -1 && errno == EINTR)
+		;
+
+	if (in_idx == out_idx)
+		error_msg_and_die("wait queue error");
+	pid = wait_pid[out_idx];
+	status = wait_status[out_idx];
+	ru = wait_rusage[out_idx];
+	if (pid > 0 && WIFSTOPPED(status) && (status >> 16) == PTRACE_EVENT_EXIT) {
+		int i = ptrace(PTRACE_SYSCALL, pid, 0L, 0L);
+		fprintf(stderr, "ptrace(PTRACE_SYSCALL, %d, 0L, 0L)=%d errno=%d\n", pid, i, errno);
+	}
+	out_idx++;
+	if (pid < 0) {
+		wait_errno = -pid;
+		out_idx--;
+		sem_post(&wait_sem);
+	}
 
 	/*
 	 * The window of opportunity to handle expirations
@@ -2791,8 +2892,25 @@
 			break;
 
 next_event_wait_next:
-		pid = wait4(-1, &status, __WALL | WNOHANG, (cflag ? &ru : NULL));
-		wait_errno = errno;
+		pid = 0;
+		if (in_idx != out_idx) {
+			while (sem_wait(&wait_sem) == -1 && errno == EINTR)
+				;
+
+			pid = wait_pid[out_idx];
+			status = wait_status[out_idx];
+			ru = wait_rusage[out_idx];
+			if (pid > 0 && WIFSTOPPED(status) && (status >> 16) == PTRACE_EVENT_EXIT) {
+				int i = ptrace(PTRACE_SYSCALL, pid, 0L, 0L);
+				fprintf(stderr, "ptrace(PTRACE_SYSCALL, %d, 0L, 0L)=%d errno=%d\n", pid, i, errno);
+			}
+			out_idx++;
+			if (pid < 0) {
+				wait_errno = -pid;
+				out_idx--;
+				sem_post(&wait_sem);
+			}
+		}
 		wait_nohang = true;
 	}
 
@@ -3019,7 +3137,8 @@
 
 	case TE_STOP_BEFORE_EXIT:
 		print_event_exit(current_tcp);
-		break;
+		//droptcb(current_tcp);
+		return true;
 	}
 
 	/* We handled quick cases, we are permitted to interrupt now. */
@@ -3138,9 +3257,10 @@
 	if (shared_log != stderr)
 		fclose(shared_log);
 	if (popen_pid) {
-		while (waitpid(popen_pid, NULL, 0) < 0 && errno == EINTR)
+		while (my_waitpid(popen_pid, NULL, 0) < 0 && errno == EINTR)
 			;
 	}
+	pthread_join(wait_thread, NULL);
 	if (sig) {
 		exit_code = 0x100 | sig;
 	}