Corresponding Bugzilla bug: Bug 1919845.
A "flow" is a way to associate markers with each other, across threads/processes and across different marker types. Example flows could be: a network request, a paint, a touch event, a setTimeout, etc. Multiple markers of different types can then be associated with each other by mentioning the same flow in their fields. And a single marker can be associated with multiple flows, for example a Paint marker could be associated with the flow for the paint itself, the flow for the refresh driver tick it was a part of, the flow for the style flush which requested the paint, and the flow for the composite which put this paint onto the screen.
Example profile: https://share.firefox.dev/4hxDJpt
This example profile was gathered on a build which contains a WIP patch from bug 1919845.
User story: I have a marker for an image request (nsImageLoadingContent::LoadImage). I want to find the marker for the DOM load event which was fired for this image request.
Here's how I would find the DOM load using the current UI, on this profile:
I start at the nsImageLoadingContent::LoadImage marker. It has a flow field with the value 000000010924c9c00.
Click on the marker, copy 000000010924c9c00 from the tooltip. This is our flow ID.
Search for 000000010924c9c00.
There are four matching markers. All of these markers are part of the same flow. (In this example we don't have to worry about flow ID reuse.)
One of the matching markers is a nsImageLoadingContent::FireEventd marker:
nsImageLoadingContent::FireEventd — nsImageLoadingContent::FireEventd (flow1=000000010924c9c00,flow2=0000000108ef89500)
This marker has a flow2 field. Click the marker, copy 0000000108ef89500.
Now search for 0000000108ef89500. There are three matching markers - one is the nsImageLoadingContent::FireEventd marker we just selected, the other two are AsyncEventDispatcher::Run and ~LoadBlockingAsyncEventDispatcher.
~LoadBlockingAsyncEventDispatcher terminates the flow with the flow ID 0000000108ef89500, because it has this ID in its terminatingFlow field.
The AsyncEventDispatcher::Run has 0000000108ef89500 in its flow1 field. Its flow2 field points to yet another flow: 000000010bc7e2000.
If we search for 000000010bc7e2000, this brings us to a DOMEvent marker. (In this example profile, that DOMEvent marker isn't the actual DOMEvent marker, because the implementation isn't polished yet - the marker we found is just an extra helper marker with roughly the same timestamp.)
Success! This is the DOM event marker we were looking for. We couldn't have found this with the existing markers - the DOMEvent marker just doesn't contain enough information to match the right marker to our nsImageLoadingContent::LoadImage marker.
What UI do we want?
Just putting in free-form strings, as in the example profile, is a good start. But without any UI changes, it can be frustrating to use.
The biggest problem is that the active flows are not tracked. Concretely, the biggest problem is that reused flow IDs cause misleading search results: the search by flow ID finds markers which are in a different flow, just because that other flow happened to use the same flow ID. The search doesn't know about "terminating flows".
The most pressing needs are:
- The ability to search by flow, not just flow ID. (See the "Data representation" section below.)
- The ability to navigate between the previous and the next marker within a flow.
Strawman proposal
- Add two new marker field type: FlowID and TerminatingFlowID. In the JSON serialization, these fields are serialized as strings. (If we ever add a binary format, we can represent flow IDs as u64 in that format.)
- In the tooltip, for a flow field, have three buttons inside the tooltip field row: "Previous", "Next", and "View all".
- Add a special marker search syntax:
flow:000000010924c9c00;10213.54 (flow ID and in-flow-timestamp, matches all markers which belong to this flow)
- Clicking "View all" changes the current marker search to one which shows all markers belonging to that flow. Use the timestamp of the clicked marker in the search.
- Clicking the next/previous buttons should find the next/previous marker in that flow, select the thread that contains that marker, scroll the marker chart track into view, select the marker, and show its tooltip in the sticky state.
- To navigate between connected flows, just click the relevant buttons in the other field.
Tracking flows across threads
You want to go between threads. In the example the markers belonging to the flow we were looking at were all on the same thread, but generally they'll be on different threads.
Navigating through flows becomes a lot more useful when the markers are on different threads.
If you just had the ability to search by flow, you could sort of get by by selecting all the tracks, but it's not ideal.
Data representation
This is heavily inspired by Perfetto.
Here's the "flows" field in the Protobuf definition: https://github.com/google/perfetto/blob/adb90dc0b61030e937326bb20c2118bc3110e7f5/protos/perfetto/trace/track_event/track_event.proto#L204-L222
There are flows and flow IDs. A flow ID is usually generated from a pointer, whose address is XORed with a per-process UUID. Since pointer addresses can get reused, two different flows may have the same flow ID. If you have a flow ID, how do you determine which flow it refers to? It depends on the timestamp of the marker with the flow ID. There is a notion of "active flows" for each timestamp. If a flow ID is used in a TerminatingFlowID field, then this marker terminates the flow - starting at this marker's timestamp, that flow is no longer active. So if you look at markers ordered by time, and you see a flow ID and there exists no active flow with that flow ID, then this marker starts a new flow for that flow ID and puts it into the list of active flows.
So markers can:
- start a flow, by having a FlowID field which is set to a flow ID which is not part of the active flows
- terminate a flow, by mentioning the flow ID in a TerminatingFlowID field
- connect multiple flows, by having multiple fields of type FlowID.
Flows can cross processes because flow IDs are more-or-less globally unique.
In Perfetto's representation, the flows and terminating flows for an event are just a list of IDs. In our representation, we would have a separate marker field for each flow / terminating flow. Is this good? It would at least allow us to name the flows. For example, if your flow is generated from a imgIRequest* pointer, you could put the flow ID into a field that's named request. Not sure if that's useful. Having a different representation means that it would be harder to convert perfetto traces to the Firefox profiler format.
┆Issue is synchronized with this Jira Task
Corresponding Bugzilla bug: Bug 1919845.
A "flow" is a way to associate markers with each other, across threads/processes and across different marker types. Example flows could be: a network request, a paint, a touch event, a setTimeout, etc. Multiple markers of different types can then be associated with each other by mentioning the same flow in their fields. And a single marker can be associated with multiple flows, for example a Paint marker could be associated with the flow for the paint itself, the flow for the refresh driver tick it was a part of, the flow for the style flush which requested the paint, and the flow for the composite which put this paint onto the screen.
Example profile: https://share.firefox.dev/4hxDJpt
This example profile was gathered on a build which contains a WIP patch from bug 1919845.
User story: I have a marker for an image request (
nsImageLoadingContent::LoadImage). I want to find the marker for the DOMloadevent which was fired for this image request.Here's how I would find the DOM load using the current UI, on this profile:
I start at the
nsImageLoadingContent::LoadImagemarker. It has aflowfield with the value 000000010924c9c00.Click on the marker, copy 000000010924c9c00 from the tooltip. This is our flow ID.
Search for 000000010924c9c00.
There are four matching markers. All of these markers are part of the same flow. (In this example we don't have to worry about flow ID reuse.)
One of the matching markers is a
nsImageLoadingContent::FireEventdmarker:nsImageLoadingContent::FireEventd — nsImageLoadingContent::FireEventd (flow1=000000010924c9c00,flow2=0000000108ef89500)This marker has a flow2 field. Click the marker, copy 0000000108ef89500.
Now search for 0000000108ef89500. There are three matching markers - one is the
nsImageLoadingContent::FireEventdmarker we just selected, the other two areAsyncEventDispatcher::Runand~LoadBlockingAsyncEventDispatcher.~LoadBlockingAsyncEventDispatcherterminates the flow with the flow ID 0000000108ef89500, because it has this ID in itsterminatingFlowfield.The
AsyncEventDispatcher::Runhas 0000000108ef89500 in its flow1 field. Its flow2 field points to yet another flow: 000000010bc7e2000.If we search for 000000010bc7e2000, this brings us to a DOMEvent marker. (In this example profile, that DOMEvent marker isn't the actual DOMEvent marker, because the implementation isn't polished yet - the marker we found is just an extra helper marker with roughly the same timestamp.)
Success! This is the DOM event marker we were looking for. We couldn't have found this with the existing markers - the DOMEvent marker just doesn't contain enough information to match the right marker to our
nsImageLoadingContent::LoadImagemarker.What UI do we want?
Just putting in free-form strings, as in the example profile, is a good start. But without any UI changes, it can be frustrating to use.
The biggest problem is that the active flows are not tracked. Concretely, the biggest problem is that reused flow IDs cause misleading search results: the search by flow ID finds markers which are in a different flow, just because that other flow happened to use the same flow ID. The search doesn't know about "terminating flows".
The most pressing needs are:
Strawman proposal
flow:000000010924c9c00;10213.54(flow ID and in-flow-timestamp, matches all markers which belong to this flow)Tracking flows across threads
You want to go between threads. In the example the markers belonging to the flow we were looking at were all on the same thread, but generally they'll be on different threads.
Navigating through flows becomes a lot more useful when the markers are on different threads.
If you just had the ability to search by flow, you could sort of get by by selecting all the tracks, but it's not ideal.
Data representation
This is heavily inspired by Perfetto.
Here's the "flows" field in the Protobuf definition: https://github.com/google/perfetto/blob/adb90dc0b61030e937326bb20c2118bc3110e7f5/protos/perfetto/trace/track_event/track_event.proto#L204-L222
There are flows and flow IDs. A flow ID is usually generated from a pointer, whose address is XORed with a per-process UUID. Since pointer addresses can get reused, two different flows may have the same flow ID. If you have a flow ID, how do you determine which flow it refers to? It depends on the timestamp of the marker with the flow ID. There is a notion of "active flows" for each timestamp. If a flow ID is used in a TerminatingFlowID field, then this marker terminates the flow - starting at this marker's timestamp, that flow is no longer active. So if you look at markers ordered by time, and you see a flow ID and there exists no active flow with that flow ID, then this marker starts a new flow for that flow ID and puts it into the list of active flows.
So markers can:
Flows can cross processes because flow IDs are more-or-less globally unique.
In Perfetto's representation, the flows and terminating flows for an event are just a list of IDs. In our representation, we would have a separate marker field for each flow / terminating flow. Is this good? It would at least allow us to name the flows. For example, if your flow is generated from a
imgIRequest*pointer, you could put the flow ID into a field that's namedrequest. Not sure if that's useful. Having a different representation means that it would be harder to convert perfetto traces to the Firefox profiler format.┆Issue is synchronized with this Jira Task