Le mardi 20 septembre 2016 17:17:37 UTC+2, mhhcbon a écrit : > > Hi, > > on my way to learn to use pprof, i now face some intriguing results with > lots of runtime.* calls, > > can you help me to understand what those call are and how i should care > about ? > > (pprof) top30 > 8720ms of 14380ms total (60.64%) > Dropped 118 nodes (cum <= 71.90ms) > Showing top 30 nodes out of 143 (cum >= 3800ms) > flat flat% sum% cum cum% > 720ms 5.01% 5.01% 1050ms 7.30% runtime.scanobject > 700ms 4.87% 9.87% 3640ms 25.31% runtime.gentraceback > 670ms 4.66% 14.53% 1780ms 12.38% runtime.pcvalue > 490ms 3.41% 17.94% 490ms 3.41% runtime.readvarint > 420ms 2.92% 20.86% 910ms 6.33% runtime.step > 420ms 2.92% 23.78% 420ms 2.92% runtime/internal/atomic.Xchg > 380ms 2.64% 26.43% 380ms 2.64% runtime.heapBitsForObject > 340ms 2.36% 28.79% 1580ms 10.99% runtime.mallocgc > 310ms 2.16% 30.95% 360ms 2.50% runtime.gopark > 270ms 1.88% 32.82% 270ms 1.88% runtime.heapBitsSetType > 260ms 1.81% 34.63% 510ms 3.55% runtime.scanblock > 250ms 1.74% 36.37% 250ms 1.74% runtime/internal/atomic.Cas > 240ms 1.67% 38.04% 4040ms 28.09% github.com/mh-cbon/chan/stream > .(*Transform).Push > 240ms 1.67% 39.71% 1210ms 8.41% runtime.schedule > 230ms 1.60% 41.31% 230ms 1.60% runtime.newdefer > 220ms 1.53% 42.84% 320ms 2.23% runtime.deferreturn > 210ms 1.46% 44.30% 260ms 1.81% bytes.genSplit > 210ms 1.46% 45.76% 260ms 1.81% runtime.greyobject > 210ms 1.46% 47.22% 6080ms 42.28% runtime.systemstack > 200ms 1.39% 48.61% 210ms 1.46% runtime.acquireSudog > 200ms 1.39% 50.00% 1760ms 12.24% runtime.scanframeworker > 190ms 1.32% 51.32% 790ms 5.49% sync.(*Mutex).Lock > 180ms 1.25% 52.57% 180ms 1.25% runtime.gogo > 180ms 1.25% 53.82% 180ms 1.25% runtime.memmove > 170ms 1.18% 55.01% 790ms 5.49% runtime.chanrecv > 170ms 1.18% 56.19% 530ms 3.69% runtime.lock > 170ms 1.18% 57.37% 170ms 1.18% runtime.usleep > 160ms 1.11% 58.48% 220ms 1.53% runtime.siftdownTimer > 160ms 1.11% 59.60% 160ms 1.11% runtime/internal/atomic.Load > 150ms 1.04% 60.64% 3800ms 26.43% main.main.func2 > > Also, I m not totally comfortable with flat Vs cum meanings, > and those basics are not covered in > https://blog.golang.org/profiling-go-programs > > Can you take a moment to explain those two notions ? > > One more Q. In this pprof output > > (pprof) list Push > Total: 14.38s > ROUTINE ======================== github.com/mh-cbon/chan/stream.(*Readable > ).Push in /home/mh-cbon/gow/src/github.com/mh-cbon/chan/stream/reader.go > 0 1.65s (flat, cum) 11.47% of Total > . . 79:func (s *Readable) Push(b interface{}) { > . . 80: for s.Paused() { > . . 81: <- time.After(time.Millisecond * 1) > . . 82: } > . . 83: s.writeMutex.Lock() > . 10ms 84: defer s.writeMutex.Unlock() > . . 85: for _, o := range s.Pipes { > . 1.64s 86: o.Write(b) > . . 87: } > . . 88:} > . . 89:func (s *Readable) Catch(fn ErrorFunc) Stream > { > . . 90: s.E = append(s.E, fn) > . . 91: return s > ROUTINE ======================== github.com/mh-cbon/chan/stream.(* > Transform).Push in /home/mh-cbon/gow/src/github.com/mh-cbon/chan/stream/ > transform.go > 240ms 4.13s (flat, cum) 28.72% of Total > . . 72: } else { > . . 73: s.Push(b) > . . 74: } > . . 75:} > . . 76:// Push writes data down in the stream. > 40ms 40ms 77:func (s *Transform) Push(b interface{}) { > . . 78: // s.pipeMutex.Lock() > . . 79: // defer s.pipeMutex.Unlock() > 190ms 190ms 80: for _, o := range s.Pipes { > 10ms 3.90s 81: o.Write(b) > . . 82: } > . . 83:} > . . 84:func (s *Transform) Catch(fn ErrorFunc) > Stream { > . . 85: s.E = append(s.E, fn) > . . 86: return s > > > > The tow methods are very similar, but Transform.Push shows 190ms for the > for loop, where Readable.Push does not show anything. > How to understand this ? > > > thanks! >
-- You received this message because you are subscribed to the Google Groups "golang-nuts" group. To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts+unsubscr...@googlegroups.com. For more options, visit https://groups.google.com/d/optout.
