Logstash stops getting events once in 3 days

We are using Logstash 7.4.2. Once in 3-4 days, Logstash stops processing events and its not parsing new events till we restart the service. We see only below error in log

, :body=>"{"error":{"root_cause":[{"type":"action_request_validation_exception","reason":"Validation Failed: 1: id is missing;"}],"type":"action_request_validation_exception","reason":"Validation Failed: 1: id is missing;"},"status":400}"}

My output file content is below

output 
{
	if[eventID]=="002E000A"   
	{
  	 if[update_event]=="true"
           {
            elasticsearch 
            { 
                hosts => ["localhost:9200"]
               document_id => "%{authsid}"
               index =>  "dashboard_write"
               script => "ctx._source.loginCount= params.event.get('loginCount');
                       ctx._source.contractName= params.event.get('contractName');
                        ctx._source.userName= params.event.get('userName');
                         ctx._source.sessionID= params.event.get('sessionID');
                         ctx._source.eventID= params.event.get('eventID');"
              doc_as_upsert => "true"
               action => "update"  
              ilm_enabled => false			   
            }
                 

            }
          else
          {
  elasticsearch 
            {
  hosts => ["localhost:9200"]
               document_id => "%{sessionID}"
               index =>  "dashboard_write"
			   ilm_enabled => false
}

}
  	}

	#We need to still store risk events in ES,as there may be a case of risk events w/o IDP login. IDP login events will delete these records if it extracts the data
        else if[eventID]=="002E0047" or [eventID]=="002E0027"
        {
            elasticsearch
            {
                 hosts => ["localhost:9200"]
               document_id => "%{authsid}"
               index =>  "dashboard_write"
         # this may not append if two applications using different contracts,as that //will have diff sessionID. So in that case check in NAM, ideally you should //get three events in the order 002E0525,002E0514,002E0514 in case of two //application accessed in same session
                script => "ctx._source.riskLevel= params.event.get('riskLevel');
                       ctx._source.eventType= params.event.get('eventType');
                        ctx._source.failedCount= params.event.get('failedCount');"
              doc_as_upsert => "true"
               action => "update"    
ilm_enabled => false			   
            }
  
        }

        else  if[eventID]=="002E0525"
        {
           elasticsearch
            {
               hosts => ["localhost:9200"]
               document_id => "%{sessionID}"
              script => "ctx._source.username = params.event.get('userName');
                       ctx._source.contractName= params.event.get('contractName');
                        ctx._source.deviceID= params.event.get('deviceID');
                         ctx._source.browsername= params.event.get('browserName');
                         ctx._source.devicename= params.event.get('deviceName');"
						 
               doc_as_upsert => "true"

               action => "update"


               index =>  "dashboard_write"
			   ilm_enabled => false
               
          
            }
  
           
        }

        else if[eventID]=="002E000C"
        {
            elasticsearch
            {
               hosts => ["localhost:9200"]
               index =>  "dashboard_write"
               ilm_enabled => false
            }
       
          
        }
    else if[eventID]=="002E001F"
        {
            elasticsearch
            {
               hosts => ["localhost:9200"]
               index =>  "dashboard_write"
               ilm_enabled => false
            }
    
        }
        
        else if[eventID]=="002E0514" or [eventID]=="002E0102" or [eventID]== "002E0029"
        {
		   if[sid]!="null"
		   {
            elasticsearch
            {
               hosts => ["localhost:9200"]
               document_id => "%{sid}"
               index =>  "dashboard_write"
         
                script => "if(ctx._source.appdata== null)
                         {
                           ctx._source.appdata = new ArrayList(); 
                        } 
                        ctx._source.appdata.add(params.event.get('appdata'))"
              doc_as_upsert => "true"

               action => "update"
			   ilm_enabled => false
            }
			}
			else
			{
			elasticsearch
            {
               hosts => ["localhost:9200"]
               index =>  "dashboard_write"
			   ilm_enabled => false
            }
			}
   
       
        }
        
        
        else if[eventID]=="002E0606"
        {
          if [usersCount] 
          {
            elasticsearch
            {
               hosts => ["localhost:9200"]
               index =>  "dashboard_write"
			   ilm_enabled => false
            }

          
          }
        } 
       
}

What could be reason for above error?

What is the actual exception? Is it BadResponseCodeError?

I found only this error in logs

:body=>"{"error":{"root_cause":[{"type":"action_request_validation_exception","reason":"Validation Failed: 1: id is missing;"}],"type":"action_request_validation_exception","reason":"Validation Failed: 1: id is missing;"},"status":400}"}

Can someone please update?

Please post the complete error message.

I found only this error as I mentioned in my previous comment. Its continously throwing above same error , but not processing new events. It seems evident that this error is the cause. I just wanted to know what is meaning of this error

It probably means that one of the items in a bulk request is missing the id field. However, you are not helping us to help you by refusing to show us the entire error message.

I wish I could share more error. Unfortunately I dont have much error log. I have below in logstash plain log in debug mode

[2021-05-05T18:16:49,820][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:16:54,382][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:17:14,393][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:17:18,594][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:17:19,395][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:17:19,395][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:17:24,398][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:17:24,398][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:17:29,401][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:17:29,401][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:17:34,404][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:17:46,200][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:17:49,412][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:17:49,412][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:17:51,008][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:17:53,821][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:17:54,415][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:17:54,415][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:19,427][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:19,428][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:22,597][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:18:24,430][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:24,431][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:29,433][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:29,434][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:34,436][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:34,436][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:39,439][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:39,439][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:44,441][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:44,441][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:49,444][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:49,444][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:50,202][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:18:54,447][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:54,447][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:18:55,009][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:18:57,823][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:18:59,450][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:18:59,450][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:04,453][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:04,453][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:09,456][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:09,456][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:14,458][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:14,459][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:19,462][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:19,462][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:24,464][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:24,464][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:26,599][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:19:29,466][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:29,466][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:34,469][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:34,469][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:39,471][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:39,471][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:44,474][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:44,474][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:49,477][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:49,477][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:54,205][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}
[2021-05-05T18:19:54,481][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ParNew"}
[2021-05-05T18:19:54,481][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=>"ConcurrentMarkSweep"}
[2021-05-05T18:19:59,011][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}

[2021-05-05T18:20:01,823][ERROR][logstash.outputs.elasticsearch][events] Encountered a retryable error. Will Retry with exponential backoff  {:code=>400, :url=>"http://localhost:9200/_bulk", :body=>"{\"error\":{\"root_cause\":[{\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"}],\"type\":\"action_request_validation_exception\",\"reason\":\"Validation Failed: 1: id is missing;\"},\"status\":400}"}

The "Encountered a retryable error. Will Retry ..." tells you that the code is handling a BadResponseCodeError exception.

An elasticsearch bulk request expects something like

POST _bulk
{ "index" : { "_index" : "test", "_id" : "1" } }
{ "field1" : "value1" }

I think this error is telling you it got

POST _bulk
{ "index" : { "_index" : "test", "_id" : "" } }
{ "field1" : "value1" }

Thanks for the clarification. let me try to dig further. One more question

Upon further analysis, Im able to reproduce

POST _bulk
{ "update" : {"_id" : "", "_index" : "dashboard_write"} }
{ "doc" : {"field2" : "value2"},"doc_as_upsert" : true}

This issue is happening only in case of Update/Delete with id field is empty or missing

"error": {
    "root_cause": [
      {
        "type": "action_request_validation_exception",
        "reason": "Validation Failed: 1: id is missing;"
      }
    ],
    "type": "action_request_validation_exception",
    "reason": "Validation Failed: 1: id is missing;"
  },
  "status": 400

After this error , logstash stops processing other events and retrying multiple times to parse failed events. Can we handle this error somehow and makes logstash works fine?

Now we are restarting logstash to fix this

logstash has an at-least-once delivery model, so certain problems can cause it to hang forever. There is more discussion on this here and here. Changing that would require code changes.

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