Logstash 1.5.3 does not read from file

Elastic Stack Logstash
1

I have logstash 1.5.3 installed. I want to read from an input log and write to stdout. Here are the details:

  1. sample.conf
    input {
    file {
    path => "/nfs/private/user/nabbaraj/app_logs/ohs/aaruvmtp09/test.log"
    start_position => beginning
    }
    }
    filter {
    grok {
    match => { message => "(%{DATA:x_forwarded_for}|-) - (%{WORD:email_prefix}@%{WORD:domain_prefix}.%{WORD:domain_suffix}|-) [%{HTTPDATE:date}] %{QS:request} %{NUMBER:statuscode} %{NUMBER:response_size} (%{QS:referrer}|-)(%{QS:agent}|-) %{NUMBER:time_taken_in_secs}/%{NUMBER:time_taken_in_microsecs} "(%{IPV4:true_client_ip}|-)"" }
    }
    }
    output {
    stdout { codec => rubydebug }

  2. Logstash command used:
    logstash/bin/logstash -f /home/nabbaraj/nfs_private/logstash/conf/sample.conf

  3. Contents of the log /nfs/private/user/nabbaraj/app_logs/ohs/aaruvmtp09/test.log:

      • [30/Jul/2015:05:00:00 -0700] "GET /" 302 265 "-""-" 0/157 "-"
        173.243.41.34, 96.17.163.157 - - [30/Jul/2015:05:00:09 -0700] "GET /osdc/faces/S
        earchSoftware HTTP/1.1" 302 778 "https://edelivery.oracle.com/""Mozilla/5.0 (com
        patible; MSIE 9.0; Windows NT 6.1; WOW64; Trident/5.0)" 0/439 "173.243.41.34"
      • [30/Jul/2015:05:00:10 -0700] "GET /" 302 265 "-""-" 0/117 "-"
  1. Here's the output:
    % /home/nabbaraj/nfs_private/logstash/bin/logstash -f /home/nabbaraj/nfs_private/logstash/conf/sample.conf
    Logstash startup completed
    Logstash shutdown completed

Nothing prints out.

2

What, Logstash shuts down? That should definitely not happen. Or did you Ctrl+C it? If not, please increase the logging level with --verbose (to start with) or --debug.

3

Here's what I got this time:
% /home/nabbaraj/nfs_private/logstash/bin/logstash -f /home/nabbaraj/nfs_private/logstash/conf/sample.conf --verbose
Registering file input {:path=>["/nfs/private/user/nabbaraj/app_logs/ohs/aaruvmtp09/test.log"], :level=>:info}
No sincedb_path set, generating one based on the file path {:sincedb_path=>"/home/nabbaraj/.sincedb_e8a664d5145735a3ad4b3f3e42bd5d65", :path=>["/nfs/private/user/nabbaraj/app_logs/ohs/aaruvmtp09/test.log"], :level=>:info}
Grok patterns path {:patterns_dir=>["/home/nabbaraj/nfs_private/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns", "/home/nabbaraj/nfs_private/logstash/patterns/"], :level=>:info}
Grok loading patterns from file {:path=>"/home/nabbaraj/nfs_private/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/firewalls", :level=>:info}
Grok loading patterns from file {:path=>"/home/nabbaraj/nfs_private/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/java", :level=>:info}
Grok loading patterns from file {:path=>"/home/nabbaraj/nfs_private/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/nagios", :level=>:info}
Grok loading patterns from file {:path=>"/home/nabbaraj/nfs_private/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/mcollective", :level=>:info}
Grok loading patterns from file {:path=>"/home/nabbaraj/nfs_private/logstash/vendor/bundle/jruby/1.9/gems/logstash-patterns-core-0.1.10/patterns/redis", :level=>:info}
...
...
...
Adding pattern {"RT_FLOW_EVENT"=>"(RT_FLOW_SESSION_CREATE|RT_FLOW_SESSION_CLOSE|RT_FLOW_SESSION_DENY)", :level=>:info}
Adding pattern {"RT_FLOW1"=>"%{RT_FLOW_EVENT:event}: %{GREEDYDATA:close-reason}: %{IP:src-ip}/%{DATA:src-port}->%{IP:dst-ip}/%{DATA:dst-port} %{DATA:service} %{IP:nat-src-ip}/%{DATA:nat-src-port}->%{IP:nat-dst-ip}/%{DATA:nat-dst-port} %{DATA:src-nat-rule-name} %{DATA:dst-nat-rule-name} %{INT:protocol-id} %{DATA:policy-name} %{DATA:from-zone} %{DATA:to-zone} %{INT:session-id} \d+\(%{DATA:sent}\) \d+\(%{DATA:received}\) %{INT:elapsed-time} .", :level=>:info}
Adding pattern {"RT_FLOW2"=>"%{RT_FLOW_EVENT:event}: session created %{IP:src-ip}/%{DATA:src-port}->%{IP:dst-ip}/%{DATA:dst-port} %{DATA:service} %{IP:nat-src-ip}/%{DATA:nat-src-port}->%{IP:nat-dst-ip}/%{DATA:nat-dst-port} %{DATA:src-nat-rule-name} %{DATA:dst-nat-rule-name} %{INT:protocol-id} %{DATA:policy-name} %{DATA:from-zone} %{DATA:to-zone} %{INT:session-id} .", :level=>:info}
Adding pattern {"RT_FLOW3"=>"%{RT_FLOW_EVENT:event}: session denied %{IP:src-ip}/%{DATA:src-port}->%{IP:dst-ip}/%{DATA:dst-port} %{DATA:service} %{INT:protocol-id}\(\d\) %{DATA:policy-name} %{DATA:from-zone} %{DATA:to-zone} .", :level=>:info}
Adding pattern {"RUBY_LOGLEVEL"=>"(?:DEBUG|FATAL|ERROR|WARN|INFO)", :level=>:info}
Adding pattern {"RUBY_LOGGER"=>"[DFEWI], \[%{TIMESTAMP_ISO8601:timestamp} #%{POSINT:pid}\] *%{RUBY_LOGLEVEL:loglevel} -- +%{DATA:progname}: %{GREEDYDATA:message}", :level=>:info}
Pipeline started {:level=>:info}
Logstash startup completed
Plugin is finished {:plugin=><LogStash::Outputs::Stdout codec=><LogStash::Codecs::RubyDebug metadata=>false>, workers=>1>, :level=>:info}
Pipeline shutdown complete. {:level=>:info}
Logstash shutdown completed

4

Very odd. And with --debug?

5

% /home/nabbaraj/nfs_private/logstash/bin/logstash -f /home/nabbaraj/nfs_private/logstash/conf/sample.conf --debug
Reading config file {:file=>"logstash/agent.rb", :level=>:debug, :line=>"309", :method=>"local_config"}
Compiled pipeline code:
@inputs = []
@filters = []
@outputs = []
@periodic_flushers = []
@shutdown_flushers = []

      @input_file_1 = plugin("input", "file", LogStash::Util.hash_merge_many({ "path" => ("/nfs/private/user/nabbaraj/app_logs/ohs/aaruvmtp09/test.log") }, { "start_position" => ("beginning") }))

      @inputs << @input_file_1

...
...
...
replacement_pattern => (?IPV4:true_client_ip(?<![0-9])(?:(?:25[0-5]|2[0-4][0-9]|[0-1]?[0-9]{1,2})...)(?![0-9])) {:level=>:debug, :file=>"grok-pure.rb", :line=>"121", :method=>"compile"}
Grok compiled OK {:pattern=>"(%{DATA:x_forwarded_for}|-) - (%{WORD:email_prefix}@%{WORD:domain_prefix}\.%{WORD:domain_suffix}|-) \[%{HTTPDATE:date}\] %{QS:request} %{NUMBER:statuscode} %{NUMBER:response_size} (%{QS:referrer}|-)(%{QS:agent}|-) %{NUMBER:time_taken_in_secs}/%{NUMBER:time_taken_in_microsecs} \"(%{IPV4:true_client_ip}|-)\"", :expanded_pattern=>"((?<DATA:x_forwarded_for>.*?)|-) - ((?WORD:email_prefix\b\w+\b)@(?WORD:domain_prefix\b\w+\b)\.(?WORD:domain_suffix\b\w+\b)|-) \[(?HTTPDATE:date(?:(?:(?:0[1-9])|(?:[12][0-9])|(?:3[01])|[1-9]))/(?:\b(?:Jan(?:uary)?|Feb(?:ruary)?|Mar(?:ch)?|Apr(?:il)?|May|Jun(?:e)?|Jul(?:y)?|Aug(?:ust)?|Sep(?:tember)?|Oct(?:ober)?|Nov(?:ember)?|Dec(?:ember)?)\b)/(?:(?>\d\d){1,2}):(?:(?!<[0-9])(?:(?:2[0123]|[01]?[0-9])):(?:(?:[0-5][0-9]))(?::(?:(?:(?:[0-5]?[0-9]|60)(?:[:.,][0-9]+)?)))(?![0-9])) (?:(?:[+-]?(?:[0-9]+))))\] (?QS:request(?:(?>(?<!\\)(?>"(?>\\.|[^\\"]+)+"|""|(?>'(?>\\.|[^\\']+)+')|''|(?>(?>\\\\.|[^\\\\]+)+)|``)))) (?<NUMBER:statuscode>(?:(?:(?<![0-9.+-])(?>[+-]?(?:(?:[0-9]+(?:\\.[0-9]+)?)|(?:\\.[0-9]+)))))) (?<NUMBER:response_size>(?:(?:(?<![0-9.+-])(?>[+-]?(?:(?:[0-9]+(?:\\.[0-9]+)?)|(?:\\.[0-9]+)))))) ((?<QS:referrer>(?:(?>(?<!\\\\)(?>\"(?>\\\\.|[^\\\\\"]+)+\"|\"\"|(?>'(?>\\\\.|[^\\\\']+)+')|''|(?>(?>\\.|[^\\]+)+)|))))|-)((?<QS:agent>(?:(?>(?<!\\\\)(?>\"(?>\\\\.|[^\\\\\"]+)+\"|\"\"|(?>'(?>\\\\.|[^\\\\']+)+')|''|(?>`(?>\\\\.|[^\\\\`]+)+`)|))))|-) (?NUMBER:time_taken_in_secs(?:(?:(?<![0-9.+-])(?>[+-]?(?:(?:[0-9]+(?:\.[0-9]+)?)|(?:\.[0-9]+))))))/(?NUMBER:time_taken_in_microsecs(?:(?:(?<![0-9.+-])(?>[+-]?(?:(?:[0-9]+(?:\.[0-9]+)?)|(?:\.[0-9]+)))))) \"((?IPV4:true_client_ip(?<![0-9])(?:(?:25[0-5]|2[0-4][0-9]|[0-1]?[0-9]{1,2})...)(?![0-9]))|-)\"", :level=>:debug, :file=>"grok-pure.rb", :line=>"128", :method=>"compile"}
Pipeline started {:level=>:info, :file=>"logstash/pipeline.rb", :line=>"87", :method=>"run"}
Logstash startup completed
Plugin is finished {:plugin=><LogStash::Outputs::Stdout codec=><LogStash::Codecs::RubyDebug metadata=>false>, workers=>1>, :level=>:info, :file=>"logstash/plugin.rb", :line=>"61", :method=>"finished"}
Pipeline shutdown complete. {:level=>:info, :file=>"logstash/pipeline.rb", :line=>"101", :method=>"run"}
Logstash shutdown completed

Note: stdin works but file input doesn't for whatever reasons.

6

I am having a very similar problem. Logstash 1.53, Ubuntu 14.04. This is about as simple a config as you can get:

input {
  file {
    path => "/storage/logs/bluecoat/logs/linupca18_real_old.log.2015.08.10"
    start_position => "beginning"
    sincedb_path => "/tmp/sincedb_bluecoat.db"
  }
}
output {
  stdout {
    codec => rubydebug
  }
}

I run

/opt/logstash/bin/logstash agent -l /var/log/logstash/logstash.log --debug -f /etc/logstash/conf.d/10-bluecoat.cfg

and I see no data on STDOUT only the debug information. Which I would include here, however, I can only post 5,000 characters and including the debug information will exceed that. Instead, I'm including the following that just happened because it may be very important to the issue:

UPDATE:
While I was typing this, I saw a backtrace pop. I've run the same command dozens of times and have never seen this. I've run the same command line several times after seeing the backtrace and it's not popping any more:

NotImplementedError: stat.st_gid unsupported or native support failed to load
             gid at org/jruby/RubyFileStat.java:247
    atomic_write at /opt/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.4/lib/filewatch/helper.rb:45
  _sincedb_write at /opt/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.4/lib/filewatch/tail.rb:236
   sincedb_write at /opt/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.4/lib/filewatch/tail.rb:206
        teardown at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-file-1.0.0/lib/logstash/inputs/file.rb:152
     inputworker at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.3-java/lib/logstash/pipeline.rb:203
     synchronize at org/jruby/ext/thread/Mutex.java:149
     inputworker at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.3-java/lib/logstash/pipeline.rb:203
     start_input at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.3-java/lib/logstash/pipeline.rb:171
The error reported is:
  Bad file descriptor - Bad file descriptor

Please help, this is maddening and I've lost at least 6 hours trying to just read a simple file.

And yes the basic "-e" test in the docs works fine.

7

Another update - I just installed ruby and bundler onto this system and all of the sudden LS appears to be working.

Ideas on why?

8

Please start your own thread for this :slight_smile:

9

Seeing same issue on 1.5.4 running on windows. STDIN input works fine, but file input displays nothing. Debug output looks like it's setting the pointer to the end of the file instead of the beginning.

10

Please start your own thread :slight_smile: