Logstash: Permission denied Error: Permission denied - /var/log/logstash.9844.4050.994333

[croax]

Hi guys

Having a weird problem with logstash 1.5.0-1 on CentOS 7. When I start logstash it crashes after just under two minutes. Only error in logs is the following repeated over and over:

{:timestamp=>"2015-05-25T19:43:08.410000+0000", :message=>"A plugin had an unrecoverable error. Will restart this plugin.\n Plugin: \n Error: Permission denied - /var/log/logstash.9844.4050.994333 or /var/log/logstash", :level=>:error}

I've verified all permissions:

[root@logstash log]# pwd
/var/log
[root@logstash log]# ls -la | grep -i logstash
drwxrwxrwx   2 logstash      logstash            66 May 25 16:24 logstash
-rw-r--r--   1 logstash      logstash            27 May 25 19:43 logstash.9844.4050.364642
-rw-r--r--   1 logstash      logstash            27 May 25 19:43 logstash.9844.4050.732835
-rwxr-xr-x   1 logstash      logstash            27 May 25 19:43 logstash.9844.4050.994333
[root@logstash log]# ls -la | grep network.log
-rw-rw-rw-   1 logstash      root          34946320 May 25 19:47 network.log

After giving logstash rwx to /var/log I noticed the logstash.xxxx.yyyy.zzzzzz files being created - is that expected behaviour? This problem does exist as well if I run logstash as root...

Best regards,
Daniel

[croax]

With debug output:

maí 25, 2015 8:44:20 PM org.elasticsearch.node.internal.InternalNode <init>
INFO: [logstash] version[1.5.1], pid[6496], build[5e38401/2015-04-09T13:41:35Z]
maí 25, 2015 8:44:20 PM org.elasticsearch.node.internal.InternalNode <init>
INFO: [logstash] initializing ...
maí 25, 2015 8:44:20 PM org.elasticsearch.plugins.PluginsService <init>
INFO: [logstash] loaded [], sites []
A plugin had an unrecoverable error. Will restart this plugin.
  Plugin: <LogStash::Inputs::File path=>["/var/log/network.log"], sincedb_path=>"/var/log/logstash", start_position=>"end", type=>"syslog", tags=>["asa_log"], delimiter=>"\n">
  Error: Permission denied - /var/log/logstash.9792.6496.294036 or /var/log/logstash {:level=>:error}
Errno::EACCES: Permission denied - /var/log/logstash.9792.6496.786861 or /var/log/logstash
          rename at org/jruby/RubyFile.java:976
    atomic_write at /opt/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.2/lib/filewatch/helper.rb:39
  _sincedb_write at /opt/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.2/lib/filewatch/tail.rb:233
   sincedb_write at /opt/logstash/vendor/bundle/jruby/1.9/gems/filewatch-0.6.2/lib/filewatch/tail.rb:203
        teardown at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-input-file-0.1.10/lib/logstash/inputs/file.rb:151
     inputworker at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-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.0-java/lib/logstash/pipeline.rb:203
     start_input at /opt/logstash/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:171

[croax]

Think I might have found the problem. I had sincedb_path configured in my logstash.conf pointed at /var/log/logstash. Commenting it out has fixed logstash so far..

[suyograo]

@croax sincedb path defaults to your $HOME dir so it has permission to write state. Changing this to point to a dir which can be written by logstash user is correct.

@croax can i close this?

[pmcclure]

I'm having the same issue. If we comment out the since_db statement where is the logstash.log located? I don't see anything in the $home dir

[Sodki]

I think this is a real issue with Logstash 1.5.0. Here's a test configuration, with more details:

input {
  file {
    path => "/tmp/testfile"
    sincedb_path => '/tmp/sincedb_folder/'
  }
}

output {
  stdout {}
}

Here's the creation of the folder:

$ mkdir /tmp/sincedb_folder
$ ls -ld /tmp/sincedb_folder
drwxrwxr-x 2 user user 4096 Jun  3 13:43 /tmp/sincedb_folder

Now I run Logstash with the same user:

$ bin/logstash -f /tmp/logstash.conf

And I put something on the target file:

$ echo "Hello World"  >> /tmp/testfile

Logstash breaks with the following error:

A plugin had an unrecoverable error. Will restart this plugin.
  Plugin: <LogStash::Inputs::File path=>["/tmp/testfile"], sincedb_path=>"/tmp/sincedb_folder/", start_position=>"end", delimiter=>"\n">
  Error: Permission denied - /tmp/sincedb_folder/.9784.3300.490182 or /tmp/sincedb_folder/ {:level=>:error}
Logstash shutdown completed
Errno::EACCES: Permission denied - /tmp/sincedb_folder/.9784.3300.471981
      initialize at org/jruby/RubyFile.java:362
             new at org/jruby/RubyIO.java:851
    atomic_write at /tmp/logstash-1.5.0/vendor/bundle/jruby/1.9/gems/filewatch-0.6.2/lib/filewatch/helper.rb:33
  _sincedb_write at /tmp/logstash-1.5.0/vendor/bundle/jruby/1.9/gems/filewatch-0.6.2/lib/filewatch/tail.rb:233
   sincedb_write at /tmp/logstash-1.5.0/vendor/bundle/jruby/1.9/gems/filewatch-0.6.2/lib/filewatch/tail.rb:203
        teardown at /tmp/logstash-1.5.0/vendor/bundle/jruby/1.9/gems/logstash-input-file-0.1.10/lib/logstash/inputs/file.rb:151
     inputworker at /tmp/logstash-1.5.0/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:203
     synchronize at org/jruby/ext/thread/Mutex.java:149
     inputworker at /tmp/logstash-1.5.0/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:203
     start_input at /tmp/logstash-1.5.0/vendor/bundle/jruby/1.9/gems/logstash-core-1.5.0-java/lib/logstash/pipeline.rb:171

Funny enough, the target folder seems to be broken. Please notice the lack of execution permissions on the folder, which prevents the user getting into the folder:

$ ls -ld /tmp/sincedb_folder
drw-rw-rw- 2 user user 4096 Jun  3 13:47 /tmp/sincedb_folder

Although something is there already:

$ ls -la /tmp/sincedb_folder
ls: cannot access /tmp/sincedb_folder/.: Permission denied
ls: cannot access /tmp/sincedb_folder/.9784.3300.490182: Permission denied
ls: cannot access /tmp/sincedb_folder/..: Permission denied
total 0
d????????? ? ? ? ?            ? .
d????????? ? ? ? ?            ? ..
-????????? ? ? ? ?            ? .9784.3300.490182

Now with sudo, to make things clear:

$ sudo ls -la /tmp/sincedb_folder
total 64
drw-rw-rw-  2 user user  4096 Jun  3 13:47 .
drwxrwxrwt 35 root root 53248 Jun  3 13:55 ..
-rwxrwxr-x  1 user user    21 Jun  3 13:47 .9784.3300.490182

$ sudo cat /tmp/sincedb_folder/.9784.3300.490182 
12199026 0 64512 180

This corruption of the permissions of the target folder explains the permission denied error, that's why I'm convinced it is a Logstash issue.

[Zedoki]

Hello, I have the same issue in my case it's "Error: Permission denied - /var/lib/logstash/" that cause problem.
http://pastebin.com/bqbWze1R

I updated Logstash to 1.5.1 and the issue still here. I did chmod 777 to this folder but after re-running Logstash, it's get back to his original rights i.e. rw-rw-rw-.

I will try Logstash 1.4.3 to see if issue will be still here.

[svanommen]

Pulling my hair out over the same issue. Just tried changing the sincedb path to /tmp/sincedb which I gave logstash ownership of and perms of 777:
drwxrwxrwx 2 logstash logstash 4096 Jun 17 17:50 sincedb
Started logstash again, it tanked again with the permissions issue again.
Noticed it changed the permissions on the folder to:
drw-rw-rw- 2 logstash logstash 4096 Jun 17 17:52 sincedb

Not sure if it needs execute perms to function, if it does it's breaking itself..... _sigh_

[Sodki]

As I mentioned before, looks like a legitimate bug. As a workaround, don't use sincedb_path on the logstash configuration, but use the SINCEDB_DIR environment variable instead. That works.

[jsvd]

This is a problem of poor configuration documentation, naming and expectations..
sincedb_path is not meant to be a directory but a file, that's why it's attempting to write to "/tmp/sincedb_folder" as a file.

To check that it works, setting sincedb_path => "/tmp/mysincedbfile" should work fine

[Sodki]

That's fair enough, but even then I would argue that Logstash configuration validation should fail if we're trying to use sincedb_path on a folder. Currently that folder just gets somewhat trashed, which is less than ideal.

[jsvd]

Totally agree, I'm opening an issue in logstash-plugins/logstash-input-file to properly give out an error if the destination is a directory.

[jsvd]

This might be a consequence on inconsistent File.open behavior on MRI and JRuby:

% rbenv shell 2.2.1; ruby -e "puts File.open('/tmp/meh/')"
#<File:0x007fe25b8900b8>
% rbenv shell jruby-1.7.19; ruby -e "puts File.open('/tmp/meh/')"
Errno::EACCES: Permission denied - /tmp/meh
  initialize at org/jruby/RubyFile.java:362
        open at org/jruby/RubyIO.java:1177
      (root) at -e:1

Digging deeper..

[svanommen]

Thanks @Sodki, setting the SINCEDB_DIR environment variable workaround is working for me so far! =)

[natemccoy]

I am having the exact same issue, permissions are definitely being changed by logstash

I can chmod 777 /var/cache/sincedbs and it will change the mode after logstash starts/stops

# chmod 777 /var/cache/sincedbs/
# stat /var/cache/sincedbs/ | grep Uid
Access: (0777/drwxrwxrwx)  Uid: (  492/logstash)   Gid: (  495/logstash)
# service logstash start
logstash started.
# service logstash status
logstash is running
# service logstash status
logstash is not running
# stat /var/cache/sincedbs/ | grep Uid
Access: (0666/drw-rw-rw-)  Uid: (  492/logstash)   Gid: (  495/logstash)

if i review the logstash.err log it will show the same error message that @Sodki mentions...

# grep EACCES /var/log/logstash/logstash.err
Errno::EACCES: Permission denied - /var/cache/sincedbs/.13506.22699.297366

settings the SINCEDB_DIR environment variable had no effect on this. I am running CentOS 6.6 and logstash-1.5.2-1.noarch

[jsvd]

@natemccoy as mentioned, the config setting was meant to be a file path, not a directory path. if you set it to /var/cache/sincedbs/mysince.db, no corruption of permissions will occur

[truptali]

I have resolved the issue by adding temp/sincedb/.sincedb path.

[darinfisher]

Hi,

I am having the same issue on CentOS 6.7 w/ Logstash 1.5.4

It has occurred w/o setting the 'sincedb_path' and also with setting it to a specific file
This will run and update the file fine for a period of time, anywhere from 30 minutes to 5 hours and then crash....
{:timestamp=>"2015-10-21T06:42:30.890000-0700", :message=>"A plugin had an unrecoverable error. Will restart this plugin.\n Plugin: , debug=>false, stat_interval=>1, discover_interval=>15, sincedb_write_interval=>15, delimiter=>\"\n\">\n Error: Permission denied - /var/lib/logstash/.sincedb_ea02cd1022d953a4b0364cbd826c437f.18696.19185.765920", :level=>:error}

{:timestamp=>"2015-10-21T07:42:50.868000-0700", :message=>"A plugin had an unrecoverable error. Will restart this plugin.\n Plugin: , debug=>false, stat_interval=>1, discover_interval=>15, sincedb_write_interval=>15, delimiter=>\"\n\">\n Error: Permission denied - /var/lib/logstash/sincedb_riskengine.25256.21254.235099", :level=>:error}

{:timestamp=>"2015-10-21T08:07:23.659000-0700", :message=>"A plugin had an unrecoverable error. Will restart this plugin.\n Plugin: , debug=>false, stat_interval=>1, discover_interval=>15, sincedb_write_interval=>15, delimiter=>\"\n\">\n Error: Permission denied - /var/lib/logstash/sincedb_collector.20212.23238.470530", :level=>:error}

file {
type => "GA_riskengine_1"
path => "/mnt/dc1filer02/_/current/_/logs/riskengine/*/riskengine.log"
start_position => "beginning"
sincedb_path => "/var/lib/logstash/sincedb_riskengine"
codec => multiline {
patterns_dir => "/etc/logstash/conf.d/patterns"
pattern => "^%{GATIMESTAMP}|%{IP} "
negate => true
what => previous
max_lines => 2500
}
}

[root@mon-esc-2 ~]# ls -alt /var/lib/logstash/
total 80
drwxrwxr-x. 2 logstash logstash 4096 Oct 21 09:00 .
-rw-r--r--. 1 logstash logstash 3690 Oct 21 09:00 sincedb_collector
-rw-r--r--. 1 logstash logstash 68702 Oct 21 08:59 sincedb_riskengine
drwxr-xr-x. 22 root root 4096 Oct 21 03:46 ..

Suggestions?

[natemccoy]

Hey there

I don't remember well but I think the issue was that I needed to specify a
path for a sincedb file in the configuration and then change the
permissions of the file

I had another issue once where the file was corrupt and I just deleted it
and restarted the daemon

Try both of those, keep me updated, I will try to help if I can
On 21 Oct 2015 17:11, "Darin Fisher" [email protected] wrote:

Hi,

I am having the same issue on CentOS 6.7 w/ Logstash 1.5.4

It has occurred w/o setting the 'sincedb_path' and also with setting it to
a specific file
This will run and update the file fine for a period of time, anywhere from
30 minutes to 5 hours and then crash....
{:timestamp=>"2015-10-21T06:42:30.890000-0700", :message=>"A plugin had an
unrecoverable error. Will restart this plugin.\n Plugin:
\"GA_collector_1\", path=>[\"/mnt/dc1filer02/_/current/_/logs/collector/collector.log\"],
start_position=>\"beginning\", codec=>[\"/etc/logstash/conf.d/patterns\"],
pattern=>\"^%{GATIMESTAMP}|%{IP} \", negate=>true, what=>\"previous\",
max_lines=>2500, charset=>\"UTF-8\", multiline_tag=>\"multiline\",
max_bytes=>10485760>, debug=>false, stat_interval=>1,
discover_interval=>15, sincedb_write_interval=>15, delimiter=>\"\n\">\n
Error: Permission denied -
/var/lib/logstash/.sincedb_ea02cd1022d953a4b0364cbd826c437f.18696.19185.765920",
:level=>:error}

{:timestamp=>"2015-10-21T07:42:50.868000-0700", :message=>"A plugin had an
unrecoverable error. Will restart this plugin.\n Plugin:
\"GA_riskengine_1\", path=>[\"/mnt/dc1filer02/_/current/_/logs/riskengine/*/riskengine.log\"],
start_position=>\"beginning\",
sincedb_path=>\"/var/lib/logstash/sincedb_riskengine\",
codec=>[\"/etc/logstash/conf.d/patterns\"],
pattern=>\"^%{GATIMESTAMP}|%{IP} \", negate=>true, what=>\"previous\",
max_lines=>2500, charset=>\"UTF-8\", multiline_tag=>\"multiline\",
max_bytes=>10485760>, debug=>false, stat_interval=>1,
discover_interval=>15, sincedb_write_interval=>15, delimiter=>\"\n\">\n
Error: Permission denied -
/var/lib/logstash/sincedb_riskengine.25256.21254.235099", :level=>:error}

{:timestamp=>"2015-10-21T08:07:23.659000-0700", :message=>"A plugin had an
unrecoverable error. Will restart this plugin.\n Plugin:
\"GA_collector_1\", path=>[\"/mnt/dc1filer02/_/current/_/logs/collector/collector.log\"],
start_position=>\"beginning\",
sincedb_path=>\"/var/lib/logstash/sincedb_collector\",
codec=>[\"/etc/logstash/conf.d/patterns\"],
pattern=>\"^%{GATIMESTAMP}|%{IP} \", negate=>true, what=>\"previous\",
max_lines=>2500, charset=>\"UTF-8\", multiline_tag=>\"multiline\",
max_bytes=>10485760>, debug=>false, stat_interval=>1,
discover_interval=>15, sincedb_write_interval=>15, delimiter=>\"\n\">\n
Error: Permission denied -
/var/lib/logstash/sincedb_collector.20212.23238.470530", :level=>:error}

file {
type => "GA_riskengine_1"
path => "/mnt/dc1filer02/_/current/_/logs/riskengine/*/riskengine.log"
start_position => "beginning"
sincedb_path => "/var/lib/logstash/sincedb_riskengine"
codec => multiline {
patterns_dir => "/etc/logstash/conf.d/patterns"
pattern => "^%{GATIMESTAMP}|%{IP} "
negate => true
what => previous
max_lines => 2500
}
}

[root@mon-esc-2 ~]# ls -alt /var/lib/logstash/
total 80
drwxrwxr-x. 2 logstash logstash 4096 Oct 21 09:00 .
-rw-r--r--. 1 logstash logstash 3690 Oct 21 09:00 sincedb_collector
-rw-r--r--. 1 logstash logstash 68702 Oct 21 08:59 sincedb_riskengine
drwxr-xr-x. 22 root root 4096 Oct 21 03:46 ..

Suggestions?

—
Reply to this email directly or view it on GitHub
https://github.com/elastic/logstash/issues/3311#issuecomment-149947801.

[darinfisher]

Still having the same problem.

Time frame varies, I have tried both removing the files and changing permissions.

After a period of time I still get the same permission denied error and logstash crashes.

[natemccoy]

I don't have a system setup with this to test, but I do remember a few
things, can I see view the sincedb path variable is defined?
On 22 Oct 2015 19:59, "Darin Fisher" [email protected] wrote:

Still having the same problem.

Time frame varies, I have tried both removing the files and changing
permissions.

After a period of time I still get the same permission denied error and
logstash crashes.

—
Reply to this email directly or view it on GitHub
https://github.com/elastic/logstash/issues/3311#issuecomment-150323095.

[darinfisher]

@natemccoy

Yes, here is the final log entry at the the time of the crash:

{:timestamp=>"2015-10-22T06:24:54.351000-0700", :message=>"A plugin had an unrecoverable error. Will restart this plugin.\n Plugin: , debug=>false, stat_interval=>1, discover_interval=>15, sincedb_write_interval=>15, delimiter=>\"\n\">\n Error: Permission denied - /var/lib/logstash/sincedb_riskengine_prod03.20168.11673.157291", :level=>:error}

And the input config section:

file {
    type => "GA_riskengine_1"
    path => "/mnt/dc1filer02/*/current/prod03/logs/riskengine/*/riskengine.log"
    start_position => "beginning"
    sincedb_path => "/var/lib/logstash/sincedb_riskengine_prod03"
    codec => multiline {
        patterns_dir => "/etc/logstash/conf.d/patterns"
        pattern => "^%{GATIMESTAMP}|%{IP} "
        negate => true
        what => previous
        max_lines => 2500
    }
}

[natemccoy]

Is sincedb_riskengine_prod03 a file or folder?
On 22 Oct 2015 21:14, "Darin Fisher" [email protected] wrote:

@natemccoy https://github.com/natemccoy

Yes, here is the final log entry at the the time of the crash:

{:timestamp=>"2015-10-22T06:24:54.351000-0700", :message=>"A plugin had an
unrecoverable error. Will restart this plugin.\n Plugin:
\"GA_riskengine_1\", path=>[\"/mnt/dc1filer02/
_/current/prod03/logs/riskengine/_/riskengine.log\"],
start_position=>\"beginning\",
sincedb_path=>\"/var/lib/logstash/sincedb_riskengine_prod03\",
codec=>[\"/etc/logstash/conf.d/patterns\"],
pattern=>\"^%{GATIMESTAMP}|%{IP} \", negate=>true, what=>\"previous\",
max_lines=>2500, charset=>\"UTF-8\", multiline_tag=>\"multiline\",
max_bytes=>10485760>, debug=>false, stat_interval=>1,
discover_interval=>15, sincedb_write_interval=>15, delimiter=>\"\n\">\n
Error: Permission denied -
/var/lib/logstash/sincedb_riskengine_prod03.20168.11673.157291",
:level=>:error}

And the input config section:

file {
type => "GA_riskengine_1"
path => "/mnt/dc1filer02/_/current/prod03/logs/riskengine/_/riskengine.log"
start_position => "beginning"
sincedb_path => "/var/lib/logstash/sincedb_riskengine_prod03"
codec => multiline {
patterns_dir => "/etc/logstash/conf.d/patterns"
pattern => "^%{GATIMESTAMP}|%{IP} "
negate => true
what => previous
max_lines => 2500
}
}

—
Reply to this email directly or view it on GitHub
https://github.com/elastic/logstash/issues/3311#issuecomment-150343714.

[darinfisher]

@natemccoy

and a listing of the directory.....

[root@mon-esc-2 ~]# ls -al /var/lib/logstash/
total 128
drwxrwxr-x. 2 logstash logstash 4096 Oct 22 13:14 .
drwxr-xr-x. 22 root root 4096 Oct 22 03:42 ..
-rw-r--r--. 1 logstash logstash 2061 Oct 22 13:14 sincedb_collector
-rw-r--r--. 1 logstash logstash 8744 Oct 22 12:05 sincedb_riskengine_prod00
-rw-r--r--. 1 logstash logstash 432 Oct 22 12:03 sincedb_riskengine_prod01
-rw-r--r--. 1 logstash logstash 43 Oct 22 05:13 sincedb_riskengine_prod02
-rw-r--r--. 1 logstash logstash 18571 Oct 22 12:55 sincedb_riskengine_prod03

[natemccoy]

Well I am sorry to day I am not sure, I had an issue in the past where
logstash would allow the sincedb_path to be a folder but would change the
permissions of the folder and then the daemon would crash as it could not
write or read to the folder. I then changed the variable to point to a file
and it resolved the problem.

I am sorry to day I don't think I can be of much more help, I do not have a
system I can test this in anymore.

You may want to run strace on the daemon if you know how to make it crash
and see what user is trying to wow to the files.

You may also want to check if the file permissions are changing fire some
reason

Good luck
On 22 Oct 2015 21:17, "Darin Fisher" [email protected] wrote:

@natemccoy https://github.com/natemccoy

and a listing of the directory.....

[root@mon-esc-2 ~]# ls -al /var/lib/logstash/
total 128
drwxrwxr-x. 2 logstash logstash 4096 Oct 22 13:14 .
drwxr-xr-x. 22 root root 4096 Oct 22 03:42 ..
-rw-r--r--. 1 logstash logstash 2061 Oct 22 13:14 sincedb_collector
-rw-r--r--. 1 logstash logstash 8744 Oct 22 12:05 sincedb_riskengine_prod00
-rw-r--r--. 1 logstash logstash 432 Oct 22 12:03 sincedb_riskengine_prod01
-rw-r--r--. 1 logstash logstash 43 Oct 22 05:13 sincedb_riskengine_prod02
-rw-r--r--. 1 logstash logstash 18571 Oct 22 12:55
sincedb_riskengine_prod03

—
Reply to this email directly or view it on GitHub
https://github.com/elastic/logstash/issues/3311#issuecomment-150344166.

[darinfisher]

Thanks for your help.
Hopefully we'll get to the bottom of this one soon!

[natemccoy]

Haha wow i made so many typos! Good luck!
On 22 Oct 2015 21:32, "Darin Fisher" [email protected] wrote:

Thanks for your help.
Hopefully we'll get to the bottom of this one soon!

—
Reply to this email directly or view it on GitHub
https://github.com/elastic/logstash/issues/3311#issuecomment-150348140.

[darinfisher]

If I want to dig deeper, can you point me to a place to understand how to trace this in better detail?

Thanks.

[jsvd]

closing this in favor of https://github.com/elastic/logstash/issues/4072