Logstash Conf File for Apache Log won't interpret "message"


(J. B.) #1

Hey there,

I am pretty new to Elasticsearch.
My ELK-setup on ubuntu is working so far and I receive the logfiles from the client server with filebeat.

Now I want to interpret the accesslog file.

It looks like this:

example.com:443 111.222.333.444 - - [21/Sep/2017:07:38:05 +0000] "GET / HTTP/1.1" 200 6382 "https://www.google.de/" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:55.0) Gecko/20100101 Firefox/55.0"

Then I created a conf-file:

/etc/logstash/conf.d/11-apache-filter.conf

The content of the conf file is:

filter {
    if [type] == "apache-other-vhost"{
        grok {
      match => {"message" => "%{URIHOST:domain} %{IP:clientip} %{USER:ident} %{USER:auth} \[%{HTTPDATE:apache_timestamp}\] \"%{WORD:method} /%{NOTSPACE:request_page} HTTP/%{NUMBER:http_version}\" %{NUMBER:server_response} %{NUMBER:kp} \"%{URIHOST:referrer}\" \"%{DATA:browser}\""}
        }
        geoip {
          source => "clientip"
          target => "geoip"
          database => "/etc/logstash/GeoLiteCity.dat"
          add_field => [ "[geoip][coordinates]", "%{[geoip][longitude]}" ]
          add_field => [ "[geoip][coordinates]", "%{[geoip][latitude]}"  ]
       }
       mutate {
         convert => [ "[geoip][coordinates]", "float"]
      }
    }
}

I followed some tutorial and created my own syntax.

apache-other-vhost is the type that shows up in Kibana.

Can you help me and tell me where my mistakes are?

Thank you very much!

Regards
dahansi


(Mark Walkom) #2

FYI we’ve renamed ELK to the Elastic Stack, otherwise Beats feels left out :wink:

Just use %{COMBINEDAPACHELOG}.

You don't need this, get rid of it because it only causes problems.


(J. B.) #3

Thank you for your reply :slight_smile:

I didn't want to make Beats feeled left out. I am very sorry :wink:

I changed the conf file:

filter {
    if [type] == "apache-other-vhost"{
      grok {
      match => {"message" => "%{COMBINEDAPACHELOG}"
    }
    geoip {
      source => "clientip"
      target => "geoip"
      database => "/etc/logstash/GeoLiteCity.dat"
    }
    mutate {
        convert => [ "[geoip][coordinates]", "float"]
    }
  }
}

But it is still not interpreted. Even if I just use:

filter {
    if [type] == "apache-other-vhost"{
        grok {
          match => {"message" => "%{COMBINEDAPACHELOG}"
        }
    }
}

The message filed will be one long string. Here is a Screenshot:

Am I missing something or doing something terribly wrong?

After changing the conf file I restart logstash using:

sudo service logstash restart

and I restart filebeat using:

sudo systemctl restart filebeat
sudo systemctl enable filebeat

Thanks again!
Best Regards
dahansi


(Mark Walkom) #4

To be clear your setup looks like this; Host with apache logs > filebeat > Logstash > Elasticsearch?


(J. B.) #5

Yes, I think so.

Here is what I set up:
Server 1 is where I run my websites. Here I installed Filebeat.
the filebeat.yml looks like this:

 ...
 - input_type: log
  paths:
    - /var/log/apache2/other_vhosts_access.log
  document_type: apache-other-vhost
 ...
 output.logstash:
 # The Logstash hosts
 hosts: ["ELASTICSTACKIP:5044"]
 bulk_max_size: 1024
 ssl.certificate_authorities: ["/etc/pki/tls/certs/logstash-forwarder.crt"]

On the Server 2 I installed Elasticsearch, Kibana and Logstash.
And here I created the /etc/logstash/conf.d/11-apache-filter.conf file:

filter {
    if [type] == "apache-other-vhost"{
        grok {
          match => {"message" => "%{COMBINEDAPACHELOG}"
        }
    }
}

Server 2 receives the Log-Data from Server 1, so the connection seems to work fine.
But the interpretation of the log files won't work.

Thank you very much for your help so far!


(Mark Walkom) #6

You have other Logstash config files there then? What happens if you remove them and just do the ones for this log type/source?


(J. B.) #7

Yes, I had more than one.

I deleted every other file in /etc/logstash/conf.d/
Now it is only this file in the folder: 11-apache-filter.conf

After that I restartet logstash, but still the logfile is not interpreted :-/


(Mark Walkom) #8

You need the input and output sections of the config files :slight_smile:

It might be easier to setup a simple pipeline with a stdin and stdout with your filter config in between and see if you still have the same issue?


(J. B.) #9

Yes, I had them but deleted them for testing :wink:

This is my input file /etc/logstash/conf.d/02-beats-input.conf:

input {
  beats {
    port => 5044
    ssl => true
    ssl_certificate => "/etc/pki/tls/certs/logstash-forwarder.crt"
    ssl_key => "/etc/pki/tls/private/logstash-forwarder.key"
  }
}

And this is my output file /etc/logstash/conf.d/30-elasticsearch-output.conf

output {
  elasticsearch {
    hosts => ["localhost:9200"]
    sniffing => true
    manage_template => false
    index => "%{[@metadata][beat]}-%{+YYYY.MM.dd}"
    document_type => "%{[@metadata][type]}"
  }
}

But still the message field is not interpreted.
I followed mainly these steps: http://robwillis.info/2017/04/elk-5-on-ubuntu-pt-2-installing-and-configuring-elasticsearch-logstash-kibana-nginx/


(Mark Walkom) #10

That link doesn't work for me.

However just use this config;

stdin{}
filter {
      grok {
          match => {"message" => "%{COMBINEDAPACHELOG}"
        }
    }
}
stdout{codec=>rubydebug}}

You can then do /path/to/logstash -e 'POST THE ABOVE IN' and then once it has started, literally copy and paste a log line into the shell/prompt and see what the output is.


(J. B.) #11

Hm, ok, just tried it, but I can't run lockstash from commandline properly.

I am using Ubuntu and executed this code:

sudo /usr/share/logstash/bin/logstash --path.settings=/etc/logstash -e 'stdin{} filter { grok { match => { "message" => "%{COMBINEDAPACHELOG}" } } } stdout{codec => rubydebug}'

Outputs:

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

I do not get any prompt. :-/


(Mark Walkom) #12

You won't, it waits for input which is why you need to paste the log event in.


(J. B.) #13

I think I found the problem but not the solution yet.

In my filebeat.conf I had also "outout.elasticsearch" which worked and pushd my data.
Since I commented this out, I don't receive any data on my server with es, kibana and logstash.

I looked into my logs in filebeat:

2017-09-22T11:51:49Z ERR Failed to publish events caused by: read tcp [SERVER1IP]:47044 [SERVER2IP]:5044: read: connection reset by peer
2017-09-22T11:51:49Z INFO Error publishing events (retrying): read tcp [SERVER1IP]:47046->[SERVER2IP]:5044: read: connection reset by peer
....
2017-09-22T11:52:52Z INFO Error publishing events (retrying): read tcp [SERVER1IP]:47056->[SERVER2IP]:5044: read: connection reset by peer
2017-09-22T11:53:19Z INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=1 libbeat.logstash.publish.read_errors=1 libbeat.logstash.publish.write_bytes=265 libbeat.logstash.published_but_not_acked_events=1024
2017-09-22T11:53:49Z INFO No non-zero metrics in the last 30s
2017-09-22T11:53:53Z ERR Failed to publish events caused by: read tcp [SERVER1IP]:47058->[SERVER2IP]:5044: read: connection reset by peer
2017-09-22T11:53:53Z INFO Error publishing events (retrying): read tcp [SERVER1IP]:47058->[SERVER2IP]:5044: read: connection reset by peer
2017-09-22T11:54:19Z INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=1 libbeat.logstash.publish.read_errors=1 libbeat.logstash.publish.write_bytes=262 libbeat.logstash.published_but_not_acked_events=1024
2017-09-22T11:54:23Z INFO Stopping filebeat
2017-09-22T11:54:23Z INFO Stopping Crawler
2017-09-22T11:54:23Z INFO Stopping 1 prospectors
2017-09-22T11:54:23Z INFO Prospector ticker stopped
2017-09-22T11:54:23Z INFO Stopping Prospector: 6662326667364749572
2017-09-22T11:54:23Z INFO Prospector outlet closed
2017-09-22T11:54:23Z INFO Prospector channel stopped because beat is stopping.
2017-09-22T11:54:23Z INFO Crawler stopped
2017-09-22T11:54:23Z INFO Stopping spooler
2017-09-22T11:54:23Z INFO Stopping Registrar
2017-09-22T11:54:23Z INFO Ending Registrar
2017-09-22T11:54:23Z INFO Total non-zero values:  filebeat.harvester.closed=2 filebeat.harvester.started=2 libbeat.logstash.call_count.PublishEvents=8 libbeat.logstash.publish.read_errors=8 libbeat.logstash.publish.write_bytes=2685 libbeat.logstash.published_but_not_acked_events=8192 libbeat.publisher.published_events=2046 registrar.writes=1
2017-09-22T11:54:23Z INFO Uptime: 2m34.162187202s
2017-09-22T11:54:23Z INFO filebeat stopped.

Server1: Client Server running filebeat
Server2: Server running ELK

If I try

telnet SERVER2IP 5044

I get

Connected to 46.252.27.160.

So the connection seems to work.

The Error Log in logstash:

[2017-09-22T12:15:27,083][INFO ][org.logstash.beats.BeatsHandler] Exception: not an SSL/TLS record: 325700000001324300000....

After the 00000 is a very long string (appr. 600 chars).


(J. B.) #14

So I deactived the SSL.

The log in fileabeat sill shows some error:

2017-09-22T11:51:49Z INFO Setup Beat: filebeat; Version: 5.6.1
2017-09-22T11:51:49Z INFO Max Retries set to: 3
2017-09-22T11:51:49Z INFO Activated logstash as output plugin.
2017-09-22T11:51:49Z INFO Publisher name: j303278.servers.jiffybox.net
2017-09-22T11:51:49Z INFO Flush Interval set to: 1s
2017-09-22T11:51:49Z INFO Max Bulk Size set to: 1024
2017-09-22T11:51:49Z INFO filebeat start running.
2017-09-22T11:51:49Z INFO Registry file set to: /var/lib/filebeat/registry
2017-09-22T11:51:49Z INFO Loading registrar data from /var/lib/filebeat/registry
2017-09-22T11:51:49Z INFO States Loaded from registrar: 0
2017-09-22T11:51:49Z INFO Loading Prospectors: 1
2017-09-22T11:51:49Z INFO Prospector with previous states loaded: 0
2017-09-22T11:51:49Z WARN DEPRECATED: document_type is deprecated. Use fields instead.
2017-09-22T11:51:49Z INFO Starting prospector of type: log; id: 6662326667364749572
2017-09-22T11:51:49Z INFO Loading and starting Prospectors completed. Enabled prospectors: 1
2017-09-22T11:51:49Z INFO Metrics logging every 30s
2017-09-22T11:51:49Z INFO Starting Registrar
2017-09-22T11:51:49Z INFO Start sending events to output
2017-09-22T11:51:49Z INFO Starting spooler: spool_size: 2048; idle_timeout: 5s
2017-09-22T11:51:49Z INFO Harvester started for file: /var/log/syslog
2017-09-22T11:51:49Z INFO Harvester started for file: /var/log/auth.log
2017-09-22T11:51:49Z ERR Failed to publish events caused by: read tcp [SERVER1]:47044->[SERVER2]:5044: read: connection reset by peer
2017-09-22T11:51:49Z INFO Error publishing events (retrying): read tcp [SERVER1]:47044->[SERVER2]:5044: read: connection reset by peer
2017-09-22T11:51:50Z ERR Failed to publish events caused by: read tcp [SERVER1]:47046->[SERVER2]:5044: read: connection reset by peer
2017-09-22T11:52:19Z INFO Non-zero metrics in the last 30s: filebeat.harvester.open_files=2 filebeat.harvester.running=2 filebeat.harvester.started=2 libbeat.logstash.call_count.PublishEvents=5 libbeat.logstash.publish.read_errors=5 libbeat.logstash.publish.write_bytes=1894 libbeat.logstash.published_but_not_acked_events=5120 libbeat.publisher.published_events=2046
2017-09-22T11:52:20Z ERR Failed to publish events caused by: read tcp [SERVER1]:47054->[SERVER2]:5044: read: connection reset by peer
2017-09-22T11:52:20Z INFO Error publishing events (retrying): read tcp [SERVER1]:47054->[SERVER2]:5044: read: connection reset by peer
2017-09-22T11:52:49Z INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=1 libbeat.logstash.publish.read_errors=1 libbeat.logstash.publish.write_bytes=264 libbeat.logstash.published_but_not_acked_events=1024
2017-09-22T11:52:52Z ERR Failed to publish events caused by: read tcp [SERVER1]:47056->[SERVER2]:5044: read: connection reset by peer
2017-09-22T11:52:52Z INFO Error publishing events (retrying): read tcp [SERVER1]:47056->[SERVER2]:5044: read: connection reset by peer
2017-09-22T11:53:19Z INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=1 libbeat.logstash.publish.read_errors=1 libbeat.logstash.publish.write_bytes=265 libbeat.logstash.published_but_not_acked_events=1024
2017-09-22T11:53:53Z INFO Error publishing events (retrying): read tcp [SERVER1]:47058->[SERVER2]:5044: read: connection reset by peer
2017-09-22T11:54:19Z INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=1 libbeat.logstash.publish.read_errors=1 libbeat.logstash.publish.write_bytes=262 libbeat.logstash.published_but_not_acked_events=1024
2017-09-22T11:54:23Z INFO Stopping filebeat
2017-09-22T11:54:23Z INFO Stopping Crawler
2017-09-22T11:54:23Z INFO Stopping 1 prospectors
2017-09-22T11:54:23Z INFO Prospector ticker stopped
2017-09-22T11:54:23Z INFO Stopping Prospector: 6662326667364749572
2017-09-22T11:54:23Z INFO Prospector outlet closed
2017-09-22T11:54:23Z INFO Prospector channel stopped because beat is stopping.
2017-09-22T11:54:23Z INFO Crawler stopped
2017-09-22T11:54:23Z INFO Stopping spooler
2017-09-22T11:54:23Z INFO Stopping Registrar
2017-09-22T11:54:23Z INFO Ending Registrar
2017-09-22T11:54:23Z INFO Total non-zero values:  filebeat.harvester.closed=2 filebeat.harvester.started=2 libbeat.logstash.call_count.PublishEvents=8 libbeat.logstash.publish.read_errors=8 libbeat.logstash.publish.write_bytes=2685 libbeat.logstash.published_but_not_acked_events=8192 libbeat.publisher.published_events=2046 registrar.writes=1
2017-09-22T11:54:23Z INFO Uptime: 2m34.162187202s
2017-09-22T11:54:23Z INFO filebeat stopped.

Logstash Log:

[2017-09-22T12:21:45,652][WARN ][logstash.runner          ] SIGTERM received. Shutting down the agent.
[2017-09-22T12:21:45,660][WARN ][logstash.agent           ] stopping pipeline {:id=>"main"}
[2017-09-22T12:22:07,037][INFO ][logstash.modules.scaffold] Initializing module {:module_name=>"netflow", :directory=>"/usr/share/logstash/modules/netflow/configuration"}
[2017-09-22T12:22:07,043][INFO ][logstash.modules.scaffold] Initializing module {:module_name=>"fb_apache", :directory=>"/usr/share/logstash/modules/fb_apache/configuration"}
[2017-09-22T12:22:08,161][INFO ][logstash.outputs.elasticsearch] Elasticsearch pool URLs updated {:changes=>{:removed=>[], :added=>[http://[SERVER2]:9200/]}}
[2017-09-22T12:22:08,162][INFO ][logstash.outputs.elasticsearch] Running health check to see if an Elasticsearch connection is working {:healthcheck_url=>http://[SERVER2]:9200/, :path=>"/"}
[2017-09-22T12:22:08,285][WARN ][logstash.outputs.elasticsearch] Restored connection to ES instance {:url=>"http://[SERVER2]:9200/"}
[2017-09-22T12:22:08,291][INFO ][logstash.outputs.elasticsearch] New Elasticsearch output {:class=>"LogStash::Outputs::ElasticSearch", :hosts=>["//[SERVER2]:9200"]}
[2017-09-22T12:22:08,394][INFO ][logstash.pipeline        ] Starting pipeline {"id"=>"main", "pipeline.workers"=>2, "pipeline.batch.size"=>125, "pipeline.batch.delay"=>5, "pipeline.max_inflight"=>250}
[2017-09-22T12:22:09,040][INFO ][logstash.inputs.beats    ] Beats inputs: Starting input listener {:address=>"0.0.0.0:5044"}
[2017-09-22T12:22:09,085][INFO ][logstash.pipeline        ] Pipeline main started
[2017-09-22T12:22:09,122][INFO ][org.logstash.beats.Server] Starting server on port: 5044
[2017-09-22T12:22:09,160][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}

Logstash seems to work fine, but Filebeat not :-/

Edit:
Found the problem, and now it is working :slight_smile:


(Mark Walkom) #15

What was the problem?

Also you may want to redact your IP given that host is open to the internet (which is a bad idea).


(system) #16

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