Introduce CpuProfiler, CpuProfile, and CpuProfileNode (#167)

* Introduce CpuProfiler, CpuProfile, CpuProfileNode

* Test no-op for subsequent disposes of cpu profiler

* Verify is profiler or iso is nil within start/stop functions

* Expand example in readme

* Adjust script run time to ensure sampling

* Remove unneeded unsafe pointer casts, fix time conversion, panic on nil
pointers in StartProfiling/StopProfiling

* Panic on nil ptr/iso in start/stop profiling

* Add backports for timeUnixMicro, add comments to new objects fields

* Getter methods for cpu profile + cpu profile node

* Update Readme, add GetChildrenCount to node

* Find start node on root, ignore program/garbage collector children

* Specify timeout for script + loosen search on children

* Fix reversing of order of profile start and end time

* Expose profile duration instead of start and end time.

Co-authored-by: Ryan Moran <[email protected]>
Co-authored-by: Dylan Thacker-Smith <[email protected]>

Author: 3 people

CHANGELOG.md

@@ -15,6 +15,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0
 - Support for calling a method on an object.
 - Support for calling `IsExecutionTerminating` on isolate to check if execution is still terminating.
 - Support for setting and getting internal fields for template object instances
+- Support for CPU profiling
 
 ### Changed
 - Removed error return value from NewIsolate which never fails

README.md

@@ -101,7 +101,7 @@ go func() {
 
 select {
 case val := <- vals:
-    // sucess
+    // success
 case err := <- errs:
     // javascript error
 case <- time.After(200 * time.Milliseconds):
@@ -111,6 +111,54 @@ case <- time.After(200 * time.Milliseconds):
 }
 ```
 
+### CPU Profiler
+
+```go
+func createProfile() {
+	iso := v8.NewIsolate()
+	ctx := v8.NewContext(iso)
+	cpuProfiler := v8.NewCPUProfiler(iso)
+
+	cpuProfiler.StartProfiling("my-profile")
+
+	ctx.RunScript(profileScript, "script.js") # this script is defined in cpuprofiler_test.go
+	val, _ := ctx.Global().Get("start")
+	fn, _ := val.AsFunction()
+	fn.Call(ctx.Global())
+
+	cpuProfile := cpuProfiler.StopProfiling("my-profile")
+
+	printTree("", cpuProfile.GetTopDownRoot()) # helper function to print the profile
+}
+
+func printTree(nest string, node *v8.CPUProfileNode) {
+	fmt.Printf("%s%s %s:%d:%d\n", nest, node.GetFunctionName(), node.GetScriptResourceName(), node.GetLineNumber(), node.GetColumnNumber())
+	count := node.GetChildrenCount()
+	if count == 0 {
+		return
+	}
+	nest = fmt.Sprintf("%s  ", nest)
+	for i := 0; i < count; i++ {
+		printTree(nest, node.GetChild(i))
+	}
+}
+
+// Output
+// (root) :0:0
+//   (program) :0:0
+//   start script.js:23:15
+//     foo script.js:15:13
+//       delay script.js:12:15
+//         loop script.js:1:14
+//       bar script.js:13:13
+//         delay script.js:12:15
+//           loop script.js:1:14
+//       baz script.js:14:13
+//         delay script.js:12:15
+//           loop script.js:1:14
+//   (garbage collector) :0:0
+```
+
 ## Documentation
 
 Go Reference & more examples: https://pkg.go.dev/rogchap.com/v8go

backports.go

@@ -0,0 +1,11 @@
+package v8go
+
+import "time"
+
+// Backport time.UnixMicro from go 1.17 - https://pkg.go.dev/time#UnixMicro
+// timeUnixMicro accepts microseconds and converts to nanoseconds to be used
+// with time.Unix which returns the local Time corresponding to the given Unix time,
+// usec microseconds since January 1, 1970 UTC.
+func timeUnixMicro(usec int64) time.Time {
+	return time.Unix(0, usec*1000)
+}

cpuprofile.go

@@ -0,0 +1,51 @@
+package v8go
+
+/*
+#include "v8go.h"
+*/
+import "C"
+import "time"
+
+type CPUProfile struct {
+	p *C.CPUProfile
+
+	// The CPU profile title.
+	title string
+
+	// root is the root node of the top down call tree.
+	root *CPUProfileNode
+
+	// startTimeOffset is the time when the profile recording was started
+	// since some unspecified starting point.
+	startTimeOffset time.Duration
+
+	// endTimeOffset is the time when the profile recording was stopped
+	// since some unspecified starting point.
+	// The point is equal to the starting point used by startTimeOffset.
+	endTimeOffset time.Duration
+}
+
+// Returns CPU profile title.
+func (c *CPUProfile) GetTitle() string {
+	return c.title
+}
+
+// Returns the root node of the top down call tree.
+func (c *CPUProfile) GetTopDownRoot() *CPUProfileNode {
+	return c.root
+}
+
+// Returns the duration of the profile.
+func (c *CPUProfile) GetDuration() time.Duration {
+	return c.endTimeOffset - c.startTimeOffset
+}
+
+// Deletes the profile and removes it from CpuProfiler's list.
+// All pointers to nodes previously returned become invalid.
+func (c *CPUProfile) Delete() {
+	if c.p == nil {
+		return
+	}
+	C.CPUProfileDelete(c.p)
+	c.p = nil
+}

cpuprofile_test.go

@@ -0,0 +1,66 @@
+package v8go_test
+
+import (
+	"testing"
+
+	v8 "rogchap.com/v8go"
+)
+
+func TestCPUProfile(t *testing.T) {
+	t.Parallel()
+
+	ctx := v8.NewContext(nil)
+	iso := ctx.Isolate()
+	defer iso.Dispose()
+	defer ctx.Close()
+
+	cpuProfiler := v8.NewCPUProfiler(iso)
+	defer cpuProfiler.Dispose()
+
+	title := "cpuprofiletest"
+	cpuProfiler.StartProfiling(title)
+
+	_, err := ctx.RunScript(profileScript, "script.js")
+	fatalIf(t, err)
+	val, err := ctx.Global().Get("start")
+	fatalIf(t, err)
+	fn, err := val.AsFunction()
+	fatalIf(t, err)
+	_, err = fn.Call(ctx.Global())
+	fatalIf(t, err)
+
+	cpuProfile := cpuProfiler.StopProfiling(title)
+	defer cpuProfile.Delete()
+
+	if cpuProfile.GetTitle() != title {
+		t.Fatalf("expected title %s, but got %s", title, cpuProfile.GetTitle())
+	}
+
+	root := cpuProfile.GetTopDownRoot()
+	if root == nil {
+		t.Fatal("expected root not to be nil")
+	}
+	if root.GetFunctionName() != "(root)" {
+		t.Errorf("expected (root), but got %v", root.GetFunctionName())
+	}
+
+	if cpuProfile.GetDuration() <= 0 {
+		t.Fatalf("expected positive profile duration (%s)", cpuProfile.GetDuration())
+	}
+}
+
+func TestCPUProfile_Delete(t *testing.T) {
+	t.Parallel()
+
+	iso := v8.NewIsolate()
+	defer iso.Dispose()
+
+	cpuProfiler := v8.NewCPUProfiler(iso)
+	defer cpuProfiler.Dispose()
+
+	cpuProfiler.StartProfiling("cpuprofiletest")
+	cpuProfile := cpuProfiler.StopProfiling("cpuprofiletest")
+	cpuProfile.Delete()
+	// noop when called multiple times
+	cpuProfile.Delete()
+}

cpuprofilenode.go

@@ -0,0 +1,55 @@
+package v8go
+
+type CPUProfileNode struct {
+	// The resource name for script from where the function originates.
+	scriptResourceName string
+
+	// The function name (empty string for anonymous functions.)
+	functionName string
+
+	// The number of the line where the function originates.
+	lineNumber int
+
+	// The number of the column where the function originates.
+	columnNumber int
+
+	// The children node of this node.
+	children []*CPUProfileNode
+
+	// The parent node of this node.
+	parent *CPUProfileNode
+}
+
+// Returns function name (empty string for anonymous functions.)
+func (c *CPUProfileNode) GetFunctionName() string {
+	return c.functionName
+}
+
+// Returns resource name for script from where the function originates.
+func (c *CPUProfileNode) GetScriptResourceName() string {
+	return c.scriptResourceName
+}
+
+// Returns number of the line where the function originates.
+func (c *CPUProfileNode) GetLineNumber() int {
+	return c.lineNumber
+}
+
+// Returns number of the column where the function originates.
+func (c *CPUProfileNode) GetColumnNumber() int {
+	return c.columnNumber
+}
+
+// Retrieves the ancestor node, or nil if the root.
+func (c *CPUProfileNode) GetParent() *CPUProfileNode {
+	return c.parent
+}
+
+func (c *CPUProfileNode) GetChildrenCount() int {
+	return len(c.children)
+}
+
+// Retrieves a child node by index.
+func (c *CPUProfileNode) GetChild(index int) *CPUProfileNode {
+	return c.children[index]
+}

cpuprofilenode_test.go

@@ -0,0 +1,108 @@
+package v8go_test
+
+import (
+	"testing"
+
+	v8 "rogchap.com/v8go"
+)
+
+func TestCPUProfileNode(t *testing.T) {
+	t.Parallel()
+
+	ctx := v8.NewContext(nil)
+	iso := ctx.Isolate()
+	defer iso.Dispose()
+	defer ctx.Close()
+
+	cpuProfiler := v8.NewCPUProfiler(iso)
+	defer cpuProfiler.Dispose()
+
+	title := "cpuprofilenodetest"
+	cpuProfiler.StartProfiling(title)
+
+	_, err := ctx.RunScript(profileScript, "script.js")
+	fatalIf(t, err)
+	val, err := ctx.Global().Get("start")
+	fatalIf(t, err)
+	fn, err := val.AsFunction()
+	fatalIf(t, err)
+	timeout, err := v8.NewValue(iso, int32(1000))
+	fatalIf(t, err)
+	_, err = fn.Call(ctx.Global(), timeout)
+	fatalIf(t, err)
+
+	cpuProfile := cpuProfiler.StopProfiling(title)
+	if cpuProfile == nil {
+		t.Fatal("expected profile not to be nil")
+	}
+	defer cpuProfile.Delete()
+
+	rootNode := cpuProfile.GetTopDownRoot()
+	if rootNode == nil {
+		t.Fatal("expected top down root not to be nil")
+	}
+	count := rootNode.GetChildrenCount()
+	var startNode *v8.CPUProfileNode
+	for i := 0; i < count; i++ {
+		if rootNode.GetChild(i).GetFunctionName() == "start" {
+			startNode = rootNode.GetChild(i)
+		}
+	}
+	if startNode == nil {
+		t.Fatal("expected node not to be nil")
+	}
+	checkNode(t, startNode, "script.js", "start", 23, 15)
+
+	parentName := startNode.GetParent().GetFunctionName()
+	if parentName != "(root)" {
+		t.Fatalf("expected (root), but got %v", parentName)
+	}
+
+	fooNode := findChild(t, startNode, "foo")
+	checkNode(t, fooNode, "script.js", "foo", 15, 13)
+
+	delayNode := findChild(t, fooNode, "delay")
+	checkNode(t, delayNode, "script.js", "delay", 12, 15)
+
+	barNode := findChild(t, fooNode, "bar")
+	checkNode(t, barNode, "script.js", "bar", 13, 13)
+
+	loopNode := findChild(t, delayNode, "loop")
+	checkNode(t, loopNode, "script.js", "loop", 1, 14)
+
+	bazNode := findChild(t, fooNode, "baz")
+	checkNode(t, bazNode, "script.js", "baz", 14, 13)
+}
+
+func findChild(t *testing.T, node *v8.CPUProfileNode, functionName string) *v8.CPUProfileNode {
+	t.Helper()
+
+	var child *v8.CPUProfileNode
+	count := node.GetChildrenCount()
+	for i := 0; i < count; i++ {
+		if node.GetChild(i).GetFunctionName() == functionName {
+			child = node.GetChild(i)
+		}
+	}
+	if child == nil {
+		t.Fatal("failed to find child node")
+	}
+	return child
+}
+
+func checkNode(t *testing.T, node *v8.CPUProfileNode, scriptResourceName string, functionName string, line, column int) {
+	t.Helper()
+
+	if node.GetFunctionName() != functionName {
+		t.Fatalf("expected node to have function name %s, but got %s", functionName, node.GetFunctionName())
+	}
+	if node.GetScriptResourceName() != scriptResourceName {
+		t.Fatalf("expected node to have script resource name %s, but got %s", scriptResourceName, node.GetScriptResourceName())
+	}
+	if node.GetLineNumber() != line {
+		t.Fatalf("expected node at line %d, but got %d", line, node.GetLineNumber())
+	}
+	if node.GetColumnNumber() != column {
+		t.Fatalf("expected node at column %d, but got %d", column, node.GetColumnNumber())
+	}
+}