profiler.go 8.1 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350
  1. package goja
  2. import (
  3. "errors"
  4. "io"
  5. "strconv"
  6. "sync"
  7. "sync/atomic"
  8. "time"
  9. "github.com/google/pprof/profile"
  10. )
  11. const profInterval = 10 * time.Millisecond
  12. const profMaxStackDepth = 64
  13. const (
  14. profReqNone int32 = iota
  15. profReqDoSample
  16. profReqSampleReady
  17. profReqStop
  18. )
  19. type _globalProfiler struct {
  20. p profiler
  21. w io.Writer
  22. enabled int32
  23. }
  24. var globalProfiler _globalProfiler
  25. type profTracker struct {
  26. req, finished int32
  27. start, stop time.Time
  28. numFrames int
  29. frames [profMaxStackDepth]StackFrame
  30. }
  31. type profiler struct {
  32. mu sync.Mutex
  33. trackers []*profTracker
  34. buf *profBuffer
  35. running bool
  36. }
  37. type profFunc struct {
  38. f profile.Function
  39. locs map[int32]*profile.Location
  40. }
  41. type profSampleNode struct {
  42. loc *profile.Location
  43. sample *profile.Sample
  44. parent *profSampleNode
  45. children map[*profile.Location]*profSampleNode
  46. }
  47. type profBuffer struct {
  48. funcs map[*Program]*profFunc
  49. root profSampleNode
  50. }
  51. func (pb *profBuffer) addSample(pt *profTracker) {
  52. sampleFrames := pt.frames[:pt.numFrames]
  53. n := &pb.root
  54. for j := len(sampleFrames) - 1; j >= 0; j-- {
  55. frame := sampleFrames[j]
  56. if frame.prg == nil {
  57. continue
  58. }
  59. var f *profFunc
  60. if f = pb.funcs[frame.prg]; f == nil {
  61. f = &profFunc{
  62. locs: make(map[int32]*profile.Location),
  63. }
  64. if pb.funcs == nil {
  65. pb.funcs = make(map[*Program]*profFunc)
  66. }
  67. pb.funcs[frame.prg] = f
  68. }
  69. var loc *profile.Location
  70. if loc = f.locs[int32(frame.pc)]; loc == nil {
  71. loc = &profile.Location{}
  72. f.locs[int32(frame.pc)] = loc
  73. }
  74. if nn := n.children[loc]; nn == nil {
  75. if n.children == nil {
  76. n.children = make(map[*profile.Location]*profSampleNode, 1)
  77. }
  78. nn = &profSampleNode{
  79. parent: n,
  80. loc: loc,
  81. }
  82. n.children[loc] = nn
  83. n = nn
  84. } else {
  85. n = nn
  86. }
  87. }
  88. smpl := n.sample
  89. if smpl == nil {
  90. locs := make([]*profile.Location, 0, len(sampleFrames))
  91. for n1 := n; n1.loc != nil; n1 = n1.parent {
  92. locs = append(locs, n1.loc)
  93. }
  94. smpl = &profile.Sample{
  95. Location: locs,
  96. Value: make([]int64, 2),
  97. }
  98. n.sample = smpl
  99. }
  100. smpl.Value[0]++
  101. smpl.Value[1] += int64(pt.stop.Sub(pt.start))
  102. }
  103. func (pb *profBuffer) profile() *profile.Profile {
  104. pr := profile.Profile{}
  105. pr.SampleType = []*profile.ValueType{
  106. {Type: "samples", Unit: "count"},
  107. {Type: "cpu", Unit: "nanoseconds"},
  108. }
  109. pr.PeriodType = pr.SampleType[1]
  110. pr.Period = int64(profInterval)
  111. mapping := &profile.Mapping{
  112. ID: 1,
  113. File: "[ECMAScript code]",
  114. }
  115. pr.Mapping = make([]*profile.Mapping, 1, len(pb.funcs)+1)
  116. pr.Mapping[0] = mapping
  117. pr.Function = make([]*profile.Function, 0, len(pb.funcs))
  118. funcNames := make(map[string]struct{})
  119. var funcId, locId uint64
  120. for prg, f := range pb.funcs {
  121. fileName := prg.src.Name()
  122. funcId++
  123. f.f.ID = funcId
  124. f.f.Filename = fileName
  125. var funcName string
  126. if prg.funcName != "" {
  127. funcName = prg.funcName.String()
  128. } else {
  129. funcName = "<anonymous>"
  130. }
  131. // Make sure the function name is unique, otherwise the graph display merges them into one node, even
  132. // if they are in different mappings.
  133. if _, exists := funcNames[funcName]; exists {
  134. funcName += "." + strconv.FormatUint(f.f.ID, 10)
  135. } else {
  136. funcNames[funcName] = struct{}{}
  137. }
  138. f.f.Name = funcName
  139. pr.Function = append(pr.Function, &f.f)
  140. for pc, loc := range f.locs {
  141. locId++
  142. loc.ID = locId
  143. pos := prg.src.Position(prg.sourceOffset(int(pc)))
  144. loc.Line = []profile.Line{
  145. {
  146. Function: &f.f,
  147. Line: int64(pos.Line),
  148. },
  149. }
  150. loc.Mapping = mapping
  151. pr.Location = append(pr.Location, loc)
  152. }
  153. }
  154. pb.addSamples(&pr, &pb.root)
  155. return &pr
  156. }
  157. func (pb *profBuffer) addSamples(p *profile.Profile, n *profSampleNode) {
  158. if n.sample != nil {
  159. p.Sample = append(p.Sample, n.sample)
  160. }
  161. for _, child := range n.children {
  162. pb.addSamples(p, child)
  163. }
  164. }
  165. func (p *profiler) run() {
  166. ticker := time.NewTicker(profInterval)
  167. counter := 0
  168. for ts := range ticker.C {
  169. p.mu.Lock()
  170. left := len(p.trackers)
  171. if left == 0 {
  172. break
  173. }
  174. for {
  175. // This loop runs until either one of the VMs is signalled or all of the VMs are scanned and found
  176. // busy or deleted.
  177. if counter >= len(p.trackers) {
  178. counter = 0
  179. }
  180. tracker := p.trackers[counter]
  181. req := atomic.LoadInt32(&tracker.req)
  182. if req == profReqSampleReady {
  183. p.buf.addSample(tracker)
  184. }
  185. if atomic.LoadInt32(&tracker.finished) != 0 {
  186. p.trackers[counter] = p.trackers[len(p.trackers)-1]
  187. p.trackers[len(p.trackers)-1] = nil
  188. p.trackers = p.trackers[:len(p.trackers)-1]
  189. } else {
  190. counter++
  191. if req != profReqDoSample {
  192. // signal the VM to take a sample
  193. tracker.start = ts
  194. atomic.StoreInt32(&tracker.req, profReqDoSample)
  195. break
  196. }
  197. }
  198. left--
  199. if left <= 0 {
  200. // all VMs are busy
  201. break
  202. }
  203. }
  204. p.mu.Unlock()
  205. }
  206. ticker.Stop()
  207. p.running = false
  208. p.mu.Unlock()
  209. }
  210. func (p *profiler) registerVm() *profTracker {
  211. pt := new(profTracker)
  212. p.mu.Lock()
  213. if p.buf != nil {
  214. p.trackers = append(p.trackers, pt)
  215. if !p.running {
  216. go p.run()
  217. p.running = true
  218. }
  219. } else {
  220. pt.req = profReqStop
  221. }
  222. p.mu.Unlock()
  223. return pt
  224. }
  225. func (p *profiler) start() error {
  226. p.mu.Lock()
  227. if p.buf != nil {
  228. p.mu.Unlock()
  229. return errors.New("profiler is already active")
  230. }
  231. p.buf = new(profBuffer)
  232. p.mu.Unlock()
  233. return nil
  234. }
  235. func (p *profiler) stop() *profile.Profile {
  236. p.mu.Lock()
  237. trackers, buf := p.trackers, p.buf
  238. p.trackers, p.buf = nil, nil
  239. p.mu.Unlock()
  240. if buf != nil {
  241. k := 0
  242. for i, tracker := range trackers {
  243. req := atomic.LoadInt32(&tracker.req)
  244. if req == profReqSampleReady {
  245. buf.addSample(tracker)
  246. } else if req == profReqDoSample {
  247. // In case the VM is requested to do a sample, there is a small chance of a race
  248. // where we set profReqStop in between the read and the write, so that the req
  249. // ends up being set to profReqSampleReady. It's no such a big deal if we do nothing,
  250. // it just means the VM remains in tracing mode until it finishes the current run,
  251. // but we do an extra cleanup step later just in case.
  252. if i != k {
  253. trackers[k] = trackers[i]
  254. }
  255. k++
  256. }
  257. atomic.StoreInt32(&tracker.req, profReqStop)
  258. }
  259. if k > 0 {
  260. trackers = trackers[:k]
  261. go func() {
  262. // Make sure all VMs are requested to stop tracing.
  263. for {
  264. k := 0
  265. for i, tracker := range trackers {
  266. req := atomic.LoadInt32(&tracker.req)
  267. if req != profReqStop {
  268. atomic.StoreInt32(&tracker.req, profReqStop)
  269. if i != k {
  270. trackers[k] = trackers[i]
  271. }
  272. k++
  273. }
  274. }
  275. if k == 0 {
  276. return
  277. }
  278. trackers = trackers[:k]
  279. time.Sleep(100 * time.Millisecond)
  280. }
  281. }()
  282. }
  283. return buf.profile()
  284. }
  285. return nil
  286. }
  287. /*
  288. StartProfile enables execution time profiling for all Runtimes within the current process.
  289. This works similar to pprof.StartCPUProfile and produces the same format which can be consumed by `go tool pprof`.
  290. There are, however, a few notable differences. Firstly, it's not a CPU profile, rather "execution time" profile.
  291. It measures the time the VM spends executing an instruction. If this instruction happens to be a call to a
  292. blocking Go function, the waiting time will be measured. Secondly, the 'cpu' sample isn't simply `count*period`,
  293. it's the time interval between when sampling was requested and when the instruction has finished. If a VM is still
  294. executing the same instruction when the time comes for the next sample, the sampling is skipped (i.e. `count` doesn't
  295. grow).
  296. If there are multiple functions with the same name, their names get a '.N' suffix, where N is a unique number,
  297. because otherwise the graph view merges them together (even if they are in different mappings). This includes
  298. "<anonymous>" functions.
  299. The sampling period is set to 10ms.
  300. It returns an error if profiling is already active.
  301. */
  302. func StartProfile(w io.Writer) error {
  303. err := globalProfiler.p.start()
  304. if err != nil {
  305. return err
  306. }
  307. globalProfiler.w = w
  308. atomic.StoreInt32(&globalProfiler.enabled, 1)
  309. return nil
  310. }
  311. /*
  312. StopProfile stops the current profile initiated by StartProfile, if any.
  313. */
  314. func StopProfile() {
  315. atomic.StoreInt32(&globalProfiler.enabled, 0)
  316. pr := globalProfiler.p.stop()
  317. if pr != nil {
  318. _ = pr.Write(globalProfiler.w)
  319. }
  320. globalProfiler.w = nil
  321. }