FreeBSD: ThreadSanitizer: main thread finished with ignores enabled

[etcwilde]

The following snippet fails in TSAN due to the main thread exiting with ignores enabled:

@main
public struct App {
  public static func main() async {
    let t = Task { return 1 }
    _ = await t.value
  }
}

The backtrace at the ThreadIgnoreBegin:

[lldb] % bt
* thread #1, name = 'a.out', stop reason = step over
  * frame #0: 0x0000000000305b33 a.out`__tsan::ThreadIgnoreBegin(thr=0x000000080131c2c0, pc=0) at tsan_rtl.cpp:1045:7
    frame #1: 0x00000000002940af a.out`__tsan::ScopedInterceptor::EnableIgnoresImpl(this=0x00007fffffffcfd8) at tsan_interceptors_posix.cpp:312:3
    frame #2: 0x0000000000293e6a a.out`__tsan::ScopedInterceptor::EnableIgnores(this=0x00007fffffffcfd8) at tsan_interceptors.h:19:7
    frame #3: 0x0000000000293e2e a.out`__tsan::ScopedInterceptor::ScopedInterceptor(this=0x00007fffffffcfd8, thr=0x000000080131c2c0, fname="thr_exit", pc=34374484911) at tsan_interceptors_posix.cpp:295:3
    frame #4: 0x00000000002d8f26 a.out`___interceptor_thr_exit(state=0x0000000801fdb008) at tsan_interceptors_posix.cpp:2813:3
    frame #5: 0x0000000800e103af libthr.so.3`___lldb_unnamed_symbol576 + 319
    frame #6: 0x0000000800e104ab libthr.so.3`___lldb_unnamed_symbol578 + 155
    frame #7: 0x0000000800e82b1e libgcc_s.so.1`___lldb_unnamed_symbol332 + 590
    frame #8: 0x0000000800e82894 libgcc_s.so.1`_Unwind_Resume + 132
    frame #9: 0x00000000003790c6 a.out`main at norace-task-group-cancellation.swift:0
    frame #10: 0x0000000800f14e34 libc.so.7`__libc_start1 + 292
    frame #11: 0x0000000000261354 a.out`_start at crt1_s.S:80

The backtrace at the ThreadFinish where we crash:

[lldb] % bt
* thread #1, name = 'a.out', stop reason = breakpoint 2.1
  * frame #0: 0x0000000000363389 a.out`__tsan::ThreadFinish(thr=0x000000080130f2c0) at tsan_rtl_thread.cpp:215:34
    frame #1: 0x0000000000290af7 a.out`__tsan::DestroyThreadState() at tsan_interceptors_posix.cpp:949:3
    frame #2: 0x00000000002d3322 a.out`___interceptor_thr_exit(state=0x0000000801fd4008) at tsan_interceptors_posix.cpp:2814:3
    frame #3: 0x0000000800ddd3af libthr.so.3`___lldb_unnamed_symbol576 + 319
    frame #4: 0x0000000800ddd4ab libthr.so.3`___lldb_unnamed_symbol578 + 155
    frame #5: 0x0000000800e5eb1e libgcc_s.so.1`___lldb_unnamed_symbol332 + 590
    frame #6: 0x0000000800e5e894 libgcc_s.so.1`_Unwind_Resume + 132
    frame #7: 0x0000000000372856 a.out`main + 150
    frame #8: 0x0000000800ef0e34 libc.so.7`__libc_start1 + 292
    frame #9: 0x000000000025b6f4 a.out`_start at crt1_s.S:80

This appears to be an issue in the scoped interceptor in TSan itself.
Running with debug info enabled, we get the following output:

#0: ThreadIgnoreEnd
#0: intercept thr_exit()
#0: ThreadIgnoreBegin
#0: ThreadFinish
ThreadSanitizer: main thread finished with ignores enabled
  One of the following ignores was not ended (in order of probability)
ewilde@latte ~/Swift-Project %  

The ignore takes place in the thr_exit scoped interceptor, which gets called as our thread is shutting down:

llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp

Lines 2812 to 2816 in 5568a88

	TSAN_INTERCEPTOR(void, thr_exit, tid_t *state) {
	SCOPED_TSAN_INTERCEPTOR(thr_exit, state);
	DestroyThreadState();
	REAL(thr_exit(state));
	}

This expands to a function that constructs an RAII ScopedInterceptor in the function scope, before calling DestroyThreadState, which tears down state, but also verifies that the thread isn’t being ignored. The ScopedInterceptor partially marks the thread as ignored though, so the thread will be ignored when we get to DestroyThreadState().

llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors.h

Lines 73 to 77 in 5568a88

	#define SCOPED_TSAN_INTERCEPTOR(func, ...) \
	SCOPED_INTERCEPTOR_RAW(func, __VA_ARGS__); \
	CHECK_REAL_FUNC(func); \
	if (MustIgnoreInterceptor(thr)) \
	return REAL(func)(__VA_ARGS__);

The scoped interceptor object instance is expanded in the SCOPED_INTERCEPTOR_RAW macro:

https://github.com/swiftlang/llvm-project/blob/5568a88e88c7198310b8cec3ed5fca68e43f5bf2/compiler-rt/lib/tsan/rtl/tsan_interceptors.h#L51C1-L54C43

The scoped interceptor constructor implementation:

llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp

Lines 275 to 296 in 5568a88

	ScopedInterceptor::ScopedInterceptor(ThreadState *thr, const char *fname,
	uptr pc)
	: thr_(thr) {
	LazyInitialize(thr);
	if (UNLIKELY(atomic_load(&thr->in_blocking_func, memory_order_relaxed))) {
	// pthread_join is marked as blocking, but it's also known to call other
	// intercepted functions (mmap, free). If we don't reset in_blocking_func
	// we can get deadlocks and memory corruptions if we deliver a synchronous
	// signal inside of an mmap/free interceptor.
	// So reset it and restore it back in the destructor.
	// See https://github.com/google/sanitizers/issues/1540
	atomic_store(&thr->in_blocking_func, 0, memory_order_relaxed);
	in_blocking_func_ = true;
	}
	if (!thr_->is_inited) return;
	if (!thr_->ignore_interceptors) FuncEntry(thr, pc);
	DPrintf("#%d: intercept %s()\n", thr_->tid, fname);
	ignoring_ =
	!thr_->in_ignored_lib && (flags()->ignore_interceptors_accesses ||
	libignore()->IsIgnored(pc, &in_ignored_lib_));
	EnableIgnores();
	}

This is where we print #0: intercept thr_exit(). Entering EnableIgnores(), ignoring_ evaluates to true and in_ignored_lib_ evaluates to false.
When ignoring_ is true, EnableIgnores() calls EnableIgnoresImpl():

llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors.h

Lines 17 to 20 in 5568a88

	void EnableIgnores() {
	if (UNLIKELY(ignoring_))
	EnableIgnoresImpl();
	}

llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp

Lines 311 to 319 in 5568a88

	void ScopedInterceptor::EnableIgnoresImpl() {
	ThreadIgnoreBegin(thr_, 0);
	if (flags()->ignore_noninstrumented_modules)
	thr_->suppress_reports++;
	if (in_ignored_lib_) {
	DCHECK(!thr_->in_ignored_lib);
	thr_->in_ignored_lib = true;
	}
	}

llvm-project/compiler-rt/lib/tsan/rtl/tsan_rtl.cpp

Lines 1037 to 1046 in 5568a88

	void ThreadIgnoreBegin(ThreadState* thr, uptr pc) {
	DPrintf("#%d: ThreadIgnoreBegin\n", thr->tid);
	thr->ignore_reads_and_writes++;
	CHECK_GT(thr->ignore_reads_and_writes, 0);
	thr->fast_state.SetIgnoreBit();
	#if !SANITIZER_GO
	if (pc && !ctx->after_multithreaded_fork)
	thr->mop_ignore_set.Add(CurrentStackId(thr, pc));
	#endif
	}

Then we return up the stack. thr_->suppress_reports is incremented to 1, in_ignored_lib_ is false so we skip the final if statement in ScopedInterceptor::EnableIgnoresImpl() and return up to the initial scoped interceptor macro. The next call is DestroyThreadState.

https://github.com/swiftlang/llvm-project/blob/5568a88e88c7198310b8cec3ed5fca68e43f5bf2/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp#L946C1-L954C2

ThreadFinish checks that the thread is not being ignored and emits an error if it is:

llvm-project/compiler-rt/lib/tsan/rtl/tsan_rtl_thread.cpp

Lines 74 to 81 in 825563e

	static void ThreadCheckIgnore(ThreadState *thr) {
	if (ctx->after_multithreaded_fork)
	return;
	if (thr->ignore_reads_and_writes)
	ReportIgnoresEnabled(thr->tctx, &thr->mop_ignore_set);
	if (thr->ignore_sync)
	ReportIgnoresEnabled(thr->tctx, &thr->sync_ignore_set);
	}

thr->ignore_reads_and_writes was incremented in ThreadIgnoreBegin, so we jump into ReportIgnoresEnabled and die.

llvm-project/compiler-rt/lib/tsan/rtl/tsan_rtl_thread.cpp

Lines 57 to 72 in 825563e

	static void ReportIgnoresEnabled(ThreadContext *tctx, IgnoreSet *set) {
	if (tctx->tid == kMainTid) {
	Printf("ThreadSanitizer: main thread finished with ignores enabled\n");
	} else {
	Printf("ThreadSanitizer: thread T%d %s finished with ignores enabled,"
	" created at:\n", tctx->tid, tctx->name);
	PrintStack(SymbolizeStackId(tctx->creation_stack_id));
	}
	Printf(" One of the following ignores was not ended"
	" (in order of probability)\n");
	for (uptr i = 0; i < set->Size(); i++) {
	Printf(" Ignore was enabled at:\n");
	PrintStack(SymbolizeStackId(set->At(i)));
	}
	Die();
	}

From the looks of it, the unbalanced ignore is coming from the TSan thread-exit interceptor itself, not from the Swift program.