[BUG] Decide Elasticsearch bulk export success from HTTP status and the errors flag - #4297
[BUG] Decide Elasticsearch bulk export success from HTTP status and the errors flag#4297thc1006 wants to merge 3 commits into
Conversation
Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
Codecov Report❌ Patch coverage is
Additional details and impacted files@@ Coverage Diff @@
## main #4297 +/- ##
==========================================
+ Coverage 80.87% 81.93% +1.06%
==========================================
Files 450 494 +44
Lines 19216 19519 +303
==========================================
+ Hits 15539 15990 +451
+ Misses 3677 3529 -148
🚀 New features to boost your workflow:
|
Review of open-telemetry#4297 found the synchronous path reported a non-2xx response as a success: ResponseHandler::OnResponse only logged the status and unconditionally set response_received_, waitForResponse returned true, and Export then checked the body alone, so HTTP 500 with a body of {"errors":false} became kSuccess. My description claiming the sync path already checked the status was wrong: it observed the status but never let it affect the ExportResult. IsBulkResponseSuccessful now takes the status code and treats a non-2xx as a failure before looking at the body. The top-level "errors" flag is item-level and cannot override a transport or application error. Both paths call it: the async handler drops its duplicated status check, and the sync handler stores the status so Export can pass it in. Tests assert the invariant directly, including HTTP 500 with {"errors":false} on the sync-shaped path, plus the errors:true generic reason and the missing item-error branches. A full handler-level mock across HttpClient/Session is out of scope: the exporter has no such mock today (its network tests are DISABLED_), and the status invariant is what the bug was, so it is covered at the validator instead. Fixes open-telemetry#4295 Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
Review of open-telemetry#4297 found the synchronous path reported a non-2xx response as a success: ResponseHandler::OnResponse only logged the status and unconditionally set response_received_, waitForResponse returned true, and Export then checked the body alone, so HTTP 500 with a body of {"errors":false} became kSuccess. My description claiming the sync path already checked the status was wrong: it observed the status but never let it affect the ExportResult. IsBulkResponseSuccessful now takes the status code and treats a non-2xx as a failure before looking at the body. The top-level "errors" flag is item-level and cannot override a transport or application error. Both paths call it: the async handler drops its duplicated status check, and the sync handler stores the status so Export can pass it in. Tests assert the invariant directly, including HTTP 500 with {"errors":false} on the sync-shaped path, plus the errors:true generic reason and the missing item-error branches. A full handler-level mock across HttpClient/Session is out of scope: the exporter has no such mock today (its network tests are DISABLED_), and the status invariant is what the bug was, so it is covered at the validator instead. Fixes open-telemetry#4295 Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
d751066 to
229ee19
Compare
189419b to
0283411
Compare
49cf38c to
223618d
Compare
26e81a8 to
7a381fb
Compare
…he errors flag The exporter decided a bulk export had succeeded by searching the response body for the substring "failed" : 0. That is a shard counter belonging to one item, not a verdict on the batch, so a body that never contained it read as a failure and a body that contained it anywhere read as a success. Decide from the documented contract instead: a 2xx HTTP status, a top level "errors" flag that is false, and one acknowledged operation result per record submitted. Each entry of "items" has to be the result of the index operation the exporter actually sent, carrying an integer status in the 2xx band, so a well formed body that acknowledges nothing cannot pass. When "errors" is true the first rejected item names the status in the log. The status is compared in the type it was parsed as. Reading it through an int first is not safe: the value comes from the server, is_number_integer() holds for unsigned as well, and 2^32 + 200 narrows back into the 2xx band on a 32 bit int. Comparing directly also removes the need for a rejected-status sentinel, which could not tell a real status of 0 apart from "nothing was rejected". The parser lives in detail/es_bulk_response.h, excluded from both the CMake install set and the Bazel public headers. Signed-off-by: thc1006 <84045975+thc1006@users.noreply.github.com>
7a381fb to
c7cf4e9
Compare
The errors:true path already treats an item's error member as proof the
operation did not apply. The errors:false path ignored it, so
{"errors":false,"items":[{"index":{"status":201,"error":{...}}}]}
was accepted while the same body with errors:true was rejected. Same
evidence, opposite verdict, decided by a flag a broken responder also
controls, which is the shape this helper exists to close.
Both signals are now read in the single pass that already validates the
items, which also drops the second walk the errors:true branch needed.
find() reports a key that is present with a null value, so the first
version rejected {"error":null}. A serialiser that writes absent
optionals as null is saying the operation applied, which is what the
flag says too, and rejecting it would fail exports that are fine while
catching nothing. Only a cause contradicts the flag.
|
Eighteen days and no human has looked at this yet. The one review on it is Copilot reporting that it could not run because the requester was out of quota, and CI has been green throughout. So here is the short entry point that What it does. Both export paths decided a bulk write had succeeded with Where to look, if you would rather spot check than read it all.
Two choices I flagged as open, which I am now closing rather than leaving on you. I raised them because both are firsts for this repository, not because I think they are wrong, and re-reading the description I can see that asking for two decisions on top of a review is a good reason to defer the whole thing.
Both stay as they are unless you would rather they did not. Say the word on either and I will change it, but nothing is waiting on an answer. If this is still unlooked-at by 18 August I will bring it to the C++ SIG meeting, which is what |
Fixes #4295
Short summary for review: #4297 (comment)
The bug
Both export paths decided whether a bulk write succeeded with
body.find("\"failed\" : 0").failedis per-shard information for one item, not the batch outcome (which is the top-levelerrorsflag), and the literal even baked in pretty-printing whitespace, so it was wrong in both directions: a batch with a rejected item read as success, and a compact successful response read as failure.The fix
A single
IsBulkResponseSuccessful(status_code, body, expected_items, reason)that both paths call. A non-2xx status is a failure first. Then the body has to be a JSON object with a booleanerrorsflag and anitemsarray holding one operation result per operation the request submitted, anderrorshas to be false. A malformed body counts as a failure, and the first item error is reported so the log says why.The count is there because the exporter posts an unfiltered
/_bulkwith exactly one index operation per record, and Elasticsearch answers those with one entry initemsper operation. Without it,{"errors":false}on its own was reported as a successful write of the whole batch. An exporter that claims success without a write acknowledgement gives the caller no reason to retry, which is the worse of the two directions to be wrong in, and a misconfigured proxy or a non-Elasticsearch endpoint answering with coincidentally shaped JSON both landed there.Matching the count is not enough on its own. Elasticsearch answers each operation with an object keyed by the action name, so
{"errors":false,"items":[null,null]}for a two record batch had the right length and was reported as a successful write of both records. That requirement already existed, but only on theerrors:truepath, where the walk that extracts the first item error skips anything that is not an object. The same body was therefore a failure witherrors:trueand a success witherrors:false, so a responder that sends neither shape correctly picked the verdict with a flag it also controls. The requirement now runs beforeerrorsis read, and the skip inside the walk goes with it.An acknowledgement is an entry with exactly one member, named
index, holding a result object with astatus. Elasticsearch keys each entry by the action it answers and the exporter writes every record with an index action, so that is what an answer to this request looks like, and the bulk schema makesstatusa required member of the result alongside_index. The parser holds the response to thestatusand stops there._indexis required of a conforming server too, but it decides nothing here, and an alias or a data stream answers with the backing index rather than the name the request was addressed to, so asking for it would only add a way to be wrong.Nothing weaker ties the entry to the operation that was sent. Being an object was not the line it looked like:
{"errors":false,"items":[{},{}]}matched the count and was an object per entry. Neither is carrying some action or other:{"unknown":{"status":201}}answers something this exporter never submitted, and{"index":{"status":201},"delete":{}}answers one operation with two. The count check is what makes those dangerous rather than untidy. A hundred records answered with a hundred filler entries reads as a successful write, the processor drops the batch, and the records are gone.The status is then read against the flag rather than instead of it. A false
errorsasserts that every operation was applied, so{"errors":false,"items":[{"index":{"status":400}}]}is the response contradicting itself, and a response that contradicts itself is not evidence that anything was written. A conforming server never sends that combination, which is why this rejects nothing the flag alone would have accepted.2xx is the whole success band here, and that is a property of this exporter rather than a policy choice: every record is written with an
indexoperation, which Elasticsearch answers with 200 or 201. There is nocreatereturning 409 for a duplicate ordeletereturning 404 to weigh, so the band is the same one the response's own HTTP status uses, pinned at 200/299/300 by a case.The band is compared in the type the number was parsed as, not through an
int. The value comes from the server,is_number_integer()holds for unsigned as well, and nlohmann does not range checkget<int>(), so2^32 + 200narrows straight back into the band on a 32 bitintand reads as applied. Comparing directly also removes the need for a rejected-status sentinel: an earlier revision returned the first rejected status as anintand used0to mean "nothing was rejected", which cannot tell those apart, so{"errors":false,"items":[{"index":{"status":0}}]}was reported as a successful write. Both are covered by cases at 0, -0, -1, 199, 200, 201, 299, 300,2^32 + 200andUINT64_MAX, plus a non-integer and a string.The status is what makes the response two things rather than one, so the synchronous handler now keeps both halves together. It publishes the status and the body only on the transition that records the outcome, and
Exporttakes them in a single call. Reading them one lock at a time, with each response overwriting them unconditionally, let a client that delivers two responses for one request pair a status from one with a body from the other, and that pair is what the verdict is computed from. The asynchronous handler keeps its body in a local for the same reason, since nothing outside the call reads it.An operation that did not apply says so twice, and both are read the same way whichever value the flag has. Elasticsearch documents
erroras present only on a failed operation, and theerrors:truepath already relied on that to name the first failure. Undererrors:falseit was ignored, so{"index":{"status":201,"error":{"type":"mapper_parsing_exception"}}}was accepted while the same body witherrors:truewas rejected. That is the same shape as theitemsentry problem above: one body, two verdicts, chosen by a flag the broken responder also controls. The status alone does not cover it, since the contradiction is between the status and the error rather than between the status and the flag. Both signals are now collected in the pass that already validates the items, which also removes the second walk theerrors:truebranch needed.A null member is not a cause.
findreports a key that is present holdingnull, and a serialiser that writes absent optionals that way is saying the operation applied, which is what the flag says too, so rejecting it would fail exports that are fine and catch nothing. Both shapes have a case.The check stops there. It never asks what an operation's status means beyond the band, and it reads no other member of the result.
An earlier revision of this branch had the count check and dropped it, on the grounds that a
filter_pathresponse need not carryitems. That reasoning does not apply here: this exporter never sendsfilter_path. If it ever does, the request side should say so rather than the parser accepting two incompatible response shapes.The HTTP status matters and was the second-round finding: the synchronous path previously only logged a non-2xx status and still returned success, so
HTTP 500with{"errors":false}was reported askSuccess. The status is now part of the result on both paths; the async handler drops its duplicated check and the sync handler stores the status forExportto pass in.Structure
The helper lives in
include/opentelemetry/exporters/elasticsearch/detail/es_bulk_response.hso tests can reach it, following thedetail/pattern already used byext/http/client/detail/default_factory.h. It is adetailheader rather than an anonymous-namespace function in the.cc(an earlier revision put it there, which is why it could not be tested).It is excluded from the installed package, both the header and the
detaildirectory, since the file name pattern alone still leaves an empty directory behind in the package. The component's*.hglob would otherwise ship it, and it includes<nlohmann/json.hpp>, which would make nlohmann a public dependency of the installed Elasticsearch headers for the first time.es_log_recordable.his the precedent one line above in the same call: it is the only other header here that includes nlohmann, and it is already excluded for the same reason. Verified by installing into a clean prefix and listing what lands underinclude/opentelemetry/exporters/elasticsearch, which is now justes_log_record_exporter.h.Worth your call rather than mine: the only other
detail/directory in the tree isext/http/client/detail, and it is installed today, sodetail/has meant "public but unstable" here rather than "private". #4327 stopped installing it when it merged on 4 August, so excluding this one follows the convention rather than standing against it. On the reading that held before that, the file would belong insrc/instead, which would need no exclusion at all. I kept it where the tests can reach it and excluded it, and I am happy to move it if you would rather it were not reachable as a header at all.On the Bazel side the header is not in the exporter target's
hdrs.hdrsis a target's public interface, so listing it there would let a Bazel consumer include a header the CMake package deliberately does not install. It has its own target, visible only to this package, and the exporter reaches it throughimplementation_depsso it is not re-exported; the test depends on it directly.Checked rather than assumed. A consumer that depends only on
:es_log_record_exporter:and the same consumer with
:es_bulk_responseadded builds. This is the repository's firstimplementation_depsand its first target levelvisibility, so say if you would rather the header simply stayed inhdrsand the two package surfaces differed, the way//ext:headerscurrently does.One other thing in this diff that is not strictly part of the fix: the bulk URI drops
?pretty. The old check depended on pretty printed whitespace, so asking the server for it no longer serves any purpose, but it does change the request and I would rather name it than have it found.Guarded with
OPENTELEMETRY_HAVE_EXCEPTIONSso thetry/catchcompiles under the-fno-exceptionsBazel config.<nlohmann/json.hpp>stays included by the.ccbecause it still callsGetJSON().dump()directly.Tests
The helper's cases are covered directly: pretty and compact success, a rejected item (reason names the underlying error), a non-2xx status with
{"errors":false}(the sync false-success invariant),errors:truewith no extractable item error, malformed and empty bodies, and a missing or non-booleanerrorsfield. The 2xx range is pinned at its 199/200/299/300 boundaries. The acknowledgement count is pinned in both directions: noitems,items:null, too few, too many, and the exact count. Entries that do not acknowledge an index operation are pinned separately:nullentries, scalars, a nested array,{}, an action the exporter never submitted,indexholding a scalar, two members in one entry, two members where one of them is valid,indexwith no status, and the samenullshape witherrors:true, which has to fail whichever way the flag reads. That case is mutation checked: removing theindexlookup from the helper while leaving the member count and the status requirement turns it red, so it pins the operation identity rather than the JSON shape around it. A separate case covers the response contradicting itself: a 400 undererrors:false, one rejection among several acknowledgements, and the 200/299/300 band boundary. The shared success and rejection fixtures now carry thestatusand_indexa real bulk response has; they were abridged to what the old substring check looked at.Now that #4298 has landed, a fake session that responds from inside
SendRequest()no longer deadlocks the synchronous path, so three cases run through the exporter itself rather than through the helper:"failed" : 0, is a failed export,The third is the one the helper tests cannot give you. A handler that stored a fixed status, or an
Export()that never asked for one, passes every helper case.Those three drive the synchronous path, and they skip in the configuration the coverage job builds.
code.coverageconfiguresall-options-abiv2-preview, which turns onENABLE_ASYNC_EXPORT, so nothing there calledExport()at all and six lines of this change went unexecuted: the handler'ssubmitted_operations_member, the bulk URI, the handler construction, and the parse with its failure log.Two more cases cover that path.
Export()returns before a response arrives there, so the parsed result decides only which internal log line is written, and they read it through a captured log handler the waybatch_span_processor_testdoes: an accepted response logs no export failure, a rejected one does. Measured with lcov on the coverage preset, the six lines go from zero hits to covered. Of the two, only the rejected one discriminates: putting the substring check back on the asynchronous path makes it fail, because"failed" : 0appears in a body that has a rejected item.The accepted one passes either way and is there as its control.
Both sets are fixtures that skip in
SetUprather than cases that compile out.gtest_add_testsregisters from the source, so a case missing from the binary is still handed to CTest, and a gtest filter that matches nothing exits zero, which reports a pass without running. Putting the skip inSetUprather than at the top of each body also keepsGTEST_SKIP, which returns, from leaving the rest of a body unreachable, which MSVC reports as C4702 and the maintainer mode jobs turn into an error.The
catch (...)guard in the helper stays uncovered. It is unreachable by input, since the parser rejects malformed bodies rather than throwing, and reaching it needs allocation fault injection, which has no precedent here.The fake client is the same one #4331 adds to this file. Whichever lands first, the other drops the duplicate when it rebases.
Verification
WITH_ELASTICSEARCH=ONgives[ PASSED ] 19 tests.with the two asynchronous cases skipped, andWITH_ASYNC_EXPORT_PREVIEW=ONgives[ PASSED ] 17 tests.with the synchronous wiring cases skipped instead. Both build with no warnings underOTELCPP_MAINTAINER_MODE=ON.Export()to the old substring check and rebuilding fails exactly the two cases that should discriminate:AcceptedBulkResponseIsASuccessfulExportstill passes there, which is correct: the happy path works under either check, so it is not a discriminator.Success is decided from the compact
/_bulkresponse; parsing no longer depends on pretty-printing../ci/do_ci.sh formatexits 0 with no diff (clang-format 18, cmake-format 0.6.13, buildifier 3.5.0).The lines the coverage report still marks in
es_bulk_response.hare the defensivecatch (...)that keeps anything from escaping thenoexceptresponse handlers. No response body reaches it, since the parser rejects malformed and invalid-UTF-8 input before any throwing call, so exercising it would mean injecting an allocation failure through a globaloperator newoverride. That is program-wide machinery this repository does not use elsewhere, and it behaves differently in the shared-library configurations, so I left the guard uncovered rather than add it. I can add it if you would rather have the coverage.clang-tidy was measured against
mainrather than in isolation, and over the test target so that the test file is compiled as well as the exporter. On theall-options-abiv2-previewpreset both trees report the same three checks and the same twenty two warning lines, and nothing ines_bulk_response.h, so the branch adds nothing towarning_limit. The include-what-you-use jobs are green on all three presets.