src: improve checked uv loop close output

addaleax · addaleax · commit c3d8efbbafb7 · 2019-12-06T01:05:40.000+01:00
Addon developers may run into this when not closing libuv handles
inside Workers.

Previously, output may have included unhelpful statements such as
`uv loop at ... has 0 active handles`, which may sound like
everything’s supposed to be fine actually.

So, instead of printing the active handle count, print the total
handle count and mark active handles individually.

Also, fix the test for this to work properly and make sure that
parsing finishes properly.
diff --git a/src/debug_utils.cc b/src/debug_utils.cc
@@ -292,19 +292,21 @@ void PrintLibuvHandleInformation(uv_loop_t* loop, FILE* stream) {
   struct Info {
     std::unique_ptr<NativeSymbolDebuggingContext> ctx;
     FILE* stream;
+    size_t num_handles;
   };
 
-  Info info { NativeSymbolDebuggingContext::New(), stream };
+  Info info { NativeSymbolDebuggingContext::New(), stream, 0 };
 
-  fprintf(stream, "uv loop at [%p] has %d active handles\n",
-          loop, loop->active_handles);
+  fprintf(stream, "uv loop at [%p] has open handles:\n", loop);
 
   uv_walk(loop, [](uv_handle_t* handle, void* arg) {
     Info* info = static_cast<Info*>(arg);
     NativeSymbolDebuggingContext* sym_ctx = info->ctx.get();
     FILE* stream = info->stream;
+    info->num_handles++;
 
-    fprintf(stream, "[%p] %s\n", handle, uv_handle_type_name(handle->type));
+    fprintf(stream, "[%p] %s%s\n", handle, uv_handle_type_name(handle->type),
+            uv_is_active(handle) ? " (active)" : "");
 
     void* close_cb = reinterpret_cast<void*>(handle->close_cb);
     fprintf(stream, "\tClose callback: %p %s\n",
@@ -328,6 +330,9 @@ void PrintLibuvHandleInformation(uv_loop_t* loop, FILE* stream) {
           first_field, sym_ctx->LookupSymbol(first_field).Display().c_str());
     }
   }, &info);
+
+  fprintf(stream, "uv loop at [%p] has %zu open handles in total\n",
+          loop, info.num_handles);
 }
 
 std::vector<std::string> NativeSymbolDebuggingContext::GetLoadedLibraries() {
diff --git a/test/abort/test-addon-uv-handle-leak.js b/test/abort/test-addon-uv-handle-leak.js
@@ -47,8 +47,8 @@ if (process.argv[2] === 'child') {
 
   // Parse output that is formatted like this:
 
-  // uv loop at [0x559b65ed5770] has active handles
-  // [0x7f2de0018430] timer
+  // uv loop at [0x559b65ed5770] has open handles:
+  // [0x7f2de0018430] timer (active)
   //         Close callback: 0x7f2df31de220 CloseCallback(uv_handle_s*) [...]
   //         Data: 0x7f2df33df140 example_instance [...]
   //         (First field): 0x7f2df33dedc0 vtable for ExampleOwnerClass [...]
@@ -89,15 +89,15 @@ if (process.argv[2] === 'child') {
 
     switch (state) {
       case 'initial':
-        assert(/^uv loop at \[.+\] has \d+ active handles$/.test(line), line);
+        assert(/^uv loop at \[.+\] has open handles:$/.test(line), line);
         state = 'handle-start';
         break;
       case 'handle-start':
-        if (/Assertion .+ failed/.test(line)) {
-          state = 'done';
+        if (/^uv loop at \[.+\] has \d+ open handles in total$/.test(line)) {
+          state = 'assertion-failure';
           break;
         }
-        assert(/^\[.+\] timer$/.test(line), line);
+        assert(/^\[.+\] timer( \(active\))?$/.test(line), line);
         state = 'close-callback';
         break;
       case 'close-callback':
@@ -109,15 +109,19 @@ if (process.argv[2] === 'child') {
         state = 'maybe-first-field';
         break;
       case 'maybe-first-field':
-        if (/^\(First field\)$/.test(line)) {
+        if (!/^\(First field\)/.test(line)) {
           lines.unshift(line);
-          state = 'handle-start';
-          break;
         }
-        state = 'maybe-first-field';
+        state = 'handle-start';
+        break;
+      case 'assertion-failure':
+        assert(/Assertion .+ failed/.test(line), line);
+        state = 'done';
         break;
       case 'done':
         break;
     }
   }
+
+  assert.strictEqual(state, 'done');
 }
