Cannot override JVM options for plugins

[Cova]

Under logstash 5, I was able to set the environment parameter on plugin resources to do something like:
LS_JVM_OPTIONS="-Xms1g -Xmx1g"
And all was good. Having now upgraded to logstash 6, the LS_JVM_OPTIONS environment variable no longer functions and was replaced with LS_JAVA_OPTS, which should work in the same way. However, when I pass an environment variable of LS_JAVA_OPTS="-Xms1g -Xmx1g" to the plugin resource, I get errors when puppet runs:

Notice: /Stage[main]/Profile::Logstash/Logstash::Plugin[logstash-filter-translate]/Exec[install-logstash-filter-translate]/returns: Error: Could not find or load main class "-Xms1g"
Error: '/usr/share/logstash/bin/logstash-plugin install logstash-filter-translate' returned 1 instead of one of [0]
Error: /Stage[main]/Profile::Logstash/Logstash::Plugin[logstash-filter-translate]/Exec[install-logstash-filter-translate]/returns: change from notrun to 0 failed: '/usr/share/logstash/bin/logstash-plugin install logstash-filter-translate' returned 1 instead of one of [0]

This would also probably be a good time to update the example config here: https://github.com/elastic/puppet-logstash/blob/master/manifests/plugin.pp#L31 to use the LS_JAVA_OPTS variable.

[jarpy]

Could you share the plugin declaration to reproduce this error, please? Thanks.

[Cova]

I try to keep everything in Hiera - so my puppet code related to plugins is this:

$hiera_pluginlist = lookup({name => 'logstash::pluginlist', default_value => undef, merge => deep})
if $hiera_pluginlist {
  create_resources('logstash::plugin', $hiera_pluginlist)
}

And in my heira data I have this:

logstash::pluginlist:
  logstash-filter-translate:
    ensure: present
    environment: LS_JAVA_OPTS="-Xms1g -Xmx1g"

If it matters, running the following command in a terminal on the same node works just fine:
LS_JAVA_OPTS="-Xms1g -Xmx1g" bin/logstash-plugin install logstash-filter-translate

[jarpy]

Thanks. That's really interesting. Check out the debug output:

Debug: Executing with uid=logstash: '/usr/share/logstash/bin/logstash-plugin list ^logstash-filter-translate$'
Debug: /Stage[main]/Main/Logstash::Plugin[logstash-filter-translate]/Exec[install-logstash-filter-translate]/unless: Op
enJDK 64-Bit Server VM warning: If the number of processors is expected to increase from one, then you should configure
 the number of parallel GC threads appropriately using -XX:ParallelGCThreads=N
Debug: /Stage[main]/Main/Logstash::Plugin[logstash-filter-translate]/Exec[install-logstash-filter-translate]/unless: Er
ror: Could not find or load main class "-Xms1g
Debug: Exec[install-logstash-filter-translate](provider=posix): Executing '/usr/share/logstash/bin/logstash-plugin inst
all logstash-filter-translate'
Debug: Executing with uid=logstash: '/usr/share/logstash/bin/logstash-plugin install logstash-filter-translate'

The command being exec'd looks fine. I can't yet see how the flag is leaking into the JVM invocation, but it clearly is... somehow.

[jarpy]

If it matters, running the following command in a terminal on the same node works just fine:
LS_JAVA_OPTS="-Xms1g -Xmx1g" bin/logstash-plugin install logstash-filter-translate

This matters a lot. 💯

Thanks for providing such a good reproduction.

Here's what I pulled out of my process list when running successfully from the shell:

/bin/java -Dfile.encoding=UTF-8 -Djava.awt.headless=true -XX:+DisableExplicitGC -XX:+HeapDumpOnOutOfMemoryError -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:CMSInitiatingOccupancyFraction=75 -Xmx1g -Xms1g -Xss2048k -Djffi.boot.library.path=/usr/share/logstash/vendor/jruby/lib/jni -XX:+TieredCompilation -XX:TieredStopAtLevel=1 -noverify -Djruby.compile.invokedynamic=false -Xbootclasspath/a:/usr/share/logstash/vendor/jruby/lib/jruby.jar -classpath : -Djruby.home=/usr/share/logstash/vendor/jruby -Djruby.lib=/usr/share/logstash/vendor/jruby/lib -Djruby.script=jruby -Djruby.shell=/bin/sh org.jruby.Main -X-C /usr/share/logstash/lib/pluginmanager/main.rb install logstash-filter-translate

...and here's what is run when using Puppet:

/bin/java -Dfile.encoding=UTF-8 -Djava.awt.headless=true -XX:+DisableExplicitGC -XX:+HeapDumpOnOutOfMemoryError -XX:+UseCMSInitiatingOccupancyOnly -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:CMSInitiatingOccupancyFraction=75 "-Xms1g -Xmx1g" -Xms256m -Xss2048k -Djffi.boot.library.path=/usr/share/logstash/vendor/jruby/lib/jni -XX:+TieredCompilation -XX:TieredStopAtLevel=1 -noverify -Djruby.compile.invokedynamic=false -Xbootclasspath/a:/usr/share/logstash/vendor/jruby/lib/jruby.jar -classpath : -Djruby.home=/usr/share/logstash/vendor/jruby -Djruby.lib=/usr/share/logstash/vendor/jruby/lib -Djruby.script=jruby -Djruby.shell=/bin/sh org.jruby.Main -X-C /usr/share/logstash/lib/pluginmanager/main.rb install logstash-filter-translate

The fail state contains this nasty piece of work: "-Xms1g -Xmx1g" -Xms256m.

That string quoting not our friend.

[jarpy]

So, if you remove the quotes from your Hiera YAML, it works:

logstash::plugin list:
  logstash-filter-translate:
    ensure: present
    environment: LS_JAVA_OPTS=-Xms1g -Xmx1g

The environment parameter of the exec resource expects a string (or an array of strings) in the form "VAR=value". This example is valid:

"VAR=a multi-word value"

But in your case, Hiera is sending the equivalent of this:

"VAR=\"a multi-word value forced into qoutes\""

It not super intuitive, with so many layers of string handling: YAML -> Hiera -> Puppet -> Shell.

Here's an example of the problem in pure Puppet:

# example.pp
exec { 'test':
  command     => '/bin/echo $CANARY > /tmp/target',
  provider    => 'shell',
  environment => 'CANARY=a yellow bird',
}

$ puppet apply example.pp
Notice: Compiled catalog for rasa.home.jarpy.net in environment production in 0.06 seconds
Notice: /Stage[main]/Main/Exec[test]/returns: executed successfully
Notice: Applied catalog in 0.01 seconds

$ cat /tmp/target
a yellow bird

---

# example.pp
exec { 'test':
  command     => '/bin/echo $CANARY > /tmp/target',
  provider    => 'shell',
  environment => 'CANARY="a yellow bird in a cage"',
}

$ puppet apply example.pp
Notice: Compiled catalog for rasa.home.jarpy.net in environment production in 0.04 seconds
Notice: /Stage[main]/Main/Exec[test]/returns: executed successfully
Notice: Applied catalog in 0.01 seconds

$ cat /tmp/target
"a yellow bird in cage"

[Cova]

Ok - I'll give it a go tomorrow when I'm back in the office, based on everything here I expect it should be fine. One last point to make though - back on previous versions of the puppet module and elastic components (when it was still LS_JVM_OPTIONS) the quotes didn't cause any problems. When I upgraded everything, the only change I made (besides new versions) was replacing LS_JVM_OPTIONS with LS_JAVA_OPTS - same puppet code, same hiera data, same quotes, etc. Quotes didn't cause a problem before, but they do now.

Thanks for the help.

[jarpy]

I understand. The plugin command (which is a shell script) must have changed its behaviour.

I updated the README and comments here to be correct for the new way.

Sorry you hit this and thanks again for the excellent report.