Attempted to schedule sentinel work while bucket is not open

[qinsoon]

We observed this assertion failure in both Julia and Ruby.

panicked at 'Attempted to schedule sentinel work while bucket is not open', /home/wks/.cargo/git/checkouts/mmtk-core-3306bdeb8eb4322b/b682c8b/src/scheduler/work_bucket.rs:216:9
Backtrace is disabled.
run with `RUST_BACKTRACE=1` environment variable to display a backtrace

We don't know what caused this, and we do not have a way to reproduce it yet.

[wks]

If I add the following sleep statements and spurious wakeups, it will almost guarantee to trigger the bug.

diff --git a/src/scheduler/controller.rs b/src/scheduler/controller.rs
index c39aea05e..e8a14059b 100644
--- a/src/scheduler/controller.rs
+++ b/src/scheduler/controller.rs
@@ -128,6 +128,8 @@ impl<VM: VMBinding> GCController<VM> {
                 CoordinatorMessage::Finish => {}
             }
         }
+        std::thread::sleep(std::time::Duration::from_millis(10));
+
         self.scheduler.deactivate_all();
 
         // Tell GC trigger that GC ended - this happens before EndOfGC where we resume mutators.
diff --git a/src/scheduler/scheduler.rs b/src/scheduler/scheduler.rs
index b6bbe4588..657efe2db 100644
--- a/src/scheduler/scheduler.rs
+++ b/src/scheduler/scheduler.rs
@@ -443,7 +443,10 @@ impl<VM: VMBinding> GCWorkScheduler<VM> {
                 // coordinator work packets.
             }
             // Wait
-            guard = self.worker_monitor.1.wait(guard).unwrap();
+            guard = {
+                let (new_guard, _timeout_result) = self.worker_monitor.1.wait_timeout(guard, std::time::Duration::from_millis(10)).unwrap();
+                new_guard
+            };
             // The worker is unparked here where `parking_guard` goes out of scope.
         }
 
diff --git a/src/scheduler/work_bucket.rs b/src/scheduler/work_bucket.rs
index 9b3c18dfe..2ff1e7c28 100644
--- a/src/scheduler/work_bucket.rs
+++ b/src/scheduler/work_bucket.rs
@@ -213,6 +213,7 @@ impl<VM: VMBinding> WorkBucket<VM> {
     }
 
     pub fn maybe_schedule_sentinel(&self) -> bool {
+        std::thread::sleep(std::time::Duration::from_millis(10));
         debug_assert!(
             self.is_activated(),
             "Attempted to schedule sentinel work while bucket is not open"

Here is the story:

Step 1: GC actually finished. All buckets are empty, and no buckets have any sentinels. The last worker parked itself, and sent the Finish message to the coordinator.

                    // In `GCWorkScheduler::poll_slow`
                    worker.sender.send(CoordinatorMessage::Finish).unwrap();

Note that this sends the message directly via the sender channel, without incrementing the pending_coordinator_packets counter. This counter remains 0.

Then it released worker_monitor.0 and went to sleep.

Step 2:

Another GC worker spuriously woke up. This is allowed.

            // In `GCWorkScheduler::poll_slow`
            guard = self.worker_monitor.1.wait(guard).unwrap();

It is now the only worker woken (others are sleeping because there is no packets available). It continued executing from the beginning of 'polling_loop: loop {. It found no schedulable work, parked itself again, found no designated work, and checked the pending_coordinator_packets counter again. It is still zero. Then it tries to schedule sentinels:

                    // In `GCWorkScheduler::poll_slow`
                    if self.schedule_sentinels() {

And schedule_sentinels() checks whether a work bucket is active before trying to schedule sentinels from it.

            // In `GCWorkScheduler::schedule_sentinels`
            if work_bucket.is_activated() && work_bucket.maybe_schedule_sentinel() {

But the operating system paused this thread right after work_bucket.is_activated() returned true, but before work_bucket.maybe_schedule_sentinel() was called.

Step 3: The coordinator thread woke up. It received the Finish message, did some cleanup, and deactivated all buckets.

        // GCController::In do_gc_until_completion
        self.scheduler.deactivate_all();

Step 4: The OS scheduled the paused GC worker again. This time, it saw the work bucket closed.

[qinsoon]

Can we move the assertion to the if-let branch?

mmtk-core/src/scheduler/work_bucket.rs

Lines 224 to 234 in 106fc71

	if let Some(work) = maybe_sentinel {
	// We cannot call `self.add` now, because:
	// 1. The current function is called only when all workers parked, and we are holding
	// the monitor lock. `self.add` also needs that lock to notify other workers.
	// Trying to lock it again will result in deadlock.
	// 2. After this function returns, the current worker will check if there is pending
	// work immediately, and notify other workers.
	// So we can just "sneak" the sentinel work packet into the current bucket now.
	self.queue.push(work);
	true
	} else {

We only assert if the bucket is open when we actually find a sentinel packet and attempt to push to the queue.

[wks]

Can we move the assertion to the if-let branch?

mmtk-core/src/scheduler/work_bucket.rs

Lines 224 to 234 in 106fc71

	if let Some(work) = maybe_sentinel {
	// We cannot call `self.add` now, because:
	// 1. The current function is called only when all workers parked, and we are holding
	// the monitor lock. `self.add` also needs that lock to notify other workers.
	// Trying to lock it again will result in deadlock.
	// 2. After this function returns, the current worker will check if there is pending
	// work immediately, and notify other workers.
	// So we can just "sneak" the sentinel work packet into the current bucket now.
	self.queue.push(work);
	true
	} else {

We only assert if the bucket is open when we actually find a sentinel packet and attempt to push to the queue.

I prefer not. The assertion at its current location actually detected a race.

I think it is better to make it atomic (w.r.t. GC workers) for the coordinator thread to receive the Finish message and close all buckets.