bin/plugin can not install plugins on CentOS

Ploy-XIV commented 8 years ago

I am unable to get bin/plugin to do anything useful other than list

I tried this on a freshly created CentOS 7.1 x64 VM. The commands listed below are literally my entire interaction with this VM:

Steps needed to reproduce

Install logstash on CentOS:

yum makecache
yum update
yum install bash-completion vim java-1.8.0-openjdk-headless
reboot
rpm --import https://packages.elastic.co/GPG-KEY-elasticsearch
vim /etc/yum.repos.d/logstash.repo
yum makecache
yum install logstash
reboot
cd /opt/logstash/

The file /etc/yum.repos.d/logstash.repo has the following content:

[logstash-2.2]
name=Logstash repository for 2.2.x packages
baseurl=http://packages.elastic.co/logstash/2.2/centos
gpgcheck=1
gpgkey=https://packages.elastic.co/GPG-KEY-elasticsearch
enabled=1

The version of logstash that was installed is 2.2.0.

Attempt to install plugins using bin/plugin (with/without verification and install from local file):

[root@testd logstash]# DATE=`date`; DEBUG=1 bin/plugin install logstash-filter-de_dot; echo $DATE; date                                                                                          
DEBUG: exec /opt/logstash/vendor/jruby/bin/jruby --1.9 -J-XX:+UseParNewGC -J-XX:+UseConcMarkSweepGC -J-Djava.awt.headless=true -J-XX:CMSInitiatingOccupancyFraction=75 -J-XX:+UseCMSInitiatingOccupancyOnly -J-XX:+HeapDumpOnOutOfMemoryError -J-Xmx1g -J-XX:HeapDumpPath=/opt/logstash/heapdump.hprof /opt/logstash/lib/pluginmanager/main.rb install logstash-filter-de_dot
Validating logstash-filter-de_dot
^CFre Feb 5 09:17:49 EST 2016
Fre Feb  5 09:19:45 EST 2016
[root@testd logstash]# DATE=`date`; DEBUG=1 bin/plugin install logstash-output-tcp; echo $DATE; date                                                                                             
DEBUG: exec /opt/logstash/vendor/jruby/bin/jruby --1.9 -J-XX:+UseParNewGC -J-XX:+UseConcMarkSweepGC -J-Djava.awt.headless=true -J-XX:CMSInitiatingOccupancyFraction=75 -J-XX:+UseCMSInitiatingOccupancyOnly -J-XX:+HeapDumpOnOutOfMemoryError -J-Xmx1g -J-XX:HeapDumpPath=/opt/logstash/heapdump.hprof /opt/logstash/lib/pluginmanager/main.rb install logstash-output-tcp
Validating logstash-output-tcp
^CFre Feb 5 09:20:05 EST 2016
Fre Feb  5 09:22:40 EST 2016
[root@testd logstash]# DATE=`date`; DEBUG=1 bin/plugin install logstash-output-csv; echo $DATE; date                                                                                             
DEBUG: exec /opt/logstash/vendor/jruby/bin/jruby --1.9 -J-XX:+UseParNewGC -J-XX:+UseConcMarkSweepGC -J-Djava.awt.headless=true -J-XX:CMSInitiatingOccupancyFraction=75 -J-XX:+UseCMSInitiatingOccupancyOnly -J-XX:+HeapDumpOnOutOfMemoryError -J-Xmx1g -J-XX:HeapDumpPath=/opt/logstash/heapdump.hprof /opt/logstash/lib/pluginmanager/main.rb install logstash-output-csv
Validating logstash-output-csv
^CFre Feb 5 09:22:49 EST 2016
Fre Feb  5 09:25:34 EST 2016
[root@testd logstash]# DATE=`date`; DEBUG=1 bin/plugin install --no-verify logstash-filter-de_dot; echo $DATE; date                                                                              
DEBUG: exec /opt/logstash/vendor/jruby/bin/jruby --1.9 -J-XX:+UseParNewGC -J-XX:+UseConcMarkSweepGC -J-Djava.awt.headless=true -J-XX:CMSInitiatingOccupancyFraction=75 -J-XX:+UseCMSInitiatingOccupancyOnly -J-XX:+HeapDumpOnOutOfMemoryError -J-Xmx1g -J-XX:HeapDumpPath=/opt/logstash/heapdump.hprof /opt/logstash/lib/pluginmanager/main.rb install --no-verify logstash-filter-de_dot
Installing logstash-filter-de_dot
^CFre Feb 5 09:25:51 EST 2016
Fre Feb  5 09:28:23 EST 2016
[root@testd logstash]# DATE=`date`; DEBUG=1 bin/plugin install --no-verify logstash-output-tcp; echo $DATE; date                                                                                 
DEBUG: exec /opt/logstash/vendor/jruby/bin/jruby --1.9 -J-XX:+UseParNewGC -J-XX:+UseConcMarkSweepGC -J-Djava.awt.headless=true -J-XX:CMSInitiatingOccupancyFraction=75 -J-XX:+UseCMSInitiatingOccupancyOnly -J-XX:+HeapDumpOnOutOfMemoryError -J-Xmx1g -J-XX:HeapDumpPath=/opt/logstash/heapdump.hprof /opt/logstash/lib/pluginmanager/main.rb install --no-verify logstash-output-tcp
Installing logstash-output-tcp
^CFre Feb 5 09:28:41 EST 2016
Fre Feb  5 09:31:05 EST 2016
[root@testd logstash]# DATE=`date`; DEBUG=1 bin/plugin install --local /root/logstash-filter-de_dot-0.1.1.gem; echo $DATE; date                                                                  
DEBUG: exec /opt/logstash/vendor/jruby/bin/jruby --1.9 -J-XX:+UseParNewGC -J-XX:+UseConcMarkSweepGC -J-Djava.awt.headless=true -J-XX:CMSInitiatingOccupancyFraction=75 -J-XX:+UseCMSInitiatingOccupancyOnly -J-XX:+HeapDumpOnOutOfMemoryError -J-Xmx1g -J-XX:HeapDumpPath=/opt/logstash/heapdump.hprof /opt/logstash/lib/pluginmanager/main.rb install --local /root/logstash-filter-de_dot-0.1.1.gem
Validating /root/logstash-filter-de_dot-0.1.1.gem
^CFre Feb 5 09:32:39 EST 2016
Fre Feb  5 09:34:56 EST 2016
[root@testd logstash]# DATE=`date`; DEBUG=1 bin/plugin install --local /root/logstash-output-tcp-2.0.2.gem; echo $DATE; date
DEBUG: exec /opt/logstash/vendor/jruby/bin/jruby --1.9 -J-XX:+UseParNewGC -J-XX:+UseConcMarkSweepGC -J-Djava.awt.headless=true -J-XX:CMSInitiatingOccupancyFraction=75 -J-XX:+UseCMSInitiatingOccupancyOnly -J-XX:+HeapDumpOnOutOfMemoryError -J-Xmx1g -J-XX:HeapDumpPath=/opt/logstash/heapdump.hprof /opt/logstash/lib/pluginmanager/main.rb install --local /root/logstash-output-tcp-2.0.2.gem
Validating /root/logstash-output-tcp-2.0.2.gem
^CFre Feb 5 09:35:09 EST 2016
Fre Feb  5 09:37:18 EST 2016

Expected outcome

Each of the executions of bin/plugin shown above should install a plugin (if it's not installed already).

Actual outcome

plugin hangs until it is killed for all tried invocations. I picked the plugin names at random, the plugins used are just examples

Ploy-XIV commented 8 years ago

Similar story for a Debian 8.3 x64 VM.

Steps needed to reproduce

apt-get update
apt-get dist-upgrade
apt-get install bash-completion vim default-jre-headless
reboot
wget -qO - https://packages.elastic.co/GPG-KEY-elasticsearch | apt-key add -
echo "deb http://packages.elastic.co/logstash/2.2/debian stable main" > /etc/apt/sources.list.d/10logstash.list
apt-get update
apt-get install logstash
systemctl enable logstash.service
reboot
cd /opt/logstash/

Now, attempting to install a plugin results in the same behavior as above. Any of:

./bin/plugin install logstash-filter-de_dot
./bin/plugin install logstash-output-tcp
./bin/plugin install logstash-output-csv

just produces the line

Validating <plugin-name>

and then hangs until plugin is killed.

purbon commented 8 years ago

@Ploy-XIV thanks a lot for your detailed report. I wonder if you can check the permissions used to run this? is the logstash user able to write inside vendor/ directory?

Ploy-XIV commented 8 years ago

For the examples I made here in this bug report, I ran all the commands as root, so, the file permissions should not matter.

(In other installs of Logstash I used to chown the files later to root:logstash, or something like that.)

purbon commented 8 years ago

Ok! I'm sorry for your pain, will investigate as soon as possible. We actually run this test with ubuntu/debian and never found this issue, so I'm preatty interested to find the root cause. thanks a lot.

On Mon, Feb 8, 2016 at 3:17 PM Ploy notifications@github.com wrote:

For the examples I made here in this bug report, I ran all the commands as root, so, the file permissions should not matter.

(In other installs of Logstash I used to chown the files later to root:logstash, or something like that.)

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

Ploy-XIV commented 8 years ago

It's of course possible that my cloud hoster did something crazy with the VM templates, and they aren't "same enough" compared to installs from official CentOS/Debian install media.

purbon commented 8 years ago

Are you able to test with official distro? might be through vagrant?

purbon

On Mon, Feb 8, 2016 at 3:21 PM Ploy notifications@github.com wrote:

It's of course possible that my cloud hoster did something crazy with the VM templates, and they aren't "same enough" compared to installs from official CentOS/Debian install media.

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

Ploy-XIV commented 8 years ago

Just to check if it's an issue of the user running bin/plugin, I tried again with CentOS and setup instructions from above:

yum makecache
yum update
yum install bash-completion vim java-1.8.0-openjdk-headless
reboot
rpm --import https://packages.elastic.co/GPG-KEY-elasticsearch
vim /etc/yum.repos.d/logstash.repo
yum makecache
yum install logstash
reboot

Making sure that all the logstash files belong to the logstash user, just in case:

chown --recursive logstash:logstash /opt/logstash

And attempt to install the plugin using the logstash user (who's home directory is /opt/logstash):

chsh --shell /bin/bash logstash
su - logstash

logstash# ./bin/plugin install logstash-filter-de_dot

Result is exactly the same as before:

Validating logstash-filter-de_dot

...and then nothing, until bin/plugin is killed.

Ploy-XIV commented 8 years ago

OK, I just tried again with CentOS installed myself from an official install medium (CentOS-7-x86_64-DVD-1503-01.iso).

Setup steps were the same as listed above, with the addition of configuring network and the OpenSSH server.

Plugin installation works as expected here...

I'll have a look and see if I can find out in what way my VM hoster's image is different that leads to breakage. I'm using DigitalOcean, BTW.

jordansissel commented 8 years ago

Is your server able to access rubygems.org? Is there any firewall settings preventing external network actvity?

Ploy-XIV commented 8 years ago

It's not a networking issue, as installing a plugin from a local file (previously downloaded from rubygems) fails in exactly the same way, as documented in my first post.

I had a look with with wireshark, and there is absolutely no network traffic when I run bin/plugin from a DigitalOcean VM. I'd expect to see some DNS traffic, or an outgoing SYN packet at least, when bin/plugin is contacting rubygems, but there's nothing.

Ploy-XIV commented 8 years ago

Just a quick update on some more things I have tried:

I have now all in all tested five different OS instances (some discussed above already):

Digitalocean Debian: ./bin/plugin does not work
Digitalocean CentOS: ./bin/plugin does not work
Virtualbox CentOS: ./bin/plugin works
RHEL VM at work: ./bin/plugin works on one machine, but not on another (supposedly equal) machine. Unfortunately, there are too many variables I can't control for my RHEL test setup to be able to investigate this any further.

For some of the machines with issues I tried most of the available logstash 2.x releases, and the behavior seems to be exactly the same across all versions (that is: ./bin/plugin behaves exactly in the same way from logstash 2.0.0 to 2.2.1, for all versions that I checked).

I tried debugging ./bin/plugin on some of the machines I tested it on with strace. It seems that after the first handful of seconds, ./bin/plugin gets stuck in and endless loop where it makes about 30 futex syscalls, and then pauses for a second or so.

I've also found out that when I move my /opt/logstash folder (with successfully installed plugins) from the CentOS to the RHEL VM that logstash works as expected. I still can't install new plugins, but the plugins already installed work. So, this can serve as a workaround for anyone else experiencing this issue.

I have no idea how to investigate this issue further...

jordansissel commented 8 years ago

./bin/plugin gets stuck in and endless loop where it makes about 30 futex syscalls, and then pauses for a second or so

When stracing java programs, especially for file or network-related activity, I recommend using -e trace=file or -e trace=network -- doing this will cut out the noise of other syscalls such as futex.

Analect commented 8 years ago

@Ploy-XIV Were you able to establish if this problem was caused by a digitalocean-related issue? I'm running ELK on DO using Ubuntu 15.10 (GNU/Linux 4.2.0-16-generic x86_64) and facing the same issues you describe. Thanks.

purbon commented 8 years ago

@Ploy-XIV @Analect I'm wondering if this might be a package issue somehow? can you test same thing with the tar.gz package? thanks a lot for your testing efforts!!

sanjay-varanasi commented 8 years ago

I have the exact same issue on Amazon Linux AMI and I can't figure out what to do to fix this. Works perfectly on Docker CentOS on an Ubuntu kernel.

cmorland commented 8 years ago

Same issue for me using CentOS 7 droplet on Digital Ocean.

It seems to be related to a lack of entropy in the PRNG. I've resolved the problem by installing haveged.

https://www.digitalocean.com/community/tutorials/how-to-setup-additional-entropy-for-cloud-servers-using-haveged

bbrendon commented 7 years ago

I had this problem on a physical box running jessie and using logstash v 5.1.1. I Installed haveged but it didn't fix the issue. Also in the process of trying to install the plugin my logstash install corrupted. I had to modify /usr/share/logstash/Gemfile and delete the last line. I was getting this error when trying to load logstash.

Bundler::GemNotFound: Could not find gem 'logstash-filter-multiline (>= 0) java' in any of the gem sources listed in your Gemfile or installed on this machine.

Running it inside of strace was a success! How is this possible?

fstat(3, {st_mode=S_IFREG|0644, st_size=1008120, ...}) = 0
mmap(NULL, 3188384, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5f52560000
mprotect(0x7f5f5264c000, 2097152, PROT_NONE) = 0
mmap(0x7f5f5284c000, 40960, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xec000) = 0x7f5f5284c000
mmap(0x7f5f52856000, 83616, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x7f5f52856000
close(3)                                = 0
open("/usr/lib/jvm/java-8-openjdk-amd64/jre/bin/../lib/amd64/jli/libm.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/jvm/java-8-openjdk-amd64/jre/bin/../lib/amd64/libm.so.6", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libm.so.6", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\200U\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=1051056, ...}) = 0
mmap(NULL, 3146072, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5f5225f000
mprotect(0x7f5f5235f000, 2093056, PROT_NONE) = 0
mmap(0x7f5f5255e000, 8192, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0xff000) = 0x7f5f5255e000
close(3)                                = 0
open("/usr/lib/jvm/java-8-openjdk-amd64/jre/bin/../lib/amd64/jli/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
open("/usr/lib/jvm/java-8-openjdk-amd64/jre/bin/../lib/amd64/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/x86_64-linux-gnu/libgcc_s.so.1", O_RDONLY|O_CLOEXEC) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\260*\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0644, st_size=90096, ...}) = 0
mmap(NULL, 2185952, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7f5f52049000
mprotect(0x7f5f5205f000, 2093056, PROT_NONE) = 0
mmap(0x7f5f5225e000, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_DENYWRITE, 3, 0x15000) = 0x7f5f5225e000
close(3)                                = 0
mprotect(0x7f5f5255e000, 4096, PROT_READ) = 0
mprotect(0x7f5f5284c000, 32768, PROT_READ) = 0
mprotect(0x7f5f53701000, 667648, PROT_READ) = 0
munmap(0x7f5f54601000, 65690)           = 0
mmap(NULL, 2101248, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_STACK, -1, 0) = 0x7f5f51e48000
mprotect(0x7f5f51e48000, 4096, PROT_NONE) = 0
clone(child_stack=0x7f5f52047ff0, flags=CLONE_VM|CLONE_FS|CLONE_FILES|CLONE_SIGHAND|CLONE_THREAD|CLONE_SYSVSEM|CLONE_SETTLS|CLONE_PARENT_SETTID|CLONE_CHILD_CLEARTID, parent_tidptr=0x7f5f520489d0, tls=0x7f5f52048700, child_tidptr=0x7f5f520489d0) = 19139
futex(0x7f5f520489d0, FUTEX_WAIT, 19139, NULLValidating logstash-filter-multiline
Installing logstash-filter-multiline
Installation successful
) = 0
exit_group(0)                           = ?
+++ exited with 0 +++

mjroeleveld commented 7 years ago

For me, this issue was solved when adding more resources. (On AWS, t2.micro -> t2.small).

nikademus79 commented 7 years ago

For me it looks to be an issue with the ENV vatiable not being referenced correctly, adding that to the Dockerfile built fine. /opt/elasticsearch/bin/elasticsearch-plugin Swap out the app name etc

elastic / logstash

bin/plugin can not install plugins on CentOS #4638