firefox-devtools / profiler

Firefox Profiler — Web app for Firefox performance analysis
https://profiler.firefox.com
Mozilla Public License 2.0
1.19k stars 388 forks source link

changing profile-logic for network panel #1122

Closed zoepage closed 6 years ago

zoepage commented 6 years ago

After working on #1110, I've realized we might have to create a new profile logic for the network panel.

Right now we use the tracing markers as our data source: https://github.com/devtools-html/perf.html/blob/65796f2124f7e67bfbab28438126682edf78b51c/src/profile-logic/profile-data.js#L1309

But this seems not a 100% fit for our needs as we either get a marker with startTime and endTime, so we can display the duration (this is good) or we just get the startTime and no duration (not so good). One possibility would be, we could display the startTime as a vertical stroke, but I am not sure if this would improve the quality of the data visualization.

Another idea that @gregtatum did bring up today was to use http://www.softwareishard.com/blog/har-12-spec/#timings (which I also discussed with @mstange last week). This is the data we are using for the network panel in devTools. That would be definitely be interesting for the network sidebar.

What are your thoughts on this @gregtatum @mstange @past @julienw?

gregtatum commented 6 years ago

I brought up the HAR suggestion primarily as an example to look at what other folks have been up to with working with network data, especially from what they are finding useful. I was thinking there might be some useful nuggets to consider in there. Although maybe it's just a distraction since we already have the data in gecko profiles.

The network marker payloads are created here: in ProfilerMarkerPayload.cpp.

Here is a search where all of the network markers are being created.

The current flow type definition is a bit looser in the different states, making everything conditional. Perhaps it would be nicer to have it list out the distinct different payload shapes using a union instead. I read through the implementation a bit and tried to construct something a bit stricter. The ... in the types work the same way as Object.assign would work.

type NetworkPayloadBase = {|
  +type: 'Network',
  +startTime: Milliseconds,
  +endTime: Milliseconds,
  +id: number,
  +pri: number, // priority of the load; always included as it can change
  +URI?: string,
|};

type RequestInformation = {|
  +domainLookupStart: Milliseconds,
  +domainLookupEnd: Milliseconds,
  +connectStart: Milliseconds,
  +tcpConnectEnd: Milliseconds,
  +secureConnectionStart: Milliseconds,
  +connectEnd: Milliseconds,
  +requestStart: Milliseconds,
  +responseStart: Milliseconds,
  +responseEnd: Milliseconds,
|};

export type NetworkPayload =
  | {|
      ...NetworkPayloadBase,
      +status: 'STATUS_START',
    |}
  | {|
      ...NetworkPayloadBase,
      ...RequestInformation,
      +count?: number, // Total size of transfer, if any
      +status: 'STATUS_STOP',
    |}
  | {|
      ...NetworkPayloadBase,
      ...RequestInformation,
      +RedirectURI?: string,
      +count?: number, // Total size of transfer, if any
      +status: 'STATUS_REDIRECT',
    |};

This definition makes the types a bit nicer for knowing the types of information you have access to.

switch (networkPayload.status) {
  case 'STATUS_START':
    // No request timing information available
    break;
  case 'STATUS_REDIRECT':
  case 'STATUS_DONE':
    const { domainLookupStart, domainLookupEnd } = networkPayload;
    // Can display request timing information
    break;
  default:
    throw new Error("Unknown network payload type")
}
gregtatum commented 6 years ago

Right now we construct MarkerTiming to display the markers. The format was chosen to minimize GC when we slice and dice up the profiles to render the markers, and be fast to iterate over while the markers are drawn via 2d canvas. The new network panel is going to use the DOM, so it might not need the same shape of data.

export type MarkerTiming = {
  // Start time in milliseconds.
  start: number[],
  // End time in milliseconds.
  end: number[],
  index: IndexIntoTracingMarkers[],
  label: string[],
  name: string,
  length: number,
};

To think out loud in code, maybe the network panel could use something like this.

type NetworkTiming = {|
  +domainLookupStart: Array<Milliseconds>,
  +domainLookupEnd: Array<Milliseconds>,
  +connectStart: Array<Milliseconds>,
  +tcpConnectEnd: Array<Milliseconds>,
  +secureConnectionStart: Array<Milliseconds>,
  +connectEnd: Array<Milliseconds>,
  +requestStart: Array<Milliseconds>,
  +responseStart: Array<Milliseconds>,
  +responseEnd: Array<Milliseconds>,
  +URI: Array<string | null>,
  +count: Array<number>,
  +isRedirect: Array<boolean>,
  +length: number,
|};

export function generateNetworkTiming(markers: MarkersTable): NetworkTiming {
  const toNetworkTimingIndex: Map<number, number> = new Map();
  const networkTiming = {
    domainLookupStart: [],
    domainLookupEnd: [],
    connectStart: [],
    tcpConnectEnd: [],
    secureConnectionStart: [],
    connectEnd: [],
    requestStart: [],
    responseStart: [],
    responseEnd: [],
    URI: [],
    count: [],
    isRedirect: [],
    length: 0,
  };

  for (let markerIndex = 0; markerIndex < markers.length; markerIndex++) {
    const data = markers.data[markerIndex];
    if (!data || data.type !== 'Network') {
      continue;
    }

    // Get the correct timing index based on the payload's unique ID.
    // There can be multiple markers for a single network event.
    let networkTimingIndex = toNetworkTimingIndex.get(data.id);
    if (networkTimingIndex === undefined) {
      networkTimingIndex = networkTiming.length++;
      toNetworkTimingIndex.set(data.id, networkTimingIndex);
    }

    switch (data.status) {
      case 'STATUS_START':
        // We know there is a start, but don't have more detailed timing.
        break;
      case 'STATUS_REDIRECT':
        // Fill in the redirect and timing information.
        break
      case 'STATUS_DONE':
        // Fill in the timing information.
        break;
      default:
        throw new Error('Unknown network payload type');
    }
  }
  return networkTiming;
}
gregtatum commented 6 years ago

Also, this is a useful profile with network markers: https://perfht.ml/2KZ0vtS

Useful snippets for the console:

var network = filteredThread.markers.data.filter(data => data && data.type ==='Network');
var start = network.filter(data => data.status === 'STATUS_START')
var stop = network.filter(data => data.status === 'STATUS_STOP')
var redirect = network.filter(data => data.status === 'STATUS_REDIRECT')
zoepage commented 6 years ago

Just a small addition as you mentioned that before @gregtatum

type NetworkTimeDetails = {|
  +domainLookupStart: Array<Milliseconds>,
  +domainLookupEnd: Array<Milliseconds>,
  +connectStart: Array<Milliseconds>,
  +tcpConnectEnd: Array<Milliseconds>,
  +secureConnectionStart: Array<Milliseconds>,
  +connectEnd: Array<Milliseconds>,
  +requestStart: Array<Milliseconds>,
  +responseStart: Array<Milliseconds>,
  +responseEnd: Array<Milliseconds>,
|}

type NetworkTiming = {|
  +timing: Array<NetworkTimeDetails | null>
  +URI: Array<string | null>,
  +count: Array<number>,
  +isRedirect: Array<boolean>,
  +length: number,
|};
zoepage commented 6 years ago

So the result would be rendered like this?

switch (data.status) {
      case 'STATUS_START':
        // We know there is a start, but don't have more detailed timing.
       return (
            <div className="tooltipDetails">
              {_markerDetail('status', 'Status', data.status)}
              {_markerDetailNullable('url', 'URL', data.URI)}
              {_markerDetail('pri', 'pri', data.pri)}
              {_markerDetailBytesNullable('count', 'Reqested bytes', data.count)}
            </div>
          );
        break;
      case 'STATUS_REDIRECT':
        // Fill in the redirect and timing information.
 <div className="tooltipDetails">
              {_markerDetail('status', 'Status', data.status)}
              {_markerDetailNullable('url', 'URL', data.URI)}
              {_markerDetailNullable(
                'redirect_url',
                'Redirect URL',
                data.RedirectURI
              )}
              {_markerDetail('pri', 'pri', data.pri)}
              {_markerDetailBytesNullable('count', 'Reqested bytes', data.count)}
              {_markerDetailDeltaTimeNullable(
                'domainLookup',
                'Lookup',
                data.domainLookupEnd,
                data.domainLookupStart
              )}
              {_markerDetailDeltaTimeNullable(
                'connect',
                'Connect',
                data.connectStart,
                data.connectEnd
              )}
              {_markerDetailDeltaTimeNullable(
                'response',
                'Transfer',
                data.responseEnd,
                data.requestStart
              )}
            </div>
        break
      case 'STATUS_DONE':
        // Fill in the timing information.
       <div className="tooltipDetails">
              {_markerDetail('status', 'Status', data.status)}
              {_markerDetailNullable('url', 'URL', data.URI)}
              {_markerDetail('pri', 'pri', data.pri)}
              {_markerDetailBytesNullable('count', 'Reqested bytes', data.count)}
              {_markerDetailDeltaTimeNullable(
                'domainLookup',
                'Lookup',
                data.domainLookupEnd,
                data.domainLookupStart
              )}
              {_markerDetailDeltaTimeNullable(
                'connect',
                'Connect',
                data.connectStart,
                data.connectEnd
              )}
              {_markerDetailDeltaTimeNullable(
                'response',
                'Transfer',
                data.responseEnd,
                data.requestStart
              )}
            </div>
        break;
      default:
        throw new Error('Unknown network payload type');
    }
gregtatum commented 6 years ago

@zoepage looks reasonable for a tooltip, although you could extract some of the shared bits into utility function.

zoepage commented 6 years ago

although you could extract some of the shared bits into utility function.

I agree. That was just a quick shoot :)

I just realized, I didn't point out what is important here for the network panel. The main idea is to move in the direction of the mock below.

group 6

Above in the tooltip code, you can see how the values for Lookup, Connect and Transfer are calculated.

The tooltip #1111 would be updated first. After the network panel and the tooltip polish land, we can change the logic as described above and work on the UI update, if this is what we want and as well switch the tooltip for the sidebar while displaying the timing breakdown here.

past commented 6 years ago

My ideal end state would be with a profiler network panel that almost matches the devtools network panel (modulo costly-to-record or unrelated-to-perf bits). To that end I had suggested that we add the markers at the same code locations that the devtools network panel uses.

In the current implementation I had proposed that we omit the start marker when the end marker is present and leave it in otherwise. But from a less prescriptive, more high-level view: I think we should not hide information that might be helpful in diagnosing a performance problem (like omitting orphan start markers), but we should display it in a way that is intuitive without having to consult the tooltip, like today. One idea would be to not use a solid rectangle for the orphan markers, but something that ends in an arrow that indicates continuation past the profile end ([===> instead of [===]).

zoepage commented 6 years ago

@past the single rectangles are for the use case when we get a lookup, but not the connection... The stoke is the indicator for markers with just a start time as the network panel seem to do the same.

Now I'm interested, if this was not obvious enough or the screenshot was too small? :)

past commented 6 years ago

Oh, I totally missed that! I guess my assumption was that if the end marker wasn't available, then the rectangle must have extended until the end of the timeline. The gray rectangle seems to correspond semantically to a request for which the DNS lookup failed, which I assume will give us both start and end markers, no?

zoepage commented 6 years ago

The gray rectangle seems to correspond semantically to a request for which the DNS lookup failed, which I assume will give us both start and end markers, no?

Yes, here we get start and end.

I guess my assumption was that if the end marker wasn't available, then the rectangle must have extended until the end of the timeline.

Ah, I see. Thanks for the explanation :)

I was thinking about this quite some time and how I see it, we have 2 options:

  1. Displaying the rectangle to the end, but in a different color or opacity. Contra here? We would add more noise to the visualization.

  2. Displaying just the start as a stroke would indicate there was a start, but we do not have an end (, which would mean the tracking was interrupted or the data lost).

past commented 6 years ago

Agreed about the 2 options. My worry with option 2 is that people will instinctively consider them as very quick loads instead, because of how other short markers behave. This can obscure for example the fact that an unfinished network load occupies one of the available connections (network.http.max-persistent-connections-per-server), blocking subsequent requests from starting.

Do we know what other browsers do in this case?

julienw commented 6 years ago

I'm more for option 1, this is what we do for other markers too. I think this is strictly better than option 1 for all the good reasons @past mentioned in the previous comment.

julienw commented 6 years ago

I really like the mock in https://github.com/devtools-html/perf.html/issues/1122#issuecomment-403977560, thanks @zoepage !

But I think we miss one technical piece: we currently get the STATUS_STOP marker with all timings at the end of a request. This means that if we end our capture before we get this marker we'd have only STATUS_START and miss all timings, even if some have already occurred. See this profile as an example: we have a lot of STATUS_START but no STATUS_STOP for a lot of requests (I captured while loading cnn.com, without waiting until the end).

A possible solution could be to have tracing markers (this means: a couple of markers (start, end)) for each status, instead of 1 tracing marker for a whole request. This needs a gecko patch, and could be a bit heavy. This also needs changes in perf.html to merge all these "technical" markers into 1 displayed marker.

Another solution is outputting network markers for all unfinished network requests at capture time. Maybe we'd need a STATUS_UNFINISHED for these ones, although we may not need a different status. This is my prefered solution but I don't know if that's easy. Thoughts @jesup ?