FAQ
Hello,

I'm trying to profile an application I wrote, while running in specific
situations in which I measure a slowdown which I don't understand how it is
caused. I'm using Go 1.6 on OSX.

This is the output of top20:

(pprof) top20
3.39s of 3.57s total (94.96%)
Dropped 54 nodes (cum <= 0.02s)
Showing top 20 nodes out of 136 (cum >= 0.17s)
       flat flat% sum% cum cum%
      1.84s 51.54% 51.54% 1.84s 51.54% runtime.mach_semaphore_signal
      0.59s 16.53% 68.07% 0.59s 16.53% runtime.mach_semaphore_wait
      0.35s 9.80% 77.87% 0.35s 9.80% runtime.usleep
      0.14s 3.92% 81.79% 0.14s 3.92% runtime.cgocall
      0.09s 2.52% 84.31% 0.09s 2.52% runtime.memclr
      0.05s 1.40% 85.71% 0.05s 1.40% runtime.memmove
      0.04s 1.12% 86.83% 0.18s 5.04% main.(*HwDmaChannel).xfer
      0.04s 1.12% 87.96% 0.05s 1.40%
  ndsemu/raster3d.(*HwEngine3d).Draw3D
      0.04s 1.12% 89.08% 0.04s 1.12% runtime.mach_semaphore_timedwait
      0.04s 1.12% 90.20% 0.04s 1.12% runtime.scanobject
      0.03s 0.84% 91.04% 0.03s 0.84% ndsemu/e2d.e2dMixer_Normal
      0.03s 0.84% 91.88% 0.03s 0.84% runtime/internal/atomic.Xadd
      0.02s 0.56% 92.44% 0.12s 3.36% runtime.lock
      0.02s 0.56% 93.00% 0.02s 0.56% runtime.scanstack
      0.02s 0.56% 93.56% 0.02s 0.56% runtime/internal/atomic.Load
      0.01s 0.28% 93.84% 0.10s 2.80% main.(*HwGeometry).WriteGXFIFO
      0.01s 0.28% 94.12% 0.03s 0.84% ndsemu/arm.(*Cpu).opRead32
      0.01s 0.28% 94.40% 0.16s 4.48% ndsemu/arm.(*Cpu).opWrite32
      0.01s 0.28% 94.68% 0.07s 1.96%
  ndsemu/e2d.(*HwEngine2d).DrawBGAffine
      0.01s 0.28% 94.96% 0.17s 4.76% runtime.call32

I've also attached the SVG produced by "web runtime.mach_semaphore_signal".

I'm at loss on how to parse this profile. It looks like 50% of execution
time is spent within the runtime for some.. semaphore contention? I don't
know. Also the callgraph shown in the SVG goes very deep within the runtime
and I can't follow it.

Assuming there is some contention/lock between goroutines/channels or
something like that, is there some other tool I could try that could give
me a different picture that helps me spotting the problem? Or can anybody
point me to any resource on how to analyze this kind of problems?

I can provide binary and profile dump to anybody willing to help (and it is
an open source project anyway).

Giovanni Bajo


--
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+unsubscribe@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Search Discussions

  • Dave Cheney at Feb 28, 2016 at 7:43 pm
    Due to a kernel bug on versions of OS X less than el captain, profiling is unreliable on OS X. You can either upgrade to El Capitan or patch your kernel as a workaround.

    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Giovanni Bajo at Feb 28, 2016 at 9:50 pm
    I'm running the latest El Capitan (10.11.3)
    On Sunday, February 28, 2016 at 8:43:01 PM UTC+1, Dave Cheney wrote:

    Due to a kernel bug on versions of OS X less than el captain, profiling is
    unreliable on OS X. You can either upgrade to El Capitan or patch your
    kernel as a workaround.
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.
  • Dave Cheney at Feb 28, 2016 at 10:56 pm
    Thanks for confirming, I'm sorry I was not clearer before, many OSX users
    are not aware of the issues with pprof and OSX.

    Looking at your svg two things come to mind

    1. are you doing a LOT of channel sends and receives ? Perhaps the amount
    of work you are doing vs the amount you are handing off between goroutines
    is relatively small
    2. are you generating a lot of garbage ? I recommend running your program
    with GODEBUG=gctrace=1 and looking at the frequency of the gc trace output,
    if it is continuous, that could be a sign you are generating too much
    garbage.
    On Monday, 29 February 2016 08:50:51 UTC+11, Giovanni Bajo wrote:

    I'm running the latest El Capitan (10.11.3)
    On Sunday, February 28, 2016 at 8:43:01 PM UTC+1, Dave Cheney wrote:

    Due to a kernel bug on versions of OS X less than el captain, profiling
    is unreliable on OS X. You can either upgrade to El Capitan or patch your
    kernel as a workaround.
    --
    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+unsubscribe@googlegroups.com.
    For more options, visit https://groups.google.com/d/optout.

Related Discussions

Discussion Navigation
viewthread | post
Discussion Overview
groupgolang-nuts @
categoriesgo
postedFeb 28, '16 at 6:20p
activeFeb 28, '16 at 10:56p
posts4
users2
websitegolang.org

2 users in discussion

Dave Cheney: 2 posts Giovanni Bajo: 2 posts

People

Translate

site design / logo © 2021 Grokbase