[SOLVED] logstash-1.4.0-1 on CentOS 5.10

Originally Posted by Habitual I hear you. Thanks for all you've done.

No problem at all. If you have new entries in logstash.log at least logstash is working like it should. If not, checkout the debug output and see if you your inputs are registered:

{:timestamp=>"2014-05-20T20:22:49.200000+0200", :message=>"Registering file input", :path=>["/var/log/*.log", "/var/log/messages", "/var/log/syslog"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"}

And see if it discovers the files you attempt to monitor

{:timestamp=>"2014-05-20T20:22:49.386000+0200", :message=>"_discover_file_glob: /var/log/*.log: glob is: [\"/var/log/yum.log\", \"/var/log/anaconda.log\", \"/var/log/anaconda.storage.log\", \"/var/log/anaconda.program.log\", \"/var/log/dracut.log\", \"/var/log/boot.log\", \"/var/log/anaconda.ifcfg.log\", \"/var/log/anaconda.yum.log\"]", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"117"}
{:timestamp=>"2014-05-20T20:22:49.393000+0200", :message=>"_discover_file: /var/log/*.log: new: /var/log/yum.log (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.401000+0200", :message=>"_discover_file: /var/log/*.log: new: /var/log/anaconda.log (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.411000+0200", :message=>"_discover_file: /var/log/*.log: new: /var/log/anaconda.storage.log (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.418000+0200", :message=>"_discover_file: /var/log/*.log: new: /var/log/anaconda.program.log (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.436000+0200", :message=>"_discover_file: /var/log/*.log: new: /var/log/dracut.log (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.443000+0200", :message=>"_discover_file: /var/log/*.log: new: /var/log/boot.log (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.448000+0200", :message=>"_discover_file: /var/log/*.log: new: /var/log/anaconda.ifcfg.log (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.457000+0200", :message=>"_discover_file: /var/log/*.log: new: /var/log/anaconda.yum.log (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.467000+0200", :message=>"_discover_file_glob: /var/log/messages: glob is: [\"/var/log/messages\"]", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"117"}
{:timestamp=>"2014-05-20T20:22:49.473000+0200", :message=>"_discover_file: /var/log/messages: new: /var/log/messages (exclude is [])", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"126"}
{:timestamp=>"2014-05-20T20:22:49.486000+0200", :message=>"_discover_file_glob: /var/log/syslog: glob is: []", :level=>:debug, :file=>"filewatch/watch.rb", :line=>"117"}

If you're not sure I won't mind taking a look at the complete logfile. Cheers!

Oh they're there:

grep "Registering file input" /var/log/logstash/logstash.log
{:timestamp=>"2014-05-21T08:23:14.999000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/web/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"}
{:timestamp=>"2014-05-21T08:23:15.003000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/cirrhus9a/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"}
{:timestamp=>"2014-05-21T08:23:15.006000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/cirrhus9b/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"}
{:timestamp=>"2014-05-21T08:28:11.573000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/web/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"}
{:timestamp=>"2014-05-21T08:28:11.580000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/cirrhus9a/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"}
{:timestamp=>"2014-05-21T08:28:11.584000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/cirrhus9b/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"}

Now that perms and the conf file has been updated to use

sincedb_path => "/opt/logstash/sincedb-access"

I was thinking of nuking via yum erase and cleaning leftovers in /opt/logstash and /var/lib/logstash/ and re-installing...
This seems to have worked once or twice.

Originally Posted by Habitual Oh they're there: grep "Registering file input" /var/log/logstash/logstash.log {:timestamp=>"2014-05-21T08:23:14.999000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/web/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"} {:timestamp=>"2014-05-21T08:23:15.003000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/cirrhus9a/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"} {:timestamp=>"2014-05-21T08:23:15.006000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/cirrhus9b/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"} {:timestamp=>"2014-05-21T08:28:11.573000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/web/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"} {:timestamp=>"2014-05-21T08:28:11.580000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/cirrhus9a/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"} {:timestamp=>"2014-05-21T08:28:11.584000-0700", :message=>"Registering file input", :path=>["/var/log/remotes/cirrhus9b/*.log"], :level=>:info, :file=>"logstash/inputs/file.rb", :line=>"74"} Now that perms and the conf file has been updated to use sincedb_path => "/opt/logstash/sincedb-access" I was thinking of nuking via yum erase and cleaning leftovers in /opt/logstash and re-installing... This seems to have worked once or twice.

Yes that might be a good idea, but I guess there is a change you'll end up in the exact same state.

One more thing, I guess you probably thought of this but are the actual logfiles in /var/log/remotes owned by root? Your previous posts only show the directory permissions, not of the actual files. Just a thought, if they are owned by root the logstash user can list but not read them

If it's possible check out that if you trigger a new log message it's picked up by logstash. In my case I also monitor /var/log/messages. When I trigger a log message:

logger TESTING

It's immediately picked up by logstash and visible in logstash.log (don't mind the "grokked" messages):

{:timestamp=>"2014-05-21T18:07:13.528000+0200", :message=>"Event now: ", :event=>#<LogStash::Event:0x23155c9e @accessors=#<LogStash::Util::Accessors:0x4f739b10 @store={"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, @lut={"type"=>[{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, "type"], "host"=>[{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, "host"], "path"=>[{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, "path"], "message"=>[{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, "message"], "timestamp"=>[{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, "timestamp"], "logsource"=>[{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, "logsource"], "program"=>[{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, "program"], "tags"=>[{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, "tags"]}>, @data={"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, @cancelled=false>, :level=>:debug, :file=>"logstash/filters/grok.rb", :line=>"299"}
{:timestamp=>"2014-05-21T18:07:13.523000+0200", :message=>"writing sincedb (delta since last write = 2462)", :level=>:debug, :file=>"filewatch/tail.rb", :line=>"177"}
{:timestamp=>"2014-05-21T18:07:13.533000+0200", :message=>"output received", :event=>{"message"=>["May 21 18:07:12 dev root: TESTING", "TESTING"], "@version"=>"1", "@timestamp"=>"2014-05-21T16:07:13.519Z", "type"=>"syslog", "host"=>"dev.kanbier.lan", "path"=>"/var/log/messages", "timestamp"=>"May 21 18:07:12", "logsource"=>"dev", "program"=>"root", "tags"=>["syslog", "grokked"]}, :level=>:debug, :file=>"(eval)", :line=>"43"}

So if you see this and it's not visible within elasticsearch (or Kibana talking to elasticsearch), the problem isn't logstash per se.

Well, we'll know tomorrow when indexes roll over, but for now we have re-initialized logstash with this recipe:

service logstash stop
rm -fr /var/lib/logstash/ /opt/logstash
rpm -Uvh /usr/src/logstash-1.4.1-1_bd507eb.noarch.rpm
touch /opt/logstash/sincedb-access
chown logstash:logstash /opt/logstash/sincedb-access
chmod -R 770 /opt/logstash/sincedb-access
chown -R logstash:logstash /var/log/remotes/
chmod -R 770 /var/log/remotes/
cp /root/logstash /etc/init.d/
/opt/logstash/bin/logstash -f  /etc/logstash/conf.d/logstash.conf --configtest
vi /opt/logstash/vendor/kibana/config.js # and adjust "http://fqdn:9200",
service logstash start

The only irregular "what the hell?" I see is:

stat -c%a /var/log/remotes/*
744
744
744

when I set them via c-line for 770

the init script I cp'd from /root is here... and I believe that's stock except for

args="agent -f ${LS_CONF_DIR}/logstash.conf

and line 153
where it was

stop && start

and is now

stop || start

logstash.conf is here...

You've been a tremendous help on this issue and I am grateful for it.

Have a Great Day!