-
Notifications
You must be signed in to change notification settings - Fork 25.6k
Description
There's been a lot of issues with serialization of IngestStats, and having the stats themselves sometimes go negative (due to a bad code path double decrementing the 'ingestCurrent' count of the IngestStats.Stats).
See #52339, #62087, and #77973, as well as #52543, #69818, #81450, #90319 and #91439.
As far as I'm aware, at this point we've actually solved the serialization issue -- in the IngestStats itself we do not allow the current count to go negative, so even through some cases could still be double decrementing, we no longer have the problem of it causing various stats APIs to break. However, it's still possible to run into issues with this code, which would manifest as something like the following stack trace in the logs:
[2023-12-34T12:34:12,345][WARN ][o.e.i.IngestMetric ] [blahblahblah] Current ingest counter decremented below 0
java.lang.RuntimeException: null
at org.elasticsearch.ingest.IngestMetric.postIngest(IngestMetric.java:69) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.ingest.CompoundProcessor.innerExecute(CompoundProcessor.java:170) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.ingest.CompoundProcessor.execute(CompoundProcessor.java:139) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.ingest.Pipeline.execute(Pipeline.java:118) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.ingest.IngestDocument.executePipeline(IngestDocument.java:840) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.ingest.IngestService.executePipeline(IngestService.java:894) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.ingest.IngestService.executePipelines(IngestService.java:791) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.ingest.IngestService$1.doRun(IngestService.java:766) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:958) ~[elasticsearch-8.7.1.jar:?]
at org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26) ~[elasticsearch-8.7.1.jar:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642) ~[?:?]
at java.lang.Thread.run(Thread.java:1623) ~[?:?]
Most recently I came across a situation where #36746 was resulting in an exception being thrown from inside the markItemAsDropped method of the TransportBulkAction.BulkRequestModifier. It turns out that specific circumstance was a still-remaining cause of double-decrementing the IngestStats. #104585 fixed the code in question so that it would no longer happen to throw an exception in that circumstance, but the overall shape of the issue still remains: if something causes markItemAsDropped or markItemAsFailed to throw an exception then it appears that we'll double-decrement the IngestStats and log the above stack trace.
We should tighten up the exception handling logic around those methods so that double decrementing will not occur even if those methods fail -- and we should log even more useful information for ourselves in the event that they fail.