Invalid document_id not handled well with elasticsearch output

Due to an issue in my multiline codec, I had an event that did not have the expected format. When I parsed the document_id out of it, it was part of a JSON object. This results in logstash looping retrying the request and no indication of what the retryable error was in either the logstash or elasticsearch logs, making it really hard to track down.


Logstash logs these ERRORs

[2018-03-13T17:08:47,546][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:08:49,550][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:08:53,557][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:09:01,563][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:10:42,717][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:10:44,756][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:10:48,764][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:10:56,772][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:11:12,784][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}
[2018-03-13T17:11:44,794][ERROR][logstash.outputs.elasticsearch] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk"}

Whilst elasticsearch does not log any errors

[2018-03-13T17:08:40,187][INFO ][o.e.m.j.JvmGcMonitorService] [sd-0364-9b52] [gc][344193] overhead, spent [327ms] collecting in the last [1s]
[2018-03-13T17:10:45,338][INFO ][o.e.m.j.JvmGcMonitorService] [sd-0364-9b52] [gc][344318] overhead, spent [380ms] collecting in the last [1s]
[2018-03-13T17:12:01,411][INFO ][o.e.m.j.JvmGcMonitorService] [sd-0364-9b52] [gc][344394] overhead, spent [265ms] collecting in the last [1s]
[2018-03-13T17:12:13,417][INFO ][o.e.m.j.JvmGcMonitorService] [sd-0364-9b52] [gc][344406] overhead, spent [317ms] collecting in the last [1s]

This can be reproduced using

input { generator { message => '2018-02-23T13:20:29.020Z' count => 1 } }
output { stdout { codec => rubydebug } }
output {
  elasticsearch {
    hosts => "localhost"
    index => "logstash-test-%{+YYYY.MM.dd}"
    document_id => '        "XXXXXXXXXXXXXXXXXXXXXX": null,
            "XXXXXXXXXXXXXXXXXXXXXX": null,
            "XXXXXXXXXXXXXXXXXXXXXX": "3.50",
            "XXXXXXXXXXXXXXXXXXXXXX": "02/16/2018",
            "XXXXXXXXXXXXXXXXXXXXXX": 3.50,
            
    "XXXXXXXXXXXXXXXXXXXXXX": {
              "XXXXXXXXXXXXXXXXXXXXXX": null,
              "XXXXXXXXXXXXXXXXXXXXXX": "XXXXXXXXXXXXXXXXXXXXXX",
              "XXXXXXXXXXXXXXXXXXXXXX": null,
              "XXXXXXXXXXXXXXXXXXXXXX": "XXXXXXXXXXXXXXXXXXXXXX"
            },
            "XXXXXXXXXXXXXXXXXXXXXX": "",
            "XXXXXXXXXXXXXXXXXXXXXX": false,
    
    "XXXXXXXXXXXXXXXXXXXXXX": {
              "XXXXXXXXXXXXXXXXXXXXXX": "3.50",
              "XXXXXXXXXXXXXXXXXXXXXX": null,
              "XXXXXXXXXXXXXXXXXXXXXX": 3.50,
              "XXXXXXXXXXXXXXXXXXXXXX": "USD"
            },
            "XXXXXXXXXXXXXXXXXXXXXX": "XXXXXXXXXXXXXXXXXXXXXX",
    
    "XXXXXXXXXXXXXXXXXXXXXX": "02/15/2018",
            "XXXXXXXXXXXXXXXXXXXXXX": "XXXXXXXXXXXXXXXXXXXXXX"
          }
        ],
        "XXXXXXXXXXXXXXXXXXXXXX": 0
      },
      "XXXXXXXXXXXXXXXXXXXXXX": null,
      "XXXXXXXXXXXXXXXXXXXXXX": false,
    
    "XXXXXXXXXXXXXXXXXXXXXX": "USD",
      "XXXXXXXXXXXXXXXXXXXXXX": true,
      "XXXXXXXXXXXXXXXXXXXXXX": false,
      "XXXXXXXXXXXXXXXXXXXXXX": "-3.50",
      "XXXXXXXXXXXXXXXXXXXXXX": "02/22/2018",
      "XXXXXXXXXXXXXXXXXXXXXX": "01/22/2018"
    }
  }'
  }
}

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.