Add support for tracing function calls

[gernest]

Closes #150

NOTE

There is no actionable insight provided on the issue. I believe I have no business implementing this (Probably someone is already working on this internally). I got too excited when I came across this project and had a lot of idle time so I decided to take this challenge.

There is a lot of shortcomings on this PR ( again, sorry to bother you guys), however I think I figured out the fundamentals of having the feature introduced. I will go into more details on this.

What is missing ?

• Tests : there are no unit tests included because I wasn't sure which direction you had in mind regarding this feature. I however made sure to make minimal changes to ensure someone can review the changes in one sitting.

• JSON and YAML output: Only table output is implemented showing function duration and function name

• Top down rendering like in https://justine.lol/ftrace/ : Reading segments logs returns them in an opposite order from ftrace. Sorting can fix this, in order to minimize changes this commit doesn't sort the call stack

Output looks like

... # omitted text for brevity
     936ns           .sync_atomic.CompareAndSwapUint64
   3.415µs          .internal_poll.__fdMutex_.rwunlock
   4.344µs         .internal_poll.__FD_.writeUnlock
   5.166µs        .internal_poll.__FD_.Write.func1
  23.386µs       .internal_poll.__FD_.Write
  24.455µs      .os.__File_.Write
  25.934µs     .bufio.__Writer_.Flush
   27.46µs    .main.main.func1
  48.527µs   .main.main
     199ns    .runtime_internal_atomic.Load
     160ns    .runtime_internal_atomic.Load
     901ns    .runtime.runExitHooks

• Limiting: Generated trace can be long, there is no way to limit rendered output

• Sampling : No way to sample the traced functions

• Fine tune which functions to trace: Currently we trace everything including system calls which may be redundant considering we already have api for tracing system calls Adding support for this is straightforward so I had to de prioritize.

How it works ?

wazero has experimental api for hooking function calls https://pkg.go.dev/github.com/tetratelabs/[email protected]/experimental#FunctionListenerFactory

We take advantage of this to provide custom implementation of this api and store the collected data in our segment registry.

For now same segment (0) is used for system calls and function calls , Initially I had separate segment for function calls segment(1) but I had to make a lot of changes to glue things together. I settled with the same segment but it should be possible to switch to separate segments.

I am more than happy to own the issue if I get feedback on which direction you had in mind . But also I won't mind if this PR is closed.

Usage

$ timecraft run testdata/go/get.wasm https://eo3qh2ncelpc9q0.m.pipedream.net
79642983-87b9-492c-b24e-b78397d28362
Hello, World!

$ timecraft trace f  79642983-87b9-492c-b24e-b78397d28362
... # truncated for brevity
   3.303µs         .internal_poll.__FD_.writeUnlock
   3.896µs        .internal_poll.__FD_.Write.func1
  17.796µs       .internal_poll.__FD_.Write
  18.578µs      .os.__File_.Write
  20.593µs     .bufio.__Writer_.Flush
  21.898µs    .main.main.func1
  38.941µs   .main.main
     164ns    .runtime_internal_atomic.Load
     144ns    .runtime_internal_atomic.Load
     734ns    .runtime.runExitHooks

This project has the highest quality go code base on github (apart from the go standard library).

I came across this on saturday and found my way to implement this feature on sunday.

Thanks for the project.