Display more information on the eBPF timeline

mmtk/Cargo.toml

@@ -12,7 +12,7 @@ edition = "2021"
 # Metadata for the Ruby repository
 [package.metadata.ci-repos.ruby]
 repo = "mmtk/ruby" # This is used by actions/checkout, so the format is "owner/repo", not URL.
-rev = "0511ec851cd290fac520dbe5a862b409488e159e"
+rev = "9036b4e1a403fdcb8e6f171ee3376d7879351e80"
 
 [lib]
 name = "mmtk_ruby"

mmtk/src/abi.rs

@@ -394,17 +394,19 @@ pub struct RubyUpcalls {
     pub move_givtbl: extern "C" fn(old_objref: ObjectReference, new_objref: ObjectReference),
     pub vm_live_bytes: extern "C" fn() -> usize,
     pub update_frozen_strings_table: extern "C" fn(),
-    pub update_finalizer_table: extern "C" fn(),
-    pub update_obj_id_tables: extern "C" fn(),
+    pub update_finalizer_and_obj_id_tables: extern "C" fn(),
     pub update_global_symbols_table: extern "C" fn(),
     pub update_overloaded_cme_table: extern "C" fn(),
     pub update_ci_table: extern "C" fn(),
+    pub get_generic_iv_tbl: extern "C" fn() -> *mut st_table,
     pub get_frozen_strings_table: extern "C" fn() -> *mut st_table,
     pub get_finalizer_table: extern "C" fn() -> *mut st_table,
-    pub get_obj_id_tables: extern "C" fn() -> *mut st_table,
+    pub get_obj_to_id_table: extern "C" fn() -> *mut st_table,
+    pub get_id_to_obj_table: extern "C" fn() -> *mut st_table,
     pub get_global_symbols_table: extern "C" fn() -> *mut st_table,
     pub get_overloaded_cme_table: extern "C" fn() -> *mut st_table,
     pub get_ci_table: extern "C" fn() -> *mut st_table,
+    pub st_get_num_entries: extern "C" fn(table: *const st_table) -> usize,
     pub st_get_size_info: extern "C" fn(
         table: *const st_table,
         entries_start: *mut libc::size_t,
@@ -418,9 +420,9 @@ pub struct RubyUpcalls {
         weak_keys: bool,
         weak_records: bool,
         forward: bool,
-    ),
+    ) -> usize,
     pub st_update_bins_range:
-        extern "C" fn(table: *mut st_table, begin: libc::size_t, end: libc::size_t),
+        extern "C" fn(table: *mut st_table, begin: libc::size_t, end: libc::size_t) -> usize,
 }
 
 unsafe impl Sync for RubyUpcalls {}

mmtk/src/utils.rs

@@ -75,14 +75,17 @@ impl AfterAll {
         self.counter.fetch_add(n, Ordering::SeqCst);
     }
 
-    pub fn count_down(&self, worker: &mut GCWorker<Ruby>) {
+    pub fn count_down(&self, worker: &mut GCWorker<Ruby>) -> bool {
         let old = self.counter.fetch_sub(1, Ordering::SeqCst);
         if old == 1 {
             let packets = {
                 let mut borrow = self.packets.borrow_mut();
                 std::mem::take(borrow.as_mut())
             };
             worker.scheduler().work_buckets[self.stage].bulk_add(packets);
+            return true;
         }
+
+        false
     }
 }

mmtk/src/weak_proc.rs

@@ -67,7 +67,7 @@ impl WeakProcessor {
         worker.scheduler().work_buckets[WorkBucketStage::VMRefClosure].bulk_add(vec![
             Box::new(UpdateGenericIvTbl) as _,
             // Box::new(UpdateFrozenStringsTable) as _,
-            Box::new(UpdateFinalizerAndObjIdTable) as _,
+            Box::new(UpdateFinalizerAndObjIdTables) as _,
             // Box::new(UpdateGlobalSymbolsTable) as _,
             Box::new(UpdateOverloadedCmeTable) as _,
             Box::new(UpdateCiTable) as _,
@@ -97,7 +97,7 @@ impl WeakProcessor {
     }
 
     pub fn process_weak_table_chunked(
-        name: &str,
+        name: &'static str,
         table: *mut st_table,
         weak_keys: bool,
         weak_values: bool,
@@ -108,8 +108,23 @@ impl WeakProcessor {
         let mut entries_bound = 0;
         let mut bins_num = 0;
         (upcalls().st_get_size_info)(table, &mut entries_start, &mut entries_bound, &mut bins_num);
+        let num_entries = (upcalls().st_get_num_entries)(table);
         debug!(
-            "name: {name}, entries_start: {entries_start}, entries_bound: {entries_bound}, bins_num: {bins_num}"
+            "name: {name}, entries_start: {entries_start}, entries_bound: {entries_bound}, bins_num: {bins_num}, num_entries: {num_entries}"
+        );
+
+        let table_name_ptr = name.as_ptr();
+        let table_name_len = name.len();
+
+        probe!(
+            mmtk_ruby,
+            initial_weak_table_stats,
+            entries_start,
+            entries_bound,
+            bins_num,
+            num_entries,
+            table_name_ptr,
+            table_name_len,
         );
 
         let entries_chunk_size = crate::binding().st_entries_chunk_size;
@@ -123,7 +138,7 @@ impl WeakProcessor {
                 let end = (begin + entries_chunk_size).min(entries_bound);
                 let after_all = after_all.clone();
                 Box::new(UpdateTableEntriesParallel {
-                    name: name.to_string(),
+                    name,
                     table,
                     begin,
                     end,
@@ -162,23 +177,35 @@ impl WeakProcessor {
         // `ObjectModel::move`.  However, because `st_table` is not thread-safe, we postpone the
         // update until now in the VMRefClosure stage.
         log::debug!("Updating global ivtbl entries...");
-        {
+        let items_moved = {
             let mut moved_givtbl = crate::binding()
                 .moved_givtbl
                 .try_lock()
                 .expect("Should have no race in weak_proc");
+            let items_moved = moved_givtbl.len();
             for (new_objref, MovedGIVTblEntry { old_objref, .. }) in moved_givtbl.drain() {
                 trace!("  givtbl {} -> {}", old_objref, new_objref);
                 RubyObjectAccess::from_objref(new_objref).clear_has_moved_givtbl();
                 (upcalls().move_givtbl)(old_objref, new_objref);
             }
-        }
-        log::debug!("Updated global ivtbl entries.");
+            items_moved
+        };
+        log::debug!("Updated global ivtbl entries.  {items_moved} items moved.");
 
         // Clean up entries for dead objects.
-        log::debug!("Cleaning up global ivtbl entries...");
+        let generic_iv_tbl = (upcalls().get_generic_iv_tbl)();
+        let old_size = (upcalls().st_get_num_entries)(generic_iv_tbl);
+        log::debug!("Cleaning up global ivtbl entries ({old_size} entries before)...");
         (crate::upcalls().cleanup_generic_iv_tbl)();
-        log::debug!("Cleaning up global ivtbl entries.");
+        let new_size = (upcalls().st_get_num_entries)(generic_iv_tbl);
+        log::debug!("Cleaning up global ivtbl entries ({new_size} entries after).");
+        probe!(
+            mmtk_ruby,
+            update_generic_iv_tbl,
+            items_moved,
+            old_size,
+            new_size
+        );
     }
 }
 
@@ -193,9 +220,8 @@ impl GCWork<Ruby> for ProcessObjFreeCandidates {
             .try_lock()
             .expect("It's GC time.  No mutators should hold this lock at this time.");
 
-        let n_cands = obj_free_candidates.len();
-
-        debug!("Total: {} candidates", n_cands);
+        let old_cands = obj_free_candidates.len();
+        debug!("Total: {} candidates", old_cands);
 
         // Process obj_free
         let mut new_candidates = Vec::new();
@@ -215,7 +241,9 @@ impl GCWork<Ruby> for ProcessObjFreeCandidates {
             }
         }
 
+        let new_cands = new_candidates.len();
         *obj_free_candidates = new_candidates;
+        probe!(mmtk_ruby, process_obj_free_candidates, old_cands, new_cands);
     }
 }
 
@@ -266,29 +294,68 @@ define_global_table_processor!(UpdateGenericIvTbl, {
     WeakProcessor::update_generic_iv_tbl();
 });
 
+fn general_update_weak_table(getter: extern "C" fn() -> *mut st_table, cleaner: extern "C" fn()) {
+    let table = getter();
+    let old_size = (upcalls().st_get_num_entries)(table);
+    cleaner();
+    let new_size = (upcalls().st_get_num_entries)(table);
+    probe!(mmtk_ruby, weak_table_size_change, old_size, new_size);
+}
+
 define_global_table_processor!(UpdateFrozenStringsTable, {
-    (crate::upcalls().update_frozen_strings_table)()
+    general_update_weak_table(
+        upcalls().get_frozen_strings_table,
+        upcalls().update_frozen_strings_table,
+    );
 });
 
-define_global_table_processor!(UpdateFinalizerAndObjIdTable, {
-    // `update_finalizer_table` depends on the `obj_to_id_table`,
-    // therefore must be processed first.
-    (crate::upcalls().update_finalizer_table)();
-    (crate::upcalls().update_obj_id_tables)();
+define_global_table_processor!(UpdateFinalizerAndObjIdTables, {
+    let finalizer_table = (upcalls().get_finalizer_table)();
+    let obj_to_id_table = (upcalls().get_obj_to_id_table)();
+    let id_to_obj_table = (upcalls().get_id_to_obj_table)();
+
+    let old_size_finalizer = (upcalls().st_get_num_entries)(finalizer_table);
+    let old_size_obj_to_id = (upcalls().st_get_num_entries)(obj_to_id_table);
+    let old_size_id_to_obj = (upcalls().st_get_num_entries)(id_to_obj_table);
+
+    (upcalls().update_finalizer_and_obj_id_tables)();
+
+    let new_size_finalizer = (upcalls().st_get_num_entries)(finalizer_table);
+    let new_size_obj_to_id = (upcalls().st_get_num_entries)(obj_to_id_table);
+    let new_size_id_to_obj = (upcalls().st_get_num_entries)(id_to_obj_table);
+
+    probe!(
+        mmtk_ruby,
+        update_finalizer_and_obj_id_tables,
+        old_size_finalizer,
+        new_size_finalizer,
+        old_size_obj_to_id,
+        new_size_obj_to_id,
+        old_size_id_to_obj,
+        new_size_id_to_obj,
+    );
 });
 
 define_global_table_processor!(UpdateGlobalSymbolsTable, {
-    (crate::upcalls().update_global_symbols_table)()
+    general_update_weak_table(
+        upcalls().get_global_symbols_table,
+        upcalls().update_global_symbols_table,
+    );
 });
 
 define_global_table_processor!(UpdateOverloadedCmeTable, {
-    (crate::upcalls().update_overloaded_cme_table)()
+    general_update_weak_table(
+        upcalls().get_overloaded_cme_table,
+        upcalls().update_overloaded_cme_table,
+    );
 });
 
-define_global_table_processor!(UpdateCiTable, (crate::upcalls().update_ci_table)());
+define_global_table_processor!(UpdateCiTable, {
+    general_update_weak_table(upcalls().get_ci_table, upcalls().update_ci_table);
+});
 
 struct UpdateTableEntriesParallel {
-    name: String,
+    name: &'static str,
     table: *mut st_table,
     begin: usize,
     end: usize,
@@ -305,7 +372,7 @@ impl UpdateTableEntriesParallel {}
 impl GCWork<Ruby> for UpdateTableEntriesParallel {
     fn do_work(&mut self, worker: &mut GCWorker<Ruby>, _mmtk: &'static mmtk::MMTK<Ruby>) {
         debug!("Updating entries of {} table", self.name);
-        (upcalls().st_update_entries_range)(
+        let deleted_entries = (upcalls().st_update_entries_range)(
             self.table,
             self.begin,
             self.end,
@@ -314,7 +381,29 @@ impl GCWork<Ruby> for UpdateTableEntriesParallel {
             self.forward,
         );
         debug!("Done updating entries of {} table", self.name);
-        self.after_all.count_down(worker);
+        let table_name = self.name.as_ptr();
+        let table_name_len = self.name.len();
+        probe!(
+            mmtk_ruby,
+            update_table_entries_parallel,
+            self.begin,
+            self.end,
+            deleted_entries,
+            table_name,
+            table_name_len
+        );
+
+        let is_last = self.after_all.count_down(worker);
+        if is_last {
+            let num_entries = (upcalls().st_get_num_entries)(self.table);
+            probe!(
+                mmtk_ruby,
+                final_weak_table_stats,
+                num_entries,
+                table_name,
+                table_name_len
+            )
+        }
     }
 }
 
@@ -332,8 +421,19 @@ impl UpdateTableBinsParallel {}
 impl GCWork<Ruby> for UpdateTableBinsParallel {
     fn do_work(&mut self, _worker: &mut GCWorker<Ruby>, _mmtk: &'static mmtk::MMTK<Ruby>) {
         debug!("Updating bins of {} table", self.name);
-        (upcalls().st_update_bins_range)(self.table, self.begin, self.end);
+        let deleted_bins = (upcalls().st_update_bins_range)(self.table, self.begin, self.end);
         debug!("Done updating bins of {} table", self.name);
+        let table_name = self.name.as_ptr();
+        let table_name_len = self.name.len();
+        probe!(
+            mmtk_ruby,
+            update_table_bins_parallel,
+            self.begin,
+            self.end,
+            deleted_bins,
+            table_name,
+            table_name_len
+        );
     }
 }
 
@@ -346,8 +446,9 @@ impl GCWork<Ruby> for UpdateWbUnprotectedObjectsList {
         );
 
         let old_objects = std::mem::take(&mut *objects);
+        let old_size = old_objects.len();
 
-        debug!("Updating {} WB-unprotected objects", old_objects.len());
+        debug!("Updating {old_size} WB-unprotected objects");
 
         for object in old_objects {
             if object.is_reachable() {
@@ -364,7 +465,15 @@ impl GCWork<Ruby> for UpdateWbUnprotectedObjectsList {
             }
         }
 
-        debug!("Retained {} live WB-unprotected objects.", objects.len());
+        let new_size = objects.len();
+        debug!("Retained {new_size} live WB-unprotected objects.");
+
+        probe!(
+            mmtk_ruby,
+            update_wb_unprotected_objects_list,
+            old_size,
+            new_size
+        );
     }
 }