Problem with gathering logs from syslog with logstash

Elastic Stack Logstash
1

Hello there, I'm new here!

What I want to achieve

I want to set ELK stack on docker containers and configure it to listen and process logs coming from various applications in JSON form already, over tcp/udp/syslog (whatever will give me proper data).

What is my problem

Logstash can't collect logs over a specified port.

Details

I'll show you all my configuration in a moment but let me explain what I tried to do and what is going on.
For testing I wrote some simple log spammer in java and tried to send it over tcp or udp or syslog to logstash sitting on it's docker container. When I used SocketAppender in log4j everything worked and I managed to have all my logs in elasticsearch database and can visualize it in Kibana. But there is a problem. As far as I know SocketAppender doesn't support any conversionPattern and the output I've seen in kibana is messy. What does it mean is that one actual log, was splitted in a couple of messages, and grokparserfailure was seen. Neverthless, I tried to use syslogAppender to send logs already in JSON format straight to the logstash over say 3456 port. An example of such JSON:

{"source_host":"Wojter","method":"run","level":"ERROR","message":"This is error","mdc":{},"environment":"dev","@timestamp":"2017-01-10T15:41:42.365Z","file":"Logging.java","application":"spam","line_number":"21","thread_name":"pool-1-thread-1","@version":1,"logger_name":"Logging","class":"Logging"}

One important thing to notice is that using tcpdump I can see those logs being send all the time on this port, so the problem is probably input configuration of logstash.

Here is my configuration:

log4j appender:

log4j.appender.SYSLOG=org.apache.log4j.net.SyslogAppender
log4j.appender.SYSLOG.SyslogHost=localhost:3456
log4j.appender.SYSLOG.Facility=Local3
log4j.appender.SYSLOG.Header=true
log4j.appender.SYSLOG.layout=org.apache.log4j.EnhancedPatternLayout
log4j.appender.SYSLOG.layout.ConversionPattern = net.logstash.log4j.JSONEventLayoutV1

Logstash conf file:

input {
syslog {
port => 3456
}
}

output {
elasticsearch {
hosts => "elasticsearch:9200"
}
stdout {
codec => rubydebug
}
}

I just can't get any single log into logstash. When I used socket appender it actually worked but here it doesn't.

I've read that syslog plugin may have a hard time to process such json logs so I switched it to udp, still to no success. Remember, those are java logs, not syslog ones, and I want to send them somehow to logstash in this particular pattern I showed you.

Please help me with this issue, because I'm literally stuck and I feel it can be easily fixed or achieved.

Greetings, Wojtek :slight_smile:

2

Is the Logstash process actually listening on port 3456? Is port 3456 exposed on the host machine?

3

No it doesn't, thank you so much for such quick response, like in chat! That was one issue, however it still doesn't capture the logs. I'm running syslog plugin in input section in logstash configuration file right now. In logs it says that logstash is listening for syslog messages both by udp and tcp on 0.0.0.0:3456. Well to clarify a bit more, here is a logstash docker-compose part:

logstash:
build: logstash/
command: -f /etc/logstash/conf.d/
volumes:
- ./logstash/config:/etc/logstash/conf.d
expose:
- 5000
- 3456
ports:
- "5000:5000"
- "3456:3456"
networks:
- docker_elk
depends_on:
- elasticsearch

4

Are you sure that something is actually attempting to send something to port 3456? Try sending something by hand with e.g. netcat. Is there anything interesting in Logstash's own log?

5

I tried to listen on it with sudo tcpdump -i lo -A udp and port 3456 and for sure something beats on this port. I receive something like this:

20:11:31.843251 IP localhost.47715 > localhost.3456: udp/vt 70 316 / 12
E..be.@.@............c...N.a<155>Jan 10 20:11:31 wojciechComp net.logstash.log4j.JSONEventLayoutV1

There you go, something happens, it points to this logger and the frequency is also the same as logging (tried with simple sleep(2000) to see if it actually responds correctly and yeah, this has to be it).

When I start the docker containers the only logs I see are the bunch (like ~10) starting logstash logs, for example that it tries to install the plugin, listens on 0.0.0.0:3456 both via udp and tcp. No error logs are send and it ends on this log:

19:11:20.712 [Api Webserver] INFO logstash.agent - Successfully started Logstash API endpoint {:port=>9600}

As I specified stdout in output section in logstash.conf config file, I'd expect logstash log with every message it receives, and this happened indeed when something was captured by it.

What is strange that inside /var/log/logstash in logstash-plain.log I only see the logs from yesterday, that is I think uncommon.

Actually I should start with this:

logstash_1 | Sending Logstash's logs to /var/log/logstash which is now configured via log4j2.properties

logstash_1 | 19:11:20.050 [[main]<udp] INFO logstash.inputs.udp - Starting UDP listener {:address=>"0.0.0.0:3456"}
logstash_1 | 19:11:20.077 [[main]<udp] INFO logstash.inputs.udp - UDP listener started {:address=>"0.0.0.0:3456", :receive_buffer_bytes=>"106496", :queue_size=>"2000"}

logstash_1 | 19:11:20.343 [[main]-pipeline-manager] INFO logstash.outputs.elasticsearch - Elasticsearch pool URLs updated {:changes=>{:removed=>[], :added=>["http://elasticsearch:9200"]}}
logstash_1 | 19:11:20.344 [[main]-pipeline-manager] INFO logstash.outputs.elasticsearch - Running health check to see if an Elasticsearch connection is working {:url=>#<URI::HTTP:0x29ffd8a0 URL:http://elasticsearch:9200>, :healthcheck_path=>"/"}
logstash_1 | 19:11:20.442 [[main]-pipeline-manager] WARN logstash.outputs.elasticsearch - Restored connection to ES instance {:url=>#<URI::HTTP:0x29ffd8a0 URL:http://elasticsearch:9200>}
logstash_1 | 19:11:20.443 [[main]-pipeline-manager] INFO logstash.outputs.elasticsearch - Using mapping template from {:path=>nil}
logstash_1 | 19:11:20.623 [[main]-pipeline-manager] INFO logstash.outputs.elasticsearch - Attempting to install template {:manage_template=>{"template"=>"logstash-", "version"=>50001, "settings"=>{"index.refresh_interval"=>"5s"}, "mappings"=>{"default"=>{"_all"=>{"enabled"=>true, "norms"=>false}, "dynamic_templates"=>[{"message_field"=>{"path_match"=>"message", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false}}}, {"string_fields"=>{"match"=>"", "match_mapping_type"=>"string", "mapping"=>{"type"=>"text", "norms"=>false, "fields"=>{"keyword"=>{"type"=>"keyword"}}}}}], "properties"=>{"@timestamp"=>{"type"=>"date", "include_in_all"=>false}, "@version"=>{"type"=>"keyword", "include_in_all"=>false}, "geoip"=>{"dynamic"=>true, "properties"=>{"ip"=>{"type"=>"ip"}, "location"=>{"type"=>"geo_point"}, "latitude"=>{"type"=>"half_float"}, "longitude"=>{"type"=>"half_float"}}}}}}}}
logstash_1 | 19:11:20.630 [[main]-pipeline-manager] INFO logstash.outputs.elasticsearch - New Elasticsearch output {:class=>"LogStash::Outputs::ElasticSearch", :hosts=>["elasticsearch:9200"]}
logstash_1 | 19:11:20.632 [[main]-pipeline-manager] INFO logstash.pipeline - Starting pipeline {"id"=>"main", "pipeline.workers"=>4, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>5, "pipeline.max_inflight"=>500}
logstash_1 | 19:11:20.643 [[main]-pipeline-manager] INFO logstash.pipeline - Pipeline main started
logstash_1 | 19:11:20.712 [Api Webserver] INFO logstash.agent - Successfully started Logstash API endpoint {:port=>9600}

These are all logstash logs I receive after taking up the container. What is a bit strange for me is this template logstash tries to install and indeed, it installs it correctly, so I can use this exact pattern in kibana. I probably took this pattern over somewhere on internet. Maybe this leads to some problems?

Again, thank you so much for any kind of help!

PS, strangley enough I can't paste here two logstash logs. They are separated from the others by blank line. Those short logs are in reality (on my computer) the infos that udp started and listens on 0.0.0.0:3456, strange...

6

Are you sure you're publishing 3456/udp onto the host? Judging by your Docker Compose file it looks like only 3456/tcp is made available.

1 Like
7

You are so right Magnus, you are so right! That was the problem, I needed to specify that 3456/udp! Thank you so much, it works! Forgive me my lack of knowledge but I'm just a junior developer who was delegated to do all kind of devops stuff - all those vagrant, ansible, docker, nginx, elk stack etc etc things! I have only one more question, right now I get in kibana something like this:

@timestamp:January 10th 2017, 21:20:57.983 @version:1 host:172.20.0.1 message:<156>Jan 10 21:20:57 wojciechComp net.logstash.log4j.JSONEventLayoutV1 tags: _id:AVmKCnQO48USxfqsTP6C _type:logs _index:logstash-2017.01.10 _score: -

If I would like to get the actual JSON sitting under JSONEventLayoutV1, then is it enough to just put the json codec inside input? Gonna try it right now, but still I wanted to ask. UPDATE: I understand now, there is no logstash fault right now, I have to figure it out how to get the json value out of the udp's datagram, not just this:

20:11:31.843251 IP localhost.47715 > localhost.3456: udp/vt 70 316 / 12
E..be.@.@............c...N.a<155>Jan 10 20:11:31 wojciechComp net.logstash.log4j.JSONEventLayoutV1

If you have some experience and any ideas of how to do get normal JSON object, I would be really thankful. Tried also with syslog input type, but got pretty much the same. Now this is not gonna be a piece of cake

Thank you again for your help :slight_smile:

8

This is a problem with the output from your program. There is no JSON data to extract. The setting

log4j.appender.SYSLOG.layout.ConversionPattern = net.logstash.log4j.JSONEventLayoutV1

doesn't make any sense; you're literally asking log4j to log the string "net.logstash.log4j.JSONEventLayoutV1". According to the documentation you should do this:

log4j.rootCategory=WARN, RollingLog
log4j.appender.RollingLog=org.apache.log4j.DailyRollingFileAppender
log4j.appender.RollingLog.Threshold=TRACE
log4j.appender.RollingLog.File=api.log
log4j.appender.RollingLog.DatePattern=.yyyy-MM-dd
log4j.appender.RollingLog.layout=net.logstash.log4j.JSONEventLayoutV1
1 Like
9

Oh my goodness, you're right again. Now that was embarassing a little :slight_smile: Again, many thanks for this lesson. Still I have some problem, this is also a common one. I'll try to resolve it myself, but neverthless, I'm gonna show here. The problem is: "_jsonparsefailure". What I send over udp is:

22:19:32.774824 IP localhost.35220 > localhost.3456: udp/vt 270 316 / 12
E..*u@.@.................)<155>{"@timestamp":"2017-01-10T21:19:32.774Z","source_host":"wojciechComp","file":"Logging.java","method":"run","level":"ERROR","line_number":"21","thread_name":"pool-1-thread-5","@version":1,"logger_name":"Logging","message":"This is error","class":"Logging","mdc":{}}

Logstash output to this is:
logstash_1 | {
logstash_1 | "@timestamp" => 2017-01-10T21:16:52.688Z,
logstash_1 | "@version" => "1",
logstash_1 | "host" => "172.20.0.1",
logstash_1 | "message" => "<155>{"@timestamp":"2017-01-10T21:16:52.684Z","source_host":"wojciechComp","file":"Logging.java","method":"run","level":"ERROR","line_number":"21","thread_name":"pool-1-thread-3","@version":1,"logger_name":"Logging","message":"This is error","class":"Logging","mdc":{}}\n",
logstash_1 | "tags" => [
logstash_1 | [0] "_jsonparsefailure"
logstash_1 | ]
logstash_1 | }

What my simple logstash config right now is:
input {
udp {
port => 3456
}
}

filter{
json{
source => "message"
}
}

output {
elasticsearch {
hosts => "elasticsearch:9200"
}
stdout {
codec => rubydebug
}
}

What I want to achieve is to get the data out of message field. Any ideas?

UPDATE: I think the problem is with "<155>" chunk. Everything starts with it and it breaks the JSON. I'll try to fix it right now.

10

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