DevTools: Add server-timing details into Network panel |
||||||
Issue descriptionThe Server-Timing spec provides a response header to attach metrics from the server to a request. Spec: http://w3c.github.io/server-timing/ There's been discussion to add support to the DevTools to surface these figures along with the existing network timing.
,
Mar 14 2016
CL is up here https://codereview.chromium.org/1794783006/ Images from the email thread attached.
,
Mar 14 2016
@ilya, yeah if we had some idea of a startTime for the metrics we could visually plot them a bit easier. @steve, without a starttime we should still try to visualize the durations. Mock attached. (But ideally we have startTimes too)
,
Mar 15 2016
Slightly updated graphic to match latest patch.
,
Mar 15 2016
It can be a little odd to show bar chart type graph when you don't know how they tie together like the first set. My default is to use a pie chart instead, but hard to label that, and my extension will do that anyhow. Maybe if the server-time bars are all centered together in the middle of the start-end range. But the total server time had better be less than the waiting and transfer time. :)
,
Mar 15 2016
,
Mar 15 2016
Actually, now that I have thought about it more, if we want bars in the server timing area, maybe they should be outlines, and not filled in. That would visually distinguish them a bit. One reason I didn't do the bars at all though, is that the names can be really long since they are not static names, but are user input.
,
Mar 15 2016
True. That works for me.
,
Mar 15 2016
I think StartTime might only be useful in small response structures. i.e. A developer could have multiple database calls. Do they all "start" at the same time? No, they happen at different times throughout the application lifecycle. So, either you group them all and just do the earliest startTime as a middle-ground or you do multiple DB call displays (for each request) which could easily become unruly. I think the best solution is to visualize duration as Irish has provided a mockup for. With a bonus for a coloring legend based on the amount of the total service timing used. i.e. Blue for short sections indicating low-impact. Red for things that are taking up a majority of the total server timing. (Maybe orange for an in-between if we want to try to calculate that.)
,
Mar 15 2016
These times are all cumulative. That is, all the time taken in MySQL. All the time dealing with a cache server. All the time taken dealing with the filesystem. I can add the graphs. It is possible to have the server time headers lie, so I will scale the data to request finish - request sent so it never looks longer then the request recorded by Chrome (this is only if the data returned is greater than what Chrome knows it to be, and should not happen in practice). To make the graphs comparable, I will need to keep everything in the same table. But to avoid having the graph area too small, I will need to clip the names of the server-timing description. Have a preference for max-width of that column?? The other thought is to represent as a pie chart.
,
Mar 15 2016
>> These times are all cumulative. That is, all the time taken in MySQL. All the time dealing with a cache server. All the time taken dealing with the filesystem. Which is sad since not aggregating it could give a much better idea on the flow of events. Such technique is called "structural profiling" as opposed to the "instrumenting profiling". It is based on the high level user markup with the timers. Then we surface this information in the tools and it starts adding much more value. >> I can add the graphs. It is possible to have the server time headers lie... Only if we get valid start times for it. Pinging igrigorik@ for it.
,
Mar 15 2016
One thing that could be really helpful here is if we could log the time at which the header was received. One extremely challenging problem that we encounter at facebook is that we use chunked encoding to flush the page multiple times. It's hard for people to understand when the client received some set of bytes Wrote up some more details here: https://github.com/w3c/server-timing/issues/4
,
Mar 16 2016
My experience with FirePHP where I send a lot more data in the headers is that it breaks Chrome pretty bad after a certain size. Somewhere in Chrome or DevTools, everything just breaks. We have to clip things on the server side. This having been an issue for a long time (and also an issue on other browsers), a lot of people with custom tools have moved to sending a token in a header, and have their extension call back for more information. This means setting up a data store for this kind of debugging, but it works pretty well. The original author of FirePHP had done something like this, and I would have to guess that z-ray does as well. I was planning at adding it to Illuminations for Developers at one point. I've thought of using such a token system to pull in web-cachegrind as well, but that profiling information is massive. We don't want hundreds of megabytes going into headers. It is not something to use Server-Timing for. That said, it would be interesting to condense that data into a format that could be used natively inside DevTools, and use the DevTools checkboxes for profiling to include server side stuff as well. Heck, at that point, chain the call stack from the client to the call stack of the server, etc. Or include a way to plug in server side debug systems like xdebug natively in the browser so you can step "inside" from the client to the server. Actually, this would be easier with nodejs, but might was well wish for anything in the ideal. ;) Anyhow, back to Server-Timing and its simplicity. There may be other ways to look at marrying the backend and the frontend, but I don't think we need to overload it here.
,
Mar 16 2016
As for chunking, it would be interesting to show that in the timing panel if it were available. BTW: A rough draft (not even a screenshot) of my server timing extension is here: https://chrome.google.com/webstore/detail/server-timing/lhebeopdclghecelfokfapiamfjmifdo It consolidates all the requests on a page together.
,
Mar 16 2016
@bmaurer, fwiw the current (experimental) network data on the timeline reveals the timestamps for response headers received and each TCP segment.
,
Mar 17 2016
So this is how my latest version looks (not uploaded yet). Thoughts?
,
Mar 17 2016
The server-timing extension on the same page (different run):
,
Mar 19 2016
OK, these are the versions I have working:
,
Mar 19 2016
v1 is that is in https://codereview.chromium.org/1794783006
,
Mar 19 2016
I found a hashing algo in devtools and a list of names, so used those (but 50% transparent), and it looks like this:
,
Mar 20 2016
We're in the process of nuking all pie charts in the UI. Google `pie charts are bad` for plenty of commentary on why, but the short version is: they make comparison between items very difficult. And for developers, evaluating relative values is often more important than identifying the one largest component. Your option 4.png in c#18 is pretty ideal, IMO. Using the color hashing for it seems nice, too.
,
Mar 20 2016
sroussey: for your extension. 1) what are the smaller concentric circles? Previous runs? 2) Got a test URL to use that emits server-timing data in production?
,
Mar 20 2016
The extension's summary view of concentric circles are more obvious with an example page, which I need to make public somewhere. The main one is the sum of the children (or average, depending on your point of view). The inner ones are all the requests of the page. As new requests come in, new inner circles are created, and the outer one adjusts to account for the new information. They are all animated so they are fun to watch. Thus the table next to it is sum of all the others. Below are the individual requests. The UI needs work, but I really needed the summary table of all requests. A stock type column chart might be interesting, showing the range of various requests (that has a non-zero value). Or a stacked column. There are a number of scenarios to play with. I wanted a pie chart for a meeting, to have various teams guess which slice was what. There is also the part in the concentric circles where you can see that one response was dominated by "Other" -- you wouldn't see that at a glance with a stacked graph. The summary will be available in the page action menu (which will need to change to a browser action menu unfortunately). It makes a nice concise view.
,
Mar 20 2016
I found the FlameChart consistent hashing color generator, so using that here. Should be easy enough to change the color scheme.
,
Mar 20 2016
I couldn't stand the total being colored like that. And since "total" would always hash to that color... Anyhow, it is easy to adjust the color scheme. I can upload the code for this version.
,
Mar 20 2016
Seems good. Yeah let's get this iteration in the CL.
,
Mar 21 2016
Apologies about the delayed response(s). pfeldman: startTimes are meaningless because they're coming from a different time source (or multiple - e.g. origin and CDN servers injecting own headers), and with unknown network delays. The only thing we can reason about is the duration. sroussey: I'm a bit wary of the piechart and the % measures. It's perfectly reasonable for multiple operations to overlap but then be reported as separate ST entries; to be safe, we should assume that ST reports CPU time, not wall-clock time. Re, firePHP: Chrome's old speedtracer extension took the same approach. ST is an intentionally simplified version of that. Fetching multi-MB reports is not a RUM friendly approach; our goal is not to enable deep server-side tracing, but to enable RUM gathering of high-level server timing metrics. Implementation questions: - Looks like "total" name is treated as special, but we don't define any such behavior in the spec. What happens when the user omits it? - Does the extension work with comma delimited headers, instead of individual headers? If not, it should, because an intermediary is allowed to combine (and split) such headers. bmaurer: I'll followup on GitHub issue; I think what you're asking for is mostly orthogonal to what's being discussed here.
,
Mar 21 2016
For DevTools: Latest version has a chart, but not a pie chart. No % in there other than visual. I don't actually add up the timing information, since, as you said, the total of the metric timings could be more than the total time spent in the request (and why I report a metric with the name total at the bottom). My initial version for this was to have no charting, and only report the numbers. The total metric, if removed, just means that no line will get the bolded timing. I'm afraid I don't know what you mean by comma delimited headers. What do you mean by that?
,
Mar 21 2016
> I'm afraid I don't know what you mean by comma delimited headers. What do you mean by that? Server-Timing: a=123;"description for A", b=245;"description for B" vs Server-Timing: a=123;"description for A" Server-Timing: b=245;"description for B" Both are equivalent, valid, and maybe transformed from one representation to the other.
,
Mar 21 2016
For my extension: Now, for my extension, I can do whatever seems valuable to me. ;) I actually plan to to support something like this: Server-Timing: sql-1: 0.1; "MySQL Lookup Server" Server-Timing: sql-2: 0.9; "MySQL Shard Server #1" Server-Timing: sql-3: 1.2; "Oracle Archive Server" Server-Timing: cpu: 2.3; "CPU" And in the individual request view, I can do the concentric circle thing again, but this time (for the above data) that would look like two circles: one with that would split the donut by cpu vs sql, and an inner pie that would show all four values. This has nothing to do with the spec, per se, but with a convention on how to use it for this particular extension. More dashes would mean more concentric donut charts, assuming that there was grouping information (for example, if there were only two ST headers like data-sql-mysql and cpu, then it would only do a pie chart since there were no other headers that shared a common prefix ending in a dash).
,
Mar 21 2016
There is something in the DevTools code I forgot to deal with: any timing value greater than the expected time of the full request. Because then the chart is wack since there is no scale. If any value is that high, none should likely be graphed. Or the one with a high number is not graphed. An example: Server-Timing: preprocessing: 3600.0 In this case, a value related is sent: that pre-processing of a data set had taken an hour. The request itself could take less than a second.
,
Mar 21 2016
Is that an HTTP spec thing? I don't see it explicitly mentioned here: https://w3c.github.io/server-timing/#dfn-server-timing-header-field
,
Mar 21 2016
I found it in the HTTP spec. I guess my question is, does Chrome de-combine them by the time I get the header values? I guess I will need to test.
,
Mar 21 2016
For reference: http://httpwg.org/specs/rfc7230.html#abnf.extension "Decombine": no, it shouldn't, and you shouldn't expect it to.
,
Mar 29 2016
OK, I am now more precise with the regexp "parsing" of the headers. It is a little loose with the quoted string. And now that I know what the # means in the spec, it also does comma delimited headers. Also, I noticed in the spec that the actual timing value is optional, so I handle that gracefully was well. And if the numbers returned would cause drawing artifacts (the number being too big), then I don't display the bar at all.
,
Apr 4 2016
Where to go from here?
,
Apr 5 2016
could you ping me from the most recent relevant CL?
,
Apr 12 2016
,
Aug 13 2016
,
Aug 14 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/b9174da95316a0d17f6868a31780b046c5a374d2 commit b9174da95316a0d17f6868a31780b046c5a374d2 Author: sroussey <sroussey@gmail.com> Date: Sun Aug 14 08:32:35 2016 Add Server-Timing support to devtools BUG= 594800 Review-Url: https://codereview.chromium.org/1794783006 Cr-Commit-Position: refs/heads/master@{#411914} [modify] https://crrev.com/b9174da95316a0d17f6868a31780b046c5a374d2/third_party/WebKit/Source/devtools/front_end/network/RequestTimingView.js [modify] https://crrev.com/b9174da95316a0d17f6868a31780b046c5a374d2/third_party/WebKit/Source/devtools/front_end/network/networkPanel.css [modify] https://crrev.com/b9174da95316a0d17f6868a31780b046c5a374d2/third_party/WebKit/Source/devtools/front_end/sdk/NetworkRequest.js [add] https://crrev.com/b9174da95316a0d17f6868a31780b046c5a374d2/third_party/WebKit/Source/devtools/front_end/sdk/ServerTiming.js [modify] https://crrev.com/b9174da95316a0d17f6868a31780b046c5a374d2/third_party/WebKit/Source/devtools/front_end/sdk/module.json
,
Feb 7 2017
About time we close this ticket, eh? Thanks again, Steven!
,
Feb 8 2017
,
Feb 14 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/968553977ba5cf51409101104a51431d60b051cd commit 968553977ba5cf51409101104a51431d60b051cd Author: paulirish <paulirish@chromium.org> Date: Tue Feb 14 04:26:42 2017 DevTools: Server Timing values should be in milliseconds This is a breaking change. This feature landed in August, but just announced this week (twitter.com/paul_irish/status/829090506084749312). Users discovered the original patch used seconds values, but the Server Timing spec dictates these as DOMHighResTimeStamp which are milliseconds. BUG= 594800 Review-Url: https://codereview.chromium.org/2689833002 Cr-Commit-Position: refs/heads/master@{#450244} [modify] https://crrev.com/968553977ba5cf51409101104a51431d60b051cd/third_party/WebKit/Source/devtools/front_end/network/RequestTimingView.js [modify] https://crrev.com/968553977ba5cf51409101104a51431d60b051cd/third_party/WebKit/Source/devtools/front_end/sdk/ServerTiming.js |
||||||
►
Sign in to add a comment |
||||||
Comment 1 by pfeldman@chromium.org
, Mar 14 2016