http2: Fix extra frames and memory underflow in MetadataEncoder. #9996

mkbehr · 2020-02-10T21:20:23Z

Description:

Previously, if encodeMetadata were called on a connection for which Envoy was
already dispatching data, it would generate extra frames, then underflow memory
when MetadataEncoder tried to populate their payload.

The codec tried to fully generate each METADATA frame before moving onto the
next one: first, it submitted a payload-less frame to nghttp2's outbound queue;
second, it called sendPendingFrames to pop the frame off of the outbound queue,
causing MetadataEncoder to fill in its payload via a callback; and third, it
asked the MetadataEncoder whether it had any more frames to fill payloads for,
to decide whether to submit the next frame. However, if the connection were in
dispatching mode, sendPendingFrames wouldn't have any effect, so the
MetadataEncoder would report more frames to fill even once enough frames had
been submitted. When the MetadataEncoder tried to pack those frames, it would
trigger debug ASSERT failures, or underflows in prod.

Fix this by submitting all the METADATA frames to nghttp2 before trying to send
any of them.

Also harden MetadataEncoder against a few other library failures that were
previously only checked with debug ASSERTs.

Risk Level: Medium (changes the control flow in and out of nghttp2 callbacks when METADATA frames are sent)
Testing: bazel test //test/... (two failing tests under //test/extensions/tracers/dynamic_ot seem unrelated)
Docs Changes: n/a
Release Notes: Added.

Signed-off-by: Michael Behr mkbehr@google.com

Previously, if encodeMetadata were called on a connection for which Envoy was already dispatching data, it would generate extra frames, then underflow memory when MetadataEncoder tried to populate their payload. The codec tried to fully generate each METADATA frame before moving onto the next one: first, it submitted a payload-less frame to nghttp2's outbound queue; second, it called sendPendingFrames to pop the frame off of the outbound queue, causing MetadataEncoder to fill in its payload via a callback; and third, it asked the MetadataEncoder whether it had any more frames to fill payloads for, to decide whether to submit the next frame. However, if the connection were in dispatching mode, sendPendingFrames wouldn't have any effect, so the MetadataEncoder would report more frames to fill even once enough frames had been submitted. When the MetadataEncoder tried to pack those frames, it would trigger debug ASSERT failures, or underflows in prod. Fix this by submitting all the METADATA frames to nghttp2 before trying to send any of them. Also harden MetadataEncoder against a few other library failures that were previously only checked with debug ASSERTs. Signed-off-by: Michael Behr <mkbehr@google.com>

Signed-off-by: Michael Behr <mkbehr@google.com>

alyssawilk · 2020-02-11T14:23:52Z

Awesome! Tracking this down was such great work. Mind checking your format build and pinging back when this is good for review?

Signed-off-by: Michael Behr <mkbehr@google.com>

mkbehr · 2020-02-11T16:34:27Z

Done.

I do see a segfault in the coverage CI run from the last version, in BufferIntegrationTest.RouterRequestPopulateContentLengthOnTrailers/IPv4_HttpDownstream_Http2Upstream. I can't replicate it on my machine (possibly because I only have clang working there right now), and I don't see any way to get more info from the CI run. That test doesn't seem to send any metadata, so it shouldn't hit most of the changed code here. The only difference I can see is that if it runs through encodeMetadata despite having no metadata to send, it'll call sendPendingFrames when it otherwise wouldn't. I'd expect that to be safe, but maybe it's triggering some other latent bug. If that's the case, I don't want to paper over the bug by omitting the sendPendingFrames call if there's no metadata. Any ideas on what to do here?

mkbehr · 2020-02-11T17:06:05Z

Maybe the segfault is #9989?

alyssawilk · 2020-02-11T18:30:43Z

source/common/http/http2/codec_impl.cc

  }
-
-  ASSERT(!metadata_encoder_->hasNextFrame());
+  for (uint8_t flags : metadata_encoder.payloadFrameFlags()) {


naming nit: shouldn't this be
for (flag : flags) rather than
for (flags : flags)?

Each of these is a technically a byte of flags, even though only the one bit is ever set or read. I renamed payloadFrameFlags -> payloadFrameFlagBytes instead.

alyssawilk · 2020-02-11T18:32:27Z

source/common/http/http2/codec_impl.cc

+  for (uint8_t flags : metadata_encoder.payloadFrameFlags()) {
+    submitMetadata(flags);
+  }
+  parent_.sendPendingFrames();


is it important or a perf optimization that we submit N times and send once, rather than prior submit:send logic?
If so consider commenting

Not important, anymore. This order just made more sense to me once I finished mentally untangling the submit operations from the send operations. (And it makes sure the sequence of those operations is always the same regardless of the network, where the bug happened because they were usually but not always interleaved - but the submits don't depend on the sends anymore so that doesn't matter.)

alyssawilk · 2020-02-11T18:37:16Z

source/common/http/http2/metadata_encoder.cc

-  ASSERT(!payload_size_queue_.empty());
+ssize_t MetadataEncoder::packNextFramePayload(uint8_t* buf, const size_t len) {
+  if (payload_size_queue_.empty()) {
+    ENVOY_LOG(error, "No payload remaining to pack into a METADATA frame.");


Do we unit test all the (awesome!) new error handling? I'm kicking the coverage run but if you EXPECT_LOG_CONTAINS in your unit tests it'd both regression-proof you cover the error you're aiming for and make it easy for your reviewer to tell :-)

Here are a couple of EXPECT_LOG_CONTAINS tests. I didn't see how to hit them all without somehow mocking out the nghttp2 calls:

We could fail to deflate the metadata payload if we run out of memory, but I don't see any other way to cause that failure.

The payload buffer could only be too small if an update to nghttp2 changes the minimum payload length it sends us. (I don't know how safe it is to assume that won't happen.)

Does this error mean that there is some consistency issue between how many METADTA frames we have enqueued into nghttp2 and how many we actually have in the encoder? What are the conditions for this? If this is only possible due to a bug, should this be a RELEASE_ASSERT + fuzzer test instead?

The consistency issue you mentioned is one possible way this could happen. It could also happen if a bug somewhere in nghttp2 caused it to call this callback more times than we enqueued METADATA frames. The style guide says that bad data from an API call is the kind of thing we should handle gracefully instead of crashing, so I don't think RELEASE_ASSERT is the right tool here.

I would at least leave a comment explaining why this check is here.

Sure, done.

In general I'm uncomfortable with this type of error logging without either a stat or just a RELEASE_ASSERT or normal ASSERT. Sorry just to clarify again, why do we think that RELEASE_ASSERT is not OK? Isn't this a bug in nghttp2? If we decide we want to handle this I think we need a stat vs. a log that could potentially spam?

Treating nghttp2 as an API, my reading of the style guide was that we should handle gracefully instead of crashing (see above) - but since you also think a RELASE_ASSERT is better, I've just changed it back to that.

(Would have liked to hear this from you a bit earlier in the process, though - this review has been taking a while!)

alyssawilk · 2020-02-11T18:45:34Z

source/common/http/http2/metadata_encoder.h

+   * and the flags to be set in each frame. This counts only frames that the encoder has not already
+   * packed; to get the full sequence of frames corresponding to the metadata map vector, call this
+   * before submitting any frames to nghttp2.
+   * @return The number of frames in each metadata payload, in sequence.


"The number of frames in each metadata payload"
maybe
"A vector indicating the number of frames in each payload?"
If it were the number of frames I'd expect
[2, 3]
instead of
[0 0 [end] 0 0 0 [end]]
which I think is what we're getting.

Oops, that line was for an old version of this function.

Your case there would actually be [0 [end] 0 0 [end]] - is that clear enough from this version?

alyssawilk · 2020-02-11T18:56:06Z

test/common/http/http2/codec_impl_test.cc

+// Encode response metadata while dispatching request data from the client, so
+// that nghttp2 can't fill the metadata frames' payloads until dispatching
+// is finished.
+TEST_P(Http2CodecImplTest, EncodeMetadataWhileDispatchingTest) {


Should we keep the old test and add the new test, or is this strictly speaking more realistic?
If the order of operations wasn't realistic in the prior unit tests I'm inclined to suggest we add an integration test as well.

Both orders are realistic, depending on (I think) what kind of network event happens to be driving us.

Signed-off-by: Michael Behr <mkbehr@google.com>

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

alyssawilk

Code changes LGTM.
Let's sort out the testing as discussed offline.

Signed-off-by: Michael Behr <mkbehr@google.com>

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

stale · 2020-02-21T16:30:48Z

This pull request has been automatically marked as stale because it has not had activity in the last 7 days. It will be closed in 7 days if no further activity occurs. Please feel free to give a status update now, ping for review, or re-open when it's ready. Thank you for your contributions!

mkbehr · 2020-02-21T19:10:05Z

Ping to keep this un-stale! I think Alyssa is away right now and can get back to this next week.

yanavlasov · 2020-02-13T17:47:08Z

source/common/http/http2/metadata_encoder.cc

-  ASSERT(!payload_size_queue_.empty());
+ssize_t MetadataEncoder::packNextFramePayload(uint8_t* buf, const size_t len) {
+  if (payload_size_queue_.empty()) {
+    ENVOY_LOG(error, "No payload remaining to pack into a METADATA frame.");


Does this error mean that there is some consistency issue between how many METADTA frames we have enqueued into nghttp2 and how many we actually have in the encoder? What are the conditions for this? If this is only possible due to a bug, should this be a RELEASE_ASSERT + fuzzer test instead?

yanavlasov · 2020-02-13T17:48:38Z

source/common/http/http2/metadata_encoder.cc

  const uint64_t current_payload_size =
      std::min(METADATA_MAX_PAYLOAD_SIZE, payload_size_queue_.front());

  // nghttp2 guarantees len is at least 16KiB. If the check fails, please verify
  // NGHTTP2_MAX_PAYLOADLEN is consistent with METADATA_MAX_PAYLOAD_SIZE.
-  ASSERT(len >= current_payload_size);
+  if (len < current_payload_size) {


Can this be a static_assert somewhere that verifies that macro values are consistent?

It can't, for two reasons: NGHTTP2_MAX_PAYLOADLEN isn't in the nghttp2 public API, and the static_assert wouldn't guarantee that nghttp2 respected that macro.

mkbehr · 2020-02-28T19:39:14Z

Hi Yan, can you have a look?

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

Signed-off-by: Michael Behr <mkbehr@google.com>

alyssawilk

LGTM. I'm going to add Yang to this one as she authored the metadata code and might catch something I missed. If she doesn't weigh in I'll merge tomorrow :-)

alyssawilk · 2020-03-02T19:55:20Z

er, please sort out CI and merge so I can actually merge tomorrow :-P

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

mkbehr · 2020-03-02T23:04:18Z

Okay, hopefully this fixes the CI. I'm seeing a few failing tests locally, but they look like they're all unrelated flakes.

soya3129 · 2020-03-03T04:27:17Z

Thanks for the awesome find and fix! Submitting metadata frames all together and call sendPendingFrames() once at the end is a great idea! LGTM.

Could you please add bug # to the description if there is a bug? Thanks!

mkbehr · 2020-03-03T17:21:34Z

I didn't open a bug for this, just the fix.

mattklein123

One question from me. Thank you!

/wait-any

mattklein123 · 2020-03-04T17:25:07Z

source/common/http/http2/metadata_encoder.cc

-  ASSERT(!payload_size_queue_.empty());
+ssize_t MetadataEncoder::packNextFramePayload(uint8_t* buf, const size_t len) {
+  if (payload_size_queue_.empty()) {
+    ENVOY_LOG(error, "No payload remaining to pack into a METADATA frame.");


In general I'm uncomfortable with this type of error logging without either a stat or just a RELEASE_ASSERT or normal ASSERT. Sorry just to clarify again, why do we think that RELEASE_ASSERT is not OK? Isn't this a bug in nghttp2? If we decide we want to handle this I think we need a stat vs. a log that could potentially spam?

Signed-off-by: Michael Behr <mkbehr@google.com>

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

mattklein123

Thanks and sorry for the late review!

mkbehr added 2 commits February 10, 2020 16:05

Add release notes.

55d2213

Signed-off-by: Michael Behr <mkbehr@google.com>

mkbehr requested a review from mattklein123 February 10, 2020 21:21

zuercher assigned alyssawilk Feb 10, 2020

Fix release notes format.

728a14a

Signed-off-by: Michael Behr <mkbehr@google.com>

alyssawilk reviewed Feb 11, 2020

View reviewed changes

alyssawilk added the waiting label Feb 12, 2020

yanavlasov self-assigned this Feb 12, 2020

asraa mentioned this pull request Feb 12, 2020

[fuzz] Add metadata and dispatching_actions to codec_impl_fuzz_test #10034

Closed

mkbehr added 2 commits February 12, 2020 17:07

Review changes.

1c2dcd0

Signed-off-by: Michael Behr <mkbehr@google.com>

Merge remote-tracking branch 'upstream/master' into metadata-callback…

df7b1ec

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

repokitteh-read-only bot removed the waiting label Feb 12, 2020

alyssawilk reviewed Feb 13, 2020

View reviewed changes

mkbehr added 2 commits February 13, 2020 14:20

Change two error logs to release asserts.

bd08438

Signed-off-by: Michael Behr <mkbehr@google.com>

Merge remote-tracking branch 'upstream/master' into metadata-callback…

1426d3d

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

stale bot added the stale stalebot believes this issue/PR has not been touched recently label Feb 21, 2020

stale bot removed the stale stalebot believes this issue/PR has not been touched recently label Feb 21, 2020

yanavlasov requested changes Feb 23, 2020

View reviewed changes

mkbehr requested a review from yanavlasov February 26, 2020 23:34

yanavlasov previously approved these changes Feb 28, 2020

View reviewed changes

mkbehr added 2 commits February 28, 2020 17:37

Merge remote-tracking branch 'upstream/master' into metadata-callback…

a75fc68

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

Add comment to explain the out-of-METADATA-payload error log.

c4b9207

Signed-off-by: Michael Behr <mkbehr@google.com>

mkbehr dismissed yanavlasov’s stale review via c4b9207 February 28, 2020 23:14

yanavlasov previously approved these changes Feb 29, 2020

View reviewed changes

Finish merging codec_impl_test.

371b749

Signed-off-by: Michael Behr <mkbehr@google.com>

alyssawilk assigned soya3129 Mar 2, 2020

alyssawilk previously approved these changes Mar 2, 2020

View reviewed changes

mkbehr dismissed stale reviews from alyssawilk and yanavlasov via 371b749 March 2, 2020 21:10

Merge remote-tracking branch 'upstream/master' into metadata-callback…

68b077a

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

alyssawilk previously approved these changes Mar 3, 2020

View reviewed changes

mattklein123 reviewed Mar 4, 2020

View reviewed changes

repokitteh-read-only bot added the waiting:any label Mar 4, 2020

mkbehr added 2 commits March 4, 2020 17:41

RELEASE_ASSERT when nghttp2 requests that we pack too many payloads.

08fdeb1

Signed-off-by: Michael Behr <mkbehr@google.com>

Merge remote-tracking branch 'upstream/master' into metadata-callback…

0a02d0d

…-fix Signed-off-by: Michael Behr <mkbehr@google.com>

mkbehr dismissed alyssawilk’s stale review via 0a02d0d March 4, 2020 23:40

repokitteh-read-only bot removed the waiting:any label Mar 4, 2020

mattklein123 approved these changes Mar 5, 2020

View reviewed changes

mattklein123 merged commit 401b65d into envoyproxy:master Mar 5, 2020

asraa mentioned this pull request May 14, 2020

[fuzz] add metadata and dispatching actions to codec fuzzer #11173

Merged

asraa mentioned this pull request Nov 25, 2020

[security] Error handling policy and macro usage clarification #14190

Closed

4 tasks

http2: Fix extra frames and memory underflow in MetadataEncoder. #9996

http2: Fix extra frames and memory underflow in MetadataEncoder. #9996

Uh oh!

Conversation

mkbehr commented Feb 10, 2020

Uh oh!

alyssawilk commented Feb 11, 2020

Uh oh!

mkbehr commented Feb 11, 2020

Uh oh!

mkbehr commented Feb 11, 2020

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

alyssawilk left a comment

Choose a reason for hiding this comment

Uh oh!

stale bot commented Feb 21, 2020

Uh oh!

mkbehr commented Feb 21, 2020

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mkbehr commented Feb 28, 2020

Uh oh!

alyssawilk left a comment

Choose a reason for hiding this comment

Uh oh!

alyssawilk commented Mar 2, 2020

Uh oh!

mkbehr commented Mar 2, 2020

Uh oh!

soya3129 commented Mar 3, 2020

Uh oh!

mkbehr commented Mar 3, 2020

Uh oh!

mattklein123 left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mattklein123 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!