GC profiling.

* Closes #6968.

* Test case for GC profiling thanks to @jdm!

components/script/script_task.rs

@@ -78,6 +78,7 @@ use string_cache::Atom;
 use util::str::DOMString;
 use util::task::spawn_named_with_send_on_failure;
 use util::task_state;
+use util::opts;
 
 use euclid::Rect;
 use euclid::point::Point2D;
@@ -89,6 +90,7 @@ use js::jsapi::{JS_SetWrapObjectCallbacks, JS_AddExtraGCRootsTracer, DisableIncr
 use js::jsapi::{JSContext, JSRuntime, JSTracer};
 use js::jsapi::{JS_GetRuntime, JS_SetGCCallback, JSGCStatus, JSAutoRequest, SetDOMCallbacks};
 use js::jsapi::{SetDOMProxyInformation, DOMProxyShadowsResult, HandleObject, HandleId, RootedValue};
+use js::jsapi::{JSGCInvocationKind, GCDescription, SetGCSliceCallback, GCProgress};
 use js::jsval::UndefinedValue;
 use js::rust::Runtime;
 use url::{Url, UrlParser};
@@ -98,6 +100,7 @@ use std::any::Any;
 use std::borrow::ToOwned;
 use std::cell::{Cell, RefCell};
 use std::collections::HashSet;
+use std::io::{stdout, Write};
 use std::mem as std_mem;
 use std::option::Option;
 use std::ptr;
@@ -105,7 +108,7 @@ use std::rc::Rc;
 use std::result::Result;
 use std::sync::{Arc, Mutex};
 use std::sync::mpsc::{channel, Sender, Receiver, Select};
-use time::Tm;
+use time::{self, Tm};
 
 use hyper::header::{ContentType, HttpDate};
 use hyper::mime::{Mime, TopLevel, SubLevel};
@@ -462,6 +465,49 @@ impl ScriptTaskFactory for ScriptTask {
     }
 }
 
+thread_local!(static GC_CYCLE_START: Cell<Option<Tm>> = Cell::new(None));
+thread_local!(static GC_SLICE_START: Cell<Option<Tm>> = Cell::new(None));
+
+unsafe extern "C" fn gc_slice_callback(_rt: *mut JSRuntime, progress: GCProgress, desc: *const GCDescription) {
+    match progress {
+        GCProgress::GC_CYCLE_BEGIN => {
+            GC_CYCLE_START.with(|start| {
+                start.set(Some(time::now()));
+                println!("GC cycle began");
+            })
+        },
+        GCProgress::GC_SLICE_BEGIN => {
+            GC_SLICE_START.with(|start| {
+                start.set(Some(time::now()));
+                println!("GC slice began");
+            })
+        },
+        GCProgress::GC_SLICE_END => {
+            GC_SLICE_START.with(|start| {
+                let dur = time::now() - start.get().unwrap();
+                start.set(None);
+                println!("GC slice ended: duration={}", dur);
+            })
+        },
+        GCProgress::GC_CYCLE_END => {
+            GC_CYCLE_START.with(|start| {
+                let dur = time::now() - start.get().unwrap();
+                start.set(None);
+                println!("GC cycle ended: duration={}", dur);
+            })
+        },
+    };
+    if !desc.is_null() {
+        let desc: &GCDescription = &*desc;
+        let invocationKind = match desc.invocationKind_ {
+            JSGCInvocationKind::GC_NORMAL => "GC_NORMAL",
+            JSGCInvocationKind::GC_SHRINK => "GC_SHRINK",
+        };
+        println!("  isCompartment={}, invocationKind={}", desc.isCompartment_, invocationKind);
+    }
+    let _ = stdout().flush();
+}
+
 unsafe extern "C" fn debug_gc_callback(_rt: *mut JSRuntime, status: JSGCStatus, _data: *mut libc::c_void) {
     match status {
         JSGCStatus::JSGC_BEGIN => task_state::enter(task_state::IN_GC),
@@ -575,6 +621,11 @@ impl ScriptTask {
                 JS_SetGCCallback(runtime.rt(), Some(debug_gc_callback), ptr::null_mut());
             }
         }
+        if opts::get().gc_profile {
+            unsafe {
+                SetGCSliceCallback(runtime.rt(), Some(gc_slice_callback));
+            }
+        }
 
         unsafe {
             SetDOMProxyInformation(ptr::null(), 0, Some(shadow_check_callback));

components/util/opts.rs

@@ -72,6 +72,9 @@ pub struct Opts {
     /// See https://github.com/servo/servo/issues/6564
     pub replace_surrogates: bool,
 
+    /// Log GC passes and their durations.
+    pub gc_profile: bool,
+
     pub headless: bool,
     pub hard_fail: bool,
 
@@ -202,6 +205,7 @@ pub fn print_debug_usage(app: &str) -> ! {
     print_option("parallel-display-list-building", "Build display lists in parallel.");
     print_option("replace-surrogates", "Replace unpaires surrogates in DOM strings with U+FFFD. \
                                         See https://github.com/servo/servo/issues/6564");
+    print_option("gc-profile", "Log GC passes and their durations.");
 
     println!("");
 
@@ -239,6 +243,7 @@ pub fn default_opts() -> Opts {
         userscripts: None,
         output_file: None,
         replace_surrogates: false,
+        gc_profile: false,
         headless: true,
         hard_fail: true,
         bubble_inline_sizes_separately: false,
@@ -417,6 +422,7 @@ pub fn from_cmdline_args(args: &[String]) {
         userscripts: opt_match.opt_default("userscripts", ""),
         output_file: opt_match.opt_str("o"),
         replace_surrogates: debug_options.contains(&"replace-surrogates"),
+        gc_profile: debug_options.contains(&"gc-profile"),
         headless: opt_match.opt_present("z"),
         hard_fail: opt_match.opt_present("f"),
         bubble_inline_sizes_separately: bubble_inline_sizes_separately,

tests/html/make-garbage.html

@@ -0,0 +1,21 @@
+<script>
+var i = 0, j;
+function K() {
+    window.gc();
+    window.onload = [];
+    i += 1;
+    for (j = 0; j <= i; ++j) {
+        window.onload[window.onload.length] = {
+            x: window.onload,
+            i: j,
+            toString: function() {
+                return "{x:" + window.onload + ", i: " + j + "}";
+            }
+        };
+    }
+    if (i <= 999999) {
+        setTimeout(K, 0);
+    }
+}
+window.onload = K;
+</script>