What happened?
👋 Howdy (from a real human)!
I spotted a nuanced bug that caught us good in production. It took a while to hunt down, but I believe I finally got to the bottom of it. The bug is a string of "coincidences" that aligned "just perfectly". I outline the behavior and issue below.
Steps to Reproduce
I outline everything in the README that you'll need to observe and reproduce.
https://github.com/therynamo/no-store-blink-otel-bug
Expected Result
As a caller of the OTel SDK in production, I expect that my telemetry data is sent to the Collector while the tab my app running on, is still present in the Browser.
As a caller of the OTel SDK while using the default behavior of fetch -> keepalive true, I expect my telemetry data to send to the Collector while the tab my app is running on is in the Browser, and the Browser tab closes, or crashes.
Actual Result
When the Collector returns a response header of Cache-Control: no-store, Blink behaves in a way that exposes a bug in the SDK itself.
As a caller of the OTel SDK in production, requests that stay under the keepalive budget of 64kib succeed. Once the keepalive budget is met, if the Collector returns a response header of Cache-Control: no-store, the exports from the OTel SDK will fail internally and show (pending) indefinitely in the Chrome Dev Tools.
Additional Details
Related bugs:
Edit: Here is the Chromium issue link https://issues.chromium.org/issues/546438373
Here is the full report, which is the same one you can find on the README:
🐛 Full Bug Report <-- Expand me!
Blink & OTel Minimal Bug Reproduction
Callout
- README outline: Written by Human
- Reproduction code in src: Written by LLM
- Triage: Human first, LLM confirmation
Browser/Render Engine Impacted
- ❌ Firefox/Gecko: No Impact
- ❌ Safari/Webkit: No Impact
- ☑️ Chromium/Blink: Impacted
TL;DR
The Bug
When OTel sends an export:
- if export, or concurrent exports, reach the
keepalive budget (i.e. 64Kib)
- then the request is canceled by the respective Browser
- if the browser uses Chromium
- then subsequent requests will remain stuck in a
(pending) state in Chrome Developer Tools
- if requests continue to send at an interval
- then the
keepalive budget will never be drained and no further requests will succeed
Example:
Breakdown
Why does this happen?
Chromium, specifically Blink, has a line in their source that explicitly omits requests with Cache-Control: no-store from using the underlying mechanism that would have otherwise "auto-drained" the memory allocations for keepalive.
Blink Fetch Code in Question
void FetchManager::Loader::DidStartLoadingResponseBody(BytesConsumer& body) {
if (GetFetchRequestData()->Integrity().empty() &&
!response_has_no_store_header_) {
// BufferingBytesConsumer reads chunks from |bytes_consumer| as soon as
// they get available to relieve backpressure. Buffering starts after
// a short delay, however, to allow the Response to be drained; e.g.
// when the Response is passed to FetchEvent.respondWith(), etc.
//
// https://fetch.spec.whatwg.org/#fetching
// The user agent should ignore the suspension request if the ongoing
// fetch is updating the response in the HTTP cache for the request.
place_holder_body_->Update(BufferingBytesConsumer::CreateWithDelay(
&body, GetExecutionContext()->GetTaskRunner(TaskType::kNetworking)));
} else {
place_holder_body_->Update(&body);
}
place_holder_body_ = nullptr;
}
Notice:
if (GetFetchRequestData()->Integrity().empty() &&
!response_has_no_store_header_)
A little catchy line that is seemingly innocuous upon first glance.
Which corresponds to the type of body that is consumed:
place_holder_body_->Update(BufferingBytesConsumer::CreateWithDelay(
&body, GetExecutionContext()->GetTaskRunner(TaskType::kNetworking)));
// versus
place_holder_body_->Update(&body);
BufferingByteConsumer will automatically drain the response body in ~50ms. &body does not auto-drain.
Okay? So why would that matter?
Cache-Control: no-store is a reasonable response header to send back to the browser when you're sending telemetry data to a Collector, and subsequently receiving a response. (There's no particular reason you'd ever want it cached anyway.)
The same fetch-transport mentioned above in the OTel sdk, is where this becomes our problem.
if (response.status >= 200 && response.status <= 299) {
diag.debug(`export response success (status: ${response.status})`);
return { status: 'success' };
}
The first few requests that succeed are handled with this conditional.
What happens here is barely even noticeable.
response.status is a Response type which is processed by processResponse , which is defined separately from processResponseEndOfBody. Here is the excerpt we need:
For convenience, you may also pass an algorithm to the processResponseEndOfBody argument, which is called once you have finished fully reading the response and its body. Note that unlike processResponseConsumeBody, passing the processResponse or processResponseEndOfBody arguments does not guarantee that the response will be fully read, and callers are responsible to read it themselves.
To do that, the caller would need to call one of the following:
.arrayBuffer()
.blob()
.bytes()
.formData()
.json()
.text()
.textStream()
HandleLoaderFinish is what decrements inflight_keepalive_bytes_. HandleLoaderFinish is not reachable if has_seen_end_of_body_ is not true.
has_seen_end_of_body_ is set by ResourceLoader::DidFinishLoadingBody(). And ResponseBodyLoaderClient is only ever handled when ResponseBodyLoader reads the entire body.
Pretty much every other scenario, the caller wouldn't see issues with not manually acknowledging the response body.
And this, is where our bug lies. 🐛
IF the response body contains Cache-Control: no-store, Blink will not use the BufferingByteConsumer.
IF BufferingByteConsumer is not used AND the caller doesn't process the response body, then the body will never be read.
IF The body is never read, then the keepalive budget will never be emptied regardless of success or failure.
Looking back on our OTel fetch-transport implementation, we can see that the response body is never read and we send success.
if (response.status >= 200 && response.status <= 299) {
diag.debug(`export response success (status: ${response.status})`);
return { status: 'success' };
}
This means, that the keepalive budget from the calls that succeeded are never freed, and every subsequent request will fail.
This aligns with what we're observing in the browser.
if (useKeepalive) {
pendingBodySize -= requestSize;
pendingKeepaliveCount--;
}
In the finally block, we see that the OTel SDK decrements the internal request count and body size from the keepalive budget OTel manages.
IF the internal OTel budget is released AND Chromium has not released the Browser keepalive budget,
THEN the OTel library continues sending fetch with keepalive true AND those requests fail, because there is no budget remaining.
Sources
OpenTelemetry Setup Code
https://github.com/therynamo/no-store-blink-otel-bug
Operating System and Version
Chromium Latest
Firefox Latest
Safari Latest
Runtime and Version
All browsers, Client SDK, latest version.
Tip
👍
What happened?
👋 Howdy (from a real human)!
I spotted a nuanced bug that caught us good in production. It took a while to hunt down, but I believe I finally got to the bottom of it. The bug is a string of "coincidences" that aligned "just perfectly". I outline the behavior and issue below.
Steps to Reproduce
I outline everything in the
READMEthat you'll need to observe and reproduce.https://github.com/therynamo/no-store-blink-otel-bug
Expected Result
As a caller of the OTel SDK in production, I expect that my telemetry data is sent to the Collector while the tab my app running on, is still present in the Browser.
As a caller of the OTel SDK while using the default behavior of
fetch -> keepalive true, I expect my telemetry data to send to the Collector while the tab my app is running on is in the Browser, and the Browser tab closes, or crashes.Actual Result
When the Collector returns a response header of
Cache-Control: no-store, Blink behaves in a way that exposes a bug in the SDK itself.As a caller of the OTel SDK in production, requests that stay under the
keepalivebudget of64kibsucceed. Once thekeepalivebudget is met, if the Collector returns a response header ofCache-Control: no-store, the exports from the OTel SDK will fail internally and show(pending)indefinitely in the Chrome Dev Tools.Additional Details
Related bugs:
Edit: Here is the Chromium issue link https://issues.chromium.org/issues/546438373
Here is the full report, which is the same one you can find on the
README:🐛 Full Bug Report <-- Expand me!
Blink & OTel Minimal Bug Reproduction
Callout
Browser/Render Engine Impacted
TL;DR
The Bug
When OTel sends an export:
keepalivebudget (i.e. 64Kib)(pending)state in Chrome Developer Toolskeepalivebudget will never be drained and no further requests will succeedExample:
Breakdown
Why does this happen?
Chromium, specifically Blink, has a line in their source that explicitly omits requests with
Cache-Control: no-storefrom using the underlying mechanism that would have otherwise "auto-drained" the memory allocations forkeepalive.Blink Fetch Code in Question
Notice:
A little catchy line that is seemingly innocuous upon first glance.
Which corresponds to the type of
bodythat is consumed:BufferingByteConsumerwill automatically drain the response body in ~50ms.&bodydoes not auto-drain.Okay? So why would that matter?
Cache-Control: no-store is a reasonable response header to send back to the browser when you're sending telemetry data to a Collector, and subsequently receiving a response. (There's no particular reason you'd ever want it cached anyway.)
The same
fetch-transportmentioned above in the OTel sdk, is where this becomes our problem.The first few requests that succeed are handled with this conditional.
What happens here is barely even noticeable.
response.statusis a Response type which is processed byprocessResponse, which is defined separately fromprocessResponseEndOfBody. Here is the excerpt we need:To do that, the caller would need to call one of the following:
.arrayBuffer().blob().bytes().formData().json().text().textStream()HandleLoaderFinishis what decrementsinflight_keepalive_bytes_.HandleLoaderFinishis not reachable ifhas_seen_end_of_body_is not true.has_seen_end_of_body_is set byResourceLoader::DidFinishLoadingBody(). AndResponseBodyLoaderClientis only ever handled whenResponseBodyLoaderreads the entire body.Pretty much every other scenario, the caller wouldn't see issues with not manually acknowledging the response body.
And this, is where our bug lies. 🐛
IF the
response bodycontainsCache-Control: no-store, Blink will not use theBufferingByteConsumer.IF
BufferingByteConsumeris not used AND the caller doesn't process the response body, then the body will never be read.IF The body is never read, then the
keepalivebudget will never be emptied regardless of success or failure.Looking back on our OTel
fetch-transportimplementation, we can see that the response body is never read and we send success.This means, that the
keepalivebudget from the calls that succeeded are never freed, and every subsequent request will fail.This aligns with what we're observing in the browser.
In the finally block, we see that the OTel SDK decrements the internal request count and body size from the
keepalivebudget OTel manages.IF the internal OTel budget is released AND Chromium has not released the Browser
keepalivebudget,THEN the OTel library continues sending
fetchwithkeepalive trueAND those requests fail, because there is no budget remaining.Sources
OTel SDK - Fetch Transport
Blink - Resource Loader
Blink - Fetch Manager
WHATWG Spec on DOM Global Fetch
WHATWG Spec on
processResponseWHATWG Spec on
processResponseEndOfBodyOpenTelemetry Setup Code
https://github.com/therynamo/no-store-blink-otel-bug
Operating System and Version
Chromium Latest
Firefox Latest
Safari Latest
Runtime and Version
All browsers, Client SDK, latest version.
Tip
👍