Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Flaky crashes with "error: pthread error: 22 (Invalid argument)" #34888

Closed
mkustermann opened this issue Oct 22, 2018 · 8 comments

Comments

Projects
None yet
4 participants
@mkustermann
Copy link
Member

commented Oct 22, 2018

From this log:

FAILED: dartk-vm product_x64 co19_2/LibTest/isolate/Isolate/spawnUri_A01_t04
Expected: Pass
Actual: Crash

--- Command "vm" (took 06.000385s):
DART_CONFIGURATION=ProductX64 out/ProductX64/dart --sync-async --ignore-unrecognized-flags --packages=/b/s/w/ir/.packages /b/s/w/ir/tests/co19_2/src/LibTest/isolate/Isolate/spawnUri_A01_t04.dart

exit code:
-6

stdout:
unittest-suite-wait-for-done

stderr:
../../runtime/vm/os_thread_linux.cc: 421: error: pthread error: 22 (Invalid argument)

--- Re-run this test:
python tools/test.py -m product -n dartk-linux-product-x64 co19_2/LibTest/isolate/Isolate/spawnUri_A01_t04
@mkustermann

This comment has been minimized.

Copy link
Member Author

commented Oct 23, 2018

Here's the state of threads

Thread 13 (Thread 0x7f8239dbf700 (LWP 26240)):
#0  __lll_unlock_wake () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:371
#1  0x00007f82490df894 in _L_unlock_722 () from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007f82490df7e4 in __pthread_mutex_unlock_usercnt (decr=1, mutex=0x55a475ed0210) at pthread_mutex_unlock.c:57
#3  __GI___pthread_mutex_unlock (mutex=0x55a475ed0210) at pthread_mutex_unlock.c:310
#4  0x000055a4745de2b8 in ~MutexLocker (this=<optimized out>) at ../../runtime/vm/lockers.h:65
#5  dart::PortMap::PostMessage (message=0x55a475eda940) at ../../runtime/vm/port.cc:253
#6  0x000055a4744bc5e0 in DN_HelperSendPortImpl_sendInternal_ (isolate=<optimized out>, zone=<optimized out>, arguments=<optimized out>, thread=<optimized out>) at
 ../../runtime/lib/isolate.cc:95
#7  dart::BootstrapNatives::DN_SendPortImpl_sendInternal_ (args=0x7f8239dbdd90) at ../../runtime/lib/isolate.cc:86
#8  0x00007f8248280b99 in ?? ()
#9  0x000055a4761aea00 in ?? ()
#10 0x0000000001000002 in ?? ()
#11 0x00007f8239dbdde0 in ?? ()
#12 0x00007f8239dbddd0 in ?? ()
#13 0x00007f8234481bf1 in ?? ()
#14 0x00007f8249583d51 in ?? ()
#15 0x00007f8239dbde08 in ?? ()
#16 0x00007f823942456b in ?? ()
#17 0x00007f8249580041 in ?? ()
#18 0x0000000000000004 in ?? ()
#19 0x00007f82398db4b9 in ?? ()

Thread 12 (Thread 0x7f82438fe700 (LWP 26095)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x000055a4745dcde4 in dart::Monitor::WaitMicros (this=0x55a475ec51a0, micros=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:440
#2  0x000055a47474d03a in Wait (millis=0, this=<optimized out>) at ../../runtime/vm/lockers.h:169
#3  dart::BackgroundCompiler::Run (this=0x55a475ed1b90) at ../../runtime/vm/compiler/jit/compiler.cc:1699
#4  0x000055a47464d74d in dart::ThreadPool::Worker::Loop (this=0x55a475ee2240) at ../../runtime/vm/thread_pool.cc:381
#5  0x000055a47464d601 in dart::ThreadPool::Worker::Main (args=94164841538112) at ../../runtime/vm/thread_pool.cc:436
#6  0x000055a4745dc753 in dart::ThreadStart (data_ptr=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:131
#7  0x00007f82490dc184 in start_thread (arg=0x7f82438fe700) at pthread_create.c:312
#8  0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Thread 11 (Thread 0x7f8242cff700 (LWP 26110)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#1  0x000055a4745dcdcc in dart::Monitor::WaitMicros (this=0x55a475ee22d0, micros=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:445
#2  0x000055a47464d80e in WaitMicros (micros=5000000, this=<optimized out>) at ../../runtime/vm/lockers.h:177
#3  dart::ThreadPool::Worker::Loop (this=0x55a475ee22d0) at ../../runtime/vm/thread_pool.cc:394
#4  0x000055a47464d601 in dart::ThreadPool::Worker::Main (args=94164841538256) at ../../runtime/vm/thread_pool.cc:436
#5  0x000055a4745dc753 in dart::ThreadStart (data_ptr=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:131
#6  0x00007f82490dc184 in start_thread (arg=0x7f8242cff700) at pthread_create.c:312
#7  0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Thread 10 (Thread 0x7f82481ff700 (LWP 26092)):
#0  0x000055a47471f376 in dart::kernel::FunctionNodeHelper::ReadUntilExcluding (this=0x7f82481fbc10, field=<optimized out>) at ../../runtime/vm/compiler/frontend/k
ernel_translation_helper.cc:779
#1  0x000055a47472e455 in dart::kernel::ScopeBuilder::BuildScopes (this=0x7f82481fbcd0) at ../../runtime/vm/compiler/frontend/scope_builder.cc:153
#2  0x000055a4745dd50a in dart::ParsedFunction::EnsureKernelScopes (this=0x7f82481fcc50) at ../../runtime/vm/parser.cc:137
#3  0x000055a474706c77 in dart::kernel::StreamingFlowGraphBuilder::BuildGraph (this=0x7f82481fc0e8) at ../../runtime/vm/compiler/frontend/kernel_binary_flowgraph.c
c:1965
#4  0x000055a474718383 in dart::kernel::FlowGraphBuilder::BuildGraph (this=0x7f82481fc360) at ../../runtime/vm/compiler/frontend/kernel_to_il.cc:738
#5  0x000055a474747f74 in dart::DartCompilationPipeline::BuildFlowGraph (this=<optimized out>, zone=<optimized out>, parsed_function=<optimized out>, ic_data_array
=<optimized out>, osr_id=<optimized out>, optimized=<optimized out>) at ../../runtime/vm/compiler/jit/compiler.cc:153
#6  0x000055a47474a873 in dart::CompileParsedFunctionHelper::Compile (this=0x7f82481fcad8, pipeline=0x7f82481fd550) at ../../runtime/vm/compiler/jit/compiler.cc:77
5
#7  0x000055a47474b87c in dart::CompileFunctionHelper (pipeline=<optimized out>, function=..., optimized=<optimized out>, osr_id=<optimized out>) at ../../runtime/
vm/compiler/jit/compiler.cc:950
#8  0x000055a47474856c in DRT_HelperCompileFunction (thread=<optimized out>, zone=<optimized out>, arguments=..., isolate=<optimized out>) at ../../runtime/vm/comp
iler/jit/compiler.cc:254
#9  dart::DRT_CompileFunction (arguments=...) at ../../runtime/vm/compiler/jit/compiler.cc:230
#10 0x00007f8248280a22 in ?? ()
#11 0x000055a47698e000 in ?? ()
#12 0x0000000000000001 in ?? ()
#13 0x00007f82481fde28 in ?? ()
#14 0x00007f82481fde30 in ?? ()
#15 0x000055a47698e000 in ?? ()

Thread 9 (Thread 0x7f824277f700 (LWP 26120)):
#0  pthread_cond_signal@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_signal.S:91
#1  0x000055a4745dce51 in dart::Monitor::Notify (this=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:464
#2  0x000055a47464d31b in Notify (this=<optimized out>) at ../../runtime/vm/lockers.h:180
#3  SetTask (task=<optimized out>, this=<optimized out>) at ../../runtime/vm/thread_pool.cc:349
#4  dart::ThreadPool::Run (this=0x55a475eec000, task=0x55a475ece480) at ../../runtime/vm/thread_pool.cc:66
#5  0x000055a47455e989 in dart::MessageHandler::PostMessage (this=0x55a475eec4e0, message=<optimized out>, before_events=false) at ../../runtime/vm/message_handler
.cc:165
#6  0x000055a4745de295 in dart::PortMap::PostMessage (message=0x55a475edac80) at ../../runtime/vm/port.cc:251
#7  0x000055a47479e550 in PostCObjectHelper (port_id=<optimized out>, message=<optimized out>) at ../../runtime/vm/native_api_impl.cc:52
#8  Dart_PostCObject (port_id=<optimized out>, message=<optimized out>) at ../../runtime/vm/native_api_impl.cc:56
#9  0x000055a474552fd5 in dart::KernelIsolate::NotifyAboutIsolateShutdown (isolate=0x55a475ef0800) at ../../runtime/vm/kernel_isolate.cc:869
#10 0x000055a47454e3a0 in dart::Isolate::Shutdown (this=0x55a475ef0800) at ../../runtime/vm/isolate.cc:1878
#11 0x000055a47452957d in ShutdownIsolate () at ../../runtime/vm/dart.cc:809
#12 dart::Dart::ShutdownIsolate (isolate=<optimized out>) at ../../runtime/vm/dart.cc:801
#13 0x000055a47454dea3 in dart::ShutdownIsolate (parameter=94164841596928) at ../../runtime/vm/isolate.cc:1672
#14 0x000055a47455ef9d in dart::MessageHandler::TaskCallback (this=0x55a475eed110) at ../../runtime/vm/message_handler.cc:496
#15 0x000055a47464d74d in dart::ThreadPool::Worker::Loop (this=0x55a475ee23f0) at ../../runtime/vm/thread_pool.cc:381
#16 0x000055a47464d601 in dart::ThreadPool::Worker::Main (args=94164841538544) at ../../runtime/vm/thread_pool.cc:436
#17 0x000055a4745dc753 in dart::ThreadStart (data_ptr=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:131
#18 0x00007f82490dc184 in start_thread (arg=0x7f824277f700) at pthread_create.c:312
#19 0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111

Thread 8 (Thread 0x7f824267e700 (LWP 26121)):
#0  __lll_lock_wait () at ../nptl/sysdeps/unix/sysv/linux/x86_64/lowlevellock.S:135
#1  0x00007f82490e63f8 in _L_cond_lock_886 () from /lib/x86_64-linux-gnu/libpthread.so.0
#2  0x00007f82490e6164 in __pthread_mutex_cond_lock (mutex=0x55a475ee2480) at ../nptl/pthread_mutex_lock.c:79
#3  0x00007f82490e0890 in pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:341
#4  0x000055a4745dcdcc in dart::Monitor::WaitMicros (this=0x55a475ee2480, micros=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:445
#5  0x000055a47464d80e in WaitMicros (micros=5000000, this=<optimized out>) at ../../runtime/vm/lockers.h:177
#6  dart::ThreadPool::Worker::Loop (this=0x55a475ee2480) at ../../runtime/vm/thread_pool.cc:394
#7  0x000055a47464d601 in dart::ThreadPool::Worker::Main (args=94164841538688) at ../../runtime/vm/thread_pool.cc:436
#8  0x000055a4745dc753 in dart::ThreadStart (data_ptr=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:131
#9  0x00007f82490dc184 in start_thread (arg=0x7f824267e700) at pthread_create.c:312
#10 0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Thread 7 (Thread 0x7f82360bf700 (LWP 26152)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#1  0x000055a4745dcdcc in dart::Monitor::WaitMicros (this=0x55a475ee2630, micros=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:445
#2  0x000055a47464d80e in WaitMicros (micros=5000000, this=<optimized out>) at ../../runtime/vm/lockers.h:177
#3  dart::ThreadPool::Worker::Loop (this=0x55a475ee2630) at ../../runtime/vm/thread_pool.cc:394
#4  0x000055a47464d601 in dart::ThreadPool::Worker::Main (args=94164841539120) at ../../runtime/vm/thread_pool.cc:436
#5  0x000055a4745dc753 in dart::ThreadStart (data_ptr=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:131
#6  0x00007f82490dc184 in start_thread (arg=0x7f82360bf700) at pthread_create.c:312
#7  0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Thread 6 (Thread 0x7f8241fbf700 (LWP 26126)):
#0  pthread_cond_timedwait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_timedwait.S:238
#1  0x000055a4745dcdcc in dart::Monitor::WaitMicros (this=0x55a475ee21b0, micros=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:445
#2  0x000055a47464d80e in WaitMicros (micros=5000000, this=<optimized out>) at ../../runtime/vm/lockers.h:177
#3  dart::ThreadPool::Worker::Loop (this=0x55a475ee21b0) at ../../runtime/vm/thread_pool.cc:394
#4  0x000055a47464d601 in dart::ThreadPool::Worker::Main (args=94164841537968) at ../../runtime/vm/thread_pool.cc:436
#5  0x000055a4745dc753 in dart::ThreadStart (data_ptr=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:131
#6  0x00007f82490dc184 in start_thread (arg=0x7f8241fbf700) at pthread_create.c:312
#7  0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Thread 5 (Thread 0x7f8242aff700 (LWP 26102)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x000055a4745dcde4 in dart::Monitor::WaitMicros (this=0x55a475ec4900, micros=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:440
#2  0x000055a47474d03a in Wait (millis=0, this=<optimized out>) at ../../runtime/vm/lockers.h:169
#3  dart::BackgroundCompiler::Run (this=0x55a475ed1470) at ../../runtime/vm/compiler/jit/compiler.cc:1699
#4  0x000055a47464d74d in dart::ThreadPool::Worker::Loop (this=0x55a475ee2360) at ../../runtime/vm/thread_pool.cc:381
#5  0x000055a47464d601 in dart::ThreadPool::Worker::Main (args=94164841538400) at ../../runtime/vm/thread_pool.cc:436
#6  0x000055a4745dc753 in dart::ThreadStart (data_ptr=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:131
#7  0x00007f82490dc184 in start_thread (arg=0x7f8242aff700) at pthread_create.c:312
#8  0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Thread 4 (Thread 0x7f82496fb700 (LWP 26091)):
#0  0x00007f82483e16d3 in epoll_wait () at ../sysdeps/unix/syscall-template.S:81
#1  0x000055a47436cd75 in dart::bin::EventHandlerImplementation::Poll (args=94164841504832) at ../../runtime/bin/eventhandler_linux.cc:392
#2  0x000055a47438a17b in dart::bin::ThreadStart (data_ptr=<optimized out>) at ../../runtime/bin/thread_linux.cc:85
#3  0x00007f82490dc184 in start_thread (arg=0x7f82496fb700) at pthread_create.c:312
#4  0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
Thread 3 (Thread 0x7f82496fd800 (LWP 26090)):
#0  pthread_cond_wait@@GLIBC_2.3.2 () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_cond_wait.S:185
#1  0x000055a4745dcde4 in dart::Monitor::WaitMicros (this=0x7ffe5ed6d9f0, micros=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:440
#2  0x000055a474777b7a in Wait (millis=0, this=<optimized out>) at ../../runtime/vm/lockers.h:169
#3  Dart_RunLoop () at ../../runtime/vm/dart_api_impl.cc:1589
#4  0x000055a4743658c7 in dart::bin::RunMainIsolate (script_name=0x7ffe5ed6fbb8 "/b/s/w/ir/tests/co19_2/src/LibTest/isolate/Isolate/spawnUri_A01_t04.dart", dart_op
tions=0x7ffe5ed6db50) at ../../runtime/bin/main.cc:910
#5  0x000055a4743663d4 in dart::bin::main (argc=5, argv=0x7ffe5ed6dcf8) at ../../runtime/bin/main.cc:1145
#6  0x000055a474366ca6 in main (argc=1591138844, argv=0x80) at ../../runtime/bin/main.cc:1183
Thread 2 (Thread 0x7f82480fe700 (LWP 26093)):
#0  dart::ICData::AddReceiverCheck (this=0x7f82480fcac8, receiver_class_id=246, target=..., count=1, exactness=...) at ../../runtime/vm/object.cc:13974
#1  0x000055a474624a36 in dart::InlineCacheMissHandler (args=..., ic_data=...) at ../../runtime/vm/runtime_entry.cc:1240
#2  0x000055a47461b124 in DRT_HelperInlineCacheMissHandlerOneArg (arguments=..., isolate=<optimized out>, thread=<optimized out>, zone=<optimized out>) at ../../ru
ntime/vm/runtime_entry.cc:1286
#3  dart::DRT_InlineCacheMissHandlerOneArg (arguments=...) at ../../runtime/vm/runtime_entry.cc:1280
#4  0x00007f8248280a22 in ?? ()
#5  0x000055a475f94a00 in ?? ()
#6  0x0000000000000002 in ?? ()
#7  0x00007f82480fcf58 in ?? ()
#8  0x00007f82480fcf60 in ?? ()
#9  0x00007f8249582761 in ?? ()
#10 0x00007f8249583ba1 in ?? ()
#11 0x00007f82480fcf88 in ?? ()
#12 0x00007f8248281aaa in ?? ()
#13 0x00007f824668e4a1 in ?? ()
#14 0x00007f8235b60d49 in ?? ()
#15 0x0000000000000000 in ?? ()
Thread 1 (Thread 0x7f82439ff700 (LWP 26094)):
#0  0x00007f8248319c37 in __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:56
#1  0x00007f824831d028 in __GI_abort () at abort.c:89
#2  0x000055a4745dc0e6 in dart::OS::Abort () at ../../runtime/vm/os_linux.cc:663
#3  0x000055a47479f07f in dart::Assert::Fail (this=<optimized out>, format=<optimized out>) at ../../runtime/platform/assert.cc:43
#4  0x000055a4745dcd16 in dart::Monitor::Exit (this=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:421
#5  0x000055a47455f526 in dart::IdleNotifier::Task::Run (this=<optimized out>) at ../../runtime/vm/message_handler.cc:720
#6  0x000055a47464d74d in dart::ThreadPool::Worker::Loop (this=0x55a475ee2120) at ../../runtime/vm/thread_pool.cc:381
#7  0x000055a47464d601 in dart::ThreadPool::Worker::Main (args=94164841537824) at ../../runtime/vm/thread_pool.cc:436
#8  0x000055a4745dc753 in dart::ThreadStart (data_ptr=<optimized out>) at ../../runtime/vm/os_thread_linux.cc:131
#9  0x00007f82490dc184 in start_thread (arg=0x7f82439ff700) at pthread_create.c:312
#10 0x00007f82483e103d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111
@mkustermann

This comment has been minimized.

Copy link
Member Author

commented Oct 23, 2018

It appears to me that the idle notify mechanism is racing with isolate shutdown, namely:

 78 MessageHandler::~MessageHandler() {
 79   IdleNotifier::Remove(this);
 80   delete queue_;
 81   delete oob_queue_;
 82   queue_ = NULL;
 83   oob_queue_ = NULL;
 84   pool_ = NULL;
 85   task_ = NULL;
 86 }
706 class IdleNotifier::Task : public ThreadPool::Task {
707  private:
708   void Run() {
709     MonitorLocker ml(monitor_);
710     while (queue_ != NULL) {
711       Timer* timer = queue_;
712       const int64_t now = OS::GetCurrentMonotonicMicros();
713       if (now >= timer->expirary) {
714         MessageHandler* handler = timer->handler;
715         queue_ = timer->next;
716         delete timer;
717         // A handler may try to update its expirary while we try to start its
718         // task for idle notification.
719         ml.Exit();
720         handler->EnsureTaskForIdleCheck();
721         ml.Enter();
722       } else {
723         ml.WaitMicros(timer->expirary - now);
724       }
725     }
726     task_running_ = false;
727     ml.Notify();
728   }
729 };

When handler->EnsureTaskForIdleCheck() on line 720 is executing, the MessageHandler::~MessageHandler destructor will run and finish, including deleting a mutex while EnsureTaskForIdleCheck accesses the object which is being deleted.

@rmacnak-google Since this is related to the idle notifcation implementation, could you take a look at this?

Instead of making a custom MessageHandler and running it on the thread pool, would it be possible to post a message to the isolate's mailbox, which will then either process it (if it's alive) or drop it (the PortMap::PostMessage() does that if the isolate died).

@mraleph

This comment has been minimized.

Copy link
Contributor

commented Oct 24, 2018

There was an another crash with this on the bots:

FAILED: dartk-vm debug_x64 co19_2/LanguageFeatures/int-to-double/assignment_super_fail_t01/01
Expected: Pass
Actual: Crash
Missing expected compile error.

--- Command "vm" (took 02.000964s):
DART_CONFIGURATION=DebugX64 out/DebugX64/dart --no-background-compilation --sync-async --ignore-unrecognized-flags --packages=/b/s/w/ir/.packages /b/s/w/ir/out/DebugX64/generated_tests/co19_2/LanguageFeatures/int-to-double/assignment_super_fail_t01_01.dart

exit code:
-6

stderr:
out/DebugX64/generated_tests/co19_2/LanguageFeatures/int-to-double/assignment_super_fail_t01_01.dart:24:16: Error: A value of type 'dart.core::int' can't be assigned to a variable of type 'dart.core::double'.
Try changing the type of the left hand side, or casting the right hand side to 'dart.core::double'.
    super.m1 = foo();                  //# 01: compile-time error
               ^
../../runtime/vm/os_thread_linux.cc: 421: error: pthread error: 22 (Invalid argument)
Dumping native stack trace for thread 50d4
  [0x0000558876516d4f] dart::Profiler::DumpStackTrace(void*)
  [0x0000558876516d4f] dart::Profiler::DumpStackTrace(void*)
  [0x00005588767d1cc2] dart::Assert::Fail(char const*, ...)
  [0x00005588765117a1] Unknown symbol
  [0x000055887643c420] dart::MessageHandler::EnsureTaskForIdleCheck()
  [0x000055887643f03f] Unknown symbol
  [0x00005588765db9a1] dart::ThreadPool::Worker::Loop()
  [0x00005588765db47c] dart::ThreadPool::Worker::Main(unsigned long)
  [0x0000558876510ab5] Unknown symbol
-- End of DumpStackTrace

--- Re-run this test:
python tools/test.py -m debug -n dartk-linux-debug-x64 co19_2/LanguageFeatures/int-to-double/assignment_super_fail_t01/01
@a-siva

This comment has been minimized.

Copy link
Contributor

commented Oct 26, 2018

The issue here seems to be the monitor being allocated dynamically here

void IdleNotifier::Init() {
  ASSERT(monitor_ == NULL);
  monitor_ = new Monitor();
}

and being deleted here


void IdleNotifier::Cleanup() {
  ASSERT(queue_ == NULL);
  ASSERT(!task_running_);
  ASSERT(monitor_ != NULL);
  delete monitor_;
  monitor_ = NULL;
}

This pattern has always resulted in flaky crashes in the VM due the order in which things run during cleanup and we made a decision to always create static versions of all monitors in the VM.
We should convert this monitor too.

@a-siva a-siva added the crash label Oct 26, 2018

@mraleph

This comment has been minimized.

Copy link
Contributor

commented Oct 29, 2018

This is also happening on Windows, just with slightly different symptoms. Now that we have windows crashdumps available, we can confirm that flaky crashes we have observed before are exactly the same underlying issue:

00 00000000`0884f118 00007ffa`5c487287 ntdll!NtDelayExecution+0x14
01 00000000`0884f120 00000001`4095f039 KERNELBASE!SleepEx+0xa7
02 00000000`0884f1c0 00000001`4095c1bb dart!crashpad::`anonymous namespace'::UnhandledExceptionHandler+0xc9 [c:\b\s\w\ir\cache\builder\sdk\third_party\crashpad\crashpad\client\crashpad_client_win.cc @ 174] 
03 00000000`0884f400 00000001`40aaabe1 dart!crashpad::`anonymous namespace'::HandleAbortSignal+0x1bb [c:\b\s\w\ir\cache\builder\sdk\third_party\crashpad\crashpad\client\crashpad_client_win.cc @ 201] 
04 00000000`0884fbc0 00000001`40a51d39 dart!raise+0x441 [minkernel\crts\ucrt\src\appcrt\misc\signal.cpp @ 547] 
05 00000000`0884fc80 00000001`40548c90 dart!abort+0x39 [minkernel\crts\ucrt\src\appcrt\startup\abort.cpp @ 71] 
06 00000000`0884fcc0 00000001`409743d9 dart!dart::OS::Abort+0x10 [c:\b\s\w\ir\cache\builder\sdk\runtime\vm\os_win.cc @ 342] 
07 00000000`0884fcf0 00000001`40546c51 dart!dart::Assert::Fail+0x29 [c:\b\s\w\ir\cache\builder\sdk\runtime\platform\assert.cc @ 43] 
08 00000000`0884fd20 00000001`404243a3 dart!dart::Monitor::Enter+0x51 [c:\b\s\w\ir\cache\builder\sdk\runtime\vm\os_thread_win.cc @ 329] 
09 (Inline Function) --------`-------- dart!dart::MonitorLocker::{ctor}+0x3b [c:\b\s\w\ir\cache\builder\sdk\runtime\vm\lockers.h @ 139] 
0a (Inline Function) --------`-------- dart!dart::MessageHandler::EnsureTaskForIdleCheck+0x3f [c:\b\s\w\ir\cache\builder\sdk\runtime\vm\message_handler.cc @ 175] 
0b 00000000`0884fd60 00000001`40665a34 dart!dart::IdleNotifier::Task::Run+0x113 [c:\b\s\w\ir\cache\builder\sdk\runtime\vm\message_handler.cc @ 720] 
0c 00000000`0884fdc0 00000001`40665ec0 dart!dart::ThreadPool::Worker::Loop+0xc4 [c:\b\s\w\ir\cache\builder\sdk\runtime\vm\thread_pool.cc @ 382] 
0d 00000000`0884fe20 00000001`405483e0 dart!dart::ThreadPool::Worker::Main+0x130 [c:\b\s\w\ir\cache\builder\sdk\runtime\vm\thread_pool.cc @ 440] 
0e 00000000`0884fe90 00000001`40a6acc8 dart!dart::ThreadEntry+0xa0 [c:\b\s\w\ir\cache\builder\sdk\runtime\vm\os_thread_win.cc @ 67] 
0f 00000000`0884fed0 00000001`40a6a771 dart!invoke_thread_procedure+0x28 [minkernel\crts\ucrt\src\appcrt\startup\thread.cpp @ 92] 
10 00000000`0884ff10 00007ffa`5d612774 dart!thread_start<unsigned int (__cdecl*)(void * __ptr64)>+0x91 [minkernel\crts\ucrt\src\appcrt\startup\thread.cpp @ 115] 
11 00000000`0884ff60 00007ffa`5fd60d51 KERNEL32!BaseThreadInitThunk+0x14
12 00000000`0884ff90 00000000`00000000 ntdll!RtlUserThreadStart+0x21

@a-siva I think you are looking at the wrong monitor - the one being deleted is MessageHandler and an associated monitor, not the IdleNotifier and its monitor.

There is a subtle lifetime issue - IdleNotifier::Task works with MessageHandler but it does not take proper precautions for the situation when MessageHandler is being destroyed concurrently. Race looks like this:

  • Thread A: IdleNotifier::Task::Run grabs timer from the queue. Extracts handler from it and prepares to fire an event. Then it exits IdleNotifier::monitor_.
  • Thread B: Concurrently MessageHandler::~MessageHandler() is invoked which does IdleNotifier::Remove(this);. Note that IdleNotifier::monitor_ is released and there IdleNotifier::Remove can grab it, do its job and return allowing ~MessageHandler to proceed and destroy MessageHandler. Then Thread A can get priority and try to use a MessageHandler that was just destroyed.

@a-siva a-siva assigned a-siva and unassigned rmacnak-google Oct 29, 2018

dart-bot pushed a commit that referenced this issue Oct 30, 2018

[vm, reload] On the path for no shape changes, defer freeing the old …
…class table until the next safepoint.

Compare the reload rollback path.

Bug: #34888
Change-Id: I5b9e7cd8392f9c9d61df31481956a9fa67435b33
Reviewed-on: https://dart-review.googlesource.com/c/81940
Reviewed-by: Zach Anderson <zra@google.com>
Commit-Queue: Ryan Macnak <rmacnak@google.com>
@a-siva

This comment has been minimized.

Copy link
Contributor

commented Nov 1, 2018

I have turned off IdleNotifier for now as the fix for this race is a bit involved, I am reworking the IdleNotifier code.

@a-siva

This comment has been minimized.

Copy link
Contributor

commented Nov 6, 2018

The CL https://dart-review.googlesource.com/c/sdk/+/81381 should address this issue.

dart-bot pushed a commit that referenced this issue Nov 7, 2018

[vm, reload] On the path for no shape changes, defer freeing the old …
…class table until the next safepoint.

Compare the reload rollback path.

Bug: #34888
Change-Id: I5b9e7cd8392f9c9d61df31481956a9fa67435b33
Reviewed-on: https://dart-review.googlesource.com/c/81940
Reviewed-by: Zach Anderson <zra@google.com>
Commit-Queue: Ryan Macnak <rmacnak@google.com>
@a-siva

This comment has been minimized.

Copy link
Contributor

commented Nov 19, 2018

The idle notifier code has been rewritten and the windows monitor code implementation has been modified. We haven't seen these crashes after these fixes.

@a-siva a-siva closed this Nov 19, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.