feat: allow collecting profiles with more accurate line numbers (#69)

* feat: allow collecting profiles with more accurate line numbers * address comments * ensure binaries are built in system tests
google · Jun 24, 2019 · 138d5bd · 138d5bd
1 parent d165552
commit 138d5bd
Show file tree

Hide file tree

Showing 10 changed files with 345 additions and 47 deletions.
diff --git a/.gitignore b/.gitignore
@@ -6,3 +6,4 @@
 out
 node_modules
 system-test/busybench/package-lock.json
+system-test/busybench-js/package-lock.json
diff --git a/bindings/profiler.cc b/bindings/profiler.cc
@@ -79,10 +79,14 @@ NAN_METHOD(StartSamplingHeapProfiler) {
   }
 }
 
+// Signature:
+// stopSamplingHeapProfiler()
 NAN_METHOD(StopSamplingHeapProfiler) {
   info.GetIsolate()->GetHeapProfiler()->StopSamplingHeapProfiler();
 }
 
+// Signature:
+// getAllocationProfile(): AllocationProfileNode
 NAN_METHOD(GetAllocationProfile) {
   std::unique_ptr<v8::AllocationProfile> profile(
     info.GetIsolate()->GetHeapProfiler()->GetAllocationProfile());
@@ -101,61 +105,226 @@ CpuProfiler* cpuProfiler = CpuProfiler::New(v8::Isolate::GetCurrent());
 CpuProfiler* cpuProfiler = v8::Isolate::GetCurrent()->GetCpuProfiler();
 #endif
 
+Local<Object> CreateTimeNode(Local<String> name, Local<String> scriptName,
+                         Local<Integer> scriptId, Local<Integer> lineNumber,
+                         Local<Integer> columnNumber, Local<Integer> hitCount,
+                         Local<Array> children) {
+  Local<Object> js_node = Nan::New<Object>();
+  js_node->Set(Nan::New<String>("name").ToLocalChecked(), name);
+  js_node->Set(Nan::New<String>("scriptName").ToLocalChecked(), scriptName);
+  js_node->Set(Nan::New<String>("scriptId").ToLocalChecked(), scriptId);
+  js_node->Set(Nan::New<String>("lineNumber").ToLocalChecked(), lineNumber);
+  js_node->Set(Nan::New<String>("columnNumber").ToLocalChecked(), columnNumber);
+  js_node->Set(Nan::New<String>("hitCount").ToLocalChecked(), hitCount);
+  js_node->Set(Nan::New<String>("children").ToLocalChecked(), children);
+  return js_node;
+}
+
+
+#if NODE_MODULE_VERSION > NODE_11_0_MODULE_VERSION
+Local<Object> TranslateLineNumbersTimeProfileNode(const CpuProfileNode* parent,
+                                      const CpuProfileNode* node);
+
+Local<Array> GetLineNumberTimeProfileChildren(const CpuProfileNode* parent,
+                                      const CpuProfileNode* node) {
+  unsigned int index = 0;
+  Local<Array> children;
+  int32_t count = node->GetChildrenCount();
+
+  unsigned int hitLineCount = node->GetHitLineCount();
+  unsigned int hitCount = node->GetHitCount();
+  if (hitLineCount > 0) {
+    CpuProfileNode::LineTick entries[hitLineCount];
+    node->GetLineTicks(&entries[0], hitLineCount);
+    children = Nan::New<Array>(count + hitLineCount);
+    for (const CpuProfileNode::LineTick entry : entries) {
+      children->Set(index++, CreateTimeNode(
+        node->GetFunctionName(),
+        node->GetScriptResourceName(),
+        Nan::New<Integer>(node->GetScriptId()),
+        Nan::New<Integer>(entry.line),
+        Nan::New<Integer>(0),
+        Nan::New<Integer>(entry.hit_count),
+        Nan::New<Array>(0)
+      ));
+    }
+  } else if (hitCount > 0) {
+    // Handle nodes for pseudo-functions like "process" and "garbage collection"
+    // which do not have hit line counts.
+    children = Nan::New<Array>(count + 1);
+    children->Set(index++, CreateTimeNode(
+      node->GetFunctionName(),
+      node->GetScriptResourceName(),
+      Nan::New<Integer>(node->GetScriptId()),
+      Nan::New<Integer>(node->GetLineNumber()),
+      Nan::New<Integer>(node->GetColumnNumber()),
+      Nan::New<Integer>(hitCount),
+      Nan::New<Array>(0)
+    ));
+  } else {
+    children = Nan::New<Array>(count);
+  }
+
+  for (int32_t i = 0; i < count; i++) {
+    children->Set(index++, TranslateLineNumbersTimeProfileNode(node,
+        node->GetChild(i)));
+  };
+
+  return children;
+}
+
+Local<Object> TranslateLineNumbersTimeProfileNode(const CpuProfileNode* parent,
+                                      const CpuProfileNode* node) {
+  return CreateTimeNode(parent->GetFunctionName(),
+                    parent->GetScriptResourceName(),
+                    Nan::New<Integer>(parent->GetScriptId()),
+                    Nan::New<Integer>(node->GetLineNumber()),
+                    Nan::New<Integer>(node->GetColumnNumber()),
+                    Nan::New<Integer>(0),
+                    GetLineNumberTimeProfileChildren(parent, node));
+}
+
+// In profiles with line-level accurate line numbers, a node's line number
+// and column number refer to the line/column from which the function was
+// called.
+Local<Value> TranslateLineNumbersTimeProfileRoot(const CpuProfileNode* node) {
+  int32_t count = node->GetChildrenCount();
+  Local<Array> childrenArrs[count];
+  int32_t childCount = 0;
+  for (int32_t i = 0; i < count; i++) {
+    Local<Array> c = GetLineNumberTimeProfileChildren(node, node->GetChild(i));
+    childCount = childCount + c->Length();
+    childrenArrs[i] = c;
+  }
+
+  Local<Array> children = Nan::New<Array>(childCount);
+  int32_t idx = 0;
+  for (int32_t i = 0; i < count; i++) {
+    Local<Array> arr = childrenArrs[i];
+    for (int32_t j = 0; j < arr->Length(); j++) {
+      children->Set(idx, arr->Get(j));
+      idx++;
+    }
+  }
+
+  return CreateTimeNode(
+      node->GetFunctionName(),
+      node->GetScriptResourceName(),
+      Nan::New<Integer>(node->GetScriptId()),
+      Nan::New<Integer>(node->GetLineNumber()),
+      Nan::New<Integer>(node->GetColumnNumber()),
+      Nan::New<Integer>(0),
+      children
+  );
+}
+#endif
 
 Local<Value> TranslateTimeProfileNode(const CpuProfileNode* node) {
-  Local<Object> js_node = Nan::New<Object>();
-  js_node->Set(Nan::New<String>("name").ToLocalChecked(),
-    node->GetFunctionName());
-  js_node->Set(Nan::New<String>("scriptName").ToLocalChecked(),
-    node->GetScriptResourceName());
-  js_node->Set(Nan::New<String>("scriptId").ToLocalChecked(),
-    Nan::New<Integer>(node->GetScriptId()));
-  js_node->Set(Nan::New<String>("lineNumber").ToLocalChecked(),
-    Nan::New<Integer>(node->GetLineNumber()));
-  js_node->Set(Nan::New<String>("columnNumber").ToLocalChecked(),
-    Nan::New<Integer>(node->GetColumnNumber()));
-  js_node->Set(Nan::New<String>("hitCount").ToLocalChecked(),
-    Nan::New<Integer>(node->GetHitCount()));
   int32_t count = node->GetChildrenCount();
   Local<Array> children = Nan::New<Array>(count);
   for (int32_t i = 0; i < count; i++) {
     children->Set(i, TranslateTimeProfileNode(node->GetChild(i)));
   }
-  js_node->Set(Nan::New<String>("children").ToLocalChecked(),
-    children);
-  return js_node;
+
+  return CreateTimeNode(
+    node->GetFunctionName(),
+    node->GetScriptResourceName(),
+    Nan::New<Integer>(node->GetScriptId()),
+    Nan::New<Integer>(node->GetLineNumber()),
+    Nan::New<Integer>(node->GetColumnNumber()),
+    Nan::New<Integer>(node->GetHitCount()),
+    children
+  );
 }
 
-Local<Value> TranslateTimeProfile(const CpuProfile* profile) {
+Local<Value> TranslateTimeProfile(const CpuProfile* profile, bool hasDetailedLines) {
   Local<Object> js_profile = Nan::New<Object>();
   js_profile->Set(Nan::New<String>("title").ToLocalChecked(),
     profile->GetTitle());
-  js_profile->Set(Nan::New<String>("topDownRoot").ToLocalChecked(),
+
+#if NODE_MODULE_VERSION > NODE_11_0_MODULE_VERSION
+  if (hasDetailedLines) {
+    js_profile->Set(
+      Nan::New<String>("topDownRoot").ToLocalChecked(),
+      TranslateLineNumbersTimeProfileRoot(profile->GetTopDownRoot()));
+  } else {
+    js_profile->Set(
+      Nan::New<String>("topDownRoot").ToLocalChecked(),
+      TranslateTimeProfileNode(profile->GetTopDownRoot()));
+  }
+#else
+  js_profile->Set(
+    Nan::New<String>("topDownRoot").ToLocalChecked(),
     TranslateTimeProfileNode(profile->GetTopDownRoot()));
+#endif
   js_profile->Set(Nan::New<String>("startTime").ToLocalChecked(),
     Nan::New<Number>(profile->GetStartTime()));
   js_profile->Set(Nan::New<String>("endTime").ToLocalChecked(),
     Nan::New<Number>(profile->GetEndTime()));
   return js_profile;
 }
 
+// Signature:
+// startProfiling(runName: string, includeLineInfo: boolean)
 NAN_METHOD(StartProfiling) {
-  Local<String> name = info[0].As<String>();
+  if (info.Length() != 2) {
+    return Nan::ThrowTypeError("StartProfling must have two arguments.");
+  }
+  if (!info[0]->IsString()) {
+    return Nan::ThrowTypeError("First argument must be a string.");
+  }
+  if (!info[1]->IsBoolean()) {
+    return Nan::ThrowTypeError("Second argument must be a boolean.");
+  }
+
+  Local<String> name =
+      Nan::MaybeLocal<String>(info[0].As<String>()).ToLocalChecked();
 
-  // Sample counts and timestamps are not used, so we do not need to record
-  // samples.
-  cpuProfiler->StartProfiling(name, false);
+// Sample counts and timestamps are not used, so we do not need to record
+// samples.
+bool recordSamples = false;
+
+// Line-level accurate line information is not available in Node 11 or earlier.
+#if NODE_MODULE_VERSION > NODE_11_0_MODULE_VERSION
+  bool includeLineInfo =
+      Nan::MaybeLocal<Boolean>(info[1].As<Boolean>()).ToLocalChecked()->Value();
+  if (includeLineInfo) {
+    cpuProfiler->StartProfiling(name, CpuProfilingMode::kCallerLineNumbers,
+                                recordSamples);
+  } else {
+    cpuProfiler->StartProfiling(name, recordSamples);
+  }
+#else
+  cpuProfiler->StartProfiling(name, recordSamples);
+#endif
 }
 
+// Signature:
+// stopProfiling(runName: string, includedLineInfo: boolean): TimeProfile
 NAN_METHOD(StopProfiling) {
-  Local<String> name = info[0].As<String>();
-  CpuProfile* profile =
-    cpuProfiler->StopProfiling(name);
-  Local<Value> translated_profile = TranslateTimeProfile(profile);
+  if (info.Length() != 2) {
+    return Nan::ThrowTypeError("StopProfling must have two arguments.");
+  }
+  if (!info[0]->IsString()) {
+    return Nan::ThrowTypeError("First argument must be a string.");
+  }
+  if (!info[1]->IsBoolean()) {
+    return Nan::ThrowTypeError("Second argument must be a boolean.");
+  }
+  Local<String> name =
+      Nan::MaybeLocal<String>(info[0].As<String>()).ToLocalChecked();
+  bool includedLineInfo =
+      Nan::MaybeLocal<Boolean>(info[1].As<Boolean>()).ToLocalChecked()->Value();
+
+  CpuProfile* profile = cpuProfiler->StopProfiling(name);
+  Local<Value> translated_profile =
+      TranslateTimeProfile(profile, includedLineInfo);
   profile->Delete();
   info.GetReturnValue().Set(translated_profile);
 }
 
+// Signature:
+// setSamplingInterval(intervalMicros: number)
 NAN_METHOD(SetSamplingInterval) {
 #if NODE_MODULE_VERSION > NODE_8_0_MODULE_VERSION
   int us = info[0].As<Integer>()->Value();
@@ -187,3 +356,4 @@ NAN_MODULE_INIT(InitAll) {
 }
 
 NODE_MODULE(google_cloud_profiler, InitAll);
+
diff --git a/package-lock.json b/package-lock.json
diff --git a/system-test/Dockerfile.linux b/system-test/Dockerfile.linux
@@ -10,6 +10,7 @@ FROM debian:stretch
 ARG NODE_VERSION
 ARG NVM_NODEJS_ORG_MIRROR
 ARG ADDITIONAL_PACKAGES
+ARG VERIFY_TIME_LINE_NUMBERS
 
 RUN apt-get update && apt-get install -y curl $ADDITIONAL_PACKAGES \
     && rm -rf /var/lib/apt/lists/*

diff --git a/system-test/busybench-js/package.json b/system-test/busybench-js/package.json
@@ -0,0 +1,13 @@
+{
+  "name": "busybench",
+  "version": "1.0.0",
+  "description": "",
+  "main": "index.js",
+  "dependencies": {},
+  "devDependencies": {},
+  "scripts": {
+    "test": "echo \"Error: no test specified\" && exit 1"
+  },
+  "author": "",
+  "license": "ISC"
+}