Replace SpeedTracer with some other event/metric recording API

[niloc132]

GWT 2.12 will deprecate SpeedTracer - the application that can ingest the generated output no longer seems to be usable. We should plan to replace it with something else that can be consumed more easily by developers who don't already know how the compiler works.

The Flight Recorder APIs introduced in Java 11 might serve as a good choice here, allowing projects to generate details about consumed time/resources in their compilation for review.

[jnehlmeier]

I once did a PoC using OpenTracing (now OpenTelemetry) which was relatively easy to implement. If I remember correctly I only had to implement the speedtracer logger differently and reused all the events already published in compiler code.

https://groups.google.com/g/google-web-toolkit-contributors/c/n2ZzcStB0BI/m/y6lPDC-FBAAJ

It was nice to see the individual steps visualized and you could add logs to each step if you want to. But the visualizer had some trouble displaying everything smoothly because the compiler produced quite a bit data and I had the feeling that either the published start/stop events were not up-to-date or the compiler used some threads here and there which I didn't handle in the PoC. So this would need some work.

This was prior JFR APIs so JFR is probably a better fit now, possibly with a flame graph plugin if it exists.

[niloc132]

That sounds like a great idea too - I would slightly lean towards replacing the speedtracer api with something else entirely:

• so it is easier to add new features as needed/desired without an extra indirection step
• so individual callsites can use the underlying api to advertise specific details they know about directly

On the other hand, keeping the existing API would make it possible to have "multiple backends", though I'm really not sure what value that would bring.

I'd be curious if browsers (and the opentelemetry viewers) have gotten better fast enough that your prototype might be fast enough to work today?

Is your code available anywhere to take a look at?

[jnehlmeier]

so individual callsites can use the underlying api to advertise specific details they know about directly

OpenTelemetry allows attributes (key/value map) on spans and span events to publish interesting information available to the call site. It also allows publishing metrics.

I'd be curious if browsers (and the opentelemetry viewers) have gotten better fast enough that your prototype might be fast enough to work today?

Maybe. It was a very simple PoC and all speedtracer events ended up as OpenTracing spans. There were a lot of them with very small duration of just some micro seconds. I feel like those are more like "notification events" that something happend and took x-time and then should be stored as a span event, similar to storing logs on a span.

So I assume that the output can be greatly improved which would also improve performance of viewers.

Is your code available anywhere to take a look at?

I guess it is gone. Maybe in some old local backup lingering around but it is not pushed anywhere. I think it was a couple of hours of work implementing some start/end methods and commenting everything that had become red / unused.

--

But in general OpenTelemetry solves a higher level use-case than JFR as you would not do method profiling using OpenTelemetry. With OpenTelemetry you would capture broader compiler phases spanning multiple methods (= span) and then attach meaningful events/logs to these spans. So similar how you would do it using microservices but within a single process.

If we want to go very detailed then JFR is probably a better fit.

[niloc132]

Some notes on the existing speedtracer usage, as I played with building jfr Events

• GWT's DashboardNotifier is probably not the right extension point, it only recieves the event name and start/duration, none of the other data collected about the event
• The data array is for key/value pairs of strings, and can be passed when the event starts or ends, or appended mid-event via a call to addData
• Data is only written to a log file, as a series of JSON objects, optionally wrapped in HTML. It is possible to stream to some other writer - tests do this - but you can't use this for the real compiler, which always uses the singleton instance. It isn't possible to replace the event writing mechanism with something else, at least with the current implementation.
• There is a fixed set of eventType strings, which come from an interface EventType (which also provides a color, which is not passed to the dashboard). On the other hand, any key can be used for data - but in reality there is a fixed set here as well:
  • start() has 56 callsites with no event data, 47 with exactly one key (typically phase or optimizer), 4 calls with two keys (phase, module, moduleName, class, type, argument, caller, and zero with more than that.
  • addData() has 3 external calls with one key, and one call with two keys
  • end() has many calls with no data, and 16 calls with one key (all are didChange).
• Another key that speedtracer itself adds is baseTime, which is a constant within a process, allowing events from multiple processes to be merged. There is no support for this merging within GWT itself, and in theory this could be added to the log file just once... but that's not how this is implemented today. (Also see the last bullet, merging external processes doesn't work anyway?)
• The one other piece of data provided to the dashboard is the dev mode session instance itself, which is always null except under legacy dev mode. Note that going by a TODO in DashboardNotifier, it was never intended to be used this way, but instead there were supposed to be other methods added for non-devmode cases.
• Apparently SpeedTracer corrupts its own output files if you use the ExternalPermutationWorkerFactory, so either limit worker count, or only use the threaded impl. I don't see a way for ST to be asked to make a new file per worker - when multiple worker processes attempt to write to the same file, they partially overwrite each other.

The JFR event type has a limited set of data types we can work with:

Supported field types are the Java primitives: boolean, char, byte, short, int, long, float, and double. Supported reference types are: String, Thread and Class. Arrays, enums, and other reference types are silently ignored and not included.

This prevents us from having a general map/array of extra contents that should be reported.

Based just on the above, a fairly simple proposal:

• Leave speed tracer deprecated/disabled, let the existing calls delegate to a new mechanism for any existing external event producers. I presume there are no existing consumers... but just in case I think we leave it another version. Also deprecate DashboardNotifier/Factory for removal in a future release.
• Provide a new API that manages the stack of events a builder pattern when creating/modifying/ending an event to tweak a fixed set of fields - callers should use that instead to specify the details they want in the output
• Warn if unrecognized keys are used, for any legacy invocations - or just error out

I have a draft branch that does this much, and am doubting that it is this simple, or maybe there are better jfr readers out there than intellij and missioncontrol - it is hard to browse the nested events. Sample jfr file this generates: https://colinalworth.com/gwt-jfr/flight.jfr Sample branch: https://github.com/niloc132/gwt/commits/10007-jfr-sample

Next step will be to try more specific events for each type of operation, and see if that is more easily readable. Might well end up needing to build our own reader though, or make some very specific dashboard/filtering in jmc.