Log entry disappears between Logstash and Kibana

[Axl (XYZ)]

Hello,

Logstash is processing an event with:

• eventid set to cowrie.command.input
• message and input containing Unix commands

Mar 31 10:26:02 instance-42 logstash[22592]: {
Mar 31 10:26:02 instance-42 logstash[22592]:        "eventid" => "cowrie.command.input",
...
Mar 31 10:26:02 instance-42 logstash[22592]:        "message" => "CMD: cat /proc/mounts; /bin/busybox EOVZJ",
...
Mar 31 10:26:02 instance-42 logstash[22592]:        "input" => "cat /proc/mounts; /bin/busybox EOVZJ",
...
Mar 31 10:26:02 instance-42 logstash[22592]: }

However, when I search in Kibana during that timeframe,

• I don't see any event with cowrie.command.input
• input field is obviously overwritten with other information (log type) log

Actually, if I search for any time for a log with even cowrie.command.input, I don't find a single one.

Where are those events trashed? How can I debug this? I have no Kibana logs, and its journalctl is not showing anything particular.

Thanks,

FYI, I am using ELK 7.6.1, and Cowrie is a honeypot.

[Nathan_Reese]

Kibana is just a UI for Elasticsearch so I suspect the disconnect is between logstash and elasticsearch. Do you have access to your logstash logs? Are there any dropped messages? Maybe add some debug outputs to logstash to help debug the problem.

[Axl (XYZ)]

Yes, I have access to logstash logs, but at March 31 10:26, I have no logs.
The closest are 10:19:41

[2020-03-31T10:19:41,852][WARN ][logstash.outputs.elasticsearch][main] Could not index event to Elasticsearch. {:\
status=>400, :action=>["index", {:_id=>nil, :_index=>"cowrie-logstash", :routing=>nil, :_type=>"_doc"}, #<LogStas\
h::Event:0x4f753843>], :response=>{"index"=>{"_index"=>"cowrie-logstash-2020.03.20-000001", "_type"=>"_doc", "_id\
"=>"f48aMHEBYpA6orC0mSmC", "status"=>400, "error"=>{"type"=>"mapper_parsing_exception", "reason"=>"object mapping\
 for [input] tried to parse field [input] as object, but found a concrete value"}}}}

After that log, I jump straight to 11:00.

[2020-03-31T11:00:34,038][WARN ][logstash.outputs.elasticsearch][main] Could not index event to Elasticsearch. {:\
status=>400, :action=>["index", {:_id=>nil, :_index=>"cowrie-logstash", :routing=>nil, :_type=>"_doc"}, #<LogStas\
h::Event:0x49c9d63>], :response=>{"index"=>{"_index"=>"cowrie-logstash-2020.03.20-000001", "_type"=>"_doc", "_id"\
=>"OI9AMHEBYpA6orC0BCpl", "status"=>400, "error"=>{"type"=>"mapper_parsing_exception", "reason"=>"object mapping \
for [input] tried to parse field [input] as object, but found a concrete value"}}}}

As this is not the right time, I am not sure it is related, is it?

As for logs via journalctl, I dumped them in my initial post, but here are if it helps to compare:

Mar 31 10:26:02 instance-42 logstash[22592]: {
Mar 31 10:26:02 instance-42 logstash[22592]:        "eventid" => "cowrie.command.input",
...
Mar 31 10:26:02 instance-42 logstash[22592]:        "message" => "CMD: cat /proc/mounts; /bin/busybox EOVZJ",
...
Mar 31 10:26:02 instance-42 logstash[22592]:        "input" => "cat /proc/mounts; /bin/busybox EOVZJ",
...
Mar 31 10:26:02 instance-42 logstash[22592]: }

[Ian_Boje]

Do you have the dead letter queue option enabled in Logstash? Are you able to see your missing messages in the dead letter queue?

[Axl (XYZ)]

No, it's not enabled:

logstash.yml:# dead_letter_queue.enable: false

You think I should try and enable it to see what happens to those kind of missing logs?

[Axl (XYZ)]

In ElasticSearch, I have this log which complains about input field. Do you think there is any relation?

[2020-04-03T09:53:37,718][DEBUG][o.e.a.b.TransportShardBulkAction] [instance-42] [honeypot-logstash-2020.04.03-000001][0] failed to execute bulk item (index) index {[honeypot-logstash][_doc][mo91P3EBYpA6orC0z2C2], source[_na_]}
org.elasticsearch.index.mapper.MapperParsingException: object mapping for [input] tried to parse field [input] as object, but found a concrete value

[Axl (XYZ)]

I solved this. It was a Logstash config issue.

In the logs of ElasticSearch (see below) I noticed the exception was occurring on field input, which was precisely one of the fields I was expecting to see in my "disappearing" logs.

[2020-04-03T09:53:37,718][DEBUG][o.e.a.b.TransportShardBulkAction] [instance-42] [honeypot-logstash-2020.04.03-000001][0] failed to execute bulk item (index) index {[honeypot-logstash][_doc][mo91P3EBYpA6orC0z2C2], source[_na_]}
org.elasticsearch.index.mapper.MapperParsingException: object mapping for [input] tried to parse field [input] as object, but found a concrete value

Then, in Logstash, I noticed this type of log, with the same error message:

Mar 31 05:44:14 instance-42 logstash[22592]: [2020-03-31T03:44:14,883][WARN ][logstash.outputs.elasticsearch][main] Could not index event to Elasticsearch. {:status=>400, :action=>["index", {:_id=>nil, :_index=>"cowrie-logstash", :routing=>nil, :_type=>"_doc"}, #<LogStash::Event:0x2082e9af>], :response=>{"index"=>{"_index"=>"cowrie-logstash-2020.03.20-000001", "_type"=>"_doc", "_id"=>"Go-wLnEBYpA6orC0jiYT", "status"=>400, "error"=>{"type"=>"mapper_parsing_exception", "reason"=>"object mapping for [input] tried to parse field [input] as object, but found a concrete value"}}}}

So, I had a look at my entries and found out that in some cases, I had input field with sublayers

"input" => {
        "type" => "log"
    },

and in other cases, directly a string.

"command" => "echo \"this is my test\""

I searched for the problem (in particular this thread), and found out that this is a situation where Logstash is lost at types: in the first case, it expect an object, and it does not like in the second case to find a string.

Solution: I need to either always to have an object, or always a string, but not mix.

The fix will depend on your log structure, in my case (cowrie), I was doing

json {
 source => "message"
}

which would read the JSON input from field message and create log structure from that. In my case, that was overwriting several fields such as input. The solution is to specify a target, so that fields from the JSON input don't overwrite other fields, and for instance, they'd go in honeypot.input, not input.

json {
 source => "message"
 target => "honeypot"
}