Slow bulk speed

Hi! We have performance issue with bulk operations in Elasticsearch 8.14.3. Bulks looks like this (tried from 1000 up to 25000 records - no changes):

{ "index": {"_id" : "627", "_index": "iv_counter_fd7bb2fd122ca9a08d40d8721e733905313fccec_1"} }
{ "id": "627", "dateFrom": "1737872762", "dateTo": "1737872772", "value": "8013642237878653277", "totalReservedAmount": "3750473857864547949", "modifyTS": "1737872771", "metaVersion": 1890764634, "classificationAttrs": [ { "type": "personalAccountId", "value": "617307394" } ], "domainCode": 866654073, "isPeriodic": true, "templateId": 771116071, "templateVersion": 4, "profileId": 1, "activationCode": "MEFWeEwtcE", "startOfLifeDate": "1737872762", "endOfLifeDate": "1737872772", "nextDateFrom": "1737872768", "moveRatio": "2861305372577635778", "moveLimitRatio": "4027764992922434915", "flags": 8, "occurOnReserve": [ "QqTlgUartYwVBXl0SW0sPdEDPn6tjx5LoosltChzocVMs8nDY7pAsGyphFOCMSNL", "fIkmVl5lk7cXH1t55KlHtt5ERVzf0Y8EbxYbLpjV1t01X3g9X9D6p0uD0F26Ooeq", "wUVM6eQAwwqnzfbYrutGOBHEfH7WWvj6kk3y1tpTyyqXLOBwSfDNRN8u5Xhb1xx9" ], "occurOnCommit": [ "AYKCXTCSJgvwTJv3jmNdphoPvPqYVGIXYeYgSQ4SNc4jeSSfJ95fYU1sOl0bYFW7", "K7LcbVKhLvJ1ck9lVAqtC8GEBSFs2GeRspVoE3KyFpmJe8q5n4ym4pYUIUrXInGa", "Jk79glpX4egTmad6dk5Foaa48NiwDQkUbgeXBnS7QqdnQ4JQeL4PHEqeaPbyptCa" ], "occurOnFullCommit": [ "okLcWNb1uGkIQGRz5pQ87r78TNAQGZB7EBXqzKRQ9pnF6ScuutuO1ar2bF6ZAhSd", "3WDY22UpihL0SxcXNL0ca7gCSqohWKsR6BC2TC8mZ4OT55HEGLVZFuKuWWEOaXY7" ], "occurOnGet": [ "sCIq86zdbZ6dsjvG7G79UqbpIqdqxCJRlB9c6L4CjJrRD6IUWUAkGqqZj26ZaUjR", "xDvfm4zMmBfduyVJ1vU5Ilwbn0Q42ZFVL7Xz2FzugnegGvARkxYdzUHW1x7jURMB" ], "occurOnLifecycle": [ "UYfrQW8tZaKRHKeWZn8UD29nGdpkvnWqxcPVgbx5vJYj6E6FySn8IBv8RASdswZg" ], "initialValue": "3154138969255271271", "IRPAamount": "6600453853226938062", "valueHistory": [ { "value": "2721073467101191060", "totalReservedAmount": "5493514222296149495", "dateFrom": "1737872769", "dateTo": "1737872779", "realModifyTime": "551052756" }, { "value": "3303591803327152453", "totalReservedAmount": "6659231958921893806", "dateFrom": "1737872770", "dateTo": "1737872775", "realModifyTime": "674240877" }, { "value": "6824078905440788558", "totalReservedAmount": "5247724868887723338", "dateFrom": "1737872769", "dateTo": "1737872773", "realModifyTime": "123745833" }, { "value": "4772824632370736712", "totalReservedAmount": "7170061691535416162", "dateFrom": "1737872763", "dateTo": "1737872779", "realModifyTime": "440388519" } ], "extAttrs": [ { "name": "wNrm6hUG", "value": "6QGlscEf2NaF6YZx8q8L", "dateFrom": "1737872766", "dateTo": "1737872780" } ], "autoRefills": [ { "dateFrom": "1737872769", "value": "4657436717165935773" }, { "dateFrom": "1737872769", "value": "3368079656787141426" }, { "dateFrom": "1737872770", "value": "4933458923744484622" } ], "recalcFactors": [ { "extCode": "zSq5t", "expirationDate": "1737882003", "value": { "integer": "7569928218894961710", "scale": 6 }, "ratio": "3415827438021528035" }, { "extCode": "sxYPl", "expirationDate": "1737877125", "value": { "integer": "7644506914038783848", "scale": 6 }, "type": "OutBonus" }, { "extCode": "49ExT", "applicationType": "FromNewPeriod", "value": { "integer": "2134963443824046386", "scale": 2 } }, { "extCode": "IIlU2", "ratio": "5006330077974600229" }, { "extCode": "hDMmV", "applicationType": "TillNewPeriod", "type": "InstanceRatio" } ] }

and index mapping like this - also tried to completely turn off mappings (e.g. index without any mappings) - nothing changed in performance:

{
  "runtime": {
    "flagsHex": {
      "type": "keyword",
      "script": {
        "source": "long flags = doc['flags'].value; String asHex = Long.toHexString(flags); emit(\"0x\" + asHex)"
      },
      "on_script_error": "continue"
    },
    "updateDirectionFlagsHex": {
      "type": "keyword",
      "script": {
        "source": "long updateDirectionFlags = doc['updateDirectionFlags'].value; String asHex = Long.toHexString(updateDirectionFlags); emit(\"0x\" + asHex)"
      },
      "on_script_error": "continue"
    }
  },
  "mappings": {
    "_doc": {
      "dynamic": "false",
      "properties": {
        "id": {
          "type": "long"
        },
        "dateFrom": {
          "type": "date",
          "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
          "fields": {}
        },
        "dateTo": {
          "type": "date",
          "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
          "fields": {}
        },
        "value": {
          "type": "long"
        },
        "totalReservedAmount": {
          "type": "long"
        },
        "modifyTS": {
          "type": "date",
          "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
          "fields": {}
        },
        "metaVersion": {
          "type": "long"
        },
        "classificationAttrs": {
          "type": "nested",
          "properties": {
            "type": {
              "type": "text",
              "fields": {}
            },
            "value": {
              "type": "text",
              "fields": {}
            }
          }
        },
        "domainCode": {
          "type": "long"
        },
        "isPeriodic": {
          "type": "boolean"
        },
        "templateId": {
          "type": "long"
        },
        "templateVersion": {
          "type": "long"
        },
        "profileId": {
          "type": "long"
        },
        "activationCode": {
          "type": "text",
          "fields": {}
        },
        "passedPeriodCounter": {
          "type": "long"
        },
        "startOfLifeDate": {
          "type": "date",
          "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
          "fields": {}
        },
        "endOfLifeDate": {
          "type": "date",
          "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
          "fields": {}
        },
        "nextDateFrom": {
          "type": "date",
          "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
          "fields": {}
        },
        "timeZone": {
          "type": "long"
        },
        "moveRatio": {
          "type": "long"
        },
        "moveLimitRatio": {
          "type": "long"
        },
        "flagsHex": {
          "type": "text",
          "fields": {}
        },
        "flags": {
          "type": "long"
        },
        "occurOnReserve": {
          "type": "text",
          "fields": {}
        },
        "occurOnCommit": {
          "type": "text",
          "fields": {}
        },
        "occurOnFullCommit": {
          "type": "text",
          "fields": {}
        },
        "occurOnGet": {
          "type": "text",
          "fields": {}
        },
        "occurOnLifecycle": {
          "type": "text",
          "fields": {}
        },
        "initialValue": {
          "type": "long"
        },
        "movedValue": {
          "type": "long"
        },
        "IRPAamount": {
          "type": "long"
        },
        "valueHistory": {
          "type": "nested",
          "properties": {
            "value": {
              "type": "long"
            },
            "totalReservedAmount": {
              "type": "long"
            },
            "dateFrom": {
              "type": "date",
              "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
              "fields": {}
            },
            "dateTo": {
              "type": "date",
              "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
              "fields": {}
            },
            "realModifyTime": {
              "type": "date",
              "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
              "fields": {}
            }
          }
        },
        "extAttrs": {
          "type": "nested",
          "properties": {
            "name": {
              "type": "text",
              "fields": {}
            },
            "value": {
              "type": "text",
              "fields": {}
            },
            "dateFrom": {
              "type": "date",
              "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
              "fields": {}
            },
            "dateTo": {
              "type": "date",
              "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
              "fields": {}
            }
          }
        },
        "autoRefills": {
          "type": "nested",
          "properties": {
            "dateFrom": {
              "type": "date",
              "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
              "fields": {}
            },
            "value": {
              "type": "long"
            }
          }
        },
        "reservationSessions": {
          "type": "long"
        },
        "recalcFactors": {
          "type": "nested",
          "properties": {
            "extCode": {
              "type": "text",
              "fields": {}
            },
            "expirationDate": {
              "type": "date",
              "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'||epoch_second",
              "fields": {}
            },
            "applicationType": {
              "type": "text",
              "fields": {}
            },
            "value": {
              "type": "nested",
              "properties": {
                "integer": {
                  "type": "long"
                },
                "scale": {
                  "type": "long"
                }
              }
            },
            "type": {
              "type": "text",
              "fields": {}
            },
            "ratio": {
              "type": "long"
            }
          }
        },
        "recalcPeriod": {
          "type": "nested",
          "properties": {
            "type": {
              "type": "text",
              "fields": {}
            },
            "regularPeriod": {
              "type": "long"
            },
            "dayOfPeriods": {
              "type": "nested",
              "properties": {
                "day": {
                  "type": "long"
                },
                "month": {
                  "type": "long"
                }
              }
            },
            "periodInitialValue": {
              "type": "nested",
              "properties": {
                "integer": {
                  "type": "long"
                },
                "scale": {
                  "type": "long"
                }
              }
            }
          }
        },
        "updateDirectionFlags": {
          "type": "long"
        },
        "updateDirectionFlagsHex": {
          "type": "text",
          "fields": {}
        }
      }
    }
  }
}

We see that hot threads:

::: {node-amdoc-newbs01}{39cU6Ym_Sd6Mz0d44xiv3w}{qqnRymfwRB6-Tm4261_5Tw}{node-amdoc-newbs01}{10.84.44.228}{10.84.44.228:9300}{cdfhilmrstw}{8.14.3}{7000099-8505000}{ml.allocated_processors=96, ml.allocated_processors_double=96.0, ml.max_jvm_size=33285996544, ml.config_version=12.0.0, xpack.installed=true, transform.config_version=10.0.0, ml.machine_memory=1080861347840}
   Hot threads at 2025-01-25T20:39:31.051Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {node-amdoc-newbs02}{1yCDZJehT8OSG3VqnmVZmw}{i7sLaGTKRVuIp2M-Ta1r5w}{node-amdoc-newbs02}{10.84.44.229}{10.84.44.229:9300}{cdfhilmrstw}{8.14.3}{7000099-8505000}{ml.allocated_processors=96, ml.allocated_processors_double=96.0, ml.max_jvm_size=33285996544, ml.config_version=12.0.0, transform.config_version=10.0.0, xpack.installed=true, ml.machine_memory=1080861347840}
   Hot threads at 2025-01-25T20:39:31.052Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:

::: {node-amdoc-newbs03}{jpSJZVuiSVeZfRksUvGOEQ}{EAdyFCgFTIWkHPBLeIhfYw}{node-amdoc-newbs03}{10.84.44.230}{10.84.44.230:9300}{cdfhilmrstw}{8.14.3}{7000099-8505000}{ml.allocated_processors=96, ml.allocated_processors_double=96.0, ml.max_jvm_size=33285996544, ml.config_version=12.0.0, xpack.installed=true, transform.config_version=10.0.0, ml.machine_memory=1080861347840}
   Hot threads at 2025-01-25T20:39:31.052Z, interval=500ms, busiestThreads=3, ignoreIdleThreads=true:
   
   100.0% [cpu=99.8%, other=0.2%] (500ms out of 500ms) cpu usage by thread 'elasticsearch[node-amdoc-newbs03][write][T#77]'
     4/10 snapshots sharing following 29 elements
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.parseObjectOrNested(DocumentParser.java:278)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.parseObjectOrField(DocumentParser.java:387)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.doParseObject(DocumentParser.java:462)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.parseObject(DocumentParser.java:450)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.parseNonDynamicArray(DocumentParser.java:573)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.parseArray(DocumentParser.java:532)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.innerParseObject(DocumentParser.java:320)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.parseObjectOrNested(DocumentParser.java:278)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.internalParseDocument(DocumentParser.java:129)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentParser.parseDocument(DocumentParser.java:86)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.mapper.DocumentMapper.parse(DocumentMapper.java:92)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.prepareIndex(IndexShard.java:1038)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.applyIndexOperation(IndexShard.java:979)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.applyIndexOperationOnPrimary(IndexShard.java:923)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.executeBulkItemRequest(TransportShardBulkAction.java:374)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction$2.doRun(TransportShardBulkAction.java:230)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.performOnPrimary(TransportShardBulkAction.java:300)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:151)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:79)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.support.replication.TransportWriteAction$1.doRun(TransportWriteAction.java:217)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:33)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:984)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       java.base@22.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
       java.base@22.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
       java.base@22.0.1/java.lang.Thread.runWith(Thread.java:1583)
       java.base@22.0.1/java.lang.Thread.run(Thread.java:1570)
     2/10 snapshots sharing following 28 elements
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexingChain$PerField.invert(IndexingChain.java:1180)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexingChain.processField(IndexingChain.java:731)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexingChain.processDocument(IndexingChain.java:609)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:263)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:425)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1558)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter.softUpdateDocuments(IndexWriter.java:1603)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.engine.InternalEngine.updateDocs(InternalEngine.java:1593)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.engine.InternalEngine.indexIntoLucene(InternalEngine.java:1406)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:1213)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:1080)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.applyIndexOperation(IndexShard.java:1005)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.applyIndexOperationOnPrimary(IndexShard.java:923)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.executeBulkItemRequest(TransportShardBulkAction.java:374)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction$2.doRun(TransportShardBulkAction.java:230)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.performOnPrimary(TransportShardBulkAction.java:300)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:151)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:79)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.support.replication.TransportWriteAction$1.doRun(TransportWriteAction.java:217)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:33)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:984)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       java.base@22.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
       java.base@22.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
       java.base@22.0.1/java.lang.Thread.runWith(Thread.java:1583)
       java.base@22.0.1/java.lang.Thread.run(Thread.java:1570)
     3/10 snapshots sharing following 25 elements
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.DocumentsWriterPerThread.updateDocuments(DocumentsWriterPerThread.java:263)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.DocumentsWriter.updateDocuments(DocumentsWriter.java:425)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter.updateDocuments(IndexWriter.java:1558)
       app/org.apache.lucene.core@9.10.0/org.apache.lucene.index.IndexWriter.softUpdateDocuments(IndexWriter.java:1603)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.engine.InternalEngine.updateDocs(InternalEngine.java:1593)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.engine.InternalEngine.indexIntoLucene(InternalEngine.java:1406)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:1213)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:1080)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.applyIndexOperation(IndexShard.java:1005)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.applyIndexOperationOnPrimary(IndexShard.java:923)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.executeBulkItemRequest(TransportShardBulkAction.java:374)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction$2.doRun(TransportShardBulkAction.java:230)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.performOnPrimary(TransportShardBulkAction.java:300)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:151)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:79)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.support.replication.TransportWriteAction$1.doRun(TransportWriteAction.java:217)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:33)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:984)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       java.base@22.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
       java.base@22.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
       java.base@22.0.1/java.lang.Thread.runWith(Thread.java:1583)
       java.base@22.0.1/java.lang.Thread.run(Thread.java:1570)
     unique snapshot
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.translog.BufferedChecksumStreamOutput.writeBytes(BufferedChecksumStreamOutput.java:43)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.io.stream.StreamOutput.writeInt(StreamOutput.java:190)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.translog.Translog.writeOperationNoSize(Translog.java:1582)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.translog.Translog.writeOperationWithSize(Translog.java:1588)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.translog.Translog.add(Translog.java:576)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.engine.InternalEngine.index(InternalEngine.java:1227)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.index(IndexShard.java:1080)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.applyIndexOperation(IndexShard.java:1005)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.index.shard.IndexShard.applyIndexOperationOnPrimary(IndexShard.java:923)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.executeBulkItemRequest(TransportShardBulkAction.java:374)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction$2.doRun(TransportShardBulkAction.java:230)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.performOnPrimary(TransportShardBulkAction.java:300)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:151)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.bulk.TransportShardBulkAction.dispatchedShardOperationOnPrimary(TransportShardBulkAction.java:79)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.action.support.replication.TransportWriteAction$1.doRun(TransportWriteAction.java:217)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.TimedRunnable.doRun(TimedRunnable.java:33)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.doRun(ThreadContext.java:984)
       app/org.elasticsearch.server@8.14.3/org.elasticsearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:26)
       java.base@22.0.1/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
       java.base@22.0.1/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
       java.base@22.0.1/java.lang.Thread.runWith(Thread.java:1583)
       java.base@22.0.1/java.lang.Thread.run(Thread.java:1570)

Hardware: Montage Jintide(R) C6248R, 96 cores, 1000GB RAM, 2TB SSD disk

What's happening: Bulk execution up to 10 seconds in worst case, 3-4 seconds at best. refresh_interval set as -1 and did nothing for increasing performance.

Please, can someone help with this problem?

Random idea - I think we had a thread recently, when you generate the _id (rather than letting ES do it) and your index gets bigger and bigger, then indexing gets slower and slower over time. Rolllver the index and it’ll be fast again.

How many docs in this index?

Thank you for reply, 5+ millions documents per index, but it's very slow even index is empty when we starting bulks

Actually, we cannot provide _id - we don't know if particular document already exists in the index, so we make 'index' not 'create' in the bulk to overwrite existed document if it's already existed in Elasticsearch, we use this API declaration from Elastisearch documentation:

The index and create actions expect a source on the next line, and have the same semantics as the op_type parameter in the standard index API: create fails if a document with the same ID already exists in the target, index adds or replaces a document as necessary.

What is the average size (in kB) of a document you are indexing?

Are all the documents within a single bulk request going to a single index? If so, how many primary and replica shards does this have? If not true and you are targeting multiple indices, how many primary and replica shards do these indices contain?

I see that you are using a fair amount of nested fields in your mappings. This will add overhead at indexing time as each nested subdocument will be indexed as a separate document behind the scenes. How many nested documents does a document contain on average?

As Kevin mentioned you are specifying your own document id and this will typically lead to indexing slowing down as the index and shards grow in size as each indexing operation must be treated as a potential update requiring a seach of the shard before indexing. Is the reason you specify your own document ids that you are you performing updates on documents in the index?

How many nodes do you have in the cluster? Is the storage a local SSD or some centralised SSD based storage accessed over the network?

Average size of the document is ~3KB Each type of document is indexed to it's own index (document - document_index, type - type_index, etc). We have:

      "number_of_shards": "1",
      "number_of_replicas": "1",

also tried to set replica to 0 on mass bulk operations - nothing changed. We have ~10 nested (as declared in the index mapping 'nested' objects) per document. As for own ID - we use own ID's for further searching (as a primary scenario) so we cannot use Elasticsearch-side generated ID's. In our scenario, we can receive from stream documents that already existed in the Elasticseach and in this case, we need to rewrite (use 'index' in the bulk) existed document. As for nodes: we setup 3 nodes, SSD is local, not a remote

Actually, we cannot provide _id

So, it’s now maybe a side issue, but you do provide the _id in the example above, for reasons you outlined. This means ES needs check if that _id is used already, if so mark that doc as deleted, and index the new one.

Was it always very slow, or used to work better but recently/now is very slow?

Also, any enrichment going on?

What’s sending the data to ES, what sort of client?

It's always slow, sometimes (rarely) it's speedup up to 9000 RPS (I mean 9000 documents per second) but most time - 2000-3000 RPS

How many different types of documents can a single bulk request consist of? One of the main benefits of bulk indexing is that you get large groups of documents going to a single shard as a group, which reduces overhead and disk I/O. If you write to a very large number of shards in a single bulk request the benefits of using bulk requests diminish.

In order to measure the impact of using nested mappings you could create a test index without any nested mappings and index the same data into this. If this is a lot faster you may have found the reason. If it is not faster you can eliminate that as a potential cause.

How to do this? We don't know when executing the bulk - is this documents already existed in the Elasticsearch or not, so, providing _id (I think) is more faster then checking via REST API document existance and than making 'create' or 'update' in the bulk or I'm wrong?

90% it's the same documents from one index, but the other 10% - mixed documents from different indexes. Thank you, I'll try to minimize nested mappings, but we also have performance impact even creating index without any mappings

So system is relatively new/fresh?

What does tools like top / vmstat / iostat tell you ? EG are your disks showing at high utilization ?

( Windows equivalents if using Windows? )

Is query load high?

Please share your elasticsearch.yml file. And JVM options too please.

Does this mean that you are relying on dynamic mappings? If so, are new fields constantly added or is the set of fields reasonably static? Every time you add a new field through dynamic mappings the cluster state must be updated and propagated, which also adds overhead and can slow down indexing.

htop with 'elastic' filter:

vmstat:

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0      0 796345984 3018132 188751104    0    0     0    19    0    0  1  1 98  0  0

JVM options is:

ES_JAVA_OPTS=-Xms4g -Xmx4g

We only tested without index mappings to find out if our mappings (marked as 'strict') have performance impact for bulk operations. So, we didn't find that removing all mappings give any speed, document fields and structure is static, and no new fields can occur, so, bulk performance is intouched and very slow - with mappings or without it

So please give it more heap, eg 32G. Not saying that’s your problem, but 4g heap is what I set on my laptop. You have plenty of RAM to utilize.

1 Like

And run iostat -x 10 for a few minutes around when the bulk index is happening, look for the device that’s getting the ES data written to it.

What it shows:

nodes stat (too large file, I put it to file share server) nodestat