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