Re: [go-nuts] Mutex profiling question

['robert engels' via golang-nuts]

Anyone have any idea on the high internal lock time on findRunnable? On Jul 18, 2024, at 10:36 AM, robert engels <reng...@ix.netcom.com> wrote: Looks like the name was changed to runtimecontentionstacks Much better now… (pprof) tree Showing nodes accounting for 481.75ms, 100% of 481.75ms total Dropped 39 nodes (cum <= 2.41ms) ----------------------------------------------------------+-------------       flat  flat%   sum%        cum   cum%   calls calls% + context    ----------------------------------------------------------+-------------                                           401.25ms 83.51% |   runtime.findRunnable (inline)                                            35.26ms  7.34% |   runtime.sysmon (inline)                                            17.37ms  3.62% |   runtime.stopm (inline)                                            14.01ms  2.92% |   runtime.saveBlockEventStack (inline)                                             6.07ms  1.26% |   runtime.goschedImpl (inline)                                             1.52ms  0.32% |   runtime.schedule (inline)                                             1.30ms  0.27% |   sync.(*Mutex).Unlock (inline)                                             1.30ms  0.27% |   github.com/robaho/go-trader/internal/exchange.sendMarketData (inline)                                             1.17ms  0.24% |   sync.(*Map).Swap (inline)                                             1.16ms  0.24% |   github.com/robaho/go-trader/internal/exchange.(*grpcServer).Connection (inline)   480.46ms 99.73% 99.73%   480.46ms 99.73%                | runtime.unlock but this seems suspect, that finding the runnable should consume so much time. Is this a side effect of the scheduler, and it is really blocked in the unlock call waiting for another routine to be runnable? On Jul 18, 2024, at 10:14 AM, 'Robert Engels' via golang-nuts <golang-nuts@googlegroups.com> wrote: I found this issue, https://github.com/golang/go/issues/57071 and tried running with  GODEBUG=profileruntimelocks=1 but it made no difference in the output. I am using Go 1.22.4 on OSX. Any ideas how I can determine what is causing this high contention shown below: (pprof) tree Showing nodes accounting for 4440.35ms, 100% of 4440.35ms total ----------------------------------------------------------+-------------       flat  flat%   sum%        cum   cum%   calls calls% + context      ----------------------------------------------------------+-------------  4324.17ms 97.38% 97.38%  4324.17ms 97.38%                | runtime._LostContendedRuntimeLock ----------------------------------------------------------+-------------                                           116.17ms   100% |   sync.(*Map).Swap (inline)   116.17ms  2.62%   100%   116.17ms  2.62%                | sync.(*Mutex).Unlock ----------------------------------------------------------+-------------                                           116.17ms   100% |   github.com/robaho/go-trader/internal/exchange.(*grpcServer).massquote          0     0%   100%   116.17ms  2.62%                | github.com/robaho/go-trader/internal/exchange.(*exchange).Quote                                           116.17ms   100% |   github.com/robaho/go-trader/internal/exchange.sendMarketData -- 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. To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/25E80A1A-DFA8-4BA6-A49C-0F8F656DFA81%40me.com. -- 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. To view this discussion on the web visit https://groups.google.com/d/msgid/golang-nuts/8F118071-A663-4CD8-963A-0F549C2D7E9E%40me.com.