Detect overly long GC sync

Summary:
GC sync is the time between a GC being intiated and all the mutator
threads finally stopping so that the GC can start. Problems that cause
the GC sync to be delayed are hard to find and can cause dramatic
slowdowns for heavily parallel programs.

The new flag --long-gc-sync=<time> helps by emitting a warning and
calling a user-overridable hook when the GC sync time exceeds the
specified threshold. A debugger can be used to set a breakpoint when
this happens and inspect the stacks of threads to find the culprit.

Test Plan:
```
$ ./inplace/bin/ghc-stage2 +RTS --long-gc-sync=0.0000001 -S
    Alloc    Copied     Live     GC     GC      TOT      TOT  Page Flts
    bytes     bytes     bytes   user   elap     user     elap
  1135856     51144    153736  0.000  0.000    0.002    0.002    0    0  (Gen:  0)
  1034760     94704    188752  0.000  0.000    0.002    0.002    0    0  (Gen:  0)
  1038888    134832    228888  0.009  0.009    0.011    0.011    0    0  (Gen:  1)
  1025288     90128    235184  0.000  0.000    0.012    0.012    0    0  (Gen:  0)
  1049088    130080    333984  0.000  0.000    0.013    0.013    0    0  (Gen:  0)
Warning: waited 0us for GC sync
  1034424     73360    331976  0.000  0.000    0.013    0.013    0    0  (Gen:  0)
```

Also tested on a real production problem.

Reviewers: niteria, bgamari, erikd

Subscribers: rwbarton, thomie

Differential Revision: https://phabricator.haskell.org/D4193

2 files changed, 43 insertions, 0 deletions

diff --git a/rts/hooks/Hooks.h b/rts/hooks/Hooks.h
index 760e1daefc..24500f19e7 100644
--- a/rts/hooks/Hooks.h
+++ b/rts/hooks/Hooks.h
@@ -22,5 +22,7 @@ extern void StackOverflowHook (W_ stack_size);
 extern void OutOfHeapHook (W_ request_size, W_ heap_size);
 extern void MallocFailHook (W_ request_size /* in bytes */, const char *msg);
 extern void FlagDefaultsHook (void);
+extern void LongGCSync (uint32_t capno, Time t);
+extern void LongGCSyncEnd (Time t);
 
 #include "EndPrivate.h"
diff --git a/rts/hooks/LongGCSync.c b/rts/hooks/LongGCSync.c
new file mode 100644
index 0000000000..351406df98
--- /dev/null
+++ b/rts/hooks/LongGCSync.c
@@ -0,0 +1,41 @@
+/* -----------------------------------------------------------------------------
+ *
+ * User-overridable RTS hooks.
+ *
+ * ---------------------------------------------------------------------------*/
+
+#include "PosixSource.h"
+#include "Rts.h"
+#include "sm/GC.h"
+#include "sm/GCThread.h"
+#include "Hooks.h"
+
+/*
+ * Called when --long-gc-sync=<time> has expired during a GC sync.  The idea is
+ * that you can set a breakpoint on this function in gdb and try to determine
+ * which thread was holding up the GC sync.
+ */
+void LongGCSync (uint32_t me USED_IF_THREADS, Time t STG_UNUSED)
+{
+#if defined(THREADED_RTS)
+    {
+        uint32_t i;
+        for (i=0; i < n_capabilities; i++) {
+            if (i != me && gc_threads[i]->wakeup != GC_THREAD_STANDING_BY) {
+                debugBelch("Warning: slow GC sync: still waiting for cap %d\n",
+                           i);
+            }
+        }
+    }
+#endif
+}
+
+/*
+ * Called at the end of a GC sync which was longer than --long-gc-sync=<time>.
+ * The idea is that you can use this function to log stats about the length of
+ * GC syncs.
+ */
+void LongGCSyncEnd (Time t)
+{
+    debugBelch("Warning: waited %" FMT_Word64 "us for GC sync\n", TimeToUS(t));
+}