Implement QuicHttpStream::GetLoadTimingInfo

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
Committed: https://crrev.com/100937eb53048b5d2df84438ce09c9067d96ccfb
Cr-Original-Original-Commit-Position: refs/heads/master@{#417969}
Cr-Original-Commit-Position: refs/heads/master@{#418567}
Cr-Commit-Position: refs/heads/master@{#418946}

[xunjieli, 2016-09-09 19:37:10]

Patchset #1 (id:1) has been deleted

[xunjieli, 2016-09-09 19:43:06]

Description was changed from

==========
Implement QuicHttpStream::GetLoadTimingInfo

This CL implements QuicHttpStream::GetLoadTimingInfo.

BUG=637051
==========

to

==========
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 it 
completes.

|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
==========

[xunjieli, 2016-09-09 19:43:51]

Description was changed from

==========
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 it 
completes.

|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
==========

to

==========
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
CryptoConnect() completes.

|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
==========

[xunjieli, 2016-09-09 19:47:32]

xunjieli@chromium.org changed reviewers:
+ mmenke@chromium.org, rch@chromium.org

[xunjieli, 2016-09-09 19:47:32]

Hi Ryan and Matt: here's an attempt to implement
QuicHttpStream::GetLoadTimingInfo(), which might be totally off... Please
advice. Thanks!

[Ryan Hamilton, 2016-09-09 20:02:49]

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
File net/quic/chromium/quic_chromium_client_session.cc (right):

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
net/quic/chromium/quic_chromium_client_session.cc:621:
connect_timing_.connect_end = base::TimeTicks::Now();
Do you know what the semantics of connect_end should be in the case of 0-RTT?
Should it be when we're able to send the request (in which case your code is
correct). Or should it be when we receive confirmation from the server?

Also, we should make sure we do the right thing in the case of failed 0-RTT:

T0: Send CHLO
T1: Send encrypted GET
T2: Receive rej
T3: Send new CHLO
T4: Send re-encrypted GET

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
File net/quic/chromium/quic_http_stream.cc (right):

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
net/quic/chromium/quic_http_stream.cc:427: // FIXME: any constant that I can use
to avoid hardcoding 5?
kHeadersStreamId + 2.

But that being said, I think the logic of "is this reused" should probably be
implemented down in the QUIC stream layer. I'd be inclined to add a bool
IsFirstStream() or something method which does this logic.

[xunjieli, 2016-09-09 21:20:12]

Patchset #2 (id:40001) has been deleted

[xunjieli, 2016-09-09 21:22:06]

Description was changed from

==========
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
CryptoConnect() completes.

|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
==========

to

==========
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
==========

[xunjieli, 2016-09-09 21:26:59]

Thanks for the review! PTAL.

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
File net/quic/chromium/quic_chromium_client_session.cc (right):

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
net/quic/chromium/quic_chromium_client_session.cc:621:
connect_timing_.connect_end = base::TimeTicks::Now();
On 2016/09/09 20:02:49, Ryan Hamilton wrote:
> Do you know what the semantics of connect_end should be in the case of 0-RTT?
> Should it be when we're able to send the request (in which case your code is
> correct). Or should it be when we receive confirmation from the server?
> 
> Also, we should make sure we do the right thing in the case of failed 0-RTT:
> 
> T0: Send CHLO
> T1: Send encrypted GET
> T2: Receive rej
> T3: Send new CHLO
> T4: Send re-encrypted GET
> 

Done. That's a really good point! I didn't think of that. I have changed the
code to track the handshake confirmation instead. I think this sould handle the
failed 0-RTT case as well,since the |connect_end| is only updated when handshake
is confirmed.

I checked with mmenke@ too -- We should wait until handshake is confirmed, and
the time should include multiple rounds of authentication attempts.

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
File net/quic/chromium/quic_http_stream.cc (right):

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
net/quic/chromium/quic_http_stream.cc:427: // FIXME: any constant that I can use
to avoid hardcoding 5?
On 2016/09/09 20:02:49, Ryan Hamilton wrote:
> kHeadersStreamId + 2.
> 
> But that being said, I think the logic of "is this reused" should probably be
> implemented down in the QUIC stream layer. I'd be inclined to add a bool
> IsFirstStream() or something method which does this logic.

Done. I added a static method to QuicChromiumClientStream. I didn't add a member
method because I need the id() to check whether |stream| creation is successful
as well. Let me know if there's a better place for the IsFirstStream(id) method.

[xunjieli, 2016-09-09 21:27:10]

The CQ bit was checked by xunjieli@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-09-09 21:27:38]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[Ryan Hamilton, 2016-09-09 22:05:39]

Thanks! I have a couple questions about what LoadTiming expects for:

1) multiplexed transports
2) 0-RTT connects

Your code seems entirely reasonable, but I wonder if there is a spec about this?

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
File net/quic/chromium/quic_chromium_client_session.cc (right):

https://codereview.chromium.org/2324183002/diff/20001/net/quic/chromium/quic_...
net/quic/chromium/quic_chromium_client_session.cc:621:
connect_timing_.connect_end = base::TimeTicks::Now();
On 2016/09/09 21:26:59, xunjieli wrote:
> On 2016/09/09 20:02:49, Ryan Hamilton wrote:
> > Do you know what the semantics of connect_end should be in the case of
0-RTT?
> > Should it be when we're able to send the request (in which case your code is
> > correct). Or should it be when we receive confirmation from the server?
> > 
> > Also, we should make sure we do the right thing in the case of failed 0-RTT:
> > 
> > T0: Send CHLO
> > T1: Send encrypted GET
> > T2: Receive rej
> > T3: Send new CHLO
> > T4: Send re-encrypted GET
> > 
> 
> Done. That's a really good point! I didn't think of that. I have changed the
> code to track the handshake confirmation instead. I think this sould handle
the
> failed 0-RTT case as well,since the |connect_end| is only updated when
handshake
> is confirmed.
> 
> I checked with mmenke@ too -- We should wait until handshake is confirmed, and
> the time should include multiple rounds of authentication attempts.

This seems reasonable to me. But it's worth keeping in mind that in the case of
a successful 0-RTT connection, the request can be sent immediately after the
handshake is started. For example:
T0: dns start
T1: dns end
T2: handshake start
T2 + epsilon: send request
T3: handshake end
T3 + epsilon: receive response.

The current code would say that
DNS = T1-T0
CONNECT = T3- T2
REQUEST = T3- T2
TOTAL = T3- T2 + T3- T2 + T1-T0
But the actual elapsed time is simply: T3-T0

(My notation is getting really sloppy, but I hope it's clear enough).

So I'm not sure what the callers for LoadTiming expect to see for Connect time
in the case of successful 0-RTT.

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
File net/quic/chromium/quic_chromium_client_session.cc (right):

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
net/quic/chromium/quic_chromium_client_session.cc:1256: 
Should we have some unit tests for the various cases? 0-RTT/Failed 0-RTT, etc

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
File net/quic/chromium/quic_chromium_client_stream.h (right):

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
net/quic/chromium/quic_chromium_client_stream.h:126: static bool
isFirstStream(QuicStreamId id);
Instead of making this a static method, let's make this non-static. In
QuicHttpStream, instead of stashing the stream_id, you'll want to stash the
result of calling this method.

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
net/quic/chromium/quic_chromium_client_stream.h:126: static bool
isFirstStream(QuicStreamId id);
I think this method should be "IsFirst", not "isFirst". "isFirst" is the
java-style and makes me miss java... *sniff*

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
File net/quic/chromium/quic_http_stream.cc (right):

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
net/quic/chromium/quic_http_stream.cc:428: load_timing_info->connect_timing =
connect_timing_;
I'm not sure what the semantics should be for connect_timing_ as it relates to
multiplexed transports. If we make two requests at the same time, they'll both
have to wait for DNS and for the Handshake so it *sorta* seems like we should
account for this is both.

But I'm happy with what you're doing here if that's the semantics that
LoadTimingInfo wants)

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
File net/quic/chromium/quic_http_stream.h (right):

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
net/quic/chromium/quic_http_stream.h:182: QuicStreamId closed_stream_id_;
Let's store is_first, instead.

[commit-bot: I haz the power, 2016-09-09 22:32:10]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-09-09 22:32:11]

Dry run: This issue passed the CQ dry run.

[xunjieli, 2016-09-12 16:01:39]

Patchset #3 (id:80001) has been deleted

[xunjieli, 2016-09-12 16:05:22]

Patchset #3 (id:100001) has been deleted

[xunjieli, 2016-09-12 16:07:23]

> 1) multiplexed transports
> 2) 0-RTT connects

> Your code seems entirely reasonable, but I wonder if there 
> is a spec about this?


Thanks a lot for the review!

The specs are at 
https://www.w3.org/TR/resource-timing/
and
https://www.w3.org/TR/navigation-timing/

However, the specs are designed with TCP in mind and they don't have any
guideline to the 0-RTT scenario and the multiplex scenario.

(1) multiplex transport
H2 currently only populates the first stream/request. I think it's reasonable to
match H2's implementation.
(2) 0-RTT
The specs doesn't say anything about this. I think for now we can let our Cronet
users know that they cannot simply sum up the timings, and they need to take
note of 0-RTT.

I have uploaded a new patch. PTAL.

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
File net/quic/chromium/quic_chromium_client_stream.h (right):

https://codereview.chromium.org/2324183002/diff/60001/net/quic/chromium/quic_...
net/quic/chromium/quic_chromium_client_stream.h:126: static bool
isFirstStream(QuicStreamId id);
On 2016/09/09 22:05:39, Ryan Hamilton wrote:
> Instead of making this a static method, let's make this non-static. In
> QuicHttpStream, instead of stashing the stream_id, you'll want to stash the
> result of calling this method.

If we only use a bool, there is no way to differentiate in QuicHttpStream
between when the QuicChromiumClientStream fails to be created and when the
QuicChromiumClientStream is not the first stream.

If we only have a |is_first_| bool in QuicHttpStream. Its default value is
false. If the stream failed for some reason, |is_first_| is false, and we will
return true in GetLoadTimingInfo.

In SpdyHttpStream, GetLoadTimingInfo returns false if the underlying spdy_stream
failed to be created. I stored the |id| to match the behavior. You can see the
diff of quic_http_stream_test.cc between PS #2 and PS #3 to see the change in
QuicHttpStream::GetLoadTimingInfo's behavior.

Maybe the difference is not significant, so I changed to use your approach.
Done.

[xunjieli, 2016-09-12 16:32:23]

The CQ bit was checked by xunjieli@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-09-12 16:32:50]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[Ryan Hamilton, 2016-09-12 16:37:58]

lgtm

[xunjieli, 2016-09-12 17:20:53]

xunjieli@chromium.org changed reviewers:
- mmenke@chromium.org

[xunjieli, 2016-09-12 17:24:11]

The CQ bit was unchecked by xunjieli@chromium.org

[xunjieli, 2016-09-12 17:24:20]

The CQ bit was checked by xunjieli@chromium.org

[commit-bot: I haz the power, 2016-09-12 17:24:36]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-09-12 17:44:41]

Description was changed from

==========
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
==========

to

==========
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
==========

[commit-bot: I haz the power, 2016-09-12 17:44:43]

Committed patchset #3 (id:120001)

[commit-bot: I haz the power, 2016-09-12 17:46:09]

Description was changed from

==========
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
==========

to

==========
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}
==========

[commit-bot: I haz the power, 2016-09-12 17:46:10]

Patchset 3 (id:??) landed as
https://crrev.com/5608fc1bd4f0a80b6d1996f3f4059f2efa0a0777
Cr-Commit-Position: refs/heads/master@{#417969}

[mef, 2016-09-12 21:16:11]

A revert of this CL (patchset #3 id:120001) has been created in
https://codereview.chromium.org/2333863003/ by mef@chromium.org.

The reason for reverting is: Causing http://crbug.com/646087.

[xunjieli, 2016-09-13 18:56:00]

Description was changed from

==========
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}
==========

to

==========
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}
==========

[xunjieli, 2016-09-13 18:56:29]

The CQ bit was checked by xunjieli@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-09-13 18:57:02]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-09-13 18:59:55]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-09-13 18:59:56]

Dry run: Try jobs failed on following builders:
  ios-device on master.tryserver.chromium.mac (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.mac/builders/ios-device/builds...)
  ios-simulator on master.tryserver.chromium.mac (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.mac/builders/ios-simulator/bui...)
  mac_chromium_compile_dbg_ng on master.tryserver.chromium.mac (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.mac/builders/mac_chromium_comp...)

[xunjieli, 2016-09-13 19:08:45]

Hi Ryan, there was a bug in my earlier patch. Sorry about that!
The bug is that |QuicHttpStream::connect_timing_| was set before handshake is
confirmed. When URLRequest's ConvertRealLoadTimesToBlockingTimes() checks the
|connect_timing|, |connect_end| can be null while |connect_start| isn't. Patch
#4 has the fix and two regression tests (url_request_quic_unittest.cc). I also
built chrome and confirmed that we no longer see the DCHECK failure. The http
stream level tests didn't catch the problem because the test fixture always
triggers handshake before the tests and the DCHECKs are in url_request.cc.

PTAL at diffs between PS#3 and #4. Thanks!

[xunjieli, 2016-09-13 19:20:21]

The CQ bit was checked by xunjieli@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-09-13 19:21:03]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-09-13 19:58:29]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-09-13 19:58:31]

Dry run: Try jobs failed on following builders:
  win_chromium_x64_rel_ng on master.tryserver.chromium.win (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_x64_...)

[Ryan Hamilton, 2016-09-13 20:54:08]

lgtm

https://codereview.chromium.org/2324183002/diff/180001/net/url_request/url_re...
File net/url_request/url_request_quic_unittest.cc (right):

https://codereview.chromium.org/2324183002/diff/180001/net/url_request/url_re...
net/url_request/url_request_quic_unittest.cc:181: CheckLoadTimingDelegate
delegate(false);
Thanks for doing this!! We have net/quic/chromium/quic_end_to_end_unittest.cc
but that only tests at the transaction level not the URLRequest level.

[xunjieli, 2016-09-14 13:55:13]

The CQ bit was checked by xunjieli@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-09-14 13:55:26]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-09-14 15:02:25]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-09-14 15:02:26]

Dry run: This issue passed the CQ dry run.

[xunjieli, 2016-09-14 15:07:46]

Thanks for the review!

https://codereview.chromium.org/2324183002/diff/180001/net/url_request/url_re...
File net/url_request/url_request_quic_unittest.cc (right):

https://codereview.chromium.org/2324183002/diff/180001/net/url_request/url_re...
net/url_request/url_request_quic_unittest.cc:181: CheckLoadTimingDelegate
delegate(false);
On 2016/09/13 20:54:08, Ryan Hamilton wrote:
> Thanks for doing this!! We have net/quic/chromium/quic_end_to_end_unittest.cc
> but that only tests at the transaction level not the URLRequest level.

No problem! Yes, I copied over the test fixture setup from
quic_end_to_end_unittest.cc. There's a bit of duplicated test code, but it's
nice to have them on a higher layer (URLRequest layer) :)

[xunjieli, 2016-09-14 15:07:52]

The CQ bit was checked by xunjieli@chromium.org

[xunjieli, 2016-09-14 15:07:53]

The patchset sent to the CQ was uploaded after l-g-t-m from rch@chromium.org
Link to the patchset: https://codereview.chromium.org/2324183002/#ps200001
(title: "style fix")

[commit-bot: I haz the power, 2016-09-14 15:08:13]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-09-14 15:13:06]

Description was changed from

==========
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}
==========

to

==========
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}
==========

[commit-bot: I haz the power, 2016-09-14 15:13:07]

Committed patchset #7 (id:200001)

[commit-bot: I haz the power, 2016-09-14 15:16:49]

Description was changed from

==========
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}
==========

to

==========
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}
==========

[commit-bot: I haz the power, 2016-09-14 15:16:50]

Patchset 7 (id:??) landed as
https://crrev.com/83ac2f22700c563fef8a670ad4c5c57d34032e03
Cr-Commit-Position: refs/heads/master@{#418567}

[grt (UTC plus 2), 2016-09-15 09:43:05]

A revert of this CL (patchset #7 id:200001) has been created in
https://codereview.chromium.org/2341033002/ by grt@chromium.org.

The reason for reverting is: URLRequestQuicTest.TestTwoRequests is flaky, see
https://crbug.com/647071..

[xunjieli, 2016-09-15 15:07:45]

Description was changed from

==========
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}
==========

to

==========
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}
==========

[xunjieli, 2016-09-15 15:07:57]

The CQ bit was checked by xunjieli@chromium.org to run a CQ dry run

[commit-bot: I haz the power, 2016-09-15 15:08:30]

Dry run: CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[xunjieli, 2016-09-15 15:10:34]

Hi Ryan,

PTAL at the diff in url_request_quic_unittest.cc between PS#7 and PS#8. This is
to fix the flakiness seen on a Windows bot (crbug.com/647071). 

I talked to mmenke@ and learned that TestDelegate is hacky and pre-dates
base::RunLoop. The solution here is to use a custom NetworkDelegate which waits
until both requests complete before checking the response body.

PTAL. Thanks!

[commit-bot: I haz the power, 2016-09-15 16:49:13]

The CQ bit was unchecked by commit-bot@chromium.org

[commit-bot: I haz the power, 2016-09-15 16:49:14]

Dry run: Try jobs failed on following builders:
  win_chromium_rel_ng on master.tryserver.chromium.win (JOB_FAILED,
http://build.chromium.org/p/tryserver.chromium.win/builders/win_chromium_rel_...)

[Ryan Hamilton, 2016-09-15 16:58:37]

On 2016/09/15 15:10:34, xunjieli wrote:
> Hi Ryan,
> 
> PTAL at the diff in url_request_quic_unittest.cc between PS#7 and PS#8. This
is
> to fix the flakiness seen on a Windows bot (crbug.com/647071). 
> 
> I talked to mmenke@ and learned that TestDelegate is hacky and pre-dates
> base::RunLoop. The solution here is to use a custom NetworkDelegate which
waits
> until both requests complete before checking the response body.
> 
> PTAL. Thanks!

Wow, I'm glad you figured that out! LGTM.

FWIW, PS#8 includes both a Rebase and the fix. Next time you might consider
uploading
the Rebase as a distinct patch set, and then the fix as a second one to make the
diffs more obvious.

Thanks for doing this work! It's great to have this test!

[xunjieli, 2016-09-15 17:47:27]

On 2016/09/15 16:58:37, Ryan Hamilton wrote:
> On 2016/09/15 15:10:34, xunjieli wrote:
> > Hi Ryan,
> > 
> > PTAL at the diff in url_request_quic_unittest.cc between PS#7 and PS#8. This
> is
> > to fix the flakiness seen on a Windows bot (crbug.com/647071). 
> > 
> > I talked to mmenke@ and learned that TestDelegate is hacky and pre-dates
> > base::RunLoop. The solution here is to use a custom NetworkDelegate which
> waits
> > until both requests complete before checking the response body.
> > 
> > PTAL. Thanks!
> 
> Wow, I'm glad you figured that out! LGTM.
> 
> FWIW, PS#8 includes both a Rebase and the fix. Next time you might consider
> uploading
> the Rebase as a distinct patch set, and then the fix as a second one to make
the
> diffs more obvious.

Ah, you are right! I should have thought that. I will keep that in mind next
time. Thanks for getting back to this so quickly!

[xunjieli, 2016-09-15 17:47:55]

The CQ bit was checked by xunjieli@chromium.org

[commit-bot: I haz the power, 2016-09-15 17:48:42]

CQ is trying da patch. Follow status at
 
https://chromium-cq-status.appspot.com/v2/patch-status/codereview.chromium.or...

[commit-bot: I haz the power, 2016-09-15 20:09:53]

Description was changed from

==========
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}
==========

to

==========
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}
==========

[commit-bot: I haz the power, 2016-09-15 20:09:54]

Committed patchset #8 (id:220001)

[commit-bot: I haz the power, 2016-09-15 20:12:34]

Description was changed from

==========
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}
==========

to

==========
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
Committed: https://crrev.com/100937eb53048b5d2df84438ce09c9067d96ccfb
Cr-Original-Original-Commit-Position: refs/heads/master@{#417969}
Cr-Original-Commit-Position: refs/heads/master@{#418567}
Cr-Commit-Position: refs/heads/master@{#418946}
==========

[commit-bot: I haz the power, 2016-09-15 20:12:36]

Patchset 8 (id:??) landed as
https://crrev.com/100937eb53048b5d2df84438ce09c9067d96ccfb
Cr-Commit-Position: refs/heads/master@{#418946}