Chromium Code Reviews
|
|
Chromium Code Reviews
Issue
2351793003:
Implement timing metrics for UrlRequest (Closed)
DescriptionImplement timing metrics for UrlRequest
This CL implements all of the timing APIs in
RequestFinishedInfo.Metrics, in most cases by plumbing them through from
net::LoadTimingInfo. Some of the old metrics code is no longer used and
will be deleted in a follow-up CL. Redirect handling and new features of
RequestFinishedInfo other than timing are not yet implemented.
BUG=629194
Committed: https://crrev.com/6408523c44fd12383d385b02ba9aee872fe8618c
Cr-Commit-Position: refs/heads/master@{#423194}
Patch Set 1 #
Total comments: 15
Patch Set 2 : add more testing, and other comments #
Total comments: 26
Patch Set 3 : New test, and some rearranging things #
Total comments: 2
Patch Set 4 : Fix tests #Patch Set 5 : rebase #Patch Set 6 : oops #
Total comments: 4
Patch Set 7 : Small cleanups #Dependent Patchsets: Messages
Total messages: 18 (4 generated)
mgersh@chromium.org changed reviewers: + xunjieli@chromium.org
PTAL, and let me know if you'd prefer deleting the dead code in this CL instead of a separate one
First pass. My preference to keep individual CLs as small as possible. If you can additionally move RequestFinishedInfo.java and CronetMetrics.java changes and other unrelated changes in a separate CL, that will be great. Ideally this CL should only contain the plumbing and the new tests. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:401: cronet::Java_CronetUrlRequest_onMetricsCollected( Can we combine this with onError, onSucceeded, onCanceled? We should try to minimize number of Java <-> C++ trips unless there is a reason not to do so. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:420: base::TimeTicks ticks, const base::TimeTicks& ? https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... File components/cronet/android/cronet_url_request_adapter.h (right): https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.h:145: int64_t ConvertTime(base::TimeTicks ticks, #include base/time/time.h https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.h:164: bool enable_metrics_; nit: Add a documentation. It's clear what this means now, but the meaning might be obscured when this file grows in size. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/t... File components/cronet/android/test/javatests/src/org/chromium/net/QuicTest.java (right): https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/t... components/cronet/android/test/javatests/src/org/chromium/net/QuicTest.java:270: assertTrue(metrics.getSslEnd().before(endTime)); Suggest having util functions equivalent to "ExpectConnectTimingHasNoTimes" and "ExpectConnectTimingHasTimes" in load_timing_info_test_util.cc. Suggest adding a test where we make two requests, and check that the second request has no connect timing.
I split the changes to CronetMetrics.java into their own CL which this one now depends on, but that's the only thing I can find that's independent. The javadoc change in RequestFinishedInfo is actually a behavior change with the switch from old to new metrics. In theory I could add plumbing in one CL and then flip from old to new in another, but that would involve adding the plumbing and its tests separately, which seems bad. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:401: cronet::Java_CronetUrlRequest_onMetricsCollected( On 2016/09/20 14:32:46, xunjieli wrote: > Can we combine this with onError, onSucceeded, onCanceled? We should try to > minimize number of Java <-> C++ trips unless there is a reason not to do so. The reason for this was to avoid adding 15 more arguments to each of those, which would have to be repeated on each one, and would need to be filled in even when metrics aren't being collected. From https://docs.google.com/spreadsheets/d/1ulggKOZ7VQ8IytP1hKr-1wvBu70qG2qxKT4vR..., it looks like time for a JNI call depends on number of arguments and having the extra arguments on onSucceeded etc. would potentially be just as bad in the case where there are listeners, and worse in the case where there aren't. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:420: base::TimeTicks ticks, On 2016/09/20 14:32:46, xunjieli wrote: > const base::TimeTicks& ? TimeTicks and Time are stored as a single int64_t and are passed as values in a bunch of other places, including time.h itself (https://cs.chromium.org/chromium/src/base/time/time.h?q=time.h&sq=package:chr...). My understanding was that this makes sense to do with a class this small. Given that, do you still think it's better as references? https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... File components/cronet/android/cronet_url_request_adapter.h (right): https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.h:145: int64_t ConvertTime(base::TimeTicks ticks, On 2016/09/20 14:32:46, xunjieli wrote: > #include base/time/time.h Done. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.h:164: bool enable_metrics_; On 2016/09/20 14:32:46, xunjieli wrote: > nit: Add a documentation. It's clear what this means now, but the meaning might > be obscured when this file grows in size. Done. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/t... File components/cronet/android/test/javatests/src/org/chromium/net/QuicTest.java (right): https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/t... components/cronet/android/test/javatests/src/org/chromium/net/QuicTest.java:270: assertTrue(metrics.getSslEnd().before(endTime)); On 2016/09/20 14:32:46, xunjieli wrote: > Suggest having util functions equivalent to "ExpectConnectTimingHasNoTimes" and > "ExpectConnectTimingHasTimes" in load_timing_info_test_util.cc. > > Suggest adding a test where we make two requests, and check that the second > request has no connect timing. Done.
Looks great. Ready to sign off after the following comments are addressed. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:398: JNIEnv* env = base::android::AttachCurrentThread(); How about passing |env| as an argument of MaybeReportMetrics() so we don't do AttachCurrentThread() twice? https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:401: cronet::Java_CronetUrlRequest_onMetricsCollected( On 2016/09/20 20:48:24, mgersh wrote: > On 2016/09/20 14:32:46, xunjieli wrote: > > Can we combine this with onError, onSucceeded, onCanceled? We should try to > > minimize number of Java <-> C++ trips unless there is a reason not to do so. > > The reason for this was to avoid adding 15 more arguments to each of those, > which would have to be repeated on each one, and would need to be filled in even > when metrics aren't being collected. From > https://docs.google.com/spreadsheets/d/1ulggKOZ7VQ8IytP1hKr-1wvBu70qG2qxKT4vR..., > it looks like time for a JNI call depends on number of arguments and having the > extra arguments on onSucceeded etc. would potentially be just as bad in the case > where there are listeners, and worse in the case where there aren't. Acknowledged. That's a good point. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:420: base::TimeTicks ticks, On 2016/09/20 20:48:24, mgersh wrote: > On 2016/09/20 14:32:46, xunjieli wrote: > > const base::TimeTicks& ? > > TimeTicks and Time are stored as a single int64_t and are passed as values in a > bunch of other places, including time.h itself > (https://cs.chromium.org/chromium/src/base/time/time.h?q=time.h&sq=package:chr...). > My understanding was that this makes sense to do with a class this small. Given > that, do you still think it's better as references? That's a good point. I was looking at https://cs.chromium.org/search/?q=%22const+base::TimeTicks%26%22+file:%5Esrc/... In general, I prefer passing by references over values for nonprimitive types. But since the time.h is passing by value, I am not sure what is the best practice for this particular type. Your call. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:400: base::TimeTicks start_ticks = metrics.request_start; Are we sure that |start_ticks| is not null? If so, can we add a DCHECK here to check both start_time and start_ticks are (!is_null())? https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.h (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.h:146: int64_t ConvertTime(base::TimeTicks ticks, nit: add a documentation for this method. optional nit: maybe switch the place of last two arguments, so it's easier to visually differentiate base::Time and base::TimeTicks. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java:207: mRequestContext.hasRequestFinishedListener()); Can we just use the metricsCollectionEnabled field from the constructor? Grabbing the mUrlRequestAdapterLock and another lock makes me nervous about deadlock. Since this is a best effort thing, I think it's fine to use metricsCollectionEnabled from the constructor. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java:87: static class TestRequestFinishedListener extends RequestFinishedInfo.Listener { Instead of making these classes packet protected, can we move them to a new class something like MetricsTestUtil.java? https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java:150: static void checkNoConnectTiming(RequestFinishedInfo.Metrics metrics) { It will be great if you can move these to a standalone Java file, so they can be reused. It's a bit uncommon to reuse methods from a Test file.
https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:364: MaybeReportMetrics(url_request_.get()); This will be invoked after the Java destroyRequestAdapter() which calls mRequestContext.reportFinished(). It looks like we will not have the Metrics info at the time when we try to update CronetUrlRequestContext if request fails or is canceled. How about removing all invocations of MaybeReportMetrics() in this file, and only leave one here in DestroyOnNetworkThread()? if (enable_metrics_) then call Java_CronetUrlRequest_onMetricsCollected which will then do mRequestContext.reportFinished()? We should add a test where the request is canceled or fails after request headers, and make sure we have the correct load timing info.
https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:401: cronet::Java_CronetUrlRequest_onMetricsCollected( nit: "cronet::" is not necessary. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:416: metrics.socket_reused, 0, request->GetTotalReceivedBytes()); Can we add a TODO here to support GetTotalSentBytes()? https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:419: int64_t CronetURLRequestAdapter::ConvertTime( This can be a non-member function in the anonymous namespace. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.h (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.h:167: bool enable_metrics_; const bool.
https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:398: JNIEnv* env = base::android::AttachCurrentThread(); On 2016/09/20 21:53:33, xunjieli wrote: > How about passing |env| as an argument of MaybeReportMetrics() so we don't do > AttachCurrentThread() twice? Done. https://codereview.chromium.org/2351793003/diff/1/components/cronet/android/c... components/cronet/android/cronet_url_request_adapter.cc:420: base::TimeTicks ticks, On 2016/09/20 21:53:33, xunjieli wrote: > On 2016/09/20 20:48:24, mgersh wrote: > > On 2016/09/20 14:32:46, xunjieli wrote: > > > const base::TimeTicks& ? > > > > TimeTicks and Time are stored as a single int64_t and are passed as values in > a > > bunch of other places, including time.h itself > > > (https://cs.chromium.org/chromium/src/base/time/time.h?q=time.h&sq=package:chr...). > > My understanding was that this makes sense to do with a class this small. > Given > > that, do you still think it's better as references? > > That's a good point. I was looking at > https://cs.chromium.org/search/?q=%22const+base::TimeTicks%26%22+file:%5Esrc/... > > In general, I prefer passing by references over values for nonprimitive types. > But since the time.h is passing by value, I am not sure what is the best > practice for this particular type. Your call. Done. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:364: MaybeReportMetrics(url_request_.get()); On 2016/09/22 18:05:15, xunjieli wrote: > This will be invoked after the Java destroyRequestAdapter() which calls > mRequestContext.reportFinished(). It looks like we will not have the Metrics > info at the time when we try to update CronetUrlRequestContext if request fails > or is canceled. > > How about removing all invocations of MaybeReportMetrics() in this file, and > only leave one here in DestroyOnNetworkThread()? if (enable_metrics_) then call > Java_CronetUrlRequest_onMetricsCollected which will then do > mRequestContext.reportFinished()? > > We should add a test where the request is canceled or fails after request > headers, and make sure we have the correct load timing info. Wow, yeah, thanks for catching that. Wrote a test. Unfortunately, my attempt at implementing your suggested fix caused all the tests to become flaky. The version I uploaded mostly fixes it, but not 100% (I saw a failure on requestEnd not being before endTime), and the "Thread.sleep(1000)" everywhere is ugly. Do you have better ideas about how to fix it? https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:400: base::TimeTicks start_ticks = metrics.request_start; On 2016/09/20 21:53:33, xunjieli wrote: > Are we sure that |start_ticks| is not null? > If so, can we add a DCHECK here to check both start_time and start_ticks are > (!is_null())? Good catch. I checked and it's very unlikely but possible for them (both, never just one or the other) to be null if cancel() is called immediately after start(). Added some checks. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:401: cronet::Java_CronetUrlRequest_onMetricsCollected( On 2016/09/22 18:28:58, xunjieli wrote: > nit: "cronet::" is not necessary. Done. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:416: metrics.socket_reused, 0, request->GetTotalReceivedBytes()); On 2016/09/22 18:28:59, xunjieli wrote: > Can we add a TODO here to support GetTotalSentBytes()? Done. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:419: int64_t CronetURLRequestAdapter::ConvertTime( On 2016/09/22 18:28:59, xunjieli wrote: > This can be a non-member function in the anonymous namespace. Done. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.h (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.h:146: int64_t ConvertTime(base::TimeTicks ticks, On 2016/09/20 21:53:33, xunjieli wrote: > nit: add a documentation for this method. > optional nit: maybe switch the place of last two arguments, so it's easier to > visually differentiate base::Time and base::TimeTicks. Done. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.h:167: bool enable_metrics_; On 2016/09/22 18:28:59, xunjieli wrote: > const bool. Done. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java:207: mRequestContext.hasRequestFinishedListener()); On 2016/09/20 21:53:33, xunjieli wrote: > Can we just use the metricsCollectionEnabled field from the constructor? > Grabbing the mUrlRequestAdapterLock and another lock makes me nervous about > deadlock. Since this is a best effort thing, I think it's fine to use > metricsCollectionEnabled from the constructor. I was actually planning on deleting that field, so we can do the check a bit later. We're already doing the multiple locks thing elsewhere, with the same two locks, so we'll have to always acquire them in the same order anyway. Added a comment about this on mFinishedListenerLock. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java:87: static class TestRequestFinishedListener extends RequestFinishedInfo.Listener { On 2016/09/20 21:53:33, xunjieli wrote: > Instead of making these classes packet protected, can we move them to a new > class something like MetricsTestUtil.java? Done. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java:150: static void checkNoConnectTiming(RequestFinishedInfo.Metrics metrics) { On 2016/09/20 21:53:33, xunjieli wrote: > It will be great if you can move these to a standalone Java file, so they can be > reused. It's a bit uncommon to reuse methods from a Test file. Done.
Needs a bit of work on the tests, but I think the implementation looks great. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:364: MaybeReportMetrics(url_request_.get()); On 2016/09/30 23:47:14, mgersh wrote: > On 2016/09/22 18:05:15, xunjieli wrote: > > This will be invoked after the Java destroyRequestAdapter() which calls > > mRequestContext.reportFinished(). It looks like we will not have the Metrics > > info at the time when we try to update CronetUrlRequestContext if request > fails > > or is canceled. > > > > How about removing all invocations of MaybeReportMetrics() in this file, and > > only leave one here in DestroyOnNetworkThread()? if (enable_metrics_) then > call > > Java_CronetUrlRequest_onMetricsCollected which will then do > > mRequestContext.reportFinished()? > > > > We should add a test where the request is canceled or fails after request > > headers, and make sure we have the correct load timing info. > > Wow, yeah, thanks for catching that. Wrote a test. Unfortunately, my attempt at > implementing your suggested fix caused all the tests to become flaky. The > version I uploaded mostly fixes it, but not 100% (I saw a failure on requestEnd > not being before endTime), and the "Thread.sleep(1000)" everywhere is ugly. Do > you have better ideas about how to fix it? Instead of doing "Thread.sleep(1000)," how about waiting until a number of UrlRequestFinishedInfo has been observed? Something like: https://codereview.chromium.org/2360813003/diff/40001/components/cronet/andro... ? https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:400: base::TimeTicks start_ticks = metrics.request_start; On 2016/09/30 23:47:14, mgersh wrote: > On 2016/09/20 21:53:33, xunjieli wrote: > > Are we sure that |start_ticks| is not null? > > If so, can we add a DCHECK here to check both start_time and start_ticks are > > (!is_null())? > > Good catch. I checked and it's very unlikely but possible for them (both, never > just one or the other) to be null if cancel() is called immediately after > start(). Added some checks. Acknowledged. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java:207: mRequestContext.hasRequestFinishedListener()); On 2016/09/30 23:47:14, mgersh wrote: > On 2016/09/20 21:53:33, xunjieli wrote: > > Can we just use the metricsCollectionEnabled field from the constructor? > > Grabbing the mUrlRequestAdapterLock and another lock makes me nervous about > > deadlock. Since this is a best effort thing, I think it's fine to use > > metricsCollectionEnabled from the constructor. > > I was actually planning on deleting that field, so we can do the check a bit > later. We're already doing the multiple locks thing elsewhere, with the same two > locks, so we'll have to always acquire them in the same order anyway. Added a > comment about this on mFinishedListenerLock. Why do you plan to delete that field? We don't win a whole lot by delaying the check from constructor to when start() is called. However, if you planning to remove the synchronized block from CronetUrlRequestContext#createRequest(), then this is fine with me. Just making sure there won't be two synchronized blocks trying to do the same thing. https://codereview.chromium.org/2351793003/diff/40001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/40001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:414: void CronetURLRequestAdapter::MaybeReportMetrics(JNIEnv* env) const { I don't quite understand the need to populate |end_time_| elsewhere. Since |end_time_| is only useful if we are reporting metrics. How about having |end_time_| as a local variable here? I am assuming that we always destroy CronetURLRequestAdapter, so |end_time_| should be pretty accurate -- only off by one or two JNI roundtrip.
https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:364: MaybeReportMetrics(url_request_.get()); On 2016/10/01 13:43:49, xunjieli wrote: > On 2016/09/30 23:47:14, mgersh wrote: > > On 2016/09/22 18:05:15, xunjieli wrote: > > > This will be invoked after the Java destroyRequestAdapter() which calls > > > mRequestContext.reportFinished(). It looks like we will not have the > Metrics > > > info at the time when we try to update CronetUrlRequestContext if request > > fails > > > or is canceled. > > > > > > How about removing all invocations of MaybeReportMetrics() in this file, and > > > only leave one here in DestroyOnNetworkThread()? if (enable_metrics_) then > > call > > > Java_CronetUrlRequest_onMetricsCollected which will then do > > > mRequestContext.reportFinished()? > > > > > > We should add a test where the request is canceled or fails after request > > > headers, and make sure we have the correct load timing info. > > > > Wow, yeah, thanks for catching that. Wrote a test. Unfortunately, my attempt > at > > implementing your suggested fix caused all the tests to become flaky. The > > version I uploaded mostly fixes it, but not 100% (I saw a failure on > requestEnd > > not being before endTime), and the "Thread.sleep(1000)" everywhere is ugly. Do > > you have better ideas about how to fix it? > > Instead of doing "Thread.sleep(1000)," how about waiting until a number of > UrlRequestFinishedInfo has been observed? > Something like: > https://codereview.chromium.org/2360813003/diff/40001/components/cronet/andro... > ? Done, thanks for the help. https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java:207: mRequestContext.hasRequestFinishedListener()); On 2016/10/01 13:43:49, xunjieli wrote: > On 2016/09/30 23:47:14, mgersh wrote: > > On 2016/09/20 21:53:33, xunjieli wrote: > > > Can we just use the metricsCollectionEnabled field from the constructor? > > > Grabbing the mUrlRequestAdapterLock and another lock makes me nervous about > > > deadlock. Since this is a best effort thing, I think it's fine to use > > > metricsCollectionEnabled from the constructor. > > > > I was actually planning on deleting that field, so we can do the check a bit > > later. We're already doing the multiple locks thing elsewhere, with the same > two > > locks, so we'll have to always acquire them in the same order anyway. Added a > > comment about this on mFinishedListenerLock. > > Why do you plan to delete that field? We don't win a whole lot by delaying the > check from constructor to when start() is called. > However, if you planning to remove the synchronized block from > CronetUrlRequestContext#createRequest(), then this is fine with me. Just making > sure there won't be two synchronized blocks trying to do the same thing. Mostly because I prefer not having that information stored in an excessive number of places, and using metricsCollectionEnabled from the constructor would require adding it as a member variable on CronetUrlRequest in addition to the native request adapter and the list of listeners in the CronetUrlRequestContext. But yes, that block is getting deleted. https://codereview.chromium.org/2351793003/diff/40001/components/cronet/andro... File components/cronet/android/cronet_url_request_adapter.cc (right): https://codereview.chromium.org/2351793003/diff/40001/components/cronet/andro... components/cronet/android/cronet_url_request_adapter.cc:414: void CronetURLRequestAdapter::MaybeReportMetrics(JNIEnv* env) const { On 2016/10/01 13:43:49, xunjieli wrote: > I don't quite understand the need to populate |end_time_| elsewhere. Since > |end_time_| is only useful if we are reporting metrics. How about having > |end_time_| as a local variable here? I am assuming that we always destroy > CronetURLRequestAdapter, so |end_time_| should be pretty accurate -- only off by > one or two JNI roundtrip. On my test device it's usually off by 1ms, sometimes 0, sometimes 2. I guess that's fine. Changed it back.
woohoo! great work. lgtm https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... File components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java (right): https://codereview.chromium.org/2351793003/diff/20001/components/cronet/andro... components/cronet/android/java/src/org/chromium/net/impl/CronetUrlRequest.java:207: mRequestContext.hasRequestFinishedListener()); On 2016/10/04 21:14:58, mgersh wrote: > On 2016/10/01 13:43:49, xunjieli wrote: > > On 2016/09/30 23:47:14, mgersh wrote: > > > On 2016/09/20 21:53:33, xunjieli wrote: > > > > Can we just use the metricsCollectionEnabled field from the constructor? > > > > Grabbing the mUrlRequestAdapterLock and another lock makes me nervous > about > > > > deadlock. Since this is a best effort thing, I think it's fine to use > > > > metricsCollectionEnabled from the constructor. > > > > > > I was actually planning on deleting that field, so we can do the check a bit > > > later. We're already doing the multiple locks thing elsewhere, with the same > > two > > > locks, so we'll have to always acquire them in the same order anyway. Added > a > > > comment about this on mFinishedListenerLock. > > > > Why do you plan to delete that field? We don't win a whole lot by delaying the > > check from constructor to when start() is called. > > However, if you planning to remove the synchronized block from > > CronetUrlRequestContext#createRequest(), then this is fine with me. Just > making > > sure there won't be two synchronized blocks trying to do the same thing. > > Mostly because I prefer not having that information stored in an excessive > number of places, and using metricsCollectionEnabled from the constructor would > require adding it as a member variable on CronetUrlRequest in addition to the > native request adapter and the list of listeners in the CronetUrlRequestContext. > But yes, that block is getting deleted. Acknowledged. https://codereview.chromium.org/2351793003/diff/100001/components/cronet/andr... File components/cronet/android/test/javatests/src/org/chromium/net/MetricsTestUtil.java (right): https://codereview.chromium.org/2351793003/diff/100001/components/cronet/andr... components/cronet/android/test/javatests/src/org/chromium/net/MetricsTestUtil.java:25: * Executor which runs tasks only when told to with runAllTasks(). minor style nit: I didn't notice it in the other CL. Could you change the format of the * ? The * on the second line should be aligned with the first star of the first line. https://codereview.chromium.org/2351793003/diff/100001/components/cronet/andr... File components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java (right): https://codereview.chromium.org/2351793003/diff/100001/components/cronet/andr... components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java:136: testExecutor.blockUntilDone(); Why don't we use requestFinishedListener.blockUntilDone() here? Could you add a comment?
Yay! Thanks for all your help with this! https://codereview.chromium.org/2351793003/diff/100001/components/cronet/andr... File components/cronet/android/test/javatests/src/org/chromium/net/MetricsTestUtil.java (right): https://codereview.chromium.org/2351793003/diff/100001/components/cronet/andr... components/cronet/android/test/javatests/src/org/chromium/net/MetricsTestUtil.java:25: * Executor which runs tasks only when told to with runAllTasks(). On 2016/10/04 22:29:23, xunjieli wrote: > minor style nit: I didn't notice it in the other CL. Could you change the format > of the * ? The * on the second line should be aligned with the first star of the > first line. Yeah, I was wondering how/why that happened. Done. https://codereview.chromium.org/2351793003/diff/100001/components/cronet/andr... File components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java (right): https://codereview.chromium.org/2351793003/diff/100001/components/cronet/andr... components/cronet/android/test/javatests/src/org/chromium/net/RequestFinishedInfoTest.java:136: testExecutor.blockUntilDone(); On 2016/10/04 22:29:23, xunjieli wrote: > Why don't we use requestFinishedListener.blockUntilDone() here? > Could you add a comment? The point of this test is to use a direct executor, and TestRequestFinishedListener's blocking functionality doesn't work if you use the constructor with an executor. This is a little weird and I'm planning to do some cleanup in a future CL. Added a comment here, and a TODO in TestRequestFinishedListener.
The CQ bit was checked by mgersh@chromium.org
The patchset sent to the CQ was uploaded after l-g-t-m from xunjieli@chromium.org Link to the patchset: https://codereview.chromium.org/2351793003/#ps120001 (title: "Small cleanups")
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 #7 (id:120001)
Message was sent while issue was closed.
Description was changed from ========== Implement timing metrics for UrlRequest This CL implements all of the timing APIs in RequestFinishedInfo.Metrics, in most cases by plumbing them through from net::LoadTimingInfo. Some of the old metrics code is no longer used and will be deleted in a follow-up CL. Redirect handling and new features of RequestFinishedInfo other than timing are not yet implemented. BUG=629194 ========== to ========== Implement timing metrics for UrlRequest This CL implements all of the timing APIs in RequestFinishedInfo.Metrics, in most cases by plumbing them through from net::LoadTimingInfo. Some of the old metrics code is no longer used and will be deleted in a follow-up CL. Redirect handling and new features of RequestFinishedInfo other than timing are not yet implemented. BUG=629194 Committed: https://crrev.com/6408523c44fd12383d385b02ba9aee872fe8618c Cr-Commit-Position: refs/heads/master@{#423194} ==========
Message was sent while issue was closed.
Patchset 7 (id:??) landed as https://crrev.com/6408523c44fd12383d385b02ba9aee872fe8618c Cr-Commit-Position: refs/heads/master@{#423194} |
