Thanks @leandrojmp below is my config file, plz have a look,
input {
syslog {
port => 1101
tags => ["syslog1101"]
}
}
filter {
if "syslog1101" in [tags] {
grok {
#match => { "message" => "%{SYSLOGTIMESTAMP:syslog_timestamp} %{SYSLOGHOST:syslog_hostname} %{DATA:syslog_program}(?:\[%{POSINT:syslog_pid}\])?: %{GREEDYDATA:syslog_message}" }
match => { "message" => "%{SYSLOGTIMESTAMP:time} %{SYSLOGHOST:hostname} %{DATA:program}\[%{POSINT:pid}\]: %{GREEDYDATA:message1}" }
add_field => ["received_at", "%{@timestamp}"]
### add_field => ["received_from", "%{host}"]
}
date {
match => ["syslog_timestamp", "MMM d HH:mm:ss", "MMM dd HH:mm:ss"]
}
}
}
output {
elasticsearch {
hosts => ["localhost:9200"]
index => "syslog1101"
user => "elastic"
password => "somePassword"
}
#stdout { }
}
The commented grok pattern was from elastic.co official document(that too gave grokparsefailures), changed it to new one.
Update- I uncommented stdout in configfile, shutdown logstash and ran logstash with parameters now - /usr/share/logstash/bin/logstash -f /etc/logstash/conf.d/syslog.conf
The logline that I found in auth.log is-
Sep 1 15:13:29 cd-ubuntu-jh sudo: pam_unix(sudo:session): session opened for user root by cyberuser(uid=0)
Below is the syslog messages on stdout {}
[INFO ] 2021-09-01 15:13:30.041 [Ruby-0-Thread-51: /usr/share/logstash/vendor/bundle/jruby/2.5.0/gems/logstash-input-syslog-3.5.0/lib/logstash/inputs/syslog.rb:172] syslog - new connection {:client=>"172.31.3.152:34636"}
{
"message" => "pam_unix(sudo:session): session opened for user root by cyberuser(uid=0)\n",
"priority" => 86,
"severity" => 6,
"host" => "172.31.3.152",
"logsource" => "cd-ubuntu-jh",
"facility_label" => "security/authorization",
"timestamp" => "Sep 1 15:13:29",
"tags" => [
[0] "syslog1101",
[1] "_grokparsefailure"
],
"facility" => 10,
"@timestamp" => 2021-09-01T09:43:29.000Z,
"program" => "sudo",
"severity_label" => "Informational",
"@version" => "1"
}
Also with the log.level debug and starting logstash I guess I got the problem with grok failures, the log had different logline reaching the ELK ( look at <85> coming with log before timestamp )
[2021-09-01T15:18:25,094][DEBUG][logstash.filters.grok ][main][e74d8a84ae5f02e65715fe43c3578b58b1d987b0067f594b878474fc12ede372] Running grok filter {:event=>{"message"=>"<85>Sep 1 15:18:23 cd-ubuntu-jh sudo: cyberuser : TTY=pts/0 ; PWD=/home/cyberuser ; USER=root ; COMMAND=/bin/bash\n", "@version"=>"1", "tags"=>["syslog1101"], "@timestamp"=>2021-09-01T09:48:25.075Z, "host"=>"172.31.3.152"}}
[2021-09-01T15:18:25,116][DEBUG][logstash.filters.grok ][main][e74d8a84ae5f02e65715fe43c3578b58b1d987b0067f594b878474fc12ede372] Event now: {:event=>{"message"=>"cyberuser : TTY=pts/0 ; PWD=/home/cyberuser ; USER=root ; COMMAND=/bin/bash\n", "@version"=>"1", "tags"=>["syslog1101"], "program"=>"sudo", "timestamp"=>"Sep 1 15:18:23", "logsource"=>"cd-ubuntu-jh", "host"=>"172.31.3.152", "@timestamp"=>2021-09-01T09:48:25.075Z, "priority"=>"85"}}
Then I went ahead and ran tcpdump and debug together on ELK
**tcpdump -nnAs0 port 1101**
15:56:24.313353 IP 172.31.3.152.34640 > 10.48.69.68.1101: Flags [P.], seq 1841660575:1841660795, ack 1621476397, win 502, options [nop,nop,TS val 139283976 ecr 429382461], length 220
E.....@.8._.....
0ED.P.Mm...`..-...........
.MN....=<85>Sep 1 15:56:24 cd-ubuntu-jh sudo: cyberuser : TTY=pts/1 ; PWD=/var/log ; USER=root ; COMMAND=/bin/bash
<86>Sep 1 15:56:24 cd-ubuntu-jh sudo: pam_unix(sudo:session): session opened for user root by cyberuser(uid=0)
You can see .MN....=<85> before the syslog timestamp, probably causing grok failures.
Log from logstash-plain.log with debug enabled-
[2021-09-01T15:56:24,316][DEBUG][logstash.filters.grok ][main][e74d8a84ae5f02e65715fe43c3578b58b1d987b0067f594b878474fc12ede372] Running grok filter {:event=>{"message"=>"<85>Sep 1 15:56:24 cd-ubuntu-jh sudo: cyberuser : TTY=pts/1 ; PWD=/var/log ; USER=root ; COMMAND=/bin/bash\n", "@version"=>"1", "tags"=>["syslog1101"], "@timestamp"=>2021-09-01T10:26:24.315Z, "host"=>"172.31.3.152"}}
[2021-09-01T15:56:24,317][DEBUG][logstash.filters.grok ][main][e74d8a84ae5f02e65715fe43c3578b58b1d987b0067f594b878474fc12ede372] Event now: {:event=>{"message"=>"cyberuser : TTY=pts/1 ; PWD=/var/log ; USER=root ; COMMAND=/bin/bash\n", "@version"=>"1", "tags"=>["syslog1101"], "program"=>"sudo", "timestamp"=>"Sep 1 15:56:24", "logsource"=>"cd-ubuntu-jh", "host"=>"172.31.3.152", "@timestamp"=>2021-09-01T10:26:24.315Z, "priority"=>"85"}}
However <85> not included in grokpattern was still captured as priority-
Sometimes there are logs starting right with timestamp-
[2021-09-01T16:14:54,918][DEBUG][logstash.filters.grok ][main][a3e05bf8207576dab9eff27a9b9c1a31d5bca62bd4d948cf322f3431e3e2b556] Running grok filter {:event=>{"message"=>"Started OpenBSD Secure Shell server.\n", "facility_label"=>"system", "priority"=>30, "@version"=>"1", "program"=>"systemd", "@timestamp"=>2021-09-01T10:44:54.000Z, "severity_label"=>"Informational", "timestamp"=>"Sep 1 16:14:54", "host"=>"172.31.3.152", "facility"=>3, "tags"=>["syslog1101"], "pid"=>"1", "logsource"=>"cd-ubuntu-jh", "severity"=>6}}
Now how to deal with such variations in incoming logs !