src: add tracing.v8.on('gc') statistics hooks
authorBen Noordhuis <info@bnoordhuis.nl>
Mon, 28 Oct 2013 13:57:47 +0000 (14:57 +0100)
committerTimothy J Fontaine <tjfontaine@gmail.com>
Wed, 5 Feb 2014 19:49:01 +0000 (11:49 -0800)
Add a new 'tracing' module with a v8 property that lets the user
register listeners for gc events.  The listeners are invoked after
every garbage collection cycle with 'before' and 'after' statistics.
Useful for monitoring tools that want to keep track of memory usage.

lib/repl.js
lib/tracing.js [new file with mode: 0644]
node.gyp
src/env-inl.h
src/env.h
src/node_v8.cc [new file with mode: 0644]
test/simple/test-v8-gc.js [new file with mode: 0644]

index 8a23955..fe1f98c 100644 (file)
@@ -73,7 +73,8 @@ exports.writer = util.inspect;
 exports._builtinLibs = ['assert', 'buffer', 'child_process', 'cluster',
   'crypto', 'dgram', 'dns', 'domain', 'events', 'fs', 'http', 'https', 'net',
   'os', 'path', 'punycode', 'querystring', 'readline', 'stream',
-  'string_decoder', 'tls', 'tty', 'url', 'util', 'vm', 'zlib', 'smalloc'];
+  'string_decoder', 'tls', 'tty', 'url', 'util', 'vm', 'zlib', 'smalloc',
+  'tracing'];
 
 
 function REPLServer(prompt, stream, eval_, useGlobal, ignoreUndefined) {
diff --git a/lib/tracing.js b/lib/tracing.js
new file mode 100644 (file)
index 0000000..62a5609
--- /dev/null
@@ -0,0 +1,44 @@
+// Copyright Joyent, Inc. and other Node contributors.
+//
+// Permission is hereby granted, free of charge, to any person obtaining a
+// copy of this software and associated documentation files (the
+// "Software"), to deal in the Software without restriction, including
+// without limitation the rights to use, copy, modify, merge, publish,
+// distribute, sublicense, and/or sell copies of the Software, and to permit
+// persons to whom the Software is furnished to do so, subject to the
+// following conditions:
+//
+// The above copyright notice and this permission notice shall be included
+// in all copies or substantial portions of the Software.
+//
+// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS
+// OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
+// MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN
+// NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM,
+// DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
+// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE
+// USE OR OTHER DEALINGS IN THE SOFTWARE.
+
+var EventEmitter = require('events');
+var binding = process.binding('v8');
+
+var v8 = exports.v8 = new EventEmitter();
+
+
+function emitGC(before, after) {
+  v8.emit('gc', before, after);
+}
+
+
+v8.on('newListener', function(name) {
+  if (name === 'gc' && EventEmitter.listenerCount(this, name) === 0) {
+    binding.startGarbageCollectionTracking(emitGC);
+  }
+});
+
+
+v8.on('removeListener', function(name) {
+  if (name === 'gc' && EventEmitter.listenerCount(this, name) === 0) {
+    binding.stopGarbageCollectionTracking();
+  }
+});
index d4cd40e..fa9b44a 100644 (file)
--- a/node.gyp
+++ b/node.gyp
@@ -56,6 +56,7 @@
       'lib/string_decoder.js',
       'lib/sys.js',
       'lib/timers.js',
+      'lib/tracing.js',
       'lib/tls.js',
       'lib/_tls_legacy.js',
       'lib/_tls_wrap.js',
@@ -96,6 +97,7 @@
         'src/node_javascript.cc',
         'src/node_main.cc',
         'src/node_os.cc',
+        'src/node_v8.cc',
         'src/node_stat_watcher.cc',
         'src/node_watchdog.cc',
         'src/node_zlib.cc',
index ef6b3be..63f5a94 100644 (file)
 
 namespace node {
 
+inline Environment::GCInfo::GCInfo()
+    : type_(static_cast<v8::GCType>(0)),
+      flags_(static_cast<v8::GCCallbackFlags>(0)),
+      timestamp_(0) {
+}
+
+inline Environment::GCInfo::GCInfo(v8::Isolate* isolate,
+                                   v8::GCType type,
+                                   v8::GCCallbackFlags flags,
+                                   uint64_t timestamp)
+    : type_(type),
+      flags_(flags),
+      timestamp_(timestamp) {
+  isolate->GetHeapStatistics(&stats_);
+}
+
+inline v8::GCType Environment::GCInfo::type() const {
+  return type_;
+}
+
+inline v8::GCCallbackFlags Environment::GCInfo::flags() const {
+  return flags_;
+}
+
+inline v8::HeapStatistics* Environment::GCInfo::stats() const {
+  // TODO(bnoordhuis) Const-ify once https://codereview.chromium.org/63693005
+  // lands and makes it way into a stable release.
+  return const_cast<v8::HeapStatistics*>(&stats_);
+}
+
+inline uint64_t Environment::GCInfo::timestamp() const {
+  return timestamp_;
+}
+
+inline Environment::IsolateData* Environment::IsolateData::Get(
+    v8::Isolate* isolate) {
+  return static_cast<IsolateData*>(isolate->GetData());
+}
+
 inline Environment::IsolateData* Environment::IsolateData::GetOrCreate(
     v8::Isolate* isolate) {
-  IsolateData* isolate_data = static_cast<IsolateData*>(isolate->GetData());
+  IsolateData* isolate_data = Get(isolate);
   if (isolate_data == NULL) {
     isolate_data = new IsolateData(isolate);
     isolate->SetData(isolate_data);
@@ -59,6 +98,7 @@ inline Environment::IsolateData::IsolateData(v8::Isolate* isolate)
     PER_ISOLATE_STRING_PROPERTIES(V)
 #undef V
     ref_count_(0) {
+  QUEUE_INIT(&gc_tracker_queue_);
 }
 
 inline uv_loop_t* Environment::IsolateData::event_loop() const {
@@ -187,6 +227,7 @@ inline Environment::Environment(v8::Local<v8::Context> context)
   set_binding_cache_object(v8::Object::New());
   set_module_load_list_array(v8::Array::New());
   RB_INIT(&cares_task_list_);
+  QUEUE_INIT(&gc_tracker_queue_);
 }
 
 inline Environment::~Environment() {
index 68528d0..a5f0967 100644 (file)
--- a/src/env.h
+++ b/src/env.h
@@ -27,6 +27,7 @@
 #include "util.h"
 #include "uv.h"
 #include "v8.h"
+#include "queue.h"
 
 #include <stdint.h>
 
@@ -52,9 +53,9 @@ namespace node {
 // for the sake of convenience.
 #define PER_ISOLATE_STRING_PROPERTIES(V)                                      \
   V(address_string, "address")                                                \
-  V(atime_string, "atime")                                                    \
-  V(async, "async")                                                           \
   V(async_queue_string, "_asyncQueue")                                        \
+  V(async, "async")                                                           \
+  V(atime_string, "atime")                                                    \
   V(birthtime_string, "birthtime")                                            \
   V(blksize_string, "blksize")                                                \
   V(blocks_string, "blocks")                                                  \
@@ -78,9 +79,11 @@ namespace node {
   V(family_string, "family")                                                  \
   V(fatal_exception_string, "_fatalException")                                \
   V(fingerprint_string, "fingerprint")                                        \
+  V(flags_string, "flags")                                                    \
   V(gid_string, "gid")                                                        \
   V(handle_string, "handle")                                                  \
   V(headers_string, "headers")                                                \
+  V(heap_size_limit_string, "heap_size_limit")                                \
   V(heap_total_string, "heapTotal")                                           \
   V(heap_used_string, "heapUsed")                                             \
   V(immediate_callback_string, "_immediateCallback")                          \
@@ -88,6 +91,7 @@ namespace node {
   V(ipv4_string, "IPv4")                                                      \
   V(ipv6_string, "IPv6")                                                      \
   V(issuer_string, "issuer")                                                  \
+  V(mark_sweep_compact_string, "mark-sweep-compact")                          \
   V(method_string, "method")                                                  \
   V(mode_string, "mode")                                                      \
   V(modulus_string, "modulus")                                                \
@@ -114,6 +118,7 @@ namespace node {
   V(rdev_string, "rdev")                                                      \
   V(rename_string, "rename")                                                  \
   V(rss_string, "rss")                                                        \
+  V(scavenge_string, "scavenge")                                              \
   V(serial_number_string, "serialNumber")                                     \
   V(servername_string, "servername")                                          \
   V(session_id_string, "sessionId")                                           \
@@ -127,10 +132,16 @@ namespace node {
   V(subject_string, "subject")                                                \
   V(subjectaltname_string, "subjectaltname")                                  \
   V(syscall_string, "syscall")                                                \
+  V(timestamp_string, "timestamp")                                            \
   V(tls_ticket_string, "tlsTicket")                                           \
+  V(total_heap_size_executable_string, "total_heap_size_executable")          \
+  V(total_heap_size_string, "total_heap_size")                                \
+  V(total_physical_size_string, "total_physical_size")                        \
+  V(type_string, "type")                                                      \
   V(uid_string, "uid")                                                        \
   V(upgrade_string, "upgrade")                                                \
   V(url_string, "url")                                                        \
+  V(used_heap_size_string, "used_heap_size")                                  \
   V(valid_from_string, "valid_from")                                          \
   V(valid_to_string, "valid_to")                                              \
   V(version_major_string, "versionMajor")                                     \
@@ -146,6 +157,7 @@ namespace node {
   V(buffer_constructor_function, v8::Function)                                \
   V(context, v8::Context)                                                     \
   V(domain_array, v8::Array)                                                  \
+  V(gc_info_callback_function, v8::Function)                                  \
   V(module_load_list_array, v8::Array)                                        \
   V(pipe_constructor_template, v8::FunctionTemplate)                          \
   V(process_object, v8::Object)                                               \
@@ -252,6 +264,10 @@ class Environment {
   static inline Environment* New(v8::Local<v8::Context> context);
   inline void Dispose();
 
+  // Defined in src/node_profiler.cc.
+  void StartGarbageCollectionTracking(v8::Local<v8::Function> callback);
+  void StopGarbageCollectionTracking();
+
   inline v8::Isolate* isolate() const;
   inline uv_loop_t* event_loop() const;
   inline bool has_async_listener() const;
@@ -297,10 +313,13 @@ class Environment {
 #undef V
 
  private:
+  class GCInfo;
   class IsolateData;
   inline explicit Environment(v8::Local<v8::Context> context);
   inline ~Environment();
   inline IsolateData* isolate_data() const;
+  void AfterGarbageCollectionCallback(const GCInfo* before,
+                                      const GCInfo* after);
 
   enum ContextEmbedderDataIndex {
     kContextEmbedderDataIndex = NODE_CONTEXT_EMBEDDER_DATA_INDEX
@@ -320,12 +339,33 @@ class Environment {
   ares_task_list cares_task_list_;
   bool using_smalloc_alloc_cb_;
   bool using_domains_;
+  QUEUE gc_tracker_queue_;
 
 #define V(PropertyName, TypeName)                                             \
   v8::Persistent<TypeName> PropertyName ## _;
   ENVIRONMENT_STRONG_PERSISTENT_PROPERTIES(V)
 #undef V
 
+  class GCInfo {
+   public:
+    inline GCInfo();
+    inline GCInfo(v8::Isolate* isolate,
+                  v8::GCType type,
+                  v8::GCCallbackFlags flags,
+                  uint64_t timestamp);
+    inline v8::GCType type() const;
+    inline v8::GCCallbackFlags flags() const;
+    // TODO(bnoordhuis) Const-ify once https://codereview.chromium.org/63693005
+    // lands and makes it way into a stable release.
+    inline v8::HeapStatistics* stats() const;
+    inline uint64_t timestamp() const;
+   private:
+    v8::GCType type_;
+    v8::GCCallbackFlags flags_;
+    v8::HeapStatistics stats_;
+    uint64_t timestamp_;
+  };
+
   // Per-thread, reference-counted singleton.
   class IsolateData {
    public:
@@ -333,15 +373,30 @@ class Environment {
     inline void Put();
     inline uv_loop_t* event_loop() const;
 
+    // Defined in src/node_profiler.cc.
+    void StartGarbageCollectionTracking(Environment* env);
+    void StopGarbageCollectionTracking(Environment* env);
+
 #define V(PropertyName, StringValue)                                          \
     inline v8::Local<v8::String> PropertyName() const;
     PER_ISOLATE_STRING_PROPERTIES(V)
 #undef V
 
    private:
+    inline static IsolateData* Get(v8::Isolate* isolate);
     inline explicit IsolateData(v8::Isolate* isolate);
     inline v8::Isolate* isolate() const;
 
+    // Defined in src/node_profiler.cc.
+    static void BeforeGarbageCollection(v8::Isolate* isolate,
+                                        v8::GCType type,
+                                        v8::GCCallbackFlags flags);
+    static void AfterGarbageCollection(v8::Isolate* isolate,
+                                       v8::GCType type,
+                                       v8::GCCallbackFlags flags);
+    void BeforeGarbageCollection(v8::GCType type, v8::GCCallbackFlags flags);
+    void AfterGarbageCollection(v8::GCType type, v8::GCCallbackFlags flags);
+
     uv_loop_t* const event_loop_;
     v8::Isolate* const isolate_;
 
@@ -351,6 +406,9 @@ class Environment {
 #undef V
 
     unsigned int ref_count_;
+    QUEUE gc_tracker_queue_;
+    GCInfo gc_info_before_;
+    GCInfo gc_info_after_;
 
     DISALLOW_COPY_AND_ASSIGN(IsolateData);
   };
diff --git a/src/node_v8.cc b/src/node_v8.cc
new file mode 100644 (file)
index 0000000..2fd2763
--- /dev/null
@@ -0,0 +1,200 @@
+// Copyright Joyent, Inc. and other Node contributors.
+//
+// Permission is hereby granted, free of charge, to any person obtaining a
+// copy of this software and associated documentation files (the
+// "Software"), to deal in the Software without restriction, including
+// without limitation the rights to use, copy, modify, merge, publish,
+// distribute, sublicense, and/or sell copies of the Software, and to permit
+// persons to whom the Software is furnished to do so, subject to the
+// following conditions:
+//
+// The above copyright notice and this permission notice shall be included
+// in all copies or substantial portions of the Software.
+//
+// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS
+// OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
+// MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN
+// NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM,
+// DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
+// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE
+// USE OR OTHER DEALINGS IN THE SOFTWARE.
+
+#include "node.h"
+#include "env.h"
+#include "env-inl.h"
+#include "util.h"
+#include "util-inl.h"
+#include "v8.h"
+
+namespace node {
+
+using v8::Context;
+using v8::Function;
+using v8::FunctionCallbackInfo;
+using v8::GCCallbackFlags;
+using v8::GCType;
+using v8::Handle;
+using v8::HandleScope;
+using v8::Isolate;
+using v8::Local;
+using v8::Null;
+using v8::Number;
+using v8::Object;
+using v8::Uint32;
+using v8::Value;
+using v8::kGCTypeAll;
+using v8::kGCTypeMarkSweepCompact;
+using v8::kGCTypeScavenge;
+
+
+void Environment::IsolateData::BeforeGarbageCollection(Isolate* isolate,
+                                                       GCType type,
+                                                       GCCallbackFlags flags) {
+  Get(isolate)->BeforeGarbageCollection(type, flags);
+}
+
+
+void Environment::IsolateData::AfterGarbageCollection(Isolate* isolate,
+                                                      GCType type,
+                                                      GCCallbackFlags flags) {
+  Get(isolate)->AfterGarbageCollection(type, flags);
+}
+
+
+void Environment::IsolateData::BeforeGarbageCollection(GCType type,
+                                                       GCCallbackFlags flags) {
+  gc_info_before_ = GCInfo(isolate(), type, flags, uv_hrtime());
+}
+
+
+void Environment::IsolateData::AfterGarbageCollection(GCType type,
+                                                      GCCallbackFlags flags) {
+  gc_info_after_ = GCInfo(isolate(), type, flags, uv_hrtime());
+
+  // The copy upfront and the remove-then-insert is to avoid corrupting the
+  // list when the callback removes itself from it.  QUEUE_FOREACH() is unsafe
+  // when the list is mutated while being walked.
+  ASSERT(QUEUE_EMPTY(&gc_tracker_queue_) == false);
+  QUEUE queue;
+  QUEUE* q = QUEUE_HEAD(&gc_tracker_queue_);
+  QUEUE_SPLIT(&gc_tracker_queue_, q, &queue);
+  while (QUEUE_EMPTY(&queue) == false) {
+    q = QUEUE_HEAD(&queue);
+    QUEUE_REMOVE(q);
+    QUEUE_INSERT_TAIL(&gc_tracker_queue_, q);
+    Environment* env = CONTAINER_OF(q, Environment, gc_tracker_queue_);
+    env->AfterGarbageCollectionCallback(&gc_info_before_, &gc_info_after_);
+  }
+}
+
+
+void Environment::IsolateData::StartGarbageCollectionTracking(
+    Environment* env) {
+  if (QUEUE_EMPTY(&gc_tracker_queue_)) {
+    isolate()->AddGCPrologueCallback(BeforeGarbageCollection, v8::kGCTypeAll);
+    isolate()->AddGCEpilogueCallback(AfterGarbageCollection, v8::kGCTypeAll);
+  }
+  ASSERT(QUEUE_EMPTY(&env->gc_tracker_queue_) == true);
+  QUEUE_INSERT_TAIL(&gc_tracker_queue_, &env->gc_tracker_queue_);
+}
+
+
+void Environment::IsolateData::StopGarbageCollectionTracking(Environment* env) {
+  ASSERT(QUEUE_EMPTY(&env->gc_tracker_queue_) == false);
+  QUEUE_REMOVE(&env->gc_tracker_queue_);
+  QUEUE_INIT(&env->gc_tracker_queue_);
+  if (QUEUE_EMPTY(&gc_tracker_queue_)) {
+    isolate()->RemoveGCPrologueCallback(BeforeGarbageCollection);
+    isolate()->RemoveGCEpilogueCallback(AfterGarbageCollection);
+  }
+}
+
+
+// Considering a memory constrained environment, creating more objects is less
+// than ideal
+void Environment::AfterGarbageCollectionCallback(const GCInfo* before,
+                                                 const GCInfo* after) {
+  HandleScope handle_scope(isolate());
+  Context::Scope context_scope(context());
+  Local<Value> argv[] = { Object::New(), Object::New() };
+  const GCInfo* infov[] = { before, after };
+  for (unsigned i = 0; i < ARRAY_SIZE(argv); i += 1) {
+    Local<Object> obj = argv[i].As<Object>();
+    const GCInfo* info = infov[i];
+    switch (info->type()) {
+      case kGCTypeScavenge:
+        obj->Set(type_string(), scavenge_string());
+        break;
+      case kGCTypeMarkSweepCompact:
+        obj->Set(type_string(), mark_sweep_compact_string());
+        break;
+      default:
+        UNREACHABLE();
+    }
+    obj->Set(flags_string(), Uint32::NewFromUnsigned(info->flags(), isolate()));
+    obj->Set(timestamp_string(), Number::New(isolate(), info->timestamp()));
+    // TODO(trevnorris): Setting many object properties in C++ is a significant
+    // performance hit. Redo this to pass the results to JS and create/set the
+    // properties there.
+#define V(name)                                                               \
+    do {                                                                      \
+      obj->Set(name ## _string(),                                             \
+               Uint32::NewFromUnsigned(info->stats()->name(), isolate()));    \
+    } while (0)
+    V(total_heap_size);
+    V(total_heap_size_executable);
+    V(total_physical_size);
+    V(used_heap_size);
+    V(heap_size_limit);
+#undef V
+  }
+  MakeCallback(this,
+               Null(isolate()),
+               gc_info_callback_function(),
+               ARRAY_SIZE(argv),
+               argv);
+}
+
+
+void Environment::StartGarbageCollectionTracking(Local<Function> callback) {
+  ASSERT(gc_info_callback_function().IsEmpty() == true);
+  set_gc_info_callback_function(callback);
+  isolate_data()->StartGarbageCollectionTracking(this);
+}
+
+
+void Environment::StopGarbageCollectionTracking() {
+  ASSERT(gc_info_callback_function().IsEmpty() == false);
+  isolate_data()->StopGarbageCollectionTracking(this);
+  set_gc_info_callback_function(Local<Function>());
+}
+
+
+void StartGarbageCollectionTracking(const FunctionCallbackInfo<Value>& args) {
+  CHECK(args[0]->IsFunction() == true);
+  HandleScope handle_scope(args.GetIsolate());
+  Environment* env = Environment::GetCurrent(args.GetIsolate());
+  env->StartGarbageCollectionTracking(args[0].As<Function>());
+}
+
+
+void StopGarbageCollectionTracking(const FunctionCallbackInfo<Value>& args) {
+  HandleScope handle_scope(args.GetIsolate());
+  Environment::GetCurrent(args.GetIsolate())->StopGarbageCollectionTracking();
+}
+
+
+void InitializeV8Bindings(Handle<Object> target,
+                          Handle<Value> unused,
+                          Handle<Context> context) {
+  NODE_SET_METHOD(target,
+                  "startGarbageCollectionTracking",
+                  StartGarbageCollectionTracking);
+  NODE_SET_METHOD(target,
+                  "stopGarbageCollectionTracking",
+                  StopGarbageCollectionTracking);
+}
+
+}  // namespace node
+
+NODE_MODULE_CONTEXT_AWARE_BUILTIN(v8, node::InitializeV8Bindings)
diff --git a/test/simple/test-v8-gc.js b/test/simple/test-v8-gc.js
new file mode 100644 (file)
index 0000000..077e48c
--- /dev/null
@@ -0,0 +1,53 @@
+// Copyright Joyent, Inc. and other Node contributors.
+//
+// Permission is hereby granted, free of charge, to any person obtaining a
+// copy of this software and associated documentation files (the
+// "Software"), to deal in the Software without restriction, including
+// without limitation the rights to use, copy, modify, merge, publish,
+// distribute, sublicense, and/or sell copies of the Software, and to permit
+// persons to whom the Software is furnished to do so, subject to the
+// following conditions:
+//
+// The above copyright notice and this permission notice shall be included
+// in all copies or substantial portions of the Software.
+//
+// THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS
+// OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
+// MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN
+// NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM,
+// DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR
+// OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE
+// USE OR OTHER DEALINGS IN THE SOFTWARE.
+
+// Flags: --expose_gc
+
+var common = require('../common');
+var assert = require('assert');
+var v8 = require('tracing').v8;
+
+assert(typeof gc === 'function', 'Run this test with --expose_gc.');
+
+var ncalls = 0;
+var before;
+var after;
+
+function ongc(before_, after_) {
+  // Try very hard to not create garbage because that could kick off another
+  // garbage collection cycle.
+  before = before_;
+  after = after_;
+  ncalls += 1;
+}
+
+gc();
+v8.on('gc', ongc);
+gc();
+v8.removeListener('gc', ongc);
+gc();
+
+assert.equal(ncalls, 1);
+assert.equal(typeof before, 'object');
+assert.equal(typeof after, 'object');
+assert.equal(typeof before.timestamp, 'number');
+assert.equal(typeof after.timestamp, 'number');
+assert.equal(before.timestamp <= after.timestamp, true);