clinicjs / node-clinic

Clinic.js diagnoses your Node.js performance issues
https://clinicjs.org
MIT License
5.65k stars 124 forks source link

Visualize gc-events in UI #404

Open AndreasMadsen opened 6 years ago

AndreasMadsen commented 6 years ago

From https://github.com/nearform/node-clinic-doctor/pull/42

@mcollina There is no visualization, you can look at the docs if you would like to see it. The problem with gc-stats is that it doesn't expose all events. I just exposes some always and others only sometimes. It is a bit confusing. The trace_events shows all the events.

Using the trace_events is not currently possible because there I no way of synchronizing the trace_events clock with another clock. The V8 team is currently working on this: https://github.com/nodejs/node/issues/17349

AlanSl commented 6 years ago

Are the things suggested in the recent comments on that issue things we can start working with or are we still dependent on a patch to V8? If it's possible to get usable data yet can you upload a sample data dump or two?

mcollina commented 6 years ago

This is already implemented and it does not need a special build of V8, you should be able to implement it straight away.

BridgeAR commented 6 years ago

Was there any update on this @AlanSl? And are we not already using trace_events? I am pretty sure we use them in Bubbleprof.

AndreasMadsen commented 6 years ago

@BridgeAR trace_events is already used and they are also syncronized.

BridgeAR commented 6 years ago

@AndreasMadsen in that case this should be closed, right?

mcollina commented 6 years ago

No we can't, because we are not visualizing the gc events in the memory chart.

AlanSl commented 6 years ago

How much work would it be to expose the GC data to the UI? Would it be in a form like an array of arrays or objects of timestamps and how much memory was garbage collected like:

[
  { time: someTimeStamp, gcsize: 12345.6789 },
  { time: someTimeStamp, gcsize: 123.456789 }
  // etc
]

If so visualising it would be pretty easy, assuming the amounts garbage collected at any one point rarely greatly exceed the other items on the Y axis, we'd just choose a contrasting but not too contrasting colour (e.g. white at ~0.8 opacity) and scatter dots showing the timing (X) and size (Y) of the events (as a single path with multiple M defs so performance is okay even with thousands of gc events).

AndreasMadsen commented 6 years ago

@AlanSl The data that is relevant is already exposed to the UI internals. https://github.com/nearform/node-clinic-doctor/blob/master/index.js#L165

AlanSl commented 6 years ago

Great, and I see it's defined in format/trace-event-decoder.js.

They have start/finish times and durations but no data on amounts of memory recovered or equivalent - so presumably we'd just want to somehow:

a) highlight the time periods during which a GC event was in progess b) maybe also allow the user to see what type of GC event it was at any given point.

It looks like the possible types are:

  'V8.GCScavenger' // appears to be by far the most common
  'V8.GCMarkSweepCompact' // aggregated from GCFinalizeMC and GCIncrementalMarkingStart
  'V8.GCCompactor' // is marked "purpose unknown"
  'V8.GCFinalizeMCReduceMemory' // is marked "purpose unknown"
  'V8.GCPhantomHandleProcessingCallback' // is marked "purpose unknown"

Are these GC event time intervals interesting/relevant to any charts other than Memory? For example I think they could be useful for understanding some event loop anomalies judging based on an earlier discussion with Dave.

mcollina commented 6 years ago

I think the data about memory collected might be available somewhere. Il giorno lun 13 ago 2018 alle 12:56 Alan Slater notifications@github.com ha scritto:

Great, and I see it's defined in format/trace-event-decoder.js.

They have start/finish times and durations but no data on amounts of memory recovered or equivalent - so presumably we'd just want to somehow:

a) highlight the time periods during which a GC event was in progess b) maybe also allow the user to see what type of GC event it was at any given point.

It looks like the possible types are:

'V8.GCScavenger' // appears to be by far the most common 'V8.GCMarkSweepCompact' // aggregated from GCFinalizeMC and GCIncrementalMarkingStart 'V8.GCCompactor' // is marked "purpose unknown" 'V8.GCFinalizeMCReduceMemory' // is marked "purpose unknown" 'V8.GCPhantomHandleProcessingCallback' // is marked "purpose unknown"

Are these GC event time intervals interesting/relevant to any charts other than Memory? For example I think they could be useful for understanding some event loop anomalies judging based on an earlier discussion with Dave.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/nearform/node-clinic-doctor/issues/46#issuecomment-412481006, or mute the thread https://github.com/notifications/unsubscribe-auth/AADL41I46KEg1WK3j_PC1T-TkV71zPwyks5uQVtIgaJpZM4Q4QC5 .

mcollina commented 6 years ago

These events are interesting also for the CPU diagram, but I wouldn’t highlight there. Some of the spikes are caused by the GC. Il giorno lun 13 ago 2018 alle 15:08 Matteo Collina < matteo.collina@gmail.com> ha scritto:

I think the data about memory collected might be available somewhere. Il giorno lun 13 ago 2018 alle 12:56 Alan Slater notifications@github.com ha scritto:

Great, and I see it's defined in format/trace-event-decoder.js.

They have start/finish times and durations but no data on amounts of memory recovered or equivalent - so presumably we'd just want to somehow:

a) highlight the time periods during which a GC event was in progess b) maybe also allow the user to see what type of GC event it was at any given point.

It looks like the possible types are:

'V8.GCScavenger' // appears to be by far the most common 'V8.GCMarkSweepCompact' // aggregated from GCFinalizeMC and GCIncrementalMarkingStart 'V8.GCCompactor' // is marked "purpose unknown" 'V8.GCFinalizeMCReduceMemory' // is marked "purpose unknown" 'V8.GCPhantomHandleProcessingCallback' // is marked "purpose unknown"

Are these GC event time intervals interesting/relevant to any charts other than Memory? For example I think they could be useful for understanding some event loop anomalies judging based on an earlier discussion with Dave.

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/nearform/node-clinic-doctor/issues/46#issuecomment-412481006, or mute the thread https://github.com/notifications/unsubscribe-auth/AADL41I46KEg1WK3j_PC1T-TkV71zPwyks5uQVtIgaJpZM4Q4QC5 .