Puppet 4 Upgrade - ENC issues with node.rb You need the `json` gem to use the Foreman ENC script

Hey All,

Working through a puppet 3 to 4 upgrade - having some interesting issues.

My puppetmasters seem to "work" in that when there is zero environment traffic (all agents off) - my manual puppet agent -t runs all complete without issue

Example:
[jlang1@<myhostname> ~]$ sudo puppet agent -t
Info: Using configured environment 'production'
Info: Retrieving pluginfacts
Info: Retrieving plugin
Info: Loading facts
Info: Caching catalog for fmnpmprh6.paychex.com
Info: Applying configuration version '28bf521'
Notice: Applied catalog in 8.52 seconds

As soon as I tell my agents to start checking in every 30 minutes - I begin getting intermittent errors like the following:

2017-11-28 10:52:09,343 ERROR [qtp530900165-1093] [puppetserver] Puppet Server Error: Failed when searching for node <myfqdn>: Failed to find <myfqdn> via exec: Execution of '/etc/puppetlabs/puppet/node.rb <myfqdn>' returned 2: You need the `json` gem to use the Foreman ENC script file:/opt/puppetlabs/server/apps/puppetserver/puppet-server-release.jar!/puppetserver-lib/puppet/server/execution.rb:44:in `execute' file:/opt/puppetlabs/server/apps/puppetserver/puppet-server-release.jar!/puppetserver-lib/puppet/server/execution.rb:14:in `initialize_execution_stub' org/jruby/RubyProc.java:281:in `call'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/execution.rb:194:in `execute' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/node/exec.rb:33:in `execute' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/exec.rb:19:in `find' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/node/exec.rb:17:in `find' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/indirection.rb:194:in `find' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/catalog/compiler.rb:295:in `find_node' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/profiler/around_profiler.rb:58:in `profile' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/profiler.rb:51:in `profile' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/catalog/compiler.rb:292:in `find_node' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/catalog/compiler.rb:332:in `node_from_request' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/catalog/compiler.rb:50:in `find' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/indirection.rb:194:in `find' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/api/indirected_routes.rb:121:in `do_find' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/api/indirected_routes.rb:48:in `call' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:293:in `override' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/api/indirected_routes.rb:47:in `call' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/route.rb:82:in `process' org/jruby/RubyArray.java:1613:in `each'
/opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/route.rb:81:in `process' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/route.rb:87:in `process' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/route.rb:87:in `process' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/handler.rb:60:in `process' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/profiler/around_profiler.rb:58:in `profile' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/profiler.rb:51:in `profile' /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/handler.rb:58:in `process' file:/opt/puppetlabs/server/apps/puppetserver/puppet-server-release.jar!/puppetserver-lib/puppet/server/master.rb:42:in `handleRequest' Puppet$$Server$$Master_1247237185.gen:13:in `handleRequest' request_handler_core.clj:273:in `invoke'
jruby_request.clj:46:in `invoke'
jruby_request.clj:31:in `invoke'
request_handler_service.clj:34:in `handle_request'
request_handler.clj:3:in `invoke'
request_handler.clj:3:in `invoke'
core.clj:2515:in `invoke'
master_core.clj:428:in `invoke'
ring.clj:21:in `invoke'
ring.clj:12:in `invoke'
comidi.clj:249:in `invoke'
ring_middleware.clj:284:in `invoke'
core.clj:168:in `invoke'
core.clj:211:in `invoke'
core.clj:45:in `invoke'
core.clj:343:in `invoke'
core.clj:51:in `invoke'
ringutils.clj:83:in `invoke'
legacy_routes_core.clj:114:in `invoke'
legacy_routes_core.clj:94:in `invoke'
legacy_routes_core.clj:184:in `invoke'
legacy_routes_core.clj:151:in `invoke'
ring.clj:21:in `invoke'
ring.clj:12:in `invoke'
comidi.clj:249:in `invoke'
jetty9_core.clj:424:in `invoke'
normalized_uri_helpers.clj:80:in `invoke'

Now - this happens about 70% of the time with the remainder of the runs completing as expected. Doesn't seem to be related to any specific puppet master (I have several). At the same time - I can execute /etc/puppetlabs/puppet/node.rb <myfqdn>' as the puppet user on these puppet masters and it will work correctly 100% of the time, which leaves me baffled. It seems to be related only to the puppet server. Specifically 4.9.4/2.7.2 (from 3.8.2) and only when its under "load" ?

[root@fmnpmprh4 puppetserver]# puppetserver --version
puppetserver version: 2.7.2
You have new mail in /var/spool/mail/root

Json rpm's installed are as follows:
[root@<mypuppetmaster> puppetserver]# rpm -qa | grep json
payx-multi_json-1.12.2-1.noarch
json-glib-1.0.2-1.el7.x86_64
rubygem-json-1.7.7-29.el7.x86_64
tfm-rubygem-rack-jsonp-1.3.1-5.el7.noarch
rh-ror41-rubygem-multi_json-1.8.4-2.el7.noarch
sclo-ror42-rubygem-multi_json-1.10.1-3.el7.noarch
tfm-rubygem-fog-json-1.0.2-4.el7.noarch
rh-ruby23-rubygem-json-1.8.3-64.el7.x86_64
ruby193-rubygem-multi_json-1.3.6-2.el7.noarch
json-c-0.11-4.el7_0.x86_64
rh-ruby22-rubygem-json-1.8.1-16.el7.x86_64
ruby193-rubygem-json-1.5.5-51.el7.x86_64
rubygem-multi_json-1.10.1-3.el7.noarch

My "test" environment is humming along just fine - but then again it doesn't have the load of the environment - and this seems load related? (~100 clients vs 11,200 clients)

Does anyone have any pointers/suggestions as to what to check? Or what might be causing this?

I did come across this: https://tickets.puppetlabs.com/browse/SERVER-1670 however this indicates it was "fixed" in 2.7.2?

Thanks in advance,

~Jason Lang

The information contained in this message may be privileged, confidential and protected from disclosure. If the reader of this message is not the intended recipient, or an employee or agent responsible for delivering this message to the intended recipient, you are hereby notified that any dissemination, distribution or copying of this communication is strictly prohibited. If you have received this communication in error, please notify your representative immediately and delete this message from your computer. Thank you.