TSAN: Shutdown race with temporary isolates

[rmacnak-google]

WARNING: ThreadSanitizer: data race (pid=43266)
  Read of size 8 at 0x561f83bf0db8 by thread T821:
    #0 dart::Page::Deallocate() out/ReleaseTSANX64/../../runtime/vm/heap/page.cc:166:20 (dart_precompiled_runtime+0xa4f0a7)
    #1 dart::SemiSpace::~SemiSpace() out/ReleaseTSANX64/../../runtime/vm/heap/scavenger.cc:747:11 (dart_precompiled_runtime+0xa5ef24)
    #2 dart::Scavenger::~Scavenger() out/ReleaseTSANX64/../../runtime/vm/heap/scavenger.cc:827:3 (dart_precompiled_runtime+0xa5ef24)
    #3 dart::Heap::~Heap() out/ReleaseTSANX64/../../runtime/vm/heap/heap.cc:77:1 (dart_precompiled_runtime+0xa3adff)
    #4 std::_LIBCPP_ABI_NAMESPACE::default_delete<dart::Heap>::operator()[abi:v15000](dart::Heap*) const out/ReleaseTSANX64/../../third_party/libcxx/include/__memory/unique_ptr.h:48:5 (dart_precompiled_runtime+0x8b6817)
    #5 std::_LIBCPP_ABI_NAMESPACE::unique_ptr<dart::Heap, std::_LIBCPP_ABI_NAMESPACE::default_delete<dart::Heap>>::reset[abi:v15000](dart::Heap*) out/ReleaseTSANX64/../../third_party/libcxx/include/__memory/unique_ptr.h:305:7 (dart_precompiled_runtime+0x8b6817)
    #6 std::_LIBCPP_ABI_NAMESPACE::unique_ptr<dart::Heap, std::_LIBCPP_ABI_NAMESPACE::default_delete<dart::Heap>>::operator=[abi:v15000](std::nullptr_t) out/ReleaseTSANX64/../../third_party/libcxx/include/__memory/unique_ptr.h:263:5 (dart_precompiled_runtime+0x8b6817)
    #7 dart::IsolateGroup::~IsolateGroup() out/ReleaseTSANX64/../../runtime/vm/isolate.cc:419:9 (dart_precompiled_runtime+0x8b6817)
    #8 dart::IsolateGroup::Shutdown() out/ReleaseTSANX64/../../runtime/vm/isolate.cc:542:3 (dart_precompiled_runtime+0x8b733e)
    #9 dart::Isolate::LowLevelCleanup(dart::Isolate*) out/ReleaseTSANX64/../../runtime/vm/isolate.cc:2665:22 (dart_precompiled_runtime+0x8be650)
    #10 dart::Isolate::Shutdown() out/ReleaseTSANX64/../../runtime/vm/isolate.cc:2603:3 (dart_precompiled_runtime+0x8bff12)
    #11 dart::Dart::ShutdownIsolate(dart::Thread*) out/ReleaseTSANX64/../../runtime/vm/dart.cc:1129:17 (dart_precompiled_runtime+0x897469)
    #12 dart::IsolateGroup::ExitTemporaryIsolate() out/ReleaseTSANX64/../../runtime/vm/isolate.cc:875:3 (dart_precompiled_runtime+0x8b92ef)
    #13 DLRT_ExitTemporaryIsolate out/ReleaseTSANX64/../../runtime/vm/runtime_entry.cc:4486:5 (dart_precompiled_runtime+0x9d8f6f)
    #14 <null> <null> (0x7fe138f91275)

  Previous write of size 8 at 0x561f83bf0db8 by main thread:
    #0 dart::Page::Cleanup() out/ReleaseTSANX64/../../runtime/vm/heap/page.cc:48:20 (dart_precompiled_runtime+0xa4ec98)
    #1 dart::Dart::Cleanup() out/ReleaseTSANX64/../../runtime/vm/dart.cc:764:3 (dart_precompiled_runtime+0x897205)
    #2 Dart_Cleanup out/ReleaseTSANX64/../../runtime/vm/dart_api_impl.cc:1175:10 (dart_precompiled_runtime+0xafb2c3)
    #3 dart::bin::main(int, char**) out/ReleaseTSANX64/../../runtime/bin/main_impl.cc:1449:11 (dart_precompiled_runtime+0x5849d6)
    #4 main out/ReleaseTSANX64/../../runtime/bin/main.cc:9:3 (dart_precompiled_runtime+0x5836d4)

  Location is global 'dart::page_cache_mutex' of size 8 at 0x561f83bf0db8 (dart_precompiled_runtime+0x1b59db8)

  Thread T821 (tid=44095, running) created by thread T9 at:
    #0 pthread_create ../../../../../../llvm-llvm-project/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:1023:3 (dart_precompiled_runtime+0x4f99f1)
    #1 std::_LIBCPP_ABI_NAMESPACE::__libcpp_thread_create[abi:v15000](unsigned long*, void* (*)(void*), void*) out/ReleaseTSANX64/../../third_party/libcxx/include/__threading_support:376:10 (libffi_test_functions.so+0xbe711)
    #2 std::_LIBCPP_ABI_NAMESPACE::thread::thread<void (*&)(long, int), long&, int, void>(void (*&)(long, int), long&, int&&) out/ReleaseTSANX64/../../third_party/libcxx/include/thread:311:16 (libffi_test_functions.so+0xbe711)
    #3 CallFunctionOnNewThreadNonBlocking out/ReleaseTSANX64/../../runtime/bin/ffi_test/ffi_test_functions.cc:1329:15 (libffi_test_functions.so+0xbe7e0)
    #4 new NativeLibrary.#ffiClosure2 file:///b/s/w/ir/tests/ffi/async_void_function_callbacks_test.dart (out.aotsnapshot+0xa7c91) (BuildId: 09f085cde9283c7a9dd1295404b34330d3cff0d1)
    #5 dart::DartEntry::InvokeFunction(dart::Function const&, dart::Array const&) out/ReleaseTSANX64/../../runtime/vm/dart_entry.cc:38:10 (dart_precompiled_runtime+0x89bc61)
    #6 dart::DartLibraryCalls::HandleMessage(long, dart::Instance const&) out/ReleaseTSANX64/../../runtime/vm/dart_entry.cc:718:28 (dart_precompiled_runtime+0x89bc61)
    #7 dart::IsolateMessageHandler::HandleMessage(std::_LIBCPP_ABI_NAMESPACE::unique_ptr<dart::Message, std::_LIBCPP_ABI_NAMESPACE::default_delete<dart::Message>>) out/ReleaseTSANX64/../../runtime/vm/isolate.cc:1456:15 (dart_precompiled_runtime+0x8bc2b1)
    #8 dart::MessageHandler::HandleMessages(dart::MonitorLocker*, bool, bool) out/ReleaseTSANX64/../../runtime/vm/message_handler.cc:229:16 (dart_precompiled_runtime+0x8ce712)
    #9 dart::MessageHandler::TaskCallback() out/ReleaseTSANX64/../../runtime/vm/message_handler.cc:443:18 (dart_precompiled_runtime+0x8cedc1)
    #10 dart::MessageHandlerTask::Run() out/ReleaseTSANX64/../../runtime/vm/message_handler.cc:31:15 (dart_precompiled_runtime+0x8cf493)
    #11 dart::ThreadPool::WorkerLoop(dart::ThreadPool::Worker*) out/ReleaseTSANX64/../../runtime/vm/thread_pool.cc:203:15 (dart_precompiled_runtime+0xa1b3ce)
    #12 dart::ThreadPool::Worker::Main(unsigned long) out/ReleaseTSANX64/../../runtime/vm/thread_pool.cc:363:9 (dart_precompiled_runtime+0xa1b92a)
    #13 dart::ThreadStart(void*) out/ReleaseTSANX64/../../runtime/vm/os_thread_linux.cc:97:5 (dart_precompiled_runtime+0x9ac576)

log

It looks like VM shutdown isn't waiting for temporary isolates or temporary isolate join in the middle of VM shutdown.

[a-siva]

//cc @liamappelbe

[liamappelbe]

Any idea how flaky this is? I'm having trouble reproducing it locally.

[rmacnak-google]

I've only seen this one once.

[a-siva]

I guess the question is should the VM shutdown sequence be made aware of these temporary isolates entering and leaving the VM

[liamappelbe]

As far as I can tell, there's nothing special about the temporary isolates in this regard. They go through the same Isolate::InitIsolate method as ordinary isolates, which calls IsolateGroup::RegisterIsolate, so the isolate is in the group's isolate list.

During shutdown, this list is used in Isolate::KillAllIsolates, though that's probably not relevant since this method sends a kill message, and temporary isolates aren't listening for this message (they're too short lived for that to matter anyway, since all they do at the moment is marshal arguments into a message that is sent to a NativeCallable.listener).

After the kill messages are sent, it waits for isolate shutdown using Dart::WaitForApplicationIsolateShutdown(), which doesn't actually look at the isolates. It actually waits for the isolate groups to shut down, so the temporary isolates aren't treated any differently here.

My current guess is that the temporary isolate was created after these checks (3rd party native code can call the NativeCallable.listener at any time, triggering isolate creation). I'm not checking Isolate::creation_enabled_/Isolate::IsolateCreationEnabled before creating the temporary isolate, but afaict the ordinary isolate creation flow doesn't check this either. This flag only seems to be used to decide whether to notify Isolate::isolate_creation_monitor_ during IsolateGroup::Shutdown.

@rmacnak-google WDYT? Should I check Isolate::IsolateCreationEnabled before creating the temporary isolate?

[rmacnak-google]

Yeah, that's sounds good to me.

[liamappelbe]

Actually, Isolate::creation_enabled_ is already implicitly checked in Isolate::InitIsolate by Isolate::TryMarkIsolateReady. So Isolate::InitIsolate should always return null after shutdown. There's an ASSERT in IsolateGroup::EnterTemporaryIsolate() that checks that the temp isolate is not null. Maybe I just need to upgrade this to a RELEASE_ASSERT?