Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
2203913002:
Added trace events for blink feature usage (Closed)
|
Created:
4 years, 4 months ago by Pat Meenan Modified:
4 years, 4 months ago CC:
chromium-reviews, blink-reviews Base URL:
https://chromium.googlesource.com/chromium/src.git@master Target Ref:
refs/pending/heads/master Project:
chromium Visibility:
Public. |
DescriptionAdded trace events for blink feature usage
This adds a new trace category (blink.feature_usage) where trace events
are generated each time a feature use counter is updated.
BUG=633644
Committed: https://crrev.com/720d2fb5ad67e08d11b926b255086579a3bd4b39
Cr-Commit-Position: refs/heads/master@{#411343}
Patch Set 1 #
Total comments: 6
Patch Set 2 : Fixed CSS name, Eliminated duplicate code #
Total comments: 2
Patch Set 3 : Moved trace point deeper to catch all code paths #
Total comments: 5
Patch Set 4 : Only trace first use of each feature #
Messages
Total messages: 15 (4 generated)
pmeenan@chromium.org changed reviewers: + foolip@chromium.org, rbyers@chromium.org
foolip@/rbyers@, could you PTAL. This will make it trivial to collect use counter data from HTTP Archive, WebPageTest and presumably use them for lighthouse if it makes sense.
Getting these into traces seems reasonable to me, thanks! I'm out on vacation now, but here's a couple little suggestions. I'm happy with whatever you and foolip decide in my absence. https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... File third_party/WebKit/Source/core/frame/UseCounter.cpp (right): https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... third_party/WebKit/Source/core/frame/UseCounter.cpp:667: TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("blink.feature_usage"), "FeatureUsed", "feature", feature); I believe this will double count (Calls into the one below that you've also instrumented). https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... third_party/WebKit/Source/core/frame/UseCounter.cpp:756: TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("blink.feature_usage"), "FeatureUsed", "feature", feature); This 'feature' has a different range/semantics than the others (CSSPropertyID instead of UseCounter enum). Name it "CSSFeatureUsed" instead? https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... third_party/WebKit/Source/core/frame/UseCounter.cpp:763: TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("blink.feature_usage"), "FeatureUsed", "feature", feature); There are a few features which are used a LOT, do you really want EACH usage in the trace? That could really bloat the trace when this is enabled. I think it would probably be fine to check hasRecordedMeasurement first and only do the trace when it's not already true (so reporting the first usage per page load). WDYT?
Thanks. Go enjoy vacation and quit checking email ;-) https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... File third_party/WebKit/Source/core/frame/UseCounter.cpp (right): https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... third_party/WebKit/Source/core/frame/UseCounter.cpp:667: TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("blink.feature_usage"), "FeatureUsed", "feature", feature); On 2016/08/03 01:08:32, Rick Byers (OOO until Aug 22) wrote: > I believe this will double count (Calls into the one below that you've also > instrumented). It doesn't because it is calling directly into recordMeasurement() instead of count(). Instead of duplicating the functionality of count() below up here as well I just changed it to call into count() instead (and removed the ASSERT since count() does that as well). https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... third_party/WebKit/Source/core/frame/UseCounter.cpp:756: TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("blink.feature_usage"), "FeatureUsed", "feature", feature); On 2016/08/03 01:08:32, Rick Byers (OOO until Aug 22) wrote: > This 'feature' has a different range/semantics than the others (CSSPropertyID > instead of UseCounter enum). Name it "CSSFeatureUsed" instead? Doh. Good catch, thanks. Done. https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... third_party/WebKit/Source/core/frame/UseCounter.cpp:763: TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("blink.feature_usage"), "FeatureUsed", "feature", feature); On 2016/08/03 01:08:32, Rick Byers (OOO until Aug 22) wrote: > There are a few features which are used a LOT, do you really want EACH usage in > the trace? That could really bloat the trace when this is enabled. I think it > would probably be fine to check hasRecordedMeasurement first and only do the > trace when it's not already true (so reporting the first usage per page load). > WDYT? Is there value in knowing how often features were used on a given page? At least for the HTTP Archive/WPT I was going to count the occurrences of each feature recorded (and convert everything to strings). The actual memory use is small since it is just recording the pointers for the name and the enum (and the trace timestamp info) and it is only when this category is explicitly turned on. I did some browsing while testing and even the v8 modes which fire a LOT (at least on the sites I was testing) still resulted in <10k events on some of the more painful pages and well under 5% of the default buffer (and ~1MB as gz json). By measuring each occurrence we could also do arbitration for certain features if it became interesting. It could be that I also didn't hit a pathological case so I could easily be convinced to limit it to the first occurrence or maybe to treat CSS features and regular features differently.
Is there any infrastructure for testing tracing to get some confidence that this will work as intended? https://codereview.chromium.org/2203913002/diff/20001/third_party/WebKit/Sour... File third_party/WebKit/Source/core/frame/UseCounter.cpp (right): https://codereview.chromium.org/2203913002/diff/20001/third_party/WebKit/Sour... third_party/WebKit/Source/core/frame/UseCounter.cpp:761: TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("blink.feature_usage"), "FeatureUsed", "feature", feature); This relates to https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... Deprecation::countDeprecation doesn't use this code path, so it looks like deprecated things will be missed here. And it first checks hasRecordedMeasurement(feature) to avoid double logging to the console, so some care is needed to not just trace once for deprecations but any number of times for the rest. What happens if you try to push down the tracing into UseCounter::recordMeasurement inside the m_muteCount guard and also check hasRecordedMeasurement there? Something like that would be a closer fit for the above change, where you trace after some guards and right before the poking and the bit vector.
Only question now is if we only want to record the first occurrence of each feature or every time it is used (and if we want to treat CSS features the same way). Right now it is still tracing every time the feature is encountered but it's a trivial change to have it check first. As far as tests go, tracing itself has unit tests and there are pockets of tests like this one: https://cs.chromium.org/chromium/src/tools/android/loading/tracing_unittest.py but most cases I could find don't have tests around trace points themselves. https://codereview.chromium.org/2203913002/diff/20001/third_party/WebKit/Sour... File third_party/WebKit/Source/core/frame/UseCounter.cpp (right): https://codereview.chromium.org/2203913002/diff/20001/third_party/WebKit/Sour... third_party/WebKit/Source/core/frame/UseCounter.cpp:761: TRACE_EVENT1(TRACE_DISABLED_BY_DEFAULT("blink.feature_usage"), "FeatureUsed", "feature", feature); On 2016/08/03 14:53:27, foolip wrote: > This relates to > https://codereview.chromium.org/2203913002/diff/1/third_party/WebKit/Source/c... > > Deprecation::countDeprecation doesn't use this code path, so it looks like > deprecated things will be missed here. And it first checks > hasRecordedMeasurement(feature) to avoid double logging to the console, so some > care is needed to not just trace once for deprecations but any number of times > for the rest. > > What happens if you try to push down the tracing into > UseCounter::recordMeasurement inside the m_muteCount guard and also check > hasRecordedMeasurement there? > > Something like that would be a closer fit for the above change, where you trace > after some guards and right before the poking and the bit vector. Done.
AFAICT, with PS3 it will count every hit for things that are only measured, but only the first for things that are deprecated? Doing the same in both cases is important I think, otherwise one won't be able to compare between the two categories and will have to ignore the counts. If you can imagine a scenario where counting every hit would provide some useful information (I'm not sure that more hits by a single site means much) then making Deprecation::countDeprecation always count seems OK. But since usage is recorded in a bit vector and that's how we've used it so far, I'd lean towards just tracing once. lgtm % nits in case I'm slow to respond to the next PS https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... File third_party/WebKit/Source/core/frame/UseCounter.cpp (left): https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... third_party/WebKit/Source/core/frame/UseCounter.cpp:665: ASSERT(Deprecation::deprecationMessage(feature).isEmpty()); This ASSERT should still hold, right, or why was it removed? https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... File third_party/WebKit/Source/core/frame/UseCounter.cpp (right): https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... third_party/WebKit/Source/core/frame/UseCounter.cpp:789: if (!m_muteCount) { Can you do an early return instead, and put this somewhere around unmuteForInspector/updateMeasurements to be closer to the header file's order?
I switched it to only record the first use of each feature. If we get value out of the timing of when the feature triggered or decide there is value in the counts as well we can add that logic later. https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... File third_party/WebKit/Source/core/frame/UseCounter.cpp (left): https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... third_party/WebKit/Source/core/frame/UseCounter.cpp:665: ASSERT(Deprecation::deprecationMessage(feature).isEmpty()); On 2016/08/08 19:59:11, foolip wrote: > This ASSERT should still hold, right, or why was it removed? UseCounter::count() is exactly this assert + the recordMeasurement() call. Instead of duplicating both of them I changed it to pass through to the count() entry point and leave the logic there. This isn't necessary for my change since I moved the tracing into the deeper recordMeasurement() call anyway but came out as part of the cleanup from earlier iterations. https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... File third_party/WebKit/Source/core/frame/UseCounter.cpp (right): https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... third_party/WebKit/Source/core/frame/UseCounter.cpp:789: if (!m_muteCount) { On 2016/08/08 19:59:11, foolip wrote: > Can you do an early return instead, and put this somewhere around > unmuteForInspector/updateMeasurements to be closer to the header file's order? Done.
https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... File third_party/WebKit/Source/core/frame/UseCounter.cpp (left): https://codereview.chromium.org/2203913002/diff/40001/third_party/WebKit/Sour... third_party/WebKit/Source/core/frame/UseCounter.cpp:665: ASSERT(Deprecation::deprecationMessage(feature).isEmpty()); On 2016/08/09 19:06:32, Pat Meenan wrote: > On 2016/08/08 19:59:11, foolip wrote: > > This ASSERT should still hold, right, or why was it removed? > > UseCounter::count() is exactly this assert + the recordMeasurement() call. > Instead of duplicating both of them I changed it to pass through to the count() > entry point and leave the logic there. > > This isn't necessary for my change since I moved the tracing into the deeper > recordMeasurement() call anyway but came out as part of the cleanup from earlier > iterations. Acknowledged.
The CQ bit was checked by pmeenan@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from foolip@chromium.org Link to the patchset: https://codereview.chromium.org/2203913002/#ps60001 (title: "Only trace first use of each feature")
CQ is trying da patch. Follow status at https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...
Message was sent while issue was closed.
Committed patchset #4 (id:60001)
Message was sent while issue was closed.
Description was changed from ========== Added trace events for blink feature usage This adds a new trace category (blink.feature_usage) where trace events are generated each time a feature use counter is updated. BUG=633644 ========== to ========== Added trace events for blink feature usage This adds a new trace category (blink.feature_usage) where trace events are generated each time a feature use counter is updated. BUG=633644 Committed: https://crrev.com/720d2fb5ad67e08d11b926b255086579a3bd4b39 Cr-Commit-Position: refs/heads/master@{#411343} ==========
Message was sent while issue was closed.
Patchset 4 (id:??) landed as https://crrev.com/720d2fb5ad67e08d11b926b255086579a3bd4b39 Cr-Commit-Position: refs/heads/master@{#411343} |
|||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
