Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Enable the "received byte count" feature. #2004

Merged
merged 14 commits into from Jan 28, 2022

Conversation

carloseltuerto
Copy link
Contributor

@carloseltuerto carloseltuerto commented Jan 16, 2022

After a loot of cout, it turns out that the number of bytes received for the headers only account for the "trimmed" headers. What is amusing is both EM and Cronet are doing the same here: they exclude the status line, and perform trimming.

Description: Report stream_intel_.received_byte_count to the Java Layer.
Risk Level: Small
Testing: Tests added for C++, tests enabled in Java, CI
Docs Changes: N/A
Release Notes: N/A
Fixes: 1426
Signed-off-by: Charles Le Borgne cleborgne@google.com

Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Signed-off-by: Charles Le Borgne <cleborgne@google.com>
@@ -298,6 +298,9 @@ void Client::DirectStream::saveLatestStreamIntel() {
}
stream_intel_.stream_id = static_cast<uint64_t>(stream_handle_);
stream_intel_.attempt_count = info.attemptCount().value_or(0);
if (info.getUpstreamBytesMeter()) {
stream_intel_.received_byte_count = info.getUpstreamBytesMeter()->wireBytesReceived();
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So two ways to address your flaking tests.
You can either look at each point we send stream intel up, and subtract buffered data, or you could send up all received bytes, and all buffered data each time, and calculate "bytes_sent_up = bytes_received - bytes_still_buffered" in cronvoy

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The crux of the problem is on the encodeHeaders invocation, determining how many bytes are left unprocessed is not obvious - there is no Buffer to interrogate.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

but on encodeHeaders we pass it all up, no?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unfortunately, no. The received byte count already includes some coming from the response body. How can we subtract those?

Signed-off-by: Charles Le Borgne <cleborgne@google.com>
received on `encodeHeaders`

Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Signed-off-by: Charles Le Borgne <cleborgne@google.com>
@carloseltuerto carloseltuerto changed the title Partially enable the "received byte count" feature. Enable the "received byte count" feature. Jan 24, 2022
Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Copy link
Contributor

@alyssawilk alyssawilk left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sweet! Great to see progress on this one

@@ -153,6 +153,8 @@ typedef struct {
int64_t connection_id;
// The number of internal attempts to carry out a request/operation. 0 if not present.
uint64_t attempt_count;
// The number of bytes received from upstream.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

So this is close but not 100% accurate right?
Generally we'll include all the body bytes read, except on the call to pass headers up at which point we only send up header bytes. Do you think clarifying is going to cause more confusion than it solves?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Concocted something - done.

private void recordEnvoyFinalStreamIntel(EnvoyFinalStreamIntel envoyFinalStreamIntel) {
mEnvoyFinalStreamIntel = envoyFinalStreamIntel;
if (mUrlResponseInfo != null) { // Null if cancelled before receiving a Response.
mUrlResponseInfo.setReceivedByteCount(envoyFinalStreamIntel.getReceivedByteCount() +
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

so I thought cronvoy had the following behavior
if we'd read 100 header bytes and 5000 body bytes from the network but reset the stream when only 2500 bytes had been sent up to the java layer then reset the stream, that we'd want to only report the 100+2500 bytes the java layer had seen? I assumed you'd be doing the byte accounting of "headers + body bytes cronet had seen" in the java layers but it looks like we're reporting all bytes including buffered ones? Is my understanding off?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The mUrlResponseInfo is expected to be null if the request is cancelled before receiving the ResponseHeader

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

right, but if java gets the headers, and say half the body bytes which were read off the wire, what would cronet expect to report for bytes read: bytes read off the wire, or bytes handed up to java?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

still curious about this one

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's a good question. There are no tests for that. Here is what I found after many hours of "cout": Cronet is not consistent when reporting the received byte count. There is one test with an OK response where all the bytes are counted, i.e. == streamInfo().getUpstreamBytesMeter()->wireBytesReceived() == 86, and there is another test with a "NOT FOUND" where the status line is excluded from received byte count, and the expected received byte count is 120 (should be 142)

I "cout"ed the Buffer in codec_impl.cc This is the content of the test with "an OK response":

=========
HTTP/1.1 200 OK^M
Connection: close^M
Content-Length: 3^M
Content-Type: text/plain^M
^M
GET
=========== size: 86

The size is perfectly matching the value in the original Cronet test.

This is the content of the test with a "NOT FOUND":

=========
HTTP/1.1 404 Not Found^M
Content-Length: 96^M
^M
<!DOCTYPE html>
<html>
<head>
<title>Not found</title>
<p>Test page loaded.</p>
</head>
</html>

=========== size: 142

But this one the original Cronet test expects 120 bytes: this looks like the size without the Status Line.

I'm not yet sure how to reconcile this.

Signed-off-by: Charles Le Borgne <cleborgne@google.com>
alyssawilk
alyssawilk previously approved these changes Jan 25, 2022
@alyssawilk
Copy link
Contributor

@goaway any API concerns? If not I'll merge tomorrow

@goaway
Copy link
Contributor

goaway commented Jan 25, 2022

My general concern with bytes sent/received type measurements is that they're usually ambiguous about what precisely they're measuring. Encoding/framing at each network layer changes the number of bytes "seen" by other layers. For example, HTTP/2+ framing adds some bytes (probably not accounted for here), but OTOH header compression can substantially reduce what ultimately gets sent at L4 (also probably not accounted for here) and below. Something I've proposed in the past is an accounting based on the network layer doing the measuring.

(I think @alyssawilk also alludes to this above in her question.)

Is the goal here to measure the number of bytes received at L7 as if it were an unmodified HTTP/1 response?

I think it would be great if this field could be named and documented clarify what in fact is being measured.

@goaway
Copy link
Contributor

goaway commented Jan 25, 2022

Sorry, to clarify, I think receivedBytes is a somewhat ambiguous name that will lead to different people making different assumptions about what the field represents.

@carloseltuerto
Copy link
Contributor Author

My general concern with bytes sent/received type measurements is that they're usually ambiguous about what precisely they're measuring. Encoding/framing at each network layer changes the number of bytes "seen" by other layers. For example, HTTP/2+ framing adds some bytes (probably not accounted for here), but OTOH header compression can substantially reduce what ultimately gets sent at L4 (also probably not accounted for here) and below. Something I've proposed in the past is an accounting based on the network layer doing the measuring.

(I think @alyssawilk also alludes to this above in her question.)

Is the goal here to measure the number of bytes received at L7 as if it were an unmodified HTTP/1 response?

I think it would be great if this field could be named and documented clarify what in fact is being measured.

@alyssawilk @goaway @RyanTheOptimist
Mike, this is a nightmare. I still have not found the exact recipe to mimic Cronet. I don't know what Cronet is counting. Now I start suspecting that it does not matter much. The only thing I'm sure of is the count sent by the onHeaders callback: it reflects only the trimmed headers, without the Status Line - that's for HTTP1 only - my guess this one is the same for other protocols/compression schemes.

@goaway
Copy link
Contributor

goaway commented Jan 26, 2022

@carloseltuerto How would you like to proceed? If we want to commit an arbitrary definition, my main concern would be that it be named unambiguously and documented as to what it counts.

If we were to choose what we expose, I'd propose we report a layer 4 accounting of what gets read and written to the socket for a given stream - though exposing this may require some additional work in Envoy.

@carloseltuerto
Copy link
Contributor Author

carloseltuerto commented Jan 26, 2022

@goaway @alyssawilk @RyanTheOptimist I have been working for more than a day to have an environment where I can perform some tests with the original Chromium::Cronet. I was able to observe more details. It looks like that Cronet has two behaviors:

  • When the response is in a single packet: onHeaders includes all the bytes received up to the Body, and onSucceeded returns all the bytes received (Status line, untrimmed Headers, Body)
  • When the response is more than one packet: onHeaders only includes the trimmed Headers (excludes Status line), and onSucceeded returns the sum of the body size and trimmed Headers.

I suspect that when the CronetUrlRequestTest was written, the authors did not consider any of this. They rather let the test fail the first time, and then plugged the real number they saw.

I don't want to mimic this logic. So here is a suggestion for envoy_stream_intel:

  • onHeader always returns the trimmed Headers size
  • onData trimmed Headers size + previous and current Buffer sizes passed to onData
  • onError, onCancel, onComplete return the value up to now.

This logic has this flaw: the sum of onHeader and onData call will never be the one returned in final_stream_intel_.received_byte_count. If this is plain data, the latter will be bigger, and if the data is compressed, then the latter will likely be smaller. However, I believe that it is important to reflect the correct number of bytes received on the final callbacks. What is being returned by the non-final callbacks does not matter as much. That will be an improvement when compared with the original Cronet.

Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Signed-off-by: Charles Le Borgne <cleborgne@google.com>
@carloseltuerto
Copy link
Contributor Author

@goaway @alyssawilk @RyanTheOptimist The suggestion has been implemented. Please let me know what you think - thanks!

Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Copy link
Contributor

@alyssawilk alyssawilk left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice! I think this is much cleaner. One comment nit and you're good to go from my end

@@ -18,4 +18,8 @@
* The number of internal attempts to carry out a request/operation.
*/
public long getAttemptCount();
/*
* The number of bytes received from upstream.
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

update commments?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Comments updated, and also using the same names everywhere. Thanks.

Signed-off-by: Charles Le Borgne <cleborgne@google.com>
Copy link
Contributor

@goaway goaway left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks @carloseltuerto! This makes sense to me.

@goaway goaway merged commit 0fbe18a into envoyproxy:main Jan 28, 2022
jpsim added a commit to jpsim/envoy-mobile that referenced this pull request Feb 1, 2022
* main:
  [json] Remove com_github_nlohmann_json override & patch (envoyproxy#2030)
  Enable the "received byte count" feature. (envoyproxy#2004)

Signed-off-by: JP Simard <jp@jpsim.com>
jpsim added a commit to jpsim/envoy-mobile that referenced this pull request Feb 3, 2022
* origin/main: (21 commits)
  owners: adding charles (envoyproxy#2038)
  [OWNERS] Update Envoy Mobile owners (envoyproxy#2031)
  [deps] Update rules_android to a stable release URL (envoyproxy#2032)
  [json] Remove com_github_nlohmann_json override & patch (envoyproxy#2030)
  Enable the "received byte count" feature. (envoyproxy#2004)
  Run Kotlin macOS tests without EngFlow (envoyproxy#2018)
  final_intel: adding response flags (envoyproxy#2009)
  fix (envoyproxy#2025)
  stream intel: update kotlin public interface to align with swift (envoyproxy#2013)
  tls: update bundled root certificates (envoyproxy#2016)
  tooling: first pass at oncall tooling (envoyproxy#2014)
  test: Solve CI flakiness for test/java/org/chromium/net/urlconnection:urlconnection_test  (envoyproxy#2007)
  envoy: 519774f742 (envoyproxy#2015)
  Default timestamp to -1 for envoy_final_stream_intel (envoyproxy#2006)
  QuicTestServer (envoyproxy#1989)
  bump boringssl to Envoy's version (envoyproxy#1999)
  docs: addding release notes (envoyproxy#2001)
  release: cutting the 0.4.5 release (envoyproxy#2000)
  Revert "bazel: change bazelisk for M1 support (envoyproxy#1966)" (envoyproxy#1998)
  Decompress even when `no-transform` is specified (envoyproxy#1995)
  ...

Signed-off-by: JP Simard <jp@jpsim.com>
@carloseltuerto carloseltuerto deleted the cronvoy054 branch February 15, 2022 19:25
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants