Re: [PATCH] trace2: intercept all common signals

From: Jeff King <peff@peff.net>
Date: May 10, 2024, 19:41 UTC
Message-ID: <20240510194118.GA1954863@coredump.intra.peff.net>
In-Reply-To: <20240510172243.3529851-1-emilyshaffer@google.com>

On Fri, May 10, 2024 at 10:22:43AM -0700, Emily Shaffer wrote:

Show 15 quoted lines

> From: Emily Shaffer <nasamuffin@google.com>
> 
> We already use trace2 to find out about unexpected pipe breakages, which
> is nice for detecting bugs or system problems, by adding a handler for
> SIGPIPE which simply writes a trace2 line. However, there are a handful
> of other common signals which we might want to snoop on:
> 
>  - SIGINT, SIGTERM, or SIGQUIT, when a user manually cancels a command in
>    frustration or mistake (via Ctrl-C, Ctrl-D, or `kill`)
>  - SIGHUP, when the network closes unexpectedly (indicating there may be
>    a problem to solve)
> 
> There are lots more signals which we might find useful later, but at
> least let's teach trace2 to report these egregious ones. Conveniently,
> they're also already covered by the `_common` variants in sigchain.[ch].

I think this would be a useful thing to have, but having looked at the trace2 signal code, this is almost certain to cause racy deadlocks.

The exact details depend on the specific trace2 target backend, but looking at the various fn_signal() methods, they rely on allocations via strbufs. This is a problem in signal handlers because we can get a signal at any time, including when other code is inside malloc() holding a lock. And then further calls to malloc() will block forever on that lock.

We should be able to do a quick experiment. Try this snippet, which repeatedly kills "git log -p" (which is likely to be allocating memory) and waits for it to exit. Eventually each invocation will stall on a deadlock:

-- >8 --
doit() {
	me=$1
	i=0
	while true; do
		GIT_TRACE2=1 ./git log -p >/dev/null 2>&1 &
		sleep 0.1
		kill $!
		wait $! 2>/dev/null
		i=$((i+1))
		echo $me:$i
	done
}

for i in $(seq 1 64); do
	doit $i &
done
-- >8 --

I didn't have the patience to wait for all of them to stall, but if you let it run for a bit and check "ps", you'll see some git processes which are hanging. Stracing shows them stuck on a lock, like:

  $ strace -p 1838693
  strace: Process 1838693 attached
  futex(0x7facf02df3e0, FUTEX_WAIT_PRIVATE, 2, NULL^Cstrace: Process 1838693 detached
   <detached ...>

This problem existed before your patch. I imagine it was much less likely (or perhaps even impossible) with SIGPIPE though, because we'd see that signal only when in a write() syscall, which implies we're not in malloc(). Whereas we can get SIGTERM, etc, any time.

Obviously the script above is meant to exacerbate the situation, and most runs would be fine. But over the course of normal use across many users and many runs, I think we would see this in practice. I think your test won't because it triggers the signal only from raise().

So I think before doing this, we'd need to clean up the trace2 signal code to avoid any allocations.

-Peff