Caching vault object causes heisenbug on heavy-loaded puppetserver

[petems]

Caching vault object causes heisenbug on heavy-loaded puppetserver

[tiandrey]

Update: with puppetserver version 6.2.0-1stretch, there were only Vault::ConnectionPool::PoolShuttingDownError errors (about 100 errors per day)
However, with puppetserver version 6.15.1-1stretch (I tested both old single-threaded and new multithreaded JRuby mode), there are many different errors, here are stats for one day:

root@puppet:~# zcat /var/log/puppetlabs/puppetserver/puppetserver-2021-03-25.0.log.gz /var/log/puppetlabs/puppetserver/puppetserver-2021-03-25.1.log.gz | grep 'Skipping backend' | grep -o '\[hiera-vault\].*' | awk -F ' on node' '{print $1}' | awk -F ' \\(file:' '{print $1}' | sort | uniq -c | sort -n
      3 [hiera-vault] Skipping backend. Configuration error: Socket closed
      3 [hiera-vault] Skipping backend. Configuration error: undefined method `request' for nil:NilClass
      3 [hiera-vault] Skipping backend. Configuration error: undefined method `ssl_version=' for nil:NilClass
     12 [hiera-vault] Skipping backend. Configuration error: The Vault server at `https://127.0.0.1:8200' is not currently
     81 [hiera-vault] Skipping backend. Configuration error: Vault::ConnectionPool::PoolShuttingDownError
   2700 [hiera-vault] Skipping backend. Configuration error: undefined method `configure' for nil:NilClass
   3087 [hiera-vault] Skipping backend. Configuration error: no cipher match

Some of no cipher match errors may be accounted for changes in default ciphers in puppetserver, but surely not all of them.
Also, https://127.0.0.1:8200 is NOT address of my Vault server.

[petems]

@tiandrey Can you change your module to use this branch fix to see if it resolves your problem: #65

[petems]

I've just cut and pushed a release for 2.0.0, hopefully this should fix it 👍🏻

[tiandrey]

Can't check it right now, but mutex should fix the problem. I'll comment as soon as I'm able to test it.

[tiandrey]

I've tried v2.0.0 - received lots of errors like

2021-08-16T19:26:57.548+03:00 ERROR [qtp1752447289-227] [puppetserver] Puppet [hiera-vault] Skipping backend. Configuration error: no cipher match
2021-08-16T19:26:57.548+03:00 ERROR [qtp1752447289-227] [puppetserver] Puppet [hiera-vault] Skipping backend. Configuration error: no cipher match on node example-hostname
2021-08-16T19:26:57.549+03:00 ERROR [qtp1752447289-227] [puppetserver] Puppet Server Error: [hiera-vault] Skipping backend. Configuration error: no cipher match on node example-hostname
/etc/puppetlabs/code/environments/production/modules/hiera_vault/lib/puppet/functions/hiera_vault.rb:138:in `block in vault_get'
org/jruby/ext/thread/Mutex.java:164:in `synchronize'
/etc/puppetlabs/code/environments/production/modules/hiera_vault/lib/puppet/functions/hiera_vault.rb:112:in `vault_get'
/etc/puppetlabs/code/environments/production/modules/hiera_vault/lib/puppet/functions/hiera_vault.rb:89:in `lookup_key'

[petems]

What version of Vault and Puppet are you running?

Looks like this: hashicorp/vault-ruby#179

[tiandrey]

vault (0.16.0)
ii  puppet-agent                  6.23.0-1stretch                     amd64        The Puppet Agent package contains all of the elements needed to run puppet, including ruby, facter, and hiera.
ii  puppetserver                  6.15.3-1stretch                     all          Puppet Labs puppetserver

This is still a heisenbug, most of requests are completed successfully, but many still have this error.

[petems]

Which version of Vault itself do you have installed? (The app itself, not the gem)

[petems]

Are you using the same Puppet version across your estate?

[petems]

Also, could you do puppetserver gem list for me?

[tiandrey]

Which version of Vault itself do you have installed?

Don't know, don't think it matters - most requests succeed, so the problem it's not caused by cryptography issues per se.

Are you using the same Puppet version across your estate?

From 6 to 7. Again, it doesn't matter - the same node can have error on one run and success on the next.

Gems

# puppetserver gem list
2021-08-16 21:09:46,583 INFO  [p.s.j.jruby-puppet-core] Disabling i18n for puppet because using multithreaded jruby

*** LOCAL GEMS ***

aws-eventstream (1.1.1)
aws-sigv4 (1.2.3)
cmath (default: 1.0.0)
concurrent-ruby (1.1.5)
csv (default: 1.0.0)
debouncer (0.2.2)
deep_merge (1.0.1)
fast_gettext (1.1.2)
fileutils (default: 1.1.0)
gettext (3.2.2)
hiera-eyaml (3.2.1)
highline (2.0.3)
hocon (1.3.1)
ipaddr (default: 1.2.0)
jar-dependencies (default: 0.4.0)
jruby-openssl (default: 0.10.5 java)
jruby-readline (default: 1.3.7 java)
json (default: 2.2.0 java)
locale (2.1.3, 2.1.2)
multi_json (1.14.1)
optimist (3.0.1)
psych (default: 3.2.0 java)
puppet-resource_api (1.8.14)
puppetserver-ca (1.9.4)
rake-ant (default: 1.0.4)
rdoc (default: 6.1.2)
scanf (default: 1.0.0)
semantic_puppet (1.0.4, 1.0.2)
text (1.3.1)
vault (0.15.0)
webrick (default: 1.6.1)

and bonus

# /opt/puppetlabs/puppet/bin/gem list

*** LOCAL GEMS ***

aws-eventstream (1.1.1)
aws-sigv4 (1.2.3)
bigdecimal (default: 1.3.4)
cmath (default: 1.0.0)
colored2 (3.1.2)
concurrent-ruby (1.1.8)
cri (2.15.11)
csv (default: 1.0.0)
date (default: 1.0.0)
debouncer (0.2.2)
deep_merge (1.0.1)
did_you_mean (1.2.0)
etc (default: 1.0.0)
facter (3.14.18)
facter-ng (4.2.1)
faraday (0.17.4)
faraday_middleware (0.14.0)
fast_gettext (1.1.2)
fcntl (default: 1.0.0)
ffi (1.13.1)
fiddle (default: 1.0.0)
fileutils (default: 1.0.2)
gettext (3.2.2)
gettext-setup (0.34)
hiera (3.7.0)
hiera-eyaml (3.2.1)
highline (2.0.3)
hocon (1.3.1)
httpclient (2.8.3)
io-console (default: 0.4.6)
ipaddr (default: 1.2.0)
json (default: 2.1.0)
locale (2.1.3)
log4r (1.1.10)
minitar (0.9)
minitest (5.10.3)
multi_json (1.14.1)
multipart-post (2.1.1)
net-ssh (4.2.0)
net-telnet (0.1.1)
openssl (default: 2.1.2)
optimist (3.0.1)
power_assert (1.1.1)
psych (default: 3.0.2)
puppet (6.23.0)
puppet-resource_api (1.8.14)
puppet_forge (2.3.4)
puppetserver-ca (1.9.4)
r10k (3.8.0)
rake (12.3.3)
rdoc (default: 6.0.1.1)
scanf (default: 1.0.0)
sdbm (default: 1.0.0)
semantic_puppet (1.0.4)
stringio (default: 0.0.1)
strscan (default: 1.0.0)
sys-filesystem (1.3.2)
test-unit (3.2.7)
text (1.3.1)
thor (1.1.0)
thread (0.2.2)
vault (0.16.0)
webrick (default: 1.4.2.1)
xmlrpc (0.3.0)
zlib (default: 1.0.0)

[petems]

I was interested in the Vault version because there might be a specific change they've made on their side I'm not aware of (as right now the repo only tests against 1.0,1.1,1.2 and 1.3...

I'm seeing if I can setup a test environment with different versions of Vault and different JRuby versions to see what cipher issues there are

We've just merged a new feature that adds caching so that might help with some of the load issues, can you test that out?