ElasticsearchStatusException: Data too large, data / Fail to execute es requestES refresh request

SonarQube LTS 8.9.0
(we have since upgraded 8.9.6, during which we identified the previous failures)

When reviewing the SonarQube background Tasks, identified a series of project analysis failures with the same error condition. Over 900 scans were done that day and somewhere in the middle, these failed.

UUID STATUS TIMESTAMP DATE
AX4TYckDOP_YqP5z1O15 SUCCESS 1641002682650 2022-01-01 2:04:43
AX4TYdXMOP_YqP5z1O16 FAILED 1641002687816 2022-01-01 2:04:48
AX4TYleCOP_YqP5z1O17 FAILED 1641002719379 2022-01-01 2:05:19
AX4TYxymOP_YqP5z1O18 FAILED 1641002769636 2022-01-01 2:06:10
AX4TY1glOP_YqP5z1O19 FAILED 1641002784840 2022-01-01 2:06:25
AX4TY2DoOP_YqP5z1O1- FAILED 1641002787115 2022-01-01 2:06:27
AX4TY8B1OP_YqP5z1O1_ FAILED 1641002811529 2022-01-01 2:06:52
AX4TY86MOP_YqP5z1O2A FAILED 1641002815197 2022-01-01 2:06:55
AX4TZKEQOP_YqP5z1O2B SUCCESS 1641002869064 2022-01-01 2:07:49

The first project error (see below) reported as “issues”, the remainder “components” . Then everything else completed as expected.

The first failed project one is one of our larger projects, with these metrics:

Lines of Code 666,043
Lines 1,050,233
Statements 370,265
Functions 62,233
Classes 2,602
Files 2,329
Comment Lines 139,514

It has previously and since scanned successfully, as have the ones that followed in the minutes after; those are very small projects.

Seems to be related to Elastic Search data limitation:

Caused by: ElasticsearchStatusException[Elasticsearch exception [type=circuit_breaking_exception, reason=[parent] Data too large, data for [<http_request>] would be [2042481616/1.9gb], which is larger than the limit of [2040109465/1.8gb], real usage: [2042481616/1.9gb], new bytes reserved: [0/0b], usages [request=0/0b, fielddata=493847/482.2kb, in_flight_requests=0/0b, accounting=1042908/1018.4kb]]]`

Also not sure if related Q:
sonar.properties:sonar.ce.javaOpts=-Xmx2g -Xms128m -XX:+HeapDumpOnOutOfMemoryError


Elastic search System Info:

Disk Available 180 GB
Store Size 476 MB
Translog Size 1 KB
Open File Descriptors 251
Max File Descriptors 65536
JVM Heap Usage 19.00%
JVM Heap Used 397 MB
JVM Heap Max 2 GB
JVM Non Heap Used 159 MB
JVM Threads 55
Field Data Memory 1 MB
Field Data Circuit Breaker Limit 819 MB
Field Data Circuit Breaker Estimation 1 MB
Request Circuit Breaker Limit 1 GB
Request Circuit Breaker Estimation 0 bytes
Query Cache Memory 424 KB
Request Cache Memory 21 KB
Search Indexes
Index components - Docs 2236
Index components - Shards 5
Index components - Store Size 4 MB
Index projectmeasures - Docs 19609
Index projectmeasures - Shards 5
Index projectmeasures - Store Size 3 MB
Index metadatas - Docs 17
Index metadatas - Shards 1
Index metadatas - Store Size 33 KB
Index rules - Docs 19823
Index rules - Shards 2
Index rules - Store Size 13 MB
Index issues - Docs 2747925
Index issues - Shards 5
Index issues - Store Size 453 MB
Index users - Docs 397
Index users - Shards 1
Index users - Store Size 835 KB
Index views - Docs 1
Index views - Shards 5
Index views - Store Size 4 KB

Error messages

Fail to execute es requestES refresh request on indices 'issues'
"org.sonar.server.es.ElasticsearchException: Fail to execute es requestES refresh request on indices 'issues'
	at org.sonar.server.es.EsClient.execute(EsClient.java:313)
	at org.sonar.server.es.EsClient.refresh(EsClient.java:156)
	at org.sonar.server.es.BulkIndexer.stop(BulkIndexer.java:128)
	at org.sonar.server.issue.index.IssueIndexer.doIndex(IssueIndexer.java:261)
	at org.sonar.server.issue.index.IssueIndexer.indexOnAnalysis(IssueIndexer.java:115)
	at org.sonar.ce.task.projectanalysis.step.IndexAnalysisStep.execute(IndexAnalysisStep.java:45)
	at org.sonar.ce.task.step.ComputationStepExecutor.executeStep(ComputationStepExecutor.java:81)
	at org.sonar.ce.task.step.ComputationStepExecutor.executeSteps(ComputationStepExecutor.java:72)
	at org.sonar.ce.task.step.ComputationStepExecutor.execute(ComputationStepExecutor.java:59)
	at org.sonar.ce.task.projectanalysis.taskprocessor.ReportTaskProcessor.process(ReportTaskProcessor.java:81)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.executeTask(CeWorkerImpl.java:212)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.run(CeWorkerImpl.java:194)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.findAndProcessTask(CeWorkerImpl.java:160)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$$Lambda$1222/0x0000000000000000.apply(Unknown Source)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$TrackRunningState.get(CeWorkerImpl.java:135)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:87)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:53)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:836)
Caused by: ElasticsearchStatusException[Elasticsearch exception [type=circuit_breaking_exception, reason=[parent] Data too large, data for [<http_request>] would be [2042481616/1.9gb], which is larger than the limit of [2040109465/1.8gb], real usage: [2042481616/1.9gb], new bytes reserved: [0/0b], usages [request=0/0b, fielddata=493847/482.2kb, in_flight_requests=0/0b, accounting=1042908/1018.4kb]]]
	at org.elasticsearch.rest.BytesRestResponse.errorFromXContent(BytesRestResponse.java:176)
	at org.elasticsearch.client.RestHighLevelClient$$Lambda$2654/0x0000000000000000.apply(Unknown Source)
	at org.elasticsearch.client.RestHighLevelClient.parseEntity(RestHighLevelClient.java:1933)
	at org.elasticsearch.client.RestHighLevelClient.parseResponseException(RestHighLevelClient.java:1910)
	at org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:1667)
	at org.elasticsearch.client.RestHighLevelClient.performRequest(RestHighLevelClient.java:1624)
	at org.elasticsearch.client.RestHighLevelClient.performRequestAndParseEntity(RestHighLevelClient.java:1594)
	at org.elasticsearch.client.IndicesClient.refresh(IndicesClient.java:689)
	at org.sonar.server.es.EsClient.lambda$refresh$9(EsClient.java:156)
	at org.sonar.server.es.EsClient$$Lambda$1342/0x0000000000000000.execute(Unknown Source)
	at org.sonar.server.es.EsClient.execute(EsClient.java:311)
	... 25 more
	Suppressed: org.elasticsearch.client.ResponseException: method [POST], host [http://127.0.0.1:9001], URI [/issues/_refresh?ignore_throttled=false&ignore_unavailable=false&expand_wildcards=open&allow_no_indices=true], status line [HTTP/1.1 429 Too Many Requests]
{"error":{"root_cause":[{"type":"circuit_breaking_exception","reason":"[parent] Data too large, data for [<http_request>] would be [2042481616/1.9gb], which is larger than the limit of [2040109465/1.8gb], real usage: [2042481616/1.9gb], new bytes reserved: [0/0b], usages [request=0/0b, fielddata=493847/482.2kb, in_flight_requests=0/0b, accounting=1042908/1018.4kb]","bytes_wanted":2042481616,"bytes_limit":2040109465,"durability":"PERMANENT"}],"type":"circuit_breaking_exception","reason":"[parent] Data too large, data for [<http_request>] would be [2042481616/1.9gb], which is larger than the limit of [2040109465/1.8gb], real usage: [2042481616/1.9gb], new bytes reserved: [0/0b], usages [request=0/0b, fielddata=493847/482.2kb, in_flight_requests=0/0b, accounting=1042908/1018.4kb]","bytes_wanted":2042481616,"bytes_limit":2040109465,"durability":"PERMANENT"},"status":429}
		at org.elasticsearch.client.RestClient.convertResponse(RestClient.java:326)
		at org.elasticsearch.client.RestClient.performRequest(RestClient.java:296)
		at org.elasticsearch.client.RestClient.performRequest(RestClient.java:270)
		at org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:1654)
		... 31 more
"

Fail to execute es requestES refresh request on indices 'components'
"org.sonar.server.es.ElasticsearchException: Fail to execute es requestES refresh request on indices 'components'
	at org.sonar.server.es.EsClient.execute(EsClient.java:313)
	at org.sonar.server.es.EsClient.refresh(EsClient.java:156)
	at org.sonar.server.es.BulkIndexer.stop(BulkIndexer.java:128)
	at org.sonar.server.component.index.ComponentIndexer.delete(ComponentIndexer.java:170)
	at org.sonar.ce.task.projectanalysis.purge.IndexPurgeListener.onComponentsDisabling(IndexPurgeListener.java:41)
	at org.sonar.db.purge.PurgeDao.purgeDisabledComponents(PurgeDao.java:101)
	at org.sonar.db.purge.PurgeDao.purge(PurgeDao.java:64)
	at org.sonar.ce.task.projectanalysis.purge.ProjectCleaner.purge(ProjectCleaner.java:63)
	at org.sonar.ce.task.projectanalysis.purge.PurgeDatastoresStep.execute(PurgeDatastoresStep.java:54)
	at org.sonar.ce.task.step.ComputationStepExecutor.executeStep(ComputationStepExecutor.java:81)
	at org.sonar.ce.task.step.ComputationStepExecutor.executeSteps(ComputationStepExecutor.java:72)
	at org.sonar.ce.task.step.ComputationStepExecutor.execute(ComputationStepExecutor.java:59)
	at org.sonar.ce.task.projectanalysis.taskprocessor.ReportTaskProcessor.process(ReportTaskProcessor.java:81)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.executeTask(CeWorkerImpl.java:212)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$ExecuteTask.run(CeWorkerImpl.java:194)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.findAndProcessTask(CeWorkerImpl.java:160)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$$Lambda$1222/0x0000000000000000.apply(Unknown Source)
	at org.sonar.ce.taskprocessor.CeWorkerImpl$TrackRunningState.get(CeWorkerImpl.java:135)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:87)
	at org.sonar.ce.taskprocessor.CeWorkerImpl.call(CeWorkerImpl.java:53)
	at com.google.common.util.concurrent.TrustedListenableFutureTask$TrustedFutureInterruptibleTask.runInterruptibly(TrustedListenableFutureTask.java:125)
	at com.google.common.util.concurrent.InterruptibleTask.run(InterruptibleTask.java:69)
	at com.google.common.util.concurrent.TrustedListenableFutureTask.run(TrustedListenableFutureTask.java:78)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:836)
Caused by: ElasticsearchStatusException[Elasticsearch exception [type=circuit_breaking_exception, reason=[parent] Data too large, data for [<http_request>] would be [2044390368/1.9gb], which is larger than the limit of [2040109465/1.8gb], real usage: [2044390368/1.9gb], new bytes reserved: [0/0b], usages [request=0/0b, fielddata=493847/482.2kb, in_flight_requests=0/0b, accounting=1042908/1018.4kb]]]
	at org.elasticsearch.rest.BytesRestResponse.errorFromXContent(BytesRestResponse.java:176)
	at org.elasticsearch.client.RestHighLevelClient$$Lambda$2654/0x0000000000000000.apply(Unknown Source)
	at org.elasticsearch.client.RestHighLevelClient.parseEntity(RestHighLevelClient.java:1933)
	at org.elasticsearch.client.RestHighLevelClient.parseResponseException(RestHighLevelClient.java:1910)
	at org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:1667)
	at org.elasticsearch.client.RestHighLevelClient.performRequest(RestHighLevelClient.java:1624)
	at org.elasticsearch.client.RestHighLevelClient.performRequestAndParseEntity(RestHighLevelClient.java:1594)
	at org.elasticsearch.client.IndicesClient.refresh(IndicesClient.java:689)
	at org.sonar.server.es.EsClient.lambda$refresh$9(EsClient.java:156)
	at org.sonar.server.es.EsClient$$Lambda$1342/0x0000000000000000.execute(Unknown Source)
	at org.sonar.server.es.EsClient.execute(EsClient.java:311)
	... 28 more
	Suppressed: org.elasticsearch.client.ResponseException: method [POST], host [http://127.0.0.1:9001], URI [/components/_refresh?ignore_throttled=false&ignore_unavailable=false&expand_wildcards=open&allow_no_indices=true], status line [HTTP/1.1 429 Too Many Requests]
{"error":{"root_cause":[{"type":"circuit_breaking_exception","reason":"[parent] Data too large, data for [<http_request>] would be [2044390368/1.9gb], which is larger than the limit of [2040109465/1.8gb], real usage: [2044390368/1.9gb], new bytes reserved: [0/0b], usages [request=0/0b, fielddata=493847/482.2kb, in_flight_requests=0/0b, accounting=1042908/1018.4kb]","bytes_wanted":2044390368,"bytes_limit":2040109465,"durability":"PERMANENT"}],"type":"circuit_breaking_exception","reason":"[parent] Data too large, data for [<http_request>] would be [2044390368/1.9gb], which is larger than the limit of [2040109465/1.8gb], real usage: [2044390368/1.9gb], new bytes reserved: [0/0b], usages [request=0/0b, fielddata=493847/482.2kb, in_flight_requests=0/0b, accounting=1042908/1018.4kb]","bytes_wanted":2044390368,"bytes_limit":2040109465,"durability":"PERMANENT"},"status":429}
		at org.elasticsearch.client.RestClient.convertResponse(RestClient.java:326)
		at org.elasticsearch.client.RestClient.performRequest(RestClient.java:296)
		at org.elasticsearch.client.RestClient.performRequest(RestClient.java:270)
		at org.elasticsearch.client.RestHighLevelClient.internalPerformRequest(RestHighLevelClient.java:1654)
		... 34 more
"

Hey there.

Elasticsearch is doing its best here to prevent an Out Of Memory exception – adjusting sonar.es.javaOpts to a larger value (-Xmx4g -Xms4g) would prevent this error in the future.

I would be curious to know, for the analyses linked to the failing background tasks (what actually ran in the CI), how big the analysis report was.

INFO: Analysis report generated in 141ms, dir size=240.0 kB
INFO: Analysis report compressed in 70ms, zip size=50.1 kB
INFO: Analysis report uploaded in 1592ms

I believe this is what you are looking for, for the failed pass:

18:50:45 [INFO] Analysis report generated in 4310ms, dir size=146 MB
18:51:38 [INFO] Analysis report compressed in 52931ms, zip size=43 MB
18:51:44 [INFO] Analysis report uploaded in 6338ms
18:51:44 [INFO] ANALYSIS SUCCESSFUL, you can browse http://sonarqube:9000/dashboard?id=corp.app:component
18:51:44 [INFO] Note that you will be able to access the updated dashboard once the server has processed the submitted analysis report
18:51:44 [INFO] More about the report processing at http://sonarqube:9000/api/ce/task?id=AX4TjMUQOP_YqP5z1O3o
18:51:54 [INFO] Analysis total time: 46:42.567 s

{
    "task": {
        "id": "AX4TjMUQOP_YqP5z1O3o",
        "type": "REPORT",
        "componentId": "AWB1jBEpK9m81SQtc6Cs",
        "componentKey": "corp.app:component",
        "componentName": "component",
        "componentQualifier": "TRK",
        "analysisId": "AX4Tjb4HpSh66J-3aNAY",
        "status": "SUCCESS",
        "submittedAt": "2022-01-01T02:51:44+0000",
        "startedAt": "2022-01-01T02:52:33+0000",
        "executedAt": "2022-01-01T02:58:20+0000",
        "executionTimeMs": 346898,
        "hasScannerContext": true,
        "warningCount": 3,
        "warnings": []
    }
}

This is the next successful pass for the same component/project:

16:01:32 00:01:33.51 [INFO] Analysis report generated in 2328ms, dir size=146 MB
16:01:54 00:01:54.738 [INFO] Analysis report compressed in 21686ms, zip size=43 MB
16:02:00 00:02:00.225 [INFO] Analysis report uploaded in 5487ms
16:02:00 00:02:00.226 [INFO] ANALYSIS SUCCESSFUL, you can browse http://sonarqube:9000/dashboard?id=corp.app.component
16:02:00 00:02:00.226 [INFO] Note that you will be able to access the updated dashboard once the server has processed the submitted analysis report
16:02:00 00:02:00.226 [INFO] More about the report processing at http://sonarqube:9000/api/ce/task?id=AX6EPUrXM_oWDnZk0p3r
16:02:02 00:02:02.804 [INFO] Analysis total time: 25:02.202 s

{
    "task": {
        "id": "AX6EPUrXM_oWDnZk0p3r",
        "type": "REPORT",
        "componentId": "AWB1jBEpK9m81SQtc6Cs",
        "componentKey": "corp.app:component",
        "componentName": "component",
        "componentQualifier": "TRK",
        "analysisId": "AX6EPa3RsaUuHWKxF0Wf",
        "status": "SUCCESS",
        "submittedAt": "2022-01-23T00:02:00+0000",
        "startedAt": "2022-01-23T00:02:12+0000",
        "executedAt": "2022-01-23T00:09:09+0000",
        "executionTimeMs": 417261,
        "hasScannerContext": true,
        "warningCount": 3,
        "warnings": []
    }
}

This is the prior successful scan for the same component/project:

18:24:13 02:24:13.99 [INFO] Analysis report generated in 2628ms, dir size=146 MB
18:24:36 02:24:37.07 [INFO] Analysis report compressed in 23907ms, zip size=43 MB
18:24:42 02:24:42.735 [INFO] Analysis report uploaded in 5728ms
18:24:42 02:24:42.737 [INFO] ANALYSIS SUCCESSFUL, you can browse http://sonarqube:9000/dashboard?id=corp.app%3Acomponent
18:24:42 02:24:42.737 [INFO] Note that you will be able to access the updated dashboard once the server has processed the submitted analysis report
18:24:42 02:24:42.738 [INFO] More about the report processing at http://sonarqube:9000/api/ce/task?id=AX1zzuE9pU7azX-HEDZx
18:24:45 02:24:45.156 [INFO] Analysis total time: 45:04.991 s

{
    "task": {
        "id": "AX1zzuE9pU7azX-HEDZx",
        "type": "REPORT",
        "componentId": "AWB1jBEpK9m81SQtc6Cs",
        "componentKey": "corp.app:component",
        "componentName": "component",
        "componentQualifier": "TRK",
        "analysisId": "AX1zzxqoz6wa5BqfFSql",
        "status": "SUCCESS",
        "submittedAt": "2021-12-01T02:24:42+0000",
        "startedAt": "2021-12-01T02:24:44+0000",
        "executedAt": "2021-12-01T02:30:58+0000",
        "executionTimeMs": 374028,
        "hasScannerContext": false,
        "warningCount": 3,
        "warnings": []
    }
}

I should also point out that the source for this application actually did NOT change between these these three passes; they all show the same changeset, so it’s not clear why one should fail analysis and cascade for several more projects after that.

15:12:15 Querying for remote changeset at ‘$/path/to/app/comp/branch’ as of ‘D2022-01-22T23:12:14Z’…
15:12:15 Query result is: Changeset #354035 by Developer on ‘2021-10-29T18:38:20Z’.

17:03:14 Querying for remote changeset at ‘$/path/to/app/comp/branch’ as of ‘D2022-01-01T01:03:00Z’…
17:03:14 Query result is: Changeset #354035 by 'Developer ’ on ‘2021-10-29T18:38:20Z’.

16:56:02 Querying for remote changeset at ‘$/path/to/app/comp/branch’ as of ‘D2021-12-01T00:56:02Z’…
16:56:02 Query result is: Changeset #354035 by 'Developer ’ on ‘2021-10-29T18:38:20Z’.