Enhance net internals/net log output for QUIC.

Enhance net internals/net log output for QUIC.


Committed: https://src.chromium.org/viewvc/chrome?view=rev&revision=182331

[Ryan Hamilton, 2013-02-05 22:39:05]

Hm.  I thought I sent this to you earlier today, but looks like I forgot to hit
Publish.

[mmenke, 2013-02-05 22:56:31]

On 2013/02/05 22:39:05, Ryan Hamilton wrote:
> Hm.  I thought I sent this to you earlier today, but looks like I forgot to
hit
> Publish.

You being who, exactly?  :)

I'll plan to review this tomorrow.

[Ryan Hamilton, 2013-02-05 23:01:52]

Trying again...

[Ryan Hamilton, 2013-02-05 23:02:47]

On 2013/02/05 22:56:31, Matt Menke wrote:
> On 2013/02/05 22:39:05, Ryan Hamilton wrote:
> > Hm.  I thought I sent this to you earlier today, but looks like I forgot to
> hit
> > Publish.
> 
> You being who, exactly?  :)

ARGH!  eroman.  I had added him as a reviewer, but then when i (Eventually) hit
publish, I hit and XSRF error and had to go back and try again....  which lost
the reviewer.  Sorry!

[eroman, 2013-02-05 23:17:29]

Quick comment pass

https://codereview.chromium.org/12207020/diff/1/net/base/net_log_event_type_l...
File net/base/net_log_event_type_list.h (right):

https://codereview.chromium.org/12207020/diff/1/net/base/net_log_event_type_l...
net/base/net_log_event_type_list.h:1232: //     "error"  : <The error status of
the closure>,
What is the domain of these errors? For instance, if it is a network error, then
labeling it as net_error will get it pretty-printed symbolically by the
javascript.

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_client_session.cc
File net/quic/quic_client_session.cc (right):

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_client_session....
net/quic/quic_client_session.cc:21: Value* NetLogQuicSessionCallback(const
std::string& host,
Unless you expect to grow this in the future, you can use the pre-defined:

NetLog::StringCallback("host", &my_host)

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_client_session....
net/quic/quic_client_session.cc:28: Value*
NetLogQuicSessionCloseOnErrorCallback(int error,
Unless you expect to grow this in the future, you can use the pre-defined:

NetLog::IntegerCallback("error", my_error)

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_http_stream.cc
File net/quic/quic_http_stream.cc (right):

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_http_stream.cc#...
net/quic/quic_http_stream.cc:482: // The URLRequest logs these headers, so only
log the to the
"log the to" --> reorder :)

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_reliable_client...
File net/quic/quic_reliable_client_stream_test.cc (right):

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_reliable_client...
net/quic/quic_reliable_client_stream_test.cc:38: stream_(1, &session_, net_log_)
{
If the test doesn't use it, you can also pass in BoundNetLog() directly, and
avoid adding a new member to the test fixture.

(Since this isn't tied to any actual NetLog, it won't actually be doing any
logging).

If you wanted to tied it to something you could use CapturingBoundNetLog

[Ryan Hamilton, 2013-02-05 23:35:29]

https://codereview.chromium.org/12207020/diff/1/net/base/net_log_event_type_l...
File net/base/net_log_event_type_list.h (right):

https://codereview.chromium.org/12207020/diff/1/net/base/net_log_event_type_l...
net/base/net_log_event_type_list.h:1232: //     "error"  : <The error status of
the closure>,
On 2013/02/05 23:17:30, eroman wrote:
> What is the domain of these errors? For instance, if it is a network error,
then
> labeling it as net_error will get it pretty-printed symbolically by the
> javascript.

Awesome!  Done.

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_client_session.cc
File net/quic/quic_client_session.cc (right):

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_client_session....
net/quic/quic_client_session.cc:21: Value* NetLogQuicSessionCallback(const
std::string& host,
On 2013/02/05 23:17:30, eroman wrote:
> Unless you expect to grow this in the future, you can use the pre-defined:
> 
> NetLog::StringCallback("host", &my_host)

Done.  It'll probably grow in the future, but this is better for now.

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_client_session....
net/quic/quic_client_session.cc:28: Value*
NetLogQuicSessionCloseOnErrorCallback(int error,
On 2013/02/05 23:17:30, eroman wrote:
> Unless you expect to grow this in the future, you can use the pre-defined:
> 
> NetLog::IntegerCallback("error", my_error)

Done.

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_http_stream.cc
File net/quic/quic_http_stream.cc (right):

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_http_stream.cc#...
net/quic/quic_http_stream.cc:482: // The URLRequest logs these headers, so only
log the to the
On 2013/02/05 23:17:30, eroman wrote:
> "log the to" --> reorder :)

Done.

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_reliable_client...
File net/quic/quic_reliable_client_stream_test.cc (right):

https://codereview.chromium.org/12207020/diff/1/net/quic/quic_reliable_client...
net/quic/quic_reliable_client_stream_test.cc:38: stream_(1, &session_, net_log_)
{
On 2013/02/05 23:17:30, eroman wrote:
> If the test doesn't use it, you can also pass in BoundNetLog() directly, and
> avoid adding a new member to the test fixture.
> 
> (Since this isn't tied to any actual NetLog, it won't actually be doing any
> logging).
> 
> If you wanted to tied it to something you could use CapturingBoundNetLog

Done.

[eroman, 2013-02-05 23:52:40]

https://codereview.chromium.org/12207020/diff/8002/net/base/net_log_event_typ...
File net/base/net_log_event_type_list.h (right):

https://codereview.chromium.org/12207020/diff/8002/net/base/net_log_event_typ...
net/base/net_log_event_type_list.h:1226: //     "proxy": <The Proxy PAC string>,
Delete this -- the current code is not setting it.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
File net/quic/quic_client_session.cc (right):

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:21: Value* NetLogQuicSessionCallback(const
std::string& host,
Delete.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:28: Value*
NetLogQuicSessionCloseOnErrorCallback(int error,
Delete.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:50: net_log_(BoundNetLog::Make(net_log,
NetLog::SOURCE_QUIC_SESSION)) {
the fact that it is QUIC and not QUICK keeps blowing up my head

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:74: ++num_total_streams_;
Not familiar with this code, but should num_total_streams_ ever decrease?

i.e. i noticed there is the function GetNumOpenStreams(), how does that fit in?

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:148: NetLog::IntegerCallback("error", error));
"error" --> "net_error", per the documentation

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
File net/quic/quic_client_session_test.cc (right):

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session_test.cc:28: session_(connection_, NULL, NULL,
kServerHostname, &net_log_) {
You can also safely pass in NULL if you like.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_http_stream.cc
File net/quic/quic_http_stream.cc (right):

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_http_stream....
net/quic/quic_http_stream.cc:517: // The URLRequest logs these headers, so only
log the to the
same typo.

[Ryan Hamilton, 2013-02-06 16:40:15]

https://codereview.chromium.org/12207020/diff/8002/net/base/net_log_event_typ...
File net/base/net_log_event_type_list.h (right):

https://codereview.chromium.org/12207020/diff/8002/net/base/net_log_event_typ...
net/base/net_log_event_type_list.h:1226: //     "proxy": <The Proxy PAC string>,
On 2013/02/05 23:52:40, eroman wrote:
> Delete this -- the current code is not setting it.

Done.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
File net/quic/quic_client_session.cc (right):

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:21: Value* NetLogQuicSessionCallback(const
std::string& host,
On 2013/02/05 23:52:40, eroman wrote:
> Delete.

Whoops!  Done.  Sorry.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:28: Value*
NetLogQuicSessionCloseOnErrorCallback(int error,
On 2013/02/05 23:52:40, eroman wrote:
> Delete.

Done.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:50: net_log_(BoundNetLog::Make(net_log,
NetLog::SOURCE_QUIC_SESSION)) {
On 2013/02/05 23:52:40, eroman wrote:
> the fact that it is QUIC and not QUICK keeps blowing up my head

:>

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:74: ++num_total_streams_;
On 2013/02/05 23:52:40, eroman wrote:
> Not familiar with this code, but should num_total_streams_ ever decrease?

No, it should not.  It is the total number of streams ever seen on the
connection.
 
> i.e. i noticed there is the function GetNumOpenStreams(), how does that fit
in?

open streams does go up and down as new streams are created and then closed. 
total streams will always be >= open streams.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session.cc:148: NetLog::IntegerCallback("error", error));
On 2013/02/05 23:52:40, eroman wrote:
> "error" --> "net_error", per the documentation

Argh!  I changed it in the callback I wrote, but simply cut/paste this code.
Fixed.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
File net/quic/quic_client_session_test.cc (right):

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_client_sessi...
net/quic/quic_client_session_test.cc:28: session_(connection_, NULL, NULL,
kServerHostname, &net_log_) {
On 2013/02/05 23:52:40, eroman wrote:
> You can also safely pass in NULL if you like.

Done.

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_http_stream.cc
File net/quic/quic_http_stream.cc (right):

https://codereview.chromium.org/12207020/diff/8002/net/quic/quic_http_stream....
net/quic/quic_http_stream.cc:517: // The URLRequest logs these headers, so only
log the to the
On 2013/02/05 23:52:40, eroman wrote:
> same typo.

Done.

[eroman, 2013-02-06 20:06:52]

lgtm

https://codereview.chromium.org/12207020/diff/3003/net/quic/quic_http_stream.cc
File net/quic/quic_http_stream.cc (right):

https://codereview.chromium.org/12207020/diff/3003/net/quic/quic_http_stream....
net/quic/quic_http_stream.cc:90: // Log the actual request with the URL
Request's net log.
It seems like the comment on this and the following AddEvent() are reversed.
(isn't stream_->net_log() the quicsession's log?)

https://codereview.chromium.org/12207020/diff/3003/net/quic/quic_http_stream_...
File net/quic/quic_http_stream_test.cc (right):

https://codereview.chromium.org/12207020/diff/3003/net/quic/quic_http_stream_...
net/quic/quic_http_stream_test.cc:177: "www.google.com", net_log_.net_log()));
note: I expect you could also pass NULL here since no test is verifying any
values set.

[Ryan Hamilton, 2013-02-07 21:36:29]

thanks!

https://codereview.chromium.org/12207020/diff/3003/net/quic/quic_http_stream.cc
File net/quic/quic_http_stream.cc (right):

https://codereview.chromium.org/12207020/diff/3003/net/quic/quic_http_stream....
net/quic/quic_http_stream.cc:90: // Log the actual request with the URL
Request's net log.
On 2013/02/06 20:06:53, eroman wrote:
> It seems like the comment on this and the following AddEvent() are reversed.
> (isn't stream_->net_log() the quicsession's log?)

Whoops.  nice catch.  done.

https://codereview.chromium.org/12207020/diff/3003/net/quic/quic_http_stream_...
File net/quic/quic_http_stream_test.cc (right):

https://codereview.chromium.org/12207020/diff/3003/net/quic/quic_http_stream_...
net/quic/quic_http_stream_test.cc:177: "www.google.com", net_log_.net_log()));
On 2013/02/06 20:06:53, eroman wrote:
> note: I expect you could also pass NULL here since no test is verifying any
> values set.

Done.

[commit-bot: I haz the power, 2013-02-07 21:37:07]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/rch@chromium.org/12207020/9003

[commit-bot: I haz the power, 2013-02-08 00:11:11]

Retried try job too often on linux_rel for step(s) browser_tests
http://build.chromium.org/p/tryserver.chromium/buildstatus?builder=linux_rel&...

[mmenke, 2013-02-11 20:46:01]

https://codereview.chromium.org/12207020/diff/9003/net/base/net_log_source_ty...
File net/base/net_log_source_type_list.h (right):

https://codereview.chromium.org/12207020/diff/9003/net/base/net_log_source_ty...
net/base/net_log_source_type_list.h:17: SOURCE_TYPE(QUIC_SESSION)
There's a dependency in the tests on the order of these.  Can fix it yourself,
or just reorder these and I'll get to it myself.

[eroman, 2013-02-11 20:58:58]

I believe this is the change that Ryan needs to make. In
"src/chrome/test/data/webui/net_internals/log_view_painter.js" change:

      'params': {
        'source_dependency': {
          'id': 634,
          'type': 4
        }

To:

      'params': {
        'source_dependency': {
          'id': 634,
          'type': EventSourceType.CONNECT_JOB
        }

[mmenke, 2013-02-11 21:09:08]

On 2013/02/11 20:58:58, eroman wrote:
> I believe this is the change that Ryan needs to make. In
> "src/chrome/test/data/webui/net_internals/log_view_painter.js" change:
> 
>       'params': {
>         'source_dependency': {
>           'id': 634,
>           'type': 4
>         }
> 
> To:
> 
>       'params': {
>         'source_dependency': {
>           'id': 634,
>           'type': EventSourceType.CONNECT_JOB
>         }

If that were the only problem, the tests would have passed, since CONNECT_JOB is
less than QUIC_SESSION.

[Ryan Hamilton, 2013-02-13 19:37:17]

On 2013/02/11 21:09:08, mmenke wrote:
> On 2013/02/11 20:58:58, eroman wrote:
> > I believe this is the change that Ryan needs to make. In
> > "src/chrome/test/data/webui/net_internals/log_view_painter.js" change:
> > 
> >       'params': {
> >         'source_dependency': {
> >           'id': 634,
> >           'type': 4
> >         }
> > 
> > To:
> > 
> >       'params': {
> >         'source_dependency': {
> >           'id': 634,
> >           'type': EventSourceType.CONNECT_JOB
> >         }
> 
> If that were the only problem, the tests would have passed, since CONNECT_JOB
is
> less than QUIC_SESSION.

Thanks for the pointer.  This turned out to be the right fix:

--- a/chrome/test/data/webui/net_internals/log_view_painter.js
+++ b/chrome/test/data/webui/net_internals/log_view_painter.js
@@ -311,7 +311,7 @@ function painterTestURLRequest() {
       'params': {
         'source_dependency': {
           'id': 149,
-          'type': 11
+          'type': EventSourceType.HTTP_STREAM_JOB
         }
       },
       'phase': EventPhase.PHASE_NONE,
@@ -1139,7 +1139,7 @@ function painterTestHexEncodedBytes() {
       'params': {
         'source_dependency': {
           'id': 628,
-          'type': 11
+          'type': EventSourceType.HTTP_STREAM_JOB
         }
       },
       'phase': EventPhase.PHASE_BEGIN,

[mmenke, 2013-02-13 19:42:47]

LGTM

https://codereview.chromium.org/12207020/diff/2020/chrome/test/data/webui/net...
File chrome/test/data/webui/net_internals/log_view_painter.js (right):

https://codereview.chromium.org/12207020/diff/2020/chrome/test/data/webui/net...
chrome/test/data/webui/net_internals/log_view_painter.js:1080: 'type': 4
While you're fixing these, mind fixing this one, too?  This should be
EventSourceType.CONNECT_JOB.  Thanks!

[Ryan Hamilton, 2013-02-13 20:00:29]

Thanks!

https://codereview.chromium.org/12207020/diff/2020/chrome/test/data/webui/net...
File chrome/test/data/webui/net_internals/log_view_painter.js (right):

https://codereview.chromium.org/12207020/diff/2020/chrome/test/data/webui/net...
chrome/test/data/webui/net_internals/log_view_painter.js:1080: 'type': 4
On 2013/02/13 19:42:47, mmenke wrote:
> While you're fixing these, mind fixing this one, too?  This should be
> EventSourceType.CONNECT_JOB.  Thanks!

Done.

[commit-bot: I haz the power, 2013-02-13 20:01:53]

CQ is trying da patch. Follow status at
https://chromium-status.appspot.com/cq/rch@chromium.org/12207020/15003

[commit-bot: I haz the power, 2013-02-13 22:59:54]

Change committed as 182331