Skip to content

Commit 223618d

Browse files
committed
Require an acknowledgement for every submitted operation
The exporter posts an unfiltered /_bulk with one index operation per record, and Elasticsearch answers those with one entry in items per operation. The check accepted any 2xx body carrying errors:false, so {"errors":false\} alone was reported as a successful write of every record in the batch. An exporter that reports success without a write acknowledgement gives the caller no reason to retry, which is the more dangerous direction of the two. A misconfigured proxy, a non-Elasticsearch endpoint answering with coincidentally shaped JSON, or a server returning an incomplete envelope all reached the same result. An earlier revision of this branch dropped a count check as half baked schema validation, on the grounds that a filter_path response need not carry items. That reasoning does not apply to this exporter: it never sends filter_path. Confirming the response answers as many operations as were submitted is not the same as validating each item's contents.
1 parent 28ae57b commit 223618d

3 files changed

Lines changed: 67 additions & 31 deletions

File tree

‎exporters/elasticsearch/include/opentelemetry/exporters/elasticsearch/detail/es_bulk_response.h‎

Lines changed: 19 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -42,6 +42,7 @@ namespace detail
4242
*/
4343
inline bool IsBulkResponseSuccessful(int status_code,
4444
const std::string &body,
45+
std::size_t expected_items,
4546
std::string &failure_reason) noexcept
4647
{
4748
failure_reason.clear();
@@ -70,14 +71,30 @@ inline bool IsBulkResponseSuccessful(int status_code,
7071
return false;
7172
}
7273

74+
// The exporter posts an unfiltered /_bulk, one index operation per record, and Elasticsearch
75+
// answers those with one entry in "items" per operation. A body without that many entries is
76+
// not an answer to the request that was sent, so it is not evidence that the records were
77+
// written, whatever "errors" says.
78+
const auto items = parsed.find("items");
79+
if (items == parsed.end() || !items->is_array())
80+
{
81+
failure_reason = "the response body has no \"items\" array";
82+
return false;
83+
}
84+
85+
if (items->size() != expected_items)
86+
{
87+
failure_reason = "the response acknowledges " + std::to_string(items->size()) + " of " +
88+
std::to_string(expected_items) + " submitted operations";
89+
return false;
90+
}
91+
7392
if (!errors->get<bool>())
7493
{
7594
return true;
7695
}
7796

7897
// errors is true: report the first item error rather than only saying that something failed.
79-
const auto items = parsed.find("items");
80-
if (items != parsed.end() && items->is_array())
8198
{
8299
for (const auto &item : *items)
83100
{

‎exporters/elasticsearch/src/es_log_record_exporter.cc‎

Lines changed: 10 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -256,9 +256,11 @@ class AsyncResponseHandler : public http_client::EventHandler
256256
AsyncResponseHandler(
257257
std::shared_ptr<ext::http::client::Session> session,
258258
std::function<bool(opentelemetry::sdk::common::ExportResult)> &&result_callback,
259+
std::size_t submitted_operations,
259260
bool console_debug = false)
260261
: session_{std::move(session)},
261262
result_callback_{std::move(result_callback)},
263+
submitted_operations_{submitted_operations},
262264
console_debug_{console_debug}
263265
{}
264266

@@ -286,7 +288,8 @@ class AsyncResponseHandler : public http_client::EventHandler
286288
"[ES Log Exporter] Got response from Elasticsearch, response body: " << body_);
287289
}
288290
std::string failure_reason;
289-
if (!detail::IsBulkResponseSuccessful(response.GetStatusCode(), body_, failure_reason))
291+
if (!detail::IsBulkResponseSuccessful(response.GetStatusCode(), body_, submitted_operations_,
292+
failure_reason))
290293
{
291294
OTEL_INTERNAL_LOG_ERROR("[ES Log Exporter] Logs were not written to Elasticsearch correctly, "
292295
<< failure_reason << ", response body: " << body_);
@@ -347,6 +350,9 @@ class AsyncResponseHandler : public http_client::EventHandler
347350
// Callback to call to on receiving events
348351
std::function<bool(opentelemetry::sdk::common::ExportResult)> result_callback_;
349352

353+
// How many operations this request submitted, which is how many the response has to answer
354+
std::size_t submitted_operations_ = 0;
355+
350356
// A string to store the response body
351357
std::string body_ = "";
352358

@@ -460,7 +466,7 @@ sdk::common::ExportResult ElasticsearchLogRecordExporter::Export(
460466
synchronization_data->force_flush_cv.notify_all();
461467
return true;
462468
},
463-
options_.console_debug_);
469+
span_count, options_.console_debug_);
464470
session->SendRequest(handler);
465471
return sdk::common::ExportResult::kSuccess;
466472
#else
@@ -489,7 +495,8 @@ sdk::common::ExportResult ElasticsearchLogRecordExporter::Export(
489495
// Parse the response output to determine if Elasticsearch consumed it correctly
490496
std::string responseBody = handler->GetResponseBody();
491497
std::string failure_reason;
492-
if (!detail::IsBulkResponseSuccessful(handler->GetStatusCode(), responseBody, failure_reason))
498+
if (!detail::IsBulkResponseSuccessful(handler->GetStatusCode(), responseBody, records.size(),
499+
failure_reason))
493500
{
494501
OTEL_INTERNAL_LOG_ERROR("[ES Log Exporter] Logs were not written to Elasticsearch correctly, "
495502
<< failure_reason << ", response body: " << responseBody);

‎exporters/elasticsearch/test/es_log_record_exporter_test.cc‎

Lines changed: 38 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -167,46 +167,46 @@ constexpr const char *kOneItemRejected =
167167
TEST(ElasticsearchBulkResponseTests, ReportsSuccessWhenErrorsIsFalse)
168168
{
169169
std::string reason;
170-
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, kPrettySuccess, reason));
171-
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, kCompactSuccess, reason));
170+
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, kPrettySuccess, 1, reason));
171+
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, kCompactSuccess, 1, reason));
172172
}
173173

174174
// A successful check must not leave a stale failure reason from a previous call behind.
175175
TEST(ElasticsearchBulkResponseTests, ClearsFailureReasonOnSuccess)
176176
{
177177
std::string reason = "stale";
178-
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, kCompactSuccess, reason));
178+
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, kCompactSuccess, 1, reason));
179179
EXPECT_TRUE(reason.empty());
180180
}
181181

182182
TEST(ElasticsearchBulkResponseTests, ReportsFailureWhenAnyItemWasRejected)
183183
{
184184
std::string reason;
185-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, kOneItemRejected, reason));
185+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, kOneItemRejected, 2, reason));
186186
EXPECT_NE(reason.find("mapper_parsing_exception"), std::string::npos);
187187
}
188188

189189
TEST(ElasticsearchBulkResponseTests, ReportsFailureOnUnusableBody)
190190
{
191191
std::string reason;
192-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, "not json at all", reason));
192+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, "not json at all", 1, reason));
193193
EXPECT_FALSE(reason.empty());
194194

195-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, "", reason));
195+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, "", 1, reason));
196196
EXPECT_FALSE(reason.empty());
197197

198198
// An array rather than the expected object.
199-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, "[1,2,3]", reason));
199+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, "[1,2,3]", 1, reason));
200200
EXPECT_FALSE(reason.empty());
201201
}
202202

203203
TEST(ElasticsearchBulkResponseTests, ReportsFailureWhenErrorsFieldIsMissingOrNotBoolean)
204204
{
205205
std::string reason;
206206
EXPECT_FALSE(
207-
logs_exporter::detail::IsBulkResponseSuccessful(200, R"({"took":30,"items":[]})", reason));
207+
logs_exporter::detail::IsBulkResponseSuccessful(200, R"({"took":30,"items":[]})", 1, reason));
208208
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(
209-
200, R"({"errors":"false","items":[]})", reason));
209+
200, R"({"errors":"false","items":[]})", 0, reason));
210210
}
211211

212212
// A non-2xx status is a failure even when the body reports errors:false. This is the invariant
@@ -215,22 +215,22 @@ TEST(ElasticsearchBulkResponseTests, ReportsFailureOnNon2xxStatus)
215215
{
216216
std::string reason;
217217
const char *ok_body = R"({"errors":false,"items":[]})";
218-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(500, ok_body, reason));
219-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(429, ok_body, reason));
220-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(400, ok_body, reason));
221-
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, ok_body, reason));
218+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(500, ok_body, 0, reason));
219+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(429, ok_body, 0, reason));
220+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(400, ok_body, 0, reason));
221+
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, ok_body, 0, reason));
222222
}
223223

224224
// errors:true with no extractable item error still fails, with the generic reason.
225225
TEST(ElasticsearchBulkResponseTests, ReportsFailureWhenErrorsTrueWithoutItemError)
226226
{
227227
std::string reason;
228228
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, R"({"errors":true,"items":[]})",
229-
reason));
229+
0, reason));
230230
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(
231-
200, R"({"errors":true,"items":[null]})", reason));
231+
200, R"({"errors":true,"items":[null]})", 1, reason));
232232
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(
233-
200, R"({"errors":true,"items":[{"index":42}]})", reason));
233+
200, R"({"errors":true,"items":[{"index":42}]})", 1, reason));
234234
}
235235

236236
// The 2xx range is the success band; the codes just outside it are failures. This pins the boundary
@@ -239,20 +239,32 @@ TEST(ElasticsearchBulkResponseTests, TreatsThe2xxRangeAsTheSuccessBand)
239239
{
240240
std::string reason;
241241
const char *ok_body = R"({"errors":false,"items":[]})";
242-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(199, ok_body, reason));
243-
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, ok_body, reason));
244-
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(299, ok_body, reason));
245-
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(300, ok_body, reason));
242+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(199, ok_body, 0, reason));
243+
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, ok_body, 0, reason));
244+
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(299, ok_body, 0, reason));
245+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(300, ok_body, 0, reason));
246246
}
247247

248-
// Batch success is decided by the top-level "errors" flag alone. "items" is only read to extract a
249-
// diagnostic reason on failure, so a response without "items" (for example one filtered with
250-
// filter_path) is still a success when "errors" is false. This locks out re-introducing an
251-
// items-count success check.
252-
TEST(ElasticsearchBulkResponseTests, DoesNotRequireItemsForSuccess)
248+
// The exporter posts an unfiltered /_bulk, so Elasticsearch answers every submitted operation in
249+
// "items". A body that does not is not an answer to that request, and treating it as success would
250+
// hand the caller a write acknowledgement nobody made.
251+
TEST(ElasticsearchBulkResponseTests, RequiresAnAcknowledgementForEverySubmittedOperation)
253252
{
254253
std::string reason;
255-
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, R"({"errors":false})", reason));
254+
constexpr const char *kNoItems = R"({"errors":false})";
255+
constexpr const char *kNullItems = R"({"errors":false,"items":null})";
256+
constexpr const char *kOneItemBody =
257+
R"({"errors":false,"items":[{"index":{"_shards":{"failed":0}}}]})";
258+
constexpr const char *kTwoItemBody = R"({"errors":false,"items":[{"index":{}},{"index":{}}]})";
259+
260+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, kNoItems, 1, reason));
261+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, kNullItems, 1, reason));
262+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, kOneItemBody, 2, reason))
263+
<< "too few acknowledgements";
264+
EXPECT_FALSE(logs_exporter::detail::IsBulkResponseSuccessful(200, kTwoItemBody, 1, reason))
265+
<< "more acknowledgements than operations";
266+
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, kOneItemBody, 1, reason));
267+
EXPECT_TRUE(logs_exporter::detail::IsBulkResponseSuccessful(200, kTwoItemBody, 2, reason));
256268
}
257269
// ---------------------------------------------------------------------------
258270
// The response travelling from the HTTP callback to the verdict.

0 commit comments

Comments
 (0)