Log GOAWAY frame debug data.

Log GOAWAY frame debug data.

* Buffer GOAWAY frame debug data in BufferedSpdyFramer.
* Add |debug_data| argument to BufferedSpdyFramerVisitorInterface::OnGoAway().
* Add "debug_data" field to NetLog::TYPE_HTTP2_SESSION_GOAWAY event.
* Strip value depending on NetLogCaptureMode both in native and Javascript code.
* Add unittests.

BUG=478685
Committed: https://crrev.com/14ebd6d0797d64a3d2eceb2950048b65015d471e
Cr-Commit-Position: refs/heads/master@{#353531}

[Bence, 2015-09-25 11:34:57]

Patchset #3 (id:2) has been deleted

[Bence, 2015-10-02 22:31:42]

bnc@chromium.org changed reviewers:
+ rch@chromium.org

[Bence, 2015-10-02 22:31:42]

Ryan: PTAL.  Thanks.

[Ryan Hamilton, 2015-10-05 21:17:55]

Looks pretty good. You should probably have eroman review the net-internals js
changes because I'm not terribly familiar with that code.

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer.cc (right):

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:245: }
This method wasn't overridden previously, right? What does the default
implementation do? I'm guessing it just returned true...

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer_unittest.cc (right):

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer_unittest.cc:104: StringPiece debug_data) override
{}
Since we're now buffering GOAWAY data, can you add a test?

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/spdy_session.cc
File net/spdy/spdy_session.cc (right):

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/spdy_session....
net/spdy/spdy_session.cc:268: dict->SetString("goaway_debug_data",
nit: I think "goaway_" is redundant.

[Bence, 2015-10-06 15:18:56]

bnc@chromium.org changed reviewers:
+ eroman@chromium.org

[Bence, 2015-10-06 15:18:57]

Eric: PTAL at chrome/*/log_view_painter.js (both of them).
Ryan: PTAnotherL.

Thank you both.

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer.cc (right):

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:245: }
On 2015/10/05 21:17:55, Ryan Hamilton wrote:
> This method wasn't overridden previously, right? What does the default
> implementation do? I'm guessing it just returned true...

Exactly: it returns true.
https://code.google.com/p/chromium/codesearch#chromium/src/net/spdy/spdy_fram...

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer_unittest.cc (right):

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer_unittest.cc:104: StringPiece debug_data) override
{}
On 2015/10/05 21:17:55, Ryan Hamilton wrote:
> Since we're now buffering GOAWAY data, can you add a test?

Done.

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/spdy_session.cc
File net/spdy/spdy_session.cc (right):

https://codereview.chromium.org/1360253002/diff/130001/net/spdy/spdy_session....
net/spdy/spdy_session.cc:268: dict->SetString("goaway_debug_data",
On 2015/10/05 21:17:55, Ryan Hamilton wrote:
> nit: I think "goaway_" is redundant.

You are right.  I was using it to make it easier to strip in JavaScript, but in
fact it is better if I explicitly check for event.type.

Done.

[eroman, 2015-10-06 17:19:41]

nice testing coverage. Just a few comments but otherwise LG

https://codereview.chromium.org/1360253002/diff/210001/chrome/browser/resourc...
File chrome/browser/resources/net_internals/log_view_painter.js (right):

https://codereview.chromium.org/1360253002/diff/210001/chrome/browser/resourc...
chrome/browser/resources/net_internals/log_view_painter.js:567:
stripCookiesAndLoginInfo = function(entry) {
This function name doesn't seem accurate anymore, unless the mental model for
goaway debug data is to think of it as a cookie (same with capture mode).

Do you have a suggestion for a different name that encompasses the new
functionality?

Fine to leave as is, but might want to leave in a TODO

https://codereview.chromium.org/1360253002/diff/210001/net/http/http_log_util.cc
File net/http/http_log_util.cc (right):

https://codereview.chromium.org/1360253002/diff/210001/net/http/http_log_util...
net/http/http_log_util.cc:85: static_cast<long>(debug_data.size()));
Rather than casting, you can use the format specifier PRIuS
(base/format_macros.h).
Or base::SizeTToString

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer.cc (right):

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:229: DCHECK(!go_away_fields_.get());
nit: you can omit the .get()

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:237: if (len > 0) {
I assume the contract is that len=0 once all the data has been consumed?

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:238:
go_away_fields_->debug_data.append(goaway_data, len);
Should there be a safety-net to prevent unbounded memory growth?
Or is the total size already being controlled elsewhere?

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:243: go_away_fields_.reset(nullptr);
nit: I have generally seen nullptr omitted (has default param)

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:369: // TODO(jgraettinger): Eliminate uses of
this method (prefer SpdyGoAwayIR).
Is extending this function orthogonal to this comment?

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer.h (right):

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.h:292: // Collection of fields of a GOAWAY frame
that we need to buffer.
nit: I see other comments similarly use "we", however chromium style tries to
avoid personal pronouns. (there is a chromium-dev thread somewhere about it...)

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer_unittest.cc (right):

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer_unittest.cc:26:
promised_stream_id_(static_cast<SpdyStreamId>(-1)) {}
unrelated side-note: seems like this would be cleaner to express as something
like MAX_SPDY_STREAM_ID. The signed --> unsigned conversion to accomplish this
is icky in my opinion.

[Ryan Hamilton, 2015-10-07 00:00:35]

LGTM. as usual eroman has some great suggestions.

[Bence, 2015-10-07 10:17:56]

Patchset #12 (id:230001) has been deleted

[Bence, 2015-10-07 13:57:25]

Patchset #12 (id:250001) has been deleted

[Bence, 2015-10-07 15:18:27]

Eric: thanks for the great suggestions.  PTAL.

https://codereview.chromium.org/1360253002/diff/210001/chrome/browser/resourc...
File chrome/browser/resources/net_internals/log_view_painter.js (right):

https://codereview.chromium.org/1360253002/diff/210001/chrome/browser/resourc...
chrome/browser/resources/net_internals/log_view_painter.js:567:
stripCookiesAndLoginInfo = function(entry) {
On 2015/10/06 17:19:41, eroman wrote:
> This function name doesn't seem accurate anymore, unless the mental model for
> goaway debug data is to think of it as a cookie (same with capture mode).
> 
> Do you have a suggestion for a different name that encompasses the new
> functionality?
> 
> Fine to leave as is, but might want to leave in a TODO

I renamed this function and added TODO to capture mode members.

https://codereview.chromium.org/1360253002/diff/210001/net/http/http_log_util.cc
File net/http/http_log_util.cc (right):

https://codereview.chromium.org/1360253002/diff/210001/net/http/http_log_util...
net/http/http_log_util.cc:85: static_cast<long>(debug_data.size()));
On 2015/10/06 17:19:41, eroman wrote:
> Rather than casting, you can use the format specifier PRIuS
> (base/format_macros.h).
> Or base::SizeTToString

Done.

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer.cc (right):

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:229: DCHECK(!go_away_fields_.get());
On 2015/10/06 17:19:41, eroman wrote:
> nit: you can omit the .get()

Done.

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:237: if (len > 0) {
On 2015/10/06 17:19:41, eroman wrote:
> I assume the contract is that len=0 once all the data has been consumed?

Correct.  It is documented at
https://code.google.com/p/chromium/codesearch#chromium/src/net/spdy/spdy_fram....

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:238:
go_away_fields_->debug_data.append(goaway_data, len);
On 2015/10/06 17:19:41, eroman wrote:
> Should there be a safety-net to prevent unbounded memory growth?
> Or is the total size already being controlled elsewhere?

Yes, there should be, especially because buffering happens even if there is no
network logging or if capture mode is DEFAULT.  I added a limit of 1 kB here.

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:243: go_away_fields_.reset(nullptr);
On 2015/10/06 17:19:41, eroman wrote:
> nit: I have generally seen nullptr omitted (has default param)

Done.

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:243: go_away_fields_.reset(nullptr);
On 2015/10/06 17:19:41, eroman wrote:
> nit: I have generally seen nullptr omitted (has default param)

Done.

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer.h (right):

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.h:292: // Collection of fields of a GOAWAY frame
that we need to buffer.
On 2015/10/06 17:19:41, eroman wrote:
> nit: I see other comments similarly use "we", however chromium style tries to
> avoid personal pronouns. (there is a chromium-dev thread somewhere about
it...)

Done.

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer_unittest.cc (right):

https://codereview.chromium.org/1360253002/diff/210001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer_unittest.cc:26:
promised_stream_id_(static_cast<SpdyStreamId>(-1)) {}
On 2015/10/06 17:19:41, eroman wrote:
> unrelated side-note: seems like this would be cleaner to express as something
> like MAX_SPDY_STREAM_ID. The signed --> unsigned conversion to accomplish this
> is icky in my opinion.

Acknowledged.

[eroman, 2015-10-07 17:00:51]

lgtm

https://codereview.chromium.org/1360253002/diff/270001/chrome/browser/resourc...
File chrome/browser/resources/net_internals/log_view_painter.js (right):

https://codereview.chromium.org/1360253002/diff/270001/chrome/browser/resourc...
chrome/browser/resources/net_internals/log_view_painter.js:567:
stripCookiesAndLoginInfoAndGoAwayDebugData = function(entry) {
This name is accurate however a bit too long IMO.

What about "stripPrivacyInfo()" ? (I imagine we will keep adding things to this,
so the more general name my age better). This also seems in line with the
"privacyStripping" variable that it is conditionally called on.

https://codereview.chromium.org/1360253002/diff/270001/net/http/http_log_util.cc
File net/http/http_log_util.cc (right):

https://codereview.chromium.org/1360253002/diff/270001/net/http/http_log_util...
net/http/http_log_util.cc:85: return std::string("[") +
base::SizeTToString(debug_data.size()) +
[observation (no action needed)] Google has StrCat(a, b, c) which would be used
in places like this.

Too bad Chrome code doesn't have anything equivalent, since chaining operator+
unfortunately generates bad code (multiple allocations and temporary string
allocations).

Meh.

https://codereview.chromium.org/1360253002/diff/270001/net/log/net_log_captur...
File net/log/net_log_capture_mode.h (right):

https://codereview.chromium.org/1360253002/diff/270001/net/log/net_log_captur...
net/log/net_log_capture_mode.h:36: //
IncludeCookiesAndCredentialsAndGoAwayDebugData().
IncludePrivacyInfo ?

(not the best name, but "Privacy" gives a pretty strong clue was to what it
means)

https://codereview.chromium.org/1360253002/diff/270001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer.cc (right):

https://codereview.chromium.org/1360253002/diff/270001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:247: goaway_fields_->debug_data.size()));
This looks correct.

However when first reading it I had to pause to consider whether the unsigned
subtraction (kGoAwayDebugDataMaxSize - goaway_fields_->debug_data.size()) could
ever underflow.

Consider wrapping it in:

if (goaway_fields_->debug_data.size() < kGoAwayDebugDataMaxSize) {
  ...
}

As a defensive measure in case goaway_fields_ is ever increased beyond the
maximum outside this function.

[Bence, 2015-10-08 14:15:48]

On 2015/10/07 17:00:51, eroman wrote:
> lgtm
> 
>
https://codereview.chromium.org/1360253002/diff/270001/chrome/browser/resourc...
> File chrome/browser/resources/net_internals/log_view_painter.js (right):
> 
>
https://codereview.chromium.org/1360253002/diff/270001/chrome/browser/resourc...
> chrome/browser/resources/net_internals/log_view_painter.js:567:
> stripCookiesAndLoginInfoAndGoAwayDebugData = function(entry) {
> This name is accurate however a bit too long IMO.
> 
> What about "stripPrivacyInfo()" ? (I imagine we will keep adding things to
this,
> so the more general name my age better). This also seems in line with the
> "privacyStripping" variable that it is conditionally called on.
> 
>
https://codereview.chromium.org/1360253002/diff/270001/net/http/http_log_util.cc
> File net/http/http_log_util.cc (right):
> 
>
https://codereview.chromium.org/1360253002/diff/270001/net/http/http_log_util...
> net/http/http_log_util.cc:85: return std::string("[") +
> base::SizeTToString(debug_data.size()) +
> [observation (no action needed)] Google has StrCat(a, b, c) which would be
used
> in places like this.
> 
> Too bad Chrome code doesn't have anything equivalent, since chaining operator+
> unfortunately generates bad code (multiple allocations and temporary string
> allocations).
> 
> Meh.
> 
>
https://codereview.chromium.org/1360253002/diff/270001/net/log/net_log_captur...
> File net/log/net_log_capture_mode.h (right):
> 
>
https://codereview.chromium.org/1360253002/diff/270001/net/log/net_log_captur...
> net/log/net_log_capture_mode.h:36: //
> IncludeCookiesAndCredentialsAndGoAwayDebugData().
> IncludePrivacyInfo ?
> 
> (not the best name, but "Privacy" gives a pretty strong clue was to what it
> means)
> 
>
https://codereview.chromium.org/1360253002/diff/270001/net/spdy/buffered_spdy...
> File net/spdy/buffered_spdy_framer.cc (right):
> 
>
https://codereview.chromium.org/1360253002/diff/270001/net/spdy/buffered_spdy...
> net/spdy/buffered_spdy_framer.cc:247: goaway_fields_->debug_data.size()));
> This looks correct.
> 
> However when first reading it I had to pause to consider whether the unsigned
> subtraction (kGoAwayDebugDataMaxSize - goaway_fields_->debug_data.size())
could
> ever underflow.
> 
> Consider wrapping it in:
> 
> if (goaway_fields_->debug_data.size() < kGoAwayDebugDataMaxSize) {
>   ...
> }
> 
> As a defensive measure in case goaway_fields_ is ever increased beyond the
> maximum outside this function.

Landing this CL seems to be blocked on https://crbug.com/541158.

[eroman, 2015-10-08 17:13:49]

Sorry Bench in committee today ... I can help u look at that issue tomorrow :)

[Bence, 2015-10-12 14:27:20]

The CQ bit was checked by bnc@chromium.org

[Bence, 2015-10-12 14:27:20]

The patchset sent to the CQ was uploaded after l-g-t-m from rch@chromium.org,
eroman@chromium.org
Link to the patchset: https://codereview.chromium.org/1360253002/#ps290001
(title: "Re: #12.")

[commit-bot: I haz the power, 2015-10-12 14:27:50]

CQ is trying da patch. Follow status at
 https://chromium-cq-status.appspot.com/patch-status/1360253002/290001
View timeline at
 https://chromium-cq-status.appspot.com/patch-timeline/1360253002/290001

[commit-bot: I haz the power, 2015-10-12 16:23:23]

Committed patchset #13 (id:290001)

[commit-bot: I haz the power, 2015-10-12 16:24:21]

Patchset 13 (id:??) landed as
https://crrev.com/14ebd6d0797d64a3d2eceb2950048b65015d471e
Cr-Commit-Position: refs/heads/master@{#353531}

[Bence, 2015-10-30 11:55:27]

Sorry I forgot to publish these drafts earlier.  Thank you for having reviewed
this CL.

https://codereview.chromium.org/1360253002/diff/270001/chrome/browser/resourc...
File chrome/browser/resources/net_internals/log_view_painter.js (right):

https://codereview.chromium.org/1360253002/diff/270001/chrome/browser/resourc...
chrome/browser/resources/net_internals/log_view_painter.js:567:
stripCookiesAndLoginInfoAndGoAwayDebugData = function(entry) {
On 2015/10/07 17:00:51, eroman wrote:
> This name is accurate however a bit too long IMO.
> 
> What about "stripPrivacyInfo()" ? (I imagine we will keep adding things to
this,
> so the more general name my age better). This also seems in line with the
> "privacyStripping" variable that it is conditionally called on.

stripPrivacyInfo sounds a lot better, should have thought about that.

Done.

https://codereview.chromium.org/1360253002/diff/270001/net/http/http_log_util.cc
File net/http/http_log_util.cc (right):

https://codereview.chromium.org/1360253002/diff/270001/net/http/http_log_util...
net/http/http_log_util.cc:85: return std::string("[") +
base::SizeTToString(debug_data.size()) +
On 2015/10/07 17:00:51, eroman wrote:
> [observation (no action needed)] Google has StrCat(a, b, c) which would be
used
> in places like this.
> 
> Too bad Chrome code doesn't have anything equivalent, since chaining operator+
> unfortunately generates bad code (multiple allocations and temporary string
> allocations).
> 
> Meh.

Acknowledged.

https://codereview.chromium.org/1360253002/diff/270001/net/log/net_log_captur...
File net/log/net_log_capture_mode.h (right):

https://codereview.chromium.org/1360253002/diff/270001/net/log/net_log_captur...
net/log/net_log_capture_mode.h:36: //
IncludeCookiesAndCredentialsAndGoAwayDebugData().
On 2015/10/07 17:00:51, eroman wrote:
> IncludePrivacyInfo ?
> 
> (not the best name, but "Privacy" gives a pretty strong clue was to what it
> means)

Done.

https://codereview.chromium.org/1360253002/diff/270001/net/spdy/buffered_spdy...
File net/spdy/buffered_spdy_framer.cc (right):

https://codereview.chromium.org/1360253002/diff/270001/net/spdy/buffered_spdy...
net/spdy/buffered_spdy_framer.cc:247: goaway_fields_->debug_data.size()));
On 2015/10/07 17:00:51, eroman wrote:
> This looks correct.
> 
> However when first reading it I had to pause to consider whether the unsigned
> subtraction (kGoAwayDebugDataMaxSize - goaway_fields_->debug_data.size())
could
> ever underflow.
> 
> Consider wrapping it in:
> 
> if (goaway_fields_->debug_data.size() < kGoAwayDebugDataMaxSize) {
>   ...
> }
> 
> As a defensive measure in case goaway_fields_ is ever increased beyond the
> maximum outside this function.

Done.