New issue
Advanced search Search tips
Note: Color blocks (like or ) mean that a user may not be available. Tooltip shows the reason.

Issue 637051 link

Starred by 3 users

Issue metadata

Status: Fixed
Owner:
Last visit > 30 days ago
Closed: Sep 2016
Cc:
Components:
EstimatedDays: ----
NextAction: ----
OS: All
Pri: 2
Type: Bug

Blocked on:
issue 646087

Blocking:
issue 629194



Sign in to add a comment

Implement GetLoadTimingInfo for QuicHttpStream

Project Member Reported by xunji...@chromium.org, Aug 11 2016

Issue description

bool QuicHttpStream::GetLoadTimingInfo(LoadTimingInfo* load_timing_info) const {
  // TODO(mmenke):  Figure out what to do here.
  return true;
}

If QUIC is negotiated, we won't be able to get LoadTimingInfo. LoadTimingInfo is important as it is exposed as a web API, and it is important for metrics gathering.


 
A clarification after looking at the code some more -- we will still be able to get LoadTimingInfo, but it doesn't have ConnectTiming. If anyone is already working on this, please let me know :)
Status: Started (was: Assigned)
Project Member

Comment 3 by bugdroid1@chromium.org, Sep 8 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/c6f081483992e01bc1ce6f24842911569892b14d

commit c6f081483992e01bc1ce6f24842911569892b14d
Author: xunjieli <xunjieli@chromium.org>
Date: Thu Sep 08 19:00:21 2016

Add back initialization of |dns_resolution_end_time_| in QuicStreamFactory::Job

|dns_resolution_end_time_| is still used in other histograms
(e.g. Net.QuicServerInfo.DiskCacheWaitForDataReadyTime and
Net.QuicSession.HostResolution.HandshakeConfirmedTime).

The initialization is removed in crrev.com/2256803002. This CL adds it back
to maintain correctness of the remaining histograms which are still using this
field.

R=zhongyi@chromium.org

BUG=629384,  637051 

Review-Url: https://codereview.chromium.org/2314403006
Cr-Commit-Position: refs/heads/master@{#417355}

[modify] https://crrev.com/c6f081483992e01bc1ce6f24842911569892b14d/net/quic/chromium/quic_stream_factory.cc

Project Member

Comment 4 by bugdroid1@chromium.org, Sep 12 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777

commit 5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777
Author: xunjieli <xunjieli@chromium.org>
Date: Mon Sep 12 17:44:19 2016

Implement QuicHttpStream::GetLoadTimingInfo

This CL implements QuicHttpStream::GetLoadTimingInfo.

|dns_start| and |dns_end| are obtained in
QuicStreamFactory::Job::DoResolveHost and
DoResolveHostComplete. These two values are passed to
QuicChromiumClientSession's constructor.

|connect_start| and |connect_end| are obtained in
QuicChromiumClientSession::CrytoConnect() and when
handshake is confirmed.

|ssl_start| and |ssl_end| are the same as |connect_start|
and |connect_end| because QUIC always does encryption.

If a session is reused, the connect_timing fields should
all be null. This CL also sets
|socket_reused| field of LoadTimingInfo accordingly.

BUG= 637051 

Review-Url: https://codereview.chromium.org/2324183002
Cr-Commit-Position: refs/heads/master@{#417969}

[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/bidirectional_stream_quic_impl_unittest.cc
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_chromium_client_session.cc
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_chromium_client_session.h
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_chromium_client_session_test.cc
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_chromium_client_stream.cc
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_chromium_client_stream.h
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_http_stream.cc
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_http_stream.h
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_http_stream_test.cc
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_stream_factory.cc
[modify] https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777/net/quic/chromium/quic_stream_factory.h

Status: Fixed (was: Started)
Ryan brought up a few important issues in the CL review. The ResourceTiming and NavigationTiming specs aren't clear as to what we should do, since the specs are designed with TCP in mind and QUIC is different. 

Here's a summary:
(1) When 0-RTT is used, even though we send out the request as soon as the encryption is established, we still use the time of handshake confirmation as the |connect_end|. In the case of a successful 0-RTT, |LoadTimingInfo::send_start| might be earlier than |connect_end|. Consumers need to be aware of the 0-RTT case when doing latency measurements. 

(2) Streams are multiplexed onto a single connection. Only the first request will have non-null times in |connect_timing|. This is done to match H2's implementation. If two stream requests are started around the same time, they both might wait for DNS and handshake, but we'll only populate the |connect_timing| of the first request.

Comment 6 by mge...@chromium.org, Sep 12 2016

Thanks for leaving these notes! I added them into https://codereview.chromium.org/2220023002/.
Project Member

Comment 7 by bugdroid1@chromium.org, Sep 12 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02

commit 44c972ebe17064be1d7dbe1c7bdf7c982e56eb02
Author: mef <mef@chromium.org>
Date: Mon Sep 12 21:19:34 2016

Revert of Implement QuicHttpStream::GetLoadTimingInfo (patchset #3 id:120001 of https://codereview.chromium.org/2324183002/ )

Reason for revert:
Causing  http://crbug.com/646087 

Original issue's description:
> Implement QuicHttpStream::GetLoadTimingInfo
>
> This CL implements QuicHttpStream::GetLoadTimingInfo.
>
> |dns_start| and |dns_end| are obtained in
> QuicStreamFactory::Job::DoResolveHost and
> DoResolveHostComplete. These two values are passed to
> QuicChromiumClientSession's constructor.
>
> |connect_start| and |connect_end| are obtained in
> QuicChromiumClientSession::CrytoConnect() and when
> handshake is confirmed.
>
> |ssl_start| and |ssl_end| are the same as |connect_start|
> and |connect_end| because QUIC always does encryption.
>
> If a session is reused, the connect_timing fields should
> all be null. This CL also sets
> |socket_reused| field of LoadTimingInfo accordingly.
>
> BUG= 637051 
>
> Committed: https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777
> Cr-Commit-Position: refs/heads/master@{#417969}

TBR=rch@chromium.org,xunjieli@chromium.org
# Skipping CQ checks because original CL landed less than 1 days ago.
NOPRESUBMIT=true
NOTREECHECKS=true
NOTRY=true
BUG= 637051 

Review-Url: https://codereview.chromium.org/2333863003
Cr-Commit-Position: refs/heads/master@{#418045}

[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/bidirectional_stream_quic_impl_unittest.cc
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_chromium_client_session.cc
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_chromium_client_session.h
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_chromium_client_session_test.cc
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_chromium_client_stream.cc
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_chromium_client_stream.h
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_http_stream.cc
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_http_stream.h
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_http_stream_test.cc
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_stream_factory.cc
[modify] https://crrev.com/44c972ebe17064be1d7dbe1c7bdf7c982e56eb02/net/quic/chromium/quic_stream_factory.h

Comment 8 by kbr@chromium.org, Sep 12 2016

Blockedon: 646087

Comment 9 by kbr@chromium.org, Sep 12 2016

Cc: nedngu...@google.com erikc...@chromium.org eyaich@chromium.org
Labels: Stability
Status: Started (was: Fixed)
The tests for this change were not adequate; it managed to get through Chromium's commit queue and still run all of the bots' automated tests, but broke the browser itself.

Please rethink the testing strategy for this CL. If end-to-end tests are needed, Telemetry-based integration tests may be the best approach. However, the bots typically don't make network connections to external services, so thought needs to be given as to how to simulate the traffic that caused this assertion failure.

Cc: sullivan@chromium.org
Can we stands up a local python server that serve QUIC? If so, telemetry provides hooks for connecting to the local server.
For what it's worth, Cronet's tests did catch it, but we only have one debug bot which runs tests and it isn't on the CQ so people found it in the browser first. Whatever Cronet does that caught it (I didn't look at the details, but the test run is https://build.chromium.org/p/chromium.android/builders/Android%20Cronet%20Builder%20%28dbg%29/builds/3071) is probably either already doable in tests for the browser or could be adaptable.
Cc: rch@chromium.org
I also don't think the inadequate testing particularly has anything to do with this CL. It was a fairly limited change to improve metrics information which already exists elsewhere in the net stack and there is no reason for it to require adding new end-to-end tests. Testing for QUIC should have already existed that would have caught an issue like this one. Maybe rch@ or other QUIC people can say more.
Sorry for the trouble caused. I was OOO yesterday afternoon. The DCHECKs are checking invariants that do not apply to QUIC 0-RTT case. Since the CL is reverted, I am assuming all is good. I will work on a fix and a regression test.
Cc: xunji...@chromium.org
 Issue 646154  has been merged into this issue.
Project Member

Comment 15 by bugdroid1@chromium.org, Sep 14 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/83ac2f22700c563fef8a670ad4c5c57d34032e03

commit 83ac2f22700c563fef8a670ad4c5c57d34032e03
Author: xunjieli <xunjieli@chromium.org>
Date: Wed Sep 14 15:12:49 2016

Implement QuicHttpStream::GetLoadTimingInfo

This CL implements QuicHttpStream::GetLoadTimingInfo.

|dns_start| and |dns_end| are obtained in
QuicStreamFactory::Job::DoResolveHost and
DoResolveHostComplete. These two values are passed to
QuicChromiumClientSession's constructor.

|connect_start| and |connect_end| are obtained in
QuicChromiumClientSession::CrytoConnect() and when
handshake is confirmed.

|ssl_start| and |ssl_end| are the same as |connect_start|
and |connect_end| because QUIC always does encryption.

If a session is reused, the connect_timing fields should
all be null. This CL also sets
|socket_reused| field of LoadTimingInfo accordingly.

BUG= 637051 

Committed: https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777
Review-Url: https://codereview.chromium.org/2324183002
Cr-Original-Commit-Position: refs/heads/master@{#417969}
Cr-Commit-Position: refs/heads/master@{#418567}

[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/net.gypi
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/bidirectional_stream_quic_impl_unittest.cc
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_chromium_client_session.cc
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_chromium_client_session.h
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_chromium_client_session_test.cc
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_chromium_client_stream.cc
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_chromium_client_stream.h
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_http_stream.cc
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_http_stream.h
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_http_stream_test.cc
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_stream_factory.cc
[modify] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/quic/chromium/quic_stream_factory.h
[add] https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03/net/url_request/url_request_quic_unittest.cc

Cc: -xunji...@chromium.org
Status: Fixed (was: Started)
Thanks everyone who helped! Sorry for the trouble caused.
Project Member

Comment 17 by bugdroid1@chromium.org, Sep 15 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/f94df884d60b6b3f345c1575292b557eabd5ee0a

commit f94df884d60b6b3f345c1575292b557eabd5ee0a
Author: grt <grt@chromium.org>
Date: Thu Sep 15 09:44:03 2016

Revert of Implement QuicHttpStream::GetLoadTimingInfo (patchset #7 id:200001 of https://codereview.chromium.org/2324183002/ )

Reason for revert:
URLRequestQuicTest.TestTwoRequests is flaky, see  https://crbug.com/647071 .

Original issue's description:
> Implement QuicHttpStream::GetLoadTimingInfo
>
> This CL implements QuicHttpStream::GetLoadTimingInfo.
>
> |dns_start| and |dns_end| are obtained in
> QuicStreamFactory::Job::DoResolveHost and
> DoResolveHostComplete. These two values are passed to
> QuicChromiumClientSession's constructor.
>
> |connect_start| and |connect_end| are obtained in
> QuicChromiumClientSession::CrytoConnect() and when
> handshake is confirmed.
>
> |ssl_start| and |ssl_end| are the same as |connect_start|
> and |connect_end| because QUIC always does encryption.
>
> If a session is reused, the connect_timing fields should
> all be null. This CL also sets
> |socket_reused| field of LoadTimingInfo accordingly.
>
> BUG= 637051 
>
> Committed: https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777
> Committed: https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03
> Cr-Original-Commit-Position: refs/heads/master@{#417969}
> Cr-Commit-Position: refs/heads/master@{#418567}

TBR=rch@chromium.org,xunjieli@chromium.org
# Skipping CQ checks because original CL landed less than 1 days ago.
NOPRESUBMIT=true
NOTREECHECKS=true
NOTRY=true
BUG= 637051 

Review-Url: https://codereview.chromium.org/2341033002
Cr-Commit-Position: refs/heads/master@{#418815}

[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/net.gypi
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/bidirectional_stream_quic_impl_unittest.cc
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_chromium_client_session.cc
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_chromium_client_session.h
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_chromium_client_session_test.cc
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_chromium_client_stream.cc
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_chromium_client_stream.h
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_http_stream.cc
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_http_stream.h
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_http_stream_test.cc
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_stream_factory.cc
[modify] https://crrev.com/f94df884d60b6b3f345c1575292b557eabd5ee0a/net/quic/chromium/quic_stream_factory.h
[delete] https://crrev.com/6dfe493ac5735717b5125435db61c57fa2ff5922/net/url_request/url_request_quic_unittest.cc

Project Member

Comment 18 by bugdroid1@chromium.org, Sep 20 2016

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/84adaab847a84e634ee191d208bd8d9e9c7457d2

commit 84adaab847a84e634ee191d208bd8d9e9c7457d2
Author: xunjieli <xunjieli@chromium.org>
Date: Tue Sep 20 01:12:28 2016

Use load_timing_info_test_util.cc in quic_http_stream_test.cc

This CL uses load_timing_info_test_util.cc in quic_http_stream_test.cc
so not to duplicate test logic and fixes an incorrect use of function name
camel case.

BUG= 637051 

Review-Url: https://codereview.chromium.org/2348313004
Cr-Commit-Position: refs/heads/master@{#419620}

[modify] https://crrev.com/84adaab847a84e634ee191d208bd8d9e9c7457d2/net/quic/chromium/quic_http_stream_test.cc

Sign in to add a comment