This message was deleted.
# office-hours
s
This message was deleted.
b
do you use java 8 or 11 for puppetserver/puppetdb? Switch to java 11. configure reserved code cache to 2 GB. have at least 1 GB HEAP per jruby instance. If you have catalogs with 1500 or more resources, consider 1.5GB HEAP per jruby instance. running puppetserver 6? upgrade to 7.
if those quick changes won't fix the problems, we need to look closer at the actual errors and check the dashboard
j
• Right now we are using Java 8. • I've already updated the reserved code cache to 2GB. • Not sure about the HEAP setting for jruby instances. So I'll take a look at that. • We are already upgrade to puppetserver 7. I'll look into the Puppet Operational Dashboard. Seems like a useful tool.
b
the heap is set with -xmx and -xms for the whole jvm process
usually defined in /etc/sysconfig/puppetserver
šŸ‘ 1
or /etc/default/puppetservet
g
;;
r
@Justin Wyker, similar setup, about 3500 agents, one server. Around the time we crossed the 3000 agent threshold, I had the same problem. I set max-active-instances to
CPU - 1
and heap size to
1GB + (max-active-instances * 1GB)
and everything ran perfectly smoothly from then on. This is on a 16 CPU/ 64 GB RAM server. I could potentially downsize it after those tunings, but if it ain't broke...
this is still with java 8 (11 isn't available on this old platform)
j
Oh, awesome! Thanks @rusty I'll give that a try. Sounds like a very similar setup. Same server resources as well. šŸ™‚
@rusty Didn't end up resolving my issue. Back to the drawing board. Thanks anyways
r
Hrmm, are you using puppetdb (I am not). I also do not ship reports (network latency too high).
b
@Justin Wyker did you install the dashboard?
j
@bastelfreak - I'm just booting up my non-prod puppet server to try it out. I haven't actually had to install a puppet module on the server itself before. So going to try it out and see how it goes.
b
how do you usually install modules? r10k?
please don't use
puppet module install
j
Yeah, we usually have a Jenkin's pipeline that executes r10k to copy down some code from github. We typically don't manage any modules on the server itself though, kind of new territory for myself.
b
it's the same workflow for all modules
no matter which agent uses it
add the module to your Puppetfile, let Jenkins call r10k
r
jenkins triggered
b
and when do you see timeouts? every 30 minutes? once a week? does the puppetserver.log contain any errors? do you have splay enabled in your puppet.conf? If so: does it have the same value as runinterval?
j
Timeouts are intermittent but are becoming more and more prevalent. I would say they are occurring very consistently now effecting most puppet runs. The puppetserver.log does contain some timeout errors when attempting to generate catalogs. All of our devices have splay enabled, our runinterval is currently set at 30 minutes for all devices.
b
can you share the puppetserver.log parts?
and please verify if splay is set to 30min
j
Yeah, let me just grab the server log
Copy code
2023-03-17T18:14:20.650Z ERROR [qtp2059159079-263] [p.r.core] Internal Server Error: java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
	at org.eclipse.jetty.server.HttpInput$ErrorState.noContent(HttpInput.java:1083)
	at org.eclipse.jetty.server.HttpInput.read(HttpInput.java:321)
	at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:284)
	at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:326)
	at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:178)
	at java.io.InputStreamReader.read(InputStreamReader.java:184)
	at java.io.BufferedReader.fill(BufferedReader.java:161)
	at java.io.BufferedReader.read1(BufferedReader.java:212)
	at java.io.BufferedReader.read(BufferedReader.java:286)
	at java.io.Reader.read(Reader.java:140)
	at <http://clojure.java.io|clojure.java.io>$fn__11538.invokeStatic(io.clj:337)
	at <http://clojure.java.io|clojure.java.io>$fn__11538.invoke(io.clj:334)
	at clojure.lang.MultiFn.invoke(MultiFn.java:239)
	at <http://clojure.java.io|clojure.java.io>$copy.invokeStatic(io.clj:406)
	at <http://clojure.java.io|clojure.java.io>$copy.doInvoke(io.clj:391)
	at clojure.lang.RestFn.invoke(RestFn.java:425)
	at clojure.core$slurp.invokeStatic(core.clj:6951)
	at clojure.core$slurp.doInvoke(core.clj:6942)
	at clojure.lang.RestFn.invoke(RestFn.java:439)
	at puppetlabs.services.request_handler.request_handler_core$body_for_jruby.invokeStatic(request_handler_core.clj:78)
	at puppetlabs.services.request_handler.request_handler_core$body_for_jruby.invoke(request_handler_core.clj:54)
	at puppetlabs.services.request_handler.request_handler_core$wrap_params_for_jruby.invokeStatic(request_handler_core.clj:86)
	at puppetlabs.services.request_handler.request_handler_core$wrap_params_for_jruby.invoke(request_handler_core.clj:81)
	at puppetlabs.services.request_handler.request_handler_core$jruby_request_handler$fn__41590.invoke(request_handler_core.clj:269)
	at puppetlabs.puppetserver.jruby_request$wrap_with_jruby_instance$fn__36905.invoke(jruby_request.clj:49)
	at puppetlabs.puppetserver.jruby_request$wrap_with_error_handling$fn__36901.invoke(jruby_request.clj:34)
	at puppetlabs.services.request_handler.request_handler_service$reify__41615$service_fnk__5011__auto___positional$reify__41630.handle_request(request_handler_service.clj:47)
	at puppetlabs.services.protocols.request_handler$fn__41528$G__41524__41531.invoke(request_handler.clj:3)
	at puppetlabs.services.protocols.request_handler$fn__41528$G__41523__41535.invoke(request_handler.clj:3)
	at clojure.core$partial$fn__5839.invoke(core.clj:2624)
	at puppetlabs.trapperkeeper.authorization.ring_middleware$fn__26381$wrap_authorization_check__26386$fn__26387$fn__26388.invoke(ring_middleware.clj:290)
	at puppetlabs.ring_middleware.core$fn__23841$wrap_bad_request__23850$fn__23853$fn__23859.invoke(core.clj:187)
	at puppetlabs.ring_middleware.core$fn__23939$wrap_uncaught_errors__23948$fn__23951$fn__23956.invoke(core.clj:233)
	at puppetlabs.ring_middleware.core$fn__23509$wrap_request_logging__23514$fn__23515$fn__23517.invoke(core.clj:47)
	at puppetlabs.i18n.core$locale_negotiator$fn__124.invoke(core.clj:357)
	at puppetlabs.ring_middleware.core$fn__23538$wrap_response_logging__23543$fn__23544$fn__23545.invoke(core.clj:53)
	at puppetlabs.puppetserver.ringutils$wrap_with_puppet_version_header$fn__37154.invoke(ringutils.clj:83)
	at puppetlabs.services.master.master_core$fn__43100$v3_ruby_routes__43105$fn__43106$fn__43123.invoke(master_core.clj:1175)
	at bidi.ring$fn__17722.invokeStatic(ring.cljc:25)
	at bidi.ring$fn__17722.invoke(ring.cljc:21)
	at bidi.ring$fn__17707$G__17702__17716.invoke(ring.cljc:16)
	at puppetlabs.comidi$make_handler$fn__19638.invoke(comidi.clj:245)
	at puppetlabs.metrics.http$fn__41883$wrap_with_request_metrics__41888$fn__41892$fn__41894$fn__41895$fn__41896.invoke(http.clj:152)
	at puppetlabs.metrics.http.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
	at com.codahale.metrics.Timer.time(Timer.java:101)
	at puppetlabs.metrics.http$fn__41883$wrap_with_request_metrics__41888$fn__41892$fn__41894$fn__41895.invoke(http.clj:152)
	at puppetlabs.metrics.http.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source)
	at com.codahale.metrics.Timer.time(Timer.java:101)
	at puppetlabs.metrics.http$fn__41883$wrap_with_request_metrics__41888$fn__41892$fn__41894.invoke(http.clj:148)
	at puppetlabs.comidi$fn__19703$wrap_with_route_metadata__19708$fn__19709$fn__19711.invoke(comidi.clj:332)
	at puppetlabs.trapperkeeper.services.webserver.jetty9_core$ring_handler$fn__29738.invoke(jetty9_core.clj:455)
	at puppetlabs.trapperkeeper.services.webserver.jetty9_core.proxy$org.eclipse.jetty.server.handler.AbstractHandler$ff19274a.handle(Unknown Source)
	at sun.reflect.GeneratedMethodAccessor13.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at clojure.lang.Reflector.invokeMatchingMethod(Reflector.java:167)
	at clojure.lang.Reflector.invokeInstanceMethod(Reflector.java:102)
	at puppetlabs.trapperkeeper.services.webserver.normalized_uri_helpers$fn__29308$normalize_uri_handler__29313$fn__29314$fn__29315.invoke(normalized_uri_helpers.clj:74)
	at puppetlabs.trapperkeeper.services.webserver.normalized_uri_helpers.proxy$org.eclipse.jetty.server.handler.HandlerWrapper$ff19274a.handle(Unknown Source)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:235)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1363)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:190)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1278)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:221)
	at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:146)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:767)
	at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:54)
	at com.puppetlabs.trapperkeeper.services.webserver.jetty9.utils.MDCRequestLogHandler.handle(MDCRequestLogHandler.java:36)
	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:173)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:500)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:383)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:547)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:375)
	at org.eclipse.jetty.server.HttpChannel.run(HttpChannel.java:335)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
	at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:171)
	at org.eclipse.jetty.io.IdleTimeout.idleCheck(IdleTimeout.java:113)
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	... 1 more
	Suppressed: java.lang.Throwable: HttpInput idle timeout
		at org.eclipse.jetty.server.HttpInput.onIdleTimeout(HttpInput.java:801)
		at org.eclipse.jetty.server.HttpChannelOverHttp.onIdleTimeout(HttpChannelOverHttp.java:406)
		at org.eclipse.jetty.server.HttpConnection.onReadTimeout(HttpConnection.java:495)
		at org.eclipse.jetty.io.AbstractConnection.onFillInterestedFailed(AbstractConnection.java:172)
		at org.eclipse.jetty.server.HttpConnection.onFillInterestedFailed(HttpConnection.java:502)
		at org.eclipse.jetty.io.AbstractConnection$ReadCallback.failed(AbstractConnection.java:317)
		at org.eclipse.jetty.io.FillInterest.onFail(FillInterest.java:138)
		at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillableFail(SslConnection.java:579)
		at org.eclipse.jetty.io.ssl.SslConnection.onFillInterestedFailed(SslConnection.java:407)
		at org.eclipse.jetty.io.ssl.SslConnection$2.failed(SslConnection.java:167)
		at org.eclipse.jetty.io.FillInterest.onFail(FillInterest.java:138)
		at org.eclipse.jetty.io.AbstractEndPoint.onIdleExpired(AbstractEndPoint.java:407)
		... 9 more
b
I guess that from time to time more agents hit the server than you've free jruby instances
how many jruby instances do you have? 2500 nodes is quite a lot fora single puppetserver (if runinterval is 30min and the catalogs are big/take long to compile)
j
We just set the max active instances to 15 yesterday to see if that alleviates any issues, but it didn't. šŸ˜ž
b
I bet that's too low when splay isn't working perfectly
so what's the splay/runinterval?
j
Splay is set to 10 minutes, and the runinterval is currently 30 minutes for our agents.
b
that means that if you restart all your servers at the same time, all puppet will hit the puppserver within 10 minutes
āœ… 1
I highly recommend setting splay to the same value as runinterval
j
Oh, is that common practice?
b
yes
let's say you've 2500 nodes and runinterval is 30 minutes. that's 83 catalogs a minute. spread across 15 jruby instances that's 5 catalogs per jruby instance per minute
now it highly depends on how big your catalog is. some can be compiled in 5 seconds, some take a minute. puppetserver.log logs the compilation time
but even when your agents are perfectly distributed across the 30 minutes, each compilation needs to stay below 60/5=12 seconds
the dashboard will tell you how many jruby instances are requested and how many free instances you have. I guess there's a bottleneck. it will get better when changing splay to 30min. but it maybe won't fix the problem
there's always the possibility that my math is wrong šŸ˜„
also: switch to java 11 please