ethercrow / opentelemetry-haskell

The OpenTelemetry Haskell Client https://opentelemetry.io
Other
65 stars 6 forks source link

Make GC sync visible #42

Closed expipiplus1 closed 3 years ago

expipiplus1 commented 3 years ago

It would be great to hook into longGCSync and longGCSyncEnd to get the GC sync waits highlighted in the trace. It could be that these are already visible in the eventlog, in which case no hooks are needed.

(options described here: https://downloads.haskell.org/~ghc/latest/docs/html/users_guide/runtime_control.html#rts-flag---long-gc-sync)

ethercrow commented 3 years ago

Interesting, I wasn't aware of these hooks or even the notion of possibly long GC sync pauses.

  -- garbage collection
  | RequestSeqGC       { }
  | RequestParGC       { }
  | StartGC            { }
  | GCWork             { }
  | GCIdle             { }
  | GCDone             { }
  | EndGC              { }
  | GlobalSyncGC       { }
  | GCStatsGHC         { heapCapset   :: {-# UNPACK #-}!Capset
                       , gen          :: {-# UNPACK #-}!Int
                       , copied       :: {-# UNPACK #-}!Word64
                       , slop, frag   :: {-# UNPACK #-}!Word64
                       , parNThreads  :: {-# UNPACK #-}!Int
                       , parMaxCopied :: {-# UNPACK #-}!Word64
                       , parTotCopied :: {-# UNPACK #-}!Word64
                       }

If I understand the eventlog protocol here correctly, this pause is the period between Request*GC and StartGC.

Currently we emit gc spans according to StartGC and EndGC events, it's done here. I guess adding an appropriate handler for Request*GC would be enough to have GC syncs represented in trace data.

I'll probably have time for it on a weekend. If you want to do it that's also cool.

expipiplus1 commented 3 years ago

I don't think that I have the time for it soon, but I'm not in any massive hurry either!

ethercrow commented 3 years ago

Now (as of https://github.com/ethercrow/opentelemetry-haskell/commit/686bbdea7250dfd9b2136791bb257e45cfdd7286) there are gc_sync spans:

Screen Shot 2020-12-07 at 7 29 21 AM
expipiplus1 commented 3 years ago

Amazing! Thank you!

On Mon, Dec 7, 2020, 2:31 PM Dmitry Ivanov notifications@github.com wrote:

Now there are gc_sync spans:

[image: Screen Shot 2020-12-07 at 7 29 21 AM] https://user-images.githubusercontent.com/222467/101317061-0c565d80-385e-11eb-81df-fb9319842899.png

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/ethercrow/opentelemetry-haskell/issues/42#issuecomment-739700519, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAGRJXHRIMRJ2RBLT62BBNDSTRZEHANCNFSM4UKDXPUQ .

expipiplus1 commented 3 years ago

@bgamari ^

bgamari commented 3 years ago

Indeed the meaning of these events has never been well documented. Since you pinged I finally added some proper documentation: https://gitlab.haskell.org/ghc/ghc/-/merge_requests/4580. Do comment on the MR if you have any questions.