fix interleaved output in the default panic hook when multiple threads panic simultaneously - #127397
Conversation
|
rustbot has assigned @workingjubilee. Use |
rustbot
added
S-waiting-on-review
I suspect this is more due to us having needed to internalize, as much as possible, the horrible details of backtraces. |
|
I also suspect that in practice, backtraces on Windows are actually much more tame now due to us using |
|
Yes and no. Symbolization is still a problem area. The APIs we're using are designed to be run from an external "debugger" process and not in-process. |
|
i did find a mutex in windows that looks like it takes care of the multi-threading issues for us: https://github.com/rust-lang/backtrace-rs/blob/72265bea210891ae47bbe6d4f17b493ef0606619/src/dbghelp.rs#L283-L376 |
|
Yeah, we need a special process-wide mutex so that it works if multiple Rust DLLs are in the same process (doesn't help if another language or library uses these functions though). |
that sounds fine, tbh. "randomly-included C code" can't coordinate perfectly on this, so we can't either, and our responsibility is discharged by doing the best we can. |
5ce6bb0 to
875b730
Compare
|
|
bors
added
S-waiting-on-bors
pgrx has somewhat complex panic handling. it looks something like this: 1. when a thread panics, the panic hook captures a backtrace and saves it in a thread-local for later. 2. the thread unwinds until it hits an FFI boundary (usually `run_guarded`). that downcasts the panic, takes the backtrace out of the thread-local, and hooks into postgres' `longjmp` mechanism 3. i forget what happens after this, i think it resumes unwinding once it's past the FFI barrier there is a slight problem here: we are using a thread-local to store the backtrace. if the panic does not happen on the main thread (for example, because a spawned thread tries to call into postgres and hits the check in `check_active_thread`), the backtrace will be lost. worse, if the main thread then unwinds in response to the panic, pgrx will use *its* backtrace instead of that of the worker thread. there are two main approaches we considered to fixing this: 1. fix the backtrace not to use a thread-local, so we can attach panics in spawned threads to a pgrx connection the way we would for the main thread. 2. stop handling panics in spawned threads altogether (and use the default hook). the downside of approach 1 is that there may not *be* a pgrx connection to attach to. the connection may have already closed, or the active connection may not be related to the thread that panicked, or we may be shutting down and will never check for the panic. in those cases the panic information will be missing or wrong. the downside of approach 2 is that it does not integrate with postgres' error handling mechanism, and in particular is not reported to psql. however, it does allow for developers using pgrx to handle the panic themselves, for example by handling the result from `JoinHandle::join`, in which case it *will* be reported to psql. this takes approach 2. we may want to reconsider this in the future, or perhaps add a helper library so that it's easy for applications to pass the panic into the main thread. --- note that the default panic handler in the standard library behaves quite poorly when multiple threads panic at once (it's sound, but the output is very hard to read). this being fixed in a separate PR upstream; see rust-lang/rust#127397
commented
Jul 9, 2024
bors
added
S-waiting-on-author
commented
Jul 9, 2024
|
lol apparently some test runners set RUST_BACKTRACE=1 on globally? no idea why |
875b730 to
ae92d6a
Compare
commented
Jul 12, 2024
|
Ah, I really should have remembered and asked for @bors r- |
bors
added
S-waiting-on-author
commented
Jul 12, 2024
|
could you mark this as rollup=iffy? |
previously, we only held a lock for printing the backtrace itself. since all threads were printing to the same file descriptor, that meant random output in the default panic hook would be interleaved with the backtrace. now, we hold the lock for the full duration of the hook, and the output is ordered.
3a1dd85 to
1c8f9bb
Compare
commented
Jul 12, 2024
|
yeah. @bors rollup=iffy r+ |
commented
Jul 12, 2024
bors
added
S-waiting-on-bors
commented
Jul 13, 2024
commented
Jul 13, 2024
|
☀️ Test successful - checks-actions |
commented
Jul 13, 2024
|
Finished benchmarking commit (0065384): comparison URL. Overall result: no relevant changes - no action needed@rustbot label: -perf-regression Instruction countThis benchmark run did not return any relevant results for this metric. Max RSS (memory usage)This benchmark run did not return any relevant results for this metric. CyclesThis benchmark run did not return any relevant results for this metric. Binary sizeResults (primary -0.0%, secondary -0.0%)This is a less reliable metric that may be of interest but was not used to determine the overall result at the top of this comment.
Bootstrap: 706.568s -> 706.526s (-0.01%) |
commented
Jul 20, 2024
|
congrats to @rust-lang/wg-compiler-performance, this is a really impressively low amount of noise |
8 participants
previously, we only held a lock for printing the backtrace itself. since all threads were printing to the same file descriptor, that meant random output in the default panic hook from one thread would be interleaved with the backtrace from another. now, we hold the lock for the full duration of the hook, and the output is ordered.
i noticed some odd things while working on this you may or may not already be aware of.
cfg(backtrace_in_std)instead of a more normalcfg(feature = "rustc-dep-of-std"). probably this is left over from before rust used a cargo-based build system?trace_unsynchronized, etc, insys::backtrace::print. as a result, the lock only applies to concurrent panic handlers, not concurrent threads. in other words, if another, non-panicking, thread tried to print a backtrace at the same time as the panic handler, we may have UB, especially on windows.backtrace_in_stdis set so we can reuse their lock instead of trying to add our own.