2

First of all, I'm a total newbie to logstash. Despite the fact that I've managed to achieve some basic logging (trying to parse an apache log file without the build in COMBINEDAPACHELOG). However, I ran stuck on the following error that gets spammed at my terminal as soon as /var/log/auth.log receives an update (lines get appended). Logstash version 1.4.2. OS Ubuntu server 14.04

Failed to flush outgoing items {:outgoing_count=>1, :exception=>#, :backtrace=>["/opt/logstash-1.4.2/lib/logstash/outputs/elasticsearch/protocol.rb:225:in `build_request'", "/opt/logstash-1.4.2/lib/logstash/outputs/elasticsearch/protocol.rb:205:in `bulk'", "org/jruby/RubyArray.java:1613:in `each'", "/opt/logstash-1.4.2/lib/logstash/outputs/elasticsearch/protocol.rb:204:in `bulk'", "/opt/logstash-1.4.2/lib/logstash/outputs/elasticsearch.rb:315:in `flush'", "/opt/logstash-1.4.2/vendor/bundle/jruby/1.9/gems/stud-0.0.17/lib/stud/buffer.rb:219:in `buffer_flush'", "org/jruby/RubyHash.java:1339:in `each'", "/opt/logstash-1.4.2/vendor/bundle/jruby/1.9/gems/stud-0.0.17/lib/stud/buffer.rb:216:in `buffer_flush'", "/opt/logstash-1.4.2/vendor/bundle/jruby/1.9/gems/stud-0.0.17/lib/stud/buffer.rb:159:in `buffer_receive'", "/opt/logstash-1.4.2/lib/logstash/outputs/elasticsearch.rb:311:in `receive'", "/opt/logstash-1.4.2/lib/logstash/outputs/base.rb:86:in `handle'", "(eval):130:in `initialize'", "org/jruby/RubyProc.java:271:in `call'", "/opt/logstash-1.4.2/lib/logstash/pipeline.rb:266:in `output'", "/opt/logstash-1.4.2/lib/logstash/pipeline.rb:225:in `outputworker'", "/opt/logstash-1.4.2/lib/logstash/pipeline.rb:152:in `start_outputs'"], :level=>:warn}

Go figure what's happening here, the only thing I know is that it locks the logging process of any of the other log files.

Any ideas on what I'm doing wrong or causes this. Besides this, I have a few more questions, these are at the bottom.

additional info:

the config file

input {
    #apache
    file {
        type => "apache-access"
        path => "/var/log/apache2/access.log"
    }
    file {
        type => "apache-error"
        path => "/var/log/apache2/error.log"
    }

    #linux
    file {
        type => "authentication"
        path => "/var/log/auth.log"
    }

    #nginx
    file {
        type => "nginx-access"
        path => "/var/log/nginx/access.log"
    }
    file {
        type => "nginx-error"
        path => "/var/log/nginx/error.log"
    }
}
filter {
    if [type] == "apache-access" {
        grok {
            match => [ "message", "%{HTTP_ACC}" ]
        }
    }
    if [type] == "apache-error" {
        grok {
            match => [ "message", "%{APA_ERR}" ]
        }
    }
    if [type] == "authentication" {
        grok {
            match => [ "message", "%{AUTH_LOG}" ]
        }
    }
    if [type] == "nginx-access" {
        grok {
            match => [ "message", "%{HTTP_ACC}" ]
        }
    }
    if [type] == "nginx-error" {
        grok {
            match => [ "message", "%{NGINX_ERR}" ]
        }
    }
}
output {
    elasticsearch {
        embedded => true
    }
}

grok patterns are the defaults + the custom ones below. The groks where created using

https://grokdebug.herokuapp.com/

http://grokconstructor.appspot.com/do/match

error groks aren't perfect. grok parse errors on run so they aren't useful for visualization in kibana. See the demo logs underneath the patterns for examples to which they should be matched.

#APACHE ERROR
APA_ERR_TS \[%{DAY:dayOfTheWeek} %{MONTH:month} %{MONTHDAY:day} %{HOUR:hour}:%{MINUTE:min}:%{SECOND:sec}\.%{INT:microsec} %{YEAR:year}\]
APA_ERR_LOGCODE \[%{GREEDYDATA:source}:%{LOGLEVEL:loglevel}\]
APA_ERR_PID_TID \[pid %{INT:ProccessID}:tid %{INT:ThreadID}\]
APA_ERR %{APA_ERR_TS} %{APA_ERR_LOGCODE} %{APA_ERR_PID_TID} %{GREEDYDATA:logMessage}

#APACHE and NGINX ACCESS (they share the same structure, not log file, on my server)
HTTP_SOURCE %{IPORHOST:clientID} %{USER:ident} %{USER:auth}
HTTP_TS %{MONTHDAY:day}/%{MONTH:month}/%{YEAR:year}:%{HOUR:hour}:%{MINUTE:min}:%{SECOND:sec}
HTTP_REQ_INFO "%{WORD:action} %{NOTSPACE:request} HTTP/%{NUMBER:httpver}" %{NUMBER:httpCode} (?:%{NUMBER:fileSizeInBytes}|-)
HTTP_ACC %{HTTP_SOURCE} \[%{HTTP_TS} %{ISO8601_TIMEZONE:UTC}\] %{HTTP_REQ_INFO} "%{GREEDYDATA:referrer}" "%{GREEDYDATA:clientInfo}"

#authentication log
AUTH_LOG_TS %{MONTH:month} %{MONTHDAY:day} %{HOUR:hour}:%{MINUTE:min}:%{SECOND:sec}
AUTH_LOG_TYPE %{NOTSPACE:type}(\[%{INT:pid}\])?:
AUTH_LOG %{AUTH_LOG_TS} %{HOST:hostname} %{AUTH_LOG_TYPE} %{GREEDYDATA:logMessage}

#NGINX ERROR
NGINX_ERR_TS %{YEAR:year}/%{MONTHNUM:month}/%{MONTHDAY:day} %{HOUR:hour}:%{MINUTE:min}:%{SECOND:sec}
NGINX_ERR %{NGINX_ERR_TS} \[%{LOGLEVEL:loglevel}\] %{GREEDYDATA:logMessage}

Demo logs

# auth.log
Feb 17 08:25:55 server systemd-logind[731]: Watching system buttons on /dev/input/event1 (Sleep Button)
Feb 17 08:25:58 server sshd[894]: Server listening on 0.0.0.0 port 22.
Feb 17 08:25:58 server sshd[894]: Server listening on :: port 22.
Feb 17 08:26:35 server sshd[1328]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=192.168.200.251  user=dude
Feb 17 08:26:37 server sshd[1328]: Failed password for dude from 192.168.200.251 port 49194 ssh2
Feb 17 08:26:40 server sshd[1328]: Accepted password for dude from 192.168.200.251 port 49194 ssh2
Feb 17 08:26:40 server sshd[1328]: pam_unix(sshd:session): session opened for user dude by (uid=0)
Feb 17 08:26:40 server systemd-logind[731]: New session 1 of user dude.
Feb 17 09:17:01 server CRON[1626]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 17 09:17:01 server CRON[1626]: pam_unix(cron:session): session closed for user root
Feb 17 10:17:01 server CRON[1631]: pam_unix(cron:session): session opened for user root by (uid=0)
Feb 17 10:17:01 server CRON[1631]: pam_unix(cron:session): session closed for user root
Feb 17 10:33:33 server sudo:      dude : TTY=pts/0 ; PWD=/home/dude/ls-scripts ; USER=root ; COMMAND=/usr/bin/nano /opt/logstash-1.4.2/patterns/grok-patterns

# apache access
192.168.200.251 - - [16/Feb/2015:15:50:04 +0100] "GET /icons/ubuntu-logo.png HTTP/1.1" 304 179 "http://192.168.200.11/" "Mozilla/5.0 (Windows NT 6.3; WOW64; rv:35.0) Gecko/20100101 Firefox/35.0"
192.168.200.251 - - [16/Feb/2015:15:50:04 +0100] "GET / HTTP/1.1" 200 3593 "-" "Mozilla/5.0 (Windows NT 6.3; WOW64; rv:35.0) Gecko/20100101 Firefox/35.0"

# apache error
[Mon Feb 16 15:49:48.470722 2015] [mpm_event:notice] [pid 3601:tid 139755574097792] AH00491: caught SIGTERM, shutting down
[Mon Feb 16 15:49:49.597220 2015] [mpm_event:notice] [pid 5580:tid 140317488961408] AH00489: Apache/2.4.7 (Ubuntu) configured -- resuming normal operations
[Mon Feb 16 15:49:49.597302 2015] [core:notice] [pid 5580:tid 140317488961408] AH00094: Command line: '/usr/sbin/apache2'
[Mon Feb 16 16:20:19.948819 2015] [mpm_event:notice] [pid 5580:tid 140317488961408] AH00491: caught SIGTERM, shutting down
[Mon Feb 16 20:39:22.911352 2015] [mpm_event:notice] [pid 1059:tid 139877818292096] AH00489: Apache/2.4.7 (Ubuntu) configured -- resuming normal operations
[Mon Feb 16 20:39:22.923442 2015] [core:notice] [pid 1059:tid 139877818292096] AH00094: Command line: '/usr/sbin/apache2'
[Mon Feb 16 23:40:32.462678 2015] [mpm_event:notice] [pid 1059:tid 139877818292096] AH00491: caught SIGTERM, shutting down
[Tue Feb 17 08:26:03.727153 2015] [mpm_event:notice] [pid 1080:tid 140037385963392] AH00489: Apache/2.4.7 (Ubuntu) configured -- resuming normal operations
[Tue Feb 17 08:26:03.743771 2015] [core:notice] [pid 1080:tid 140037385963392] AH00094: Command line: '/usr/sbin/apache2'

# NGINX access
192.168.200.251 - - [16/Feb/2015:23:15:44 +0100] "GET /favicon.ico HTTP/1.1" 404 151 "-" "Mozilla/5.0 (Windows NT 6.3; WOW64; rv:35.0) Gecko/20100101 Firefox/35.0"
192.168.200.251 - - [16/Feb/2015:23:15:47 +0100] "GET / HTTP/1.1" 304 0 "-" "Mozilla/5.0 (Windows NT 6.3; WOW64; rv:35.0) Gecko/20100101 Firefox/35.0"

# NGINX error
2015/02/16 12:58:51 [emerg] 3752#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to [::]:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to [::]:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to [::]:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to [::]:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to 0.0.0.0:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: bind() to [::]:80 failed (98: Address already in use)
2015/02/16 12:58:51 [emerg] 3752#0: still could not bind()

If additional info is required, please tell.

The other questions at hand:

  • how to purge the history? => force a full re-parse of all the log files

  • suggestions on best practices and improvements of the groks

Thanks in advance

Improve this question

1 Answer 1

Reset to default
0

To re-import date, remove $HOME/.sincedb file, remove indexes in elastic search , and set start_position to beginning:

 input {
 #apache
 file {
     type => "apache-access"
     path => "/var/log/apache2/access.log"
     start_position => beginning
 }
Improve this answer
2
  • 2
    The main question at hand was the thing that caused the failed to flush outgoing items. This was due to the auth.log file. An error in my GROK syntax for this file caused this. However, the online validators said that it was ok and gave the expected results when testing. Hereby, a note if someone else has the same error: => Delete your original GROK for the file => rewrite it step by step to see where the problem occurs, THIS INCLUDES TESTING IT ON YOUR OWN LOGSTASH SERVER => fix the error when you hit it => Enjoy having this wonderful tool working for you.
    – jonny8bit
    Apr 5, 2015 at 20:44
  • You could answer your own question and it might be easier to follow in an answer than in a comment.
    – chicks
    Dec 31, 2017 at 1:59

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.