puppetdb 2 : Idle timeout expired: 30000/30000 ms
2,021 views
Skip to first unread message
Sergey Arlashin
May 20, 2014, 1:02:53 AM5/20/14
to puppet...@googlegroups.com
Hi!
Every now and then I get the following error while running puppet agent.
Error: Could not retrieve catalog from remote server: Error 400 on SERVER: Failed to submit 'replace catalog' command for prod2.site to PuppetDB at puppet.site:8081: [500 java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms] <html><head><meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/><title>Error 500 </title></head><body><h2>HTTP ERROR: 500</h2><p>Problem accessing /v3/commands. Reason:<pre> java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms</pre></p><hr /><i><small>Powered by Jetty://</small></i></body></html>
Does anybody know how I can get rid of this error?
Thanks in advance!
--
Best regards,
Sergey Arlashin
Every now and then I get the following error while running puppet agent.
Error: Could not retrieve catalog from remote server: Error 400 on SERVER: Failed to submit 'replace catalog' command for prod2.site to PuppetDB at puppet.site:8081: [500 java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms] <html><head><meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/><title>Error 500 </title></head><body><h2>HTTP ERROR: 500</h2><p>Problem accessing /v3/commands. Reason:<pre> java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms</pre></p><hr /><i><small>Powered by Jetty://</small></i></body></html>
Does anybody know how I can get rid of this error?
Thanks in advance!
--
Best regards,
Sergey Arlashin
Spencer Krum
May 20, 2014, 1:38:50 AM5/20/14
to puppet...@googlegroups.com
This looks like a puppetdb error. Can you check the PuppetDB logs and post any relevant errors?
Thanks,Spencer
--
You received this message because you are subscribed to the Google Groups "Puppet Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to puppet-users...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/8A2FC518-6B42-42D5-8524-12D39B94DBD4%40gmail.com.
For more options, visit https://groups.google.com/d/optout.
--
Spencer Krum
(619)-980-7820
Sergey Arlashin
May 20, 2014, 1:43:17 AM5/20/14
to puppet...@googlegroups.com
2014-05-20 05:34:36,684 INFO [c.p.p.command] [e806b0a2-7703-4a4a-8107-65cd2c0db9a8] [replace facts] prod1.site
2014-05-20 05:34:44,112 INFO [c.p.p.command] [e8cb3511-9734-4ba7-b040-96f663404c00] [replace facts] redmine.site
2014-05-20 05:34:45,387 INFO [c.p.p.command] [9026d779-3a43-4c06-a23d-aeefd4eb6e1f] [replace catalog] redmine.site
2014-05-20 05:34:47,487 INFO [c.p.p.command] [1234e95c-e254-4b1d-b46f-8ef5b07e9158] [replace facts] www-node1.site
2014-05-20 05:34:48,350 INFO [c.p.p.command] [56be0dc9-03b9-45b8-8b8a-527f1c25e057] [replace facts] dev01.site
2014-05-20 05:34:48,404 INFO [c.p.p.command] [17474841-6043-46cf-98a1-122f116d5cd6] [replace facts] parser1.site
2014-05-20 05:34:48,634 INFO [c.p.p.command] [44da2889-811f-4e80-8190-ad7313f0ca81] [replace facts] dev02.site
2014-05-20 05:34:48,942 INFO [c.p.p.command] [4080aa24-23c7-4f16-9011-2104a457e201] [replace catalog] www-node1.site
2014-05-20 05:34:51,429 INFO [c.p.p.command] [6b62c283-f306-44e7-8101-4948110e3d78] [replace catalog] dev01.site
2014-05-20 05:34:51,437 INFO [c.p.p.command] [55fb7348-3b36-4c5a-9265-61ca3c1f55c3] [replace catalog] dev02.site
2014-05-20 05:34:52,925 INFO [c.p.p.command] [9ace137e-f708-4656-829a-92de7722b388] [replace facts] lb-node1.site
2014-05-20 05:34:55,017 INFO [c.p.p.command] [0b6e6592-97f2-4b8a-8cc7-6d321793d2ed] [replace catalog] lb-node1.site
2014-05-20 05:34:58,285 INFO [c.p.p.command] [971285dd-b141-4f44-a6d0-375aa3af830a] [replace facts] lb-node2.site
2014-05-20 05:34:59,333 INFO [c.p.p.command] [3977fc34-aa41-43e7-8eb9-ef5398dc3567] [replace facts] www-node2.site
2014-05-20 05:35:01,625 INFO [c.p.p.command] [f095ef50-4b71-41d6-ba83-6dd4a0030fe2] [replace facts] parser2.site
2014-05-20 05:35:02,107 INFO [c.p.p.command] [539a78de-1743-4135-adeb-c5ed3b43cc24] [replace catalog] lb-node2.site
2014-05-20 05:35:02,379 INFO [c.p.p.command] [f4b7fc4d-cccd-4fb9-881e-da4007d57f6e] [replace facts] monitor.site
2014-05-20 05:35:03,945 INFO [c.p.p.command] [f49a6fcd-ca63-49eb-bbec-7712ba590675] [replace catalog] www-node2.site
2014-05-20 05:35:05,350 INFO [c.p.p.command] [6913aceb-0d60-4701-9d31-d84af8f92374] [replace facts] db-node1.site
2014-05-20 05:35:05,587 INFO [c.p.p.command] [bd9796df-e989-4788-addc-d31f2d2dda3a] [replace catalog] monitor.site
2014-05-20 05:35:05,848 INFO [c.p.p.command] [f9215b15-f646-403a-b4d3-21fd532e1c06] [replace facts] puppet.site
2014-05-20 05:35:05,871 INFO [c.p.p.command] [7820d545-1c5f-4b0f-a2e8-0dcbc12d4571] [replace facts] db-node2.site
2014-05-20 05:35:07,642 WARN [o.e.j.s.HttpChannel] /v3/commands?checksum=e51aa526e2236306cff22ef33c8cb4467166f9c0
java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 30002/30000 ms
at org.eclipse.jetty.util.BlockingCallback.block(BlockingCallback.java:101) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.HttpInputOverHTTP.blockForContent(HttpInputOverHTTP.java:62) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.HttpInput$1.waitForContent(HttpInput.java:392) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.HttpInput.read(HttpInput.java:161) ~[puppetdb.jar:na]
at sun.nio.cs.StreamDecoder.readBytes(StreamDecoder.java:283) ~[na:1.7.0_55]
at sun.nio.cs.StreamDecoder.implRead(StreamDecoder.java:325) ~[na:1.7.0_55]
at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:177) ~[na:1.7.0_55]
at java.io.InputStreamReader.read(InputStreamReader.java:184) ~[na:1.7.0_55]
at java.io.BufferedReader.fill(BufferedReader.java:154) ~[na:1.7.0_55]
at java.io.BufferedReader.read(BufferedReader.java:175) ~[na:1.7.0_55]
at clojure.core$slurp.doInvoke(core.clj:6396) ~[puppetdb.jar:na]
at clojure.lang.RestFn.invoke(RestFn.java:410) ~[puppetdb.jar:na]
at ring.util.request$eval10113$fn__10114.invoke(request.clj:30) ~[na:na]
at clojure.lang.MultiFn.invoke(MultiFn.java:227) ~[puppetdb.jar:na]
at com.puppetlabs.middleware$payload_to_body_string$fn__10429.invoke(middleware.clj:273) ~[na:na]
at com.puppetlabs.middleware$verify_content_type$fn__10379.invoke(middleware.clj:128) ~[na:na]
at com.puppetlabs.puppetdb.http.v3$v3_app$fn__11827.invoke(v3.clj:23) ~[na:na]
at com.puppetlabs.puppetdb.http.v3$v3_app.invoke(v3.clj:21) ~[na:na]
at com.puppetlabs.puppetdb.http.server$routes$fn__12370.invoke(server.clj:47) ~[na:na]
at net.cgrand.moustache$alter_request$fn__10771.invoke(moustache.clj:54) ~[na:na]
at com.puppetlabs.puppetdb.http.server$routes.invoke(server.clj:47) ~[na:na]
at ring.middleware.resource$wrap_resource$fn__12339.invoke(resource.clj:24) ~[na:na]
at ring.middleware.params$wrap_params$fn__10714.invoke(params.clj:58) ~[na:na]
at com.puppetlabs.middleware$wrap_with_authorization$fn__10346.invoke(middleware.clj:40) ~[na:na]
at com.puppetlabs.middleware$wrap_with_certificate_cn$fn__10350.invoke(middleware.clj:55) ~[na:na]
at com.puppetlabs.middleware$wrap_with_default_body$fn__10354.invoke(middleware.clj:62) ~[na:na]
at com.puppetlabs.middleware$wrap_with_metrics_STAR_$fn__10401$fn__10410.invoke(middleware.clj:207) ~[na:na]
at com.puppetlabs.utils.metrics$multitime_BANG__STAR_$fn__10068$fn__10069$fn__10070.invoke(metrics.clj:14) ~[na:na]
at com.puppetlabs.utils.metrics.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source) ~[na:na]
at com.yammer.metrics.core.Timer.time(Timer.java:91) ~[puppetdb.jar:na]
at com.puppetlabs.utils.metrics$multitime_BANG__STAR_$fn__10068$fn__10069.invoke(metrics.clj:14) ~[na:na]
at com.puppetlabs.utils.metrics$multitime_BANG__STAR_$fn__10068$fn__10069$fn__10070.invoke(metrics.clj:14) ~[na:na]
at com.puppetlabs.utils.metrics.proxy$java.lang.Object$Callable$7da976d4.call(Unknown Source) ~[na:na]
at com.yammer.metrics.core.Timer.time(Timer.java:91) ~[puppetdb.jar:na]
at com.puppetlabs.utils.metrics$multitime_BANG__STAR_$fn__10068$fn__10069.invoke(metrics.clj:14) ~[na:na]
at com.puppetlabs.utils.metrics$multitime_BANG__STAR_.invoke(metrics.clj:17) ~[na:na]
at com.puppetlabs.middleware$wrap_with_metrics_STAR_$fn__10401.invoke(middleware.clj:206) ~[na:na]
at com.puppetlabs.middleware$wrap_with_globals$fn__10358.invoke(middleware.clj:73) ~[na:na]
at com.puppetlabs.middleware$wrap_with_debug_logging$fn__10342.invoke(middleware.clj:27) ~[na:na]
at puppetlabs.trapperkeeper.services.webserver.jetty9_core$proxy_handler$fn__16765.invoke(jetty9_core.clj:66) ~[na:na]
at puppetlabs.trapperkeeper.services.webserver.jetty9_core.proxy$org.eclipse.jetty.server.handler.AbstractHandler$ff19274a.handle(Unknown Source) ~[na:na]
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1112) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1048) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:199) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:109) ~[puppetdb.jar:na]
at org.eclipse.jetty.servlets.gzip.GzipHandler.handle(GzipHandler.java:325) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.Server.handle(Server.java:459) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:280) ~[puppetdb.jar:na]
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:229) [puppetdb.jar:na]
at org.eclipse.jetty.io.AbstractConnection$1.run(AbstractConnection.java:505) [puppetdb.jar:na]
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:607) [puppetdb.jar:na]
at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:536) [puppetdb.jar:na]
at java.lang.Thread.run(Thread.java:744) [na:1.7.0_55]
Caused by: java.util.concurrent.TimeoutException: Idle timeout expired: 30002/30000 ms
at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:153) ~[puppetdb.jar:na]
at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50) ~[puppetdb.jar:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) ~[na:1.7.0_55]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_55]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) ~[na:1.7.0_55]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) ~[na:1.7.0_55]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_55]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_55]
... 1 common frames omitted
To view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/CADt6FWNbXASsOh6_hzcSQAeJjzu8cZYTPG4qkYxTBoe%2B6heLtw%40mail.gmail.com.
Sergey Arlashin
May 20, 2014, 7:41:11 AM5/20/14
to puppet...@googlegroups.com
Here is described http://www.eclipse.org/jetty/documentation/current/configuring-connectors.html how idle timeout for jetty cat be configured . But I don't know how to apply this for puppetdb :(
Does anybody have any ideas ?
Ken Barber
May 20, 2014, 9:03:59 AM5/20/14
to Puppet Users
We don't expose the idle timeout parameter for users to modify.
I am curious though, what happens when you increase max-threads in
your jetty.ini to something like 200?
ken.
On Tue, May 20, 2014 at 12:41 PM, Sergey Arlashin
> https://groups.google.com/d/msgid/puppet-users/FFF9F6EE-8B3A-48E4-A78B-42932EF41A3B%40gmail.com.
I am curious though, what happens when you increase max-threads in
your jetty.ini to something like 200?
ken.
On Tue, May 20, 2014 at 12:41 PM, Sergey Arlashin
Ken Barber
May 20, 2014, 9:19:45 AM5/20/14
to Puppet Users
Also ... I'd be curious to know what exact version of the JVM you are running.
I'm cautious this is a jetty bug of some kind, perhaps we can ship a
new Jar with a later version of Jetty to you and see if that helps.
ken.
I'm cautious this is a jetty bug of some kind, perhaps we can ship a
new Jar with a later version of Jetty to you and see if that helps.
ken.
Sergey Arlashin
May 20, 2014, 11:27:05 AM5/20/14
to puppet...@googlegroups.com
Unfortunately setting max-threads to 200 did not help.
# java -version
java version "1.7.0_55"
OpenJDK Runtime Environment (IcedTea 2.4.7) (7u55-2.4.7-1ubuntu1~0.12.04.2)
OpenJDK 64-Bit Server VM (build 24.51-b03, mixed mode)
# dpkg -l |grep -i java
ii ca-certificates-java 20110912ubuntu6 Common CA certificates (JKS keystore)
ii java-common 0.43ubuntu2 Base of all Java packages
ii libjs-jquery 1.7.1-1ubuntu1 JavaScript library for dynamic web applications
ii openjdk-7-jre-headless 7u55-2.4.7-1ubuntu1~0.12.04.2 OpenJDK Java runtime, using Hotspot JIT (headless)
ii tzdata-java 2014c-0ubuntu0.12.04 time zone and daylight-saving time data for use by java runtimes
This is a fresh output in logs:
2014-05-20 15:21:52,331 INFO [p.t.s.w.jetty9-service] Initializing web server.
2014-05-20 15:21:52,403 INFO [p.t.s.w.jetty9-service] Starting web server.
2014-05-20 15:21:52,406 INFO [o.e.j.s.Server] jetty-9.1.z-SNAPSHOT
2014-05-20 15:21:52,436 INFO [o.e.j.s.ServerConnector] Started ServerConnector@2557ce03{HTTP/1.1}{localhost:8080}
2014-05-20 15:21:52,504 INFO [o.e.j.s.ServerConnector] Started ServerConnector@253e73c6{SSL-HTTP/1.1}{puppet.site:8081}
2014-05-20 15:21:52,563 INFO [c.p.p.c.services] PuppetDB version 2.0.0
2014-05-20 15:21:52,704 INFO [c.p.p.c.services] Starting broker
2014-05-20 15:21:53,581 WARN [o.a.a.b.BrokerService] Store limit is 100000 mb, whilst the data directory: /var/lib/puppetdb/mq/localhost/KahaDB only has 63697 mb of usable space
2014-05-20 15:21:53,582 INFO [c.p.p.c.services] Starting 4 command processor threads
2014-05-20 15:21:53,602 INFO [c.p.p.c.services] Starting query server
2014-05-20 15:21:53,605 WARN [o.e.j.s.h.ContextHandler] Empty contextPath
2014-05-20 15:21:53,617 INFO [o.e.j.s.h.ContextHandler] Started o.e.j.s.h.ContextHandler@31771aa1{/,null,AVAILABLE}
2014-05-20 15:21:53,643 INFO [c.p.p.c.services] Starting sweep of stale reports (threshold: 14 days)
2014-05-20 15:21:53,667 INFO [c.p.p.c.services] Finished sweep of stale reports (threshold: 14 days)
2014-05-20 15:21:53,667 INFO [c.p.p.c.services] Starting database garbage collection
2014-05-20 15:21:53,698 INFO [c.p.p.c.services] Finished database garbage collection
2014-05-20 15:22:05,832 INFO [c.p.p.command] [ce2e1e6e-5bc8-4f0a-bb20-e1edd153038d] [replace facts] prod1.site
2014-05-20 15:22:36,859 WARN [o.e.j.s.HttpChannel] /v3/commands?checksum=7b886250b6f4ff03643ca1a82ff38476b015ec02
java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
Caused by: java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
> To view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/CAE4bNT%3D0SGVVbO%2Bevm6f3HYBx0RZSZMdmW1UYALHc-6Xk1isqA%40mail.gmail.com.
# java -version
java version "1.7.0_55"
OpenJDK Runtime Environment (IcedTea 2.4.7) (7u55-2.4.7-1ubuntu1~0.12.04.2)
OpenJDK 64-Bit Server VM (build 24.51-b03, mixed mode)
# dpkg -l |grep -i java
ii ca-certificates-java 20110912ubuntu6 Common CA certificates (JKS keystore)
ii java-common 0.43ubuntu2 Base of all Java packages
ii libjs-jquery 1.7.1-1ubuntu1 JavaScript library for dynamic web applications
ii openjdk-7-jre-headless 7u55-2.4.7-1ubuntu1~0.12.04.2 OpenJDK Java runtime, using Hotspot JIT (headless)
ii tzdata-java 2014c-0ubuntu0.12.04 time zone and daylight-saving time data for use by java runtimes
This is a fresh output in logs:
2014-05-20 15:21:52,331 INFO [p.t.s.w.jetty9-service] Initializing web server.
2014-05-20 15:21:52,403 INFO [p.t.s.w.jetty9-service] Starting web server.
2014-05-20 15:21:52,406 INFO [o.e.j.s.Server] jetty-9.1.z-SNAPSHOT
2014-05-20 15:21:52,436 INFO [o.e.j.s.ServerConnector] Started ServerConnector@2557ce03{HTTP/1.1}{localhost:8080}
2014-05-20 15:21:52,504 INFO [o.e.j.s.ServerConnector] Started ServerConnector@253e73c6{SSL-HTTP/1.1}{puppet.site:8081}
2014-05-20 15:21:52,563 INFO [c.p.p.c.services] PuppetDB version 2.0.0
2014-05-20 15:21:52,704 INFO [c.p.p.c.services] Starting broker
2014-05-20 15:21:53,581 WARN [o.a.a.b.BrokerService] Store limit is 100000 mb, whilst the data directory: /var/lib/puppetdb/mq/localhost/KahaDB only has 63697 mb of usable space
2014-05-20 15:21:53,582 INFO [c.p.p.c.services] Starting 4 command processor threads
2014-05-20 15:21:53,602 INFO [c.p.p.c.services] Starting query server
2014-05-20 15:21:53,605 WARN [o.e.j.s.h.ContextHandler] Empty contextPath
2014-05-20 15:21:53,617 INFO [o.e.j.s.h.ContextHandler] Started o.e.j.s.h.ContextHandler@31771aa1{/,null,AVAILABLE}
2014-05-20 15:21:53,643 INFO [c.p.p.c.services] Starting sweep of stale reports (threshold: 14 days)
2014-05-20 15:21:53,667 INFO [c.p.p.c.services] Finished sweep of stale reports (threshold: 14 days)
2014-05-20 15:21:53,667 INFO [c.p.p.c.services] Starting database garbage collection
2014-05-20 15:21:53,698 INFO [c.p.p.c.services] Finished database garbage collection
2014-05-20 15:22:05,832 INFO [c.p.p.command] [ce2e1e6e-5bc8-4f0a-bb20-e1edd153038d] [replace facts] prod1.site
2014-05-20 15:22:36,859 WARN [o.e.j.s.HttpChannel] /v3/commands?checksum=7b886250b6f4ff03643ca1a82ff38476b015ec02
java.io.IOException: java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:153) ~[puppetdb.jar:na]
at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50) ~[puppetdb.jar:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) ~[na:1.7.0_55]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_55]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) ~[na:1.7.0_55]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) ~[na:1.7.0_55]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_55]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_55]
... 1 common frames omitted
Also I noticed that it happens only to some particular hosts. Some of our puppet agents run without any problems. So may be this is a client related issue?
at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50) ~[puppetdb.jar:na]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) ~[na:1.7.0_55]
at java.util.concurrent.FutureTask.run(FutureTask.java:262) ~[na:1.7.0_55]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:178) ~[na:1.7.0_55]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:292) ~[na:1.7.0_55]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145) ~[na:1.7.0_55]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615) ~[na:1.7.0_55]
... 1 common frames omitted
Phil Fenstermacher
May 21, 2014, 9:45:32 AM5/21/14
to puppet...@googlegroups.com
I encountered this same issue yesterday, and unfortunately haven't found a fix either.
The error seems to be happening whenever I use the php::fpm::conf resource (with ensure => present) from https://forge.puppetlabs.com/thias/php. Removing that resource, or setting ensure to abset makes everything work fine. That resource is essentially only creating a file resource from a large template (https://github.com/thias/puppet-php/blob/master/manifests/fpm/conf.pp).
I tried setting max-threads to 200 as well without any luck.
Ken Barber
May 21, 2014, 9:53:42 AM5/21/14
to Puppet Users
Catalogue size might be a factor, as templates get stored in the catalogue.
> https://groups.google.com/d/msgid/puppet-users/779715c6-471a-4540-b641-18900ec235d5%40googlegroups.com.
Phil Fenstermacher
May 21, 2014, 12:01:38 PM5/21/14
to puppet...@googlegroups.com
Running tcpdump filtering on port 8081 renders a pcap file of about ~350K. The template is only 20K, so large here is probably somewhat relative.
Any other thoughts?
Just for reference, I'm running the same version of Java as Sergey:
java version "1.7.0_55"
OpenJDK Runtime Environment (IcedTea 2.4.7) (7u55-2.4.7-1ubuntu1~0.12.04.2)
OpenJDK 64-Bit Server VM (build 24.51-b03, mixed mode)
Ken Barber
May 21, 2014, 12:29:06 PM5/21/14
to Puppet Users
So one thing I'm sure about - is that there was no idle timeout
defined in 1.6.3 at all. I can connect idle for quite some time for
example. Its quite possible that there is another delay/lag somewhere
causing the connection to be idle in the first place - but with 1.6.3
this would not have surfaced for example as a server error, because
there was no idle handling.
ken.
On Wed, May 21, 2014 at 5:01 PM, Phil Fenstermacher
> https://groups.google.com/d/msgid/puppet-users/17ac6a1b-5803-4e7a-b2b5-1a5d43261802%40googlegroups.com.
defined in 1.6.3 at all. I can connect idle for quite some time for
example. Its quite possible that there is another delay/lag somewhere
causing the connection to be idle in the first place - but with 1.6.3
this would not have surfaced for example as a server error, because
there was no idle handling.
ken.
On Wed, May 21, 2014 at 5:01 PM, Phil Fenstermacher
Ken Barber
May 21, 2014, 1:41:50 PM5/21/14
to Puppet Users
Phil,
Do you happen to have a tcpdump I can look at, one where this problem
is replicated? I know its SSL - but I'm primarily interested in seeing
when (and _IF_) the network connection goes idle - so packet timing is
more important to me then content. I'm trying to prove/disprove that
idletimeout is doing the correct thing here or not. It could be that
the idling is caused by something else, and the timeout is valid - or
it could be that the idletimeout is not actually paying attention to
traffic (which I can't prove locally at least for cleartext - it seems
fine).
There is also a chance the idling could be after traffic is submitted,
which would make things even more interesting. Either way I'd like
some external confirmation of this reported 'idling' and the best way
is probably via tcpdump's. If we can prove the idle timeout is correct
in its behaviour, we can stop looking at Jetty as the cause, which
helps us a lot.
If you want to chat I'm on Freenode in #puppet (ken_barber).
My colleague in the meantime is trying to upgrade us to Jetty 9.1.5
(from 9.1.0), its a non-trivial upgrade though, which sucks when under
duress. We're also looking at introducing the idle-timeout setting so
we can play with that also, potentially as a work-around for now.
ken.
Do you happen to have a tcpdump I can look at, one where this problem
is replicated? I know its SSL - but I'm primarily interested in seeing
when (and _IF_) the network connection goes idle - so packet timing is
more important to me then content. I'm trying to prove/disprove that
idletimeout is doing the correct thing here or not. It could be that
the idling is caused by something else, and the timeout is valid - or
it could be that the idletimeout is not actually paying attention to
traffic (which I can't prove locally at least for cleartext - it seems
fine).
There is also a chance the idling could be after traffic is submitted,
which would make things even more interesting. Either way I'd like
some external confirmation of this reported 'idling' and the best way
is probably via tcpdump's. If we can prove the idle timeout is correct
in its behaviour, we can stop looking at Jetty as the cause, which
helps us a lot.
If you want to chat I'm on Freenode in #puppet (ken_barber).
My colleague in the meantime is trying to upgrade us to Jetty 9.1.5
(from 9.1.0), its a non-trivial upgrade though, which sucks when under
duress. We're also looking at introducing the idle-timeout setting so
we can play with that also, potentially as a work-around for now.
ken.
Ken Barber
May 21, 2014, 3:54:26 PM5/21/14
to Puppet Users
Phil and I have been conversing offline ... we found that downgrading
the terminus to 1.6.3 (not PuppetDB) fixes the issue. So far we can
see that a submission occurs but the server does not respond. This is
synonymous with a bad Content-Length, and certainly I'm able to
replicate this with some basic tests ... but we're still looking for
the ultimate cause of this.
For now can everyone who is seeing this issue, try downgrading their
puppetdb-terminus package to 1.6.3, and see if it solves it?
ken.
the terminus to 1.6.3 (not PuppetDB) fixes the issue. So far we can
see that a submission occurs but the server does not respond. This is
synonymous with a bad Content-Length, and certainly I'm able to
replicate this with some basic tests ... but we're still looking for
the ultimate cause of this.
For now can everyone who is seeing this issue, try downgrading their
puppetdb-terminus package to 1.6.3, and see if it solves it?
ken.
Sergey Arlashin
May 22, 2014, 12:06:57 AM5/22/14
to puppet...@googlegroups.com
Yesterday I downgraded both puppet to 3.5.1 and pupetdb to 1.6.3, and the problem disappeared. Unfortunately this is production infrastructure and I don't have an ability to test it further :(
> To view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/CAE4bNTk%3D4drjWmY_q_VxX%3DXLeXxU3Z3BJgPJSeeavMEHF7r13A%40mail.gmail.com.
Ken Barber
May 22, 2014, 8:54:04 AM5/22/14
to Puppet Users
Sergey,
Are you by any chance running Ubuntu 12.04 with the 3 year old Ruby
1.9.3-p0? If not what distro and exact ruby version are you running?
ken.
On Thu, May 22, 2014 at 5:06 AM, Sergey Arlashin
> To view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/4FE1FBB9-D7CC-4525-946B-2838A9EF1E3E%40gmail.com.
Are you by any chance running Ubuntu 12.04 with the 3 year old Ruby
1.9.3-p0? If not what distro and exact ruby version are you running?
ken.
On Thu, May 22, 2014 at 5:06 AM, Sergey Arlashin
Ken Barber
May 22, 2014, 9:26:45 AM5/22/14
to Puppet Users
I've been able to replicate this now for those following along at
home. It seems to be that Ubuntu 12.04 and ruby-1.9.3-p0 exhibits this
bug, which on the surface seems to be a bug in calculating the
Content-Length for the POST submission header, but I haven't
completely confirmed this.
Updating my alternatives to use the ruby-1.8.7 package makes it work
now. Another fix is to grab the latest ruby-1.9.3 package from
brightbox, but I'm guessing this is less than desirable for most
people.
Anyway I'm thinking this is a bug in Net::HTTP in p0 (it was released
in 2011 - https://www.ruby-lang.org/en/news/2011/10/31/ruby-1-9-3-p0-is-released/,
so no surprises here).
We're going to try and work-around the bug in our terminus code now
that we can replicate it.
ken.
home. It seems to be that Ubuntu 12.04 and ruby-1.9.3-p0 exhibits this
bug, which on the surface seems to be a bug in calculating the
Content-Length for the POST submission header, but I haven't
completely confirmed this.
Updating my alternatives to use the ruby-1.8.7 package makes it work
now. Another fix is to grab the latest ruby-1.9.3 package from
brightbox, but I'm guessing this is less than desirable for most
people.
Anyway I'm thinking this is a bug in Net::HTTP in p0 (it was released
in 2011 - https://www.ruby-lang.org/en/news/2011/10/31/ruby-1-9-3-p0-is-released/,
so no surprises here).
We're going to try and work-around the bug in our terminus code now
that we can replicate it.
ken.
Sergey Arlashin
May 22, 2014, 9:39:53 AM5/22/14
to puppet...@googlegroups.com
On May 22, 2014, at 4:54 PM, Ken Barber <k...@puppetlabs.com> wrote:
> Sergey,
>
> Are you by any chance running Ubuntu 12.04 with the 3 year old Ruby
> 1.9.3-p0? If not what distro and exact ruby version are you running?
>
# cat /etc/issue
Ubuntu 12.04.4 LTS \n \l
# dpkg -l |grep -i ruby
ii facter 2.0.1-1puppetlabs1 Ruby module for collecting simple facts about a host operating system
ii libaugeas-ruby 0.3.0-1.1ubuntu4 Augeas bindings for the Ruby language
ii libaugeas-ruby1.8 0.3.0-1.1ubuntu4 Augeas bindings for the Ruby language
ii libjson-ruby 1.6.3-1 Transitional package for ruby-json
ii libruby 4.8 Transitional package for libruby1.8
ii libruby1.8 1.8.7.352-2ubuntu1.4 Libraries necessary to run Ruby 1.8
ii libruby1.9.1 1.9.3.0-1ubuntu2.8 Libraries necessary to run Ruby 1.9.1
ii libruby1.9.1-dbg 1.9.3.0-1ubuntu2.8 Debugging symbols for Ruby 1.9.1
ii libshadow-ruby1.8 1.4.1-8build1 Interface of shadow password for Ruby 1.8
ii libtcltk-ruby1.9.1 1.9.3.0-1ubuntu2.8 Tcl/Tk interface for Ruby 1.9.1
ii ri1.9.1 1.9.3.0-1ubuntu2.8 Ruby Interactive reference (for Ruby 1.9.1)
ii ruby 4.8 Transitional package for ruby1.8
ii ruby-colorize 0.5.8-1 Add colors methods to string class
ii ruby-json 1.6.3-1 JSON library for Ruby
ii ruby-libshadow 1.0.0-1 shadow.h
ii ruby-net-ssh 1:2.2.1-1 Ruby implementation of the SSH protocol
ii ruby-parseconfig 1.0.2-1 Config File Parser for Standard Unix/Linux Type Config Files
ii ruby-rgen 0.6.5-1puppetlabs1 A framework supporting Model Driven Software Development (MDSD)
ii ruby-wopen3 0.3-1 Wopen3 is a simple replacement for Open3
ii ruby1.8 1.8.7.352-2ubuntu1.4 Interpreter of object-oriented scripting language Ruby 1.8
ii ruby1.9.1 1.9.3.0-1ubuntu2.8 Interpreter of object-oriented scripting language Ruby
ii ruby1.9.1-dev 1.9.3.0-1ubuntu2.8 Header files for compiling extension modules for the Ruby 1.9.1
ii ruby1.9.1-examples 1.9.3.0-1ubuntu2.8 Examples for Ruby 1.9
ii ruby1.9.1-full 1.9.3.0-1ubuntu2.8 Ruby 1.9.1 full installation
ii ruby1.9.3 1.9.3.0-1ubuntu2.8 Interpreter of object-oriented scripting language Ruby, version 1.9.3
Puppet server:
# cat /etc/issue
Ubuntu 12.04.4 LTS \n \l
# dpkg -l |grep -i ruby
ii facter 2.0.1-1puppetlabs1 Ruby module for collecting simple facts about a host operating system
ii libaugeas-ruby 0.3.0-1.1ubuntu4 Augeas bindings for the Ruby language
ii libaugeas-ruby1.8 0.3.0-1.1ubuntu4 Augeas bindings for the Ruby language
ii libjson-ruby 1.6.3-1 Transitional package for ruby-json
ii libruby 4.8 Transitional package for libruby1.8
ii libruby1.8 1.8.7.352-2ubuntu1.4 Libraries necessary to run Ruby 1.8
ii libruby1.9.1 1.9.3.0-1ubuntu2.8 Libraries necessary to run Ruby 1.9.1
ii libruby1.9.1-dbg 1.9.3.0-1ubuntu2.8 Debugging symbols for Ruby 1.9.1
ii libshadow-ruby1.8 1.4.1-8build1 Interface of shadow password for Ruby 1.8
ii libtcltk-ruby1.9.1 1.9.3.0-1ubuntu2.8 Tcl/Tk interface for Ruby 1.9.1
ii ri1.9.1 1.9.3.0-1ubuntu2.8 Ruby Interactive reference (for Ruby 1.9.1)
ii ruby 4.8 Transitional package for ruby1.8
ii ruby-amq-protocol 1.8.0-1 AMQP 0.9.1 encoder & decoder.
ii ruby-aws-s3 0.6.3-1 Client library for Amazon's Simple Storage Service's REST API
ii ruby-builder 3.2.2-1 Builders for MarkUp.
ii ruby-bunny 0.10.7-1 Popular easy to use Ruby client for RabbitMQ
ii ruby-colorize 0.5.8-1 Add colors methods to string class
ii ruby-dalli 2.6.4-1 High performance memcached client for Ruby
ii ruby-flexmock 1.3.2-1 Simple and Flexible Mock Objects for Testing
ii ruby-json 1.6.3-1 JSON library for Ruby
ii ruby-libshadow 1.0.0-1 shadow.h
ii ruby-mime-types 1.25-1 This library allows for the identification of a file's likely MIME content type
ii ruby-net-ssh 1:2.2.1-1 Ruby implementation of the SSH protocol
ii ruby-parseconfig 1.0.2-1 Config File Parser for Standard Unix/Linux Type Config Files
ii ruby-pg 0.17.0-1 Pg is the Ruby interface to the {PostgreSQL RDBMS}[http://www.postgresql.org/]
ii ruby-rgen 0.6.5-1puppetlabs1 A framework supporting Model Driven Software Development (MDSD)
ii ruby-wopen3 0.3-1 Wopen3 is a simple replacement for Open3
ii ruby-xml-simple 1.1.2-1 A simple API for XML processing.
ii ruby1.8 1.8.7.352-2ubuntu1.4 Interpreter of object-oriented scripting language Ruby 1.8
ii ruby1.9.1 1.9.3.0-1ubuntu2.8 Interpreter of object-oriented scripting language Ruby
ii ruby1.9.1-dev 1.9.3.0-1ubuntu2.8 Header files for compiling extension modules for the Ruby 1.9.1
ii ruby1.9.1-examples 1.9.3.0-1ubuntu2.8 Examples for Ruby 1.9
ii ruby1.9.1-full 1.9.3.0-1ubuntu2.8 Ruby 1.9.1 full installation
ii ruby1.9.3 1.9.3.0-1ubuntu2.8 Interpreter of object-oriented scripting language Ruby, version 1.9.3
Ken Barber
May 23, 2014, 11:36:30 AM5/23/14
to Puppet Users
So this problem is tracked here:
https://tickets.puppetlabs.com/browse/PDB-686. I've been unable to
find a work-around beyond 'switch ruby' or completely change the way
we submit JSON (which would be a shame, the new method is more
efficient). Some people have had success using the newer brightbox
version of Ruby 1.9.3, others with Ruby 1.8.7 downgrade. We also have
Ubuntu 14.04 packages now, so thats another option.
To be honest I had a lot of difficulty setting up Ubuntu 12.04 with
Ruby 1.9.3 & passenger anyway, seems like a tricky path to follow.
Ubuntu 12.04 and Ruby 1.8.7 however was easy and didn't suffer the bug
*shrug*.
For now I'm adding this bug to the release note page, as it seems
annoying enough to warrant it.
ken.
On Thu, May 22, 2014 at 2:39 PM, Sergey Arlashin
> To view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/91A38255-AC9A-415C-9CDB-C23AF39FE39B%40gmail.com.
https://tickets.puppetlabs.com/browse/PDB-686. I've been unable to
find a work-around beyond 'switch ruby' or completely change the way
we submit JSON (which would be a shame, the new method is more
efficient). Some people have had success using the newer brightbox
version of Ruby 1.9.3, others with Ruby 1.8.7 downgrade. We also have
Ubuntu 14.04 packages now, so thats another option.
To be honest I had a lot of difficulty setting up Ubuntu 12.04 with
Ruby 1.9.3 & passenger anyway, seems like a tricky path to follow.
Ubuntu 12.04 and Ruby 1.8.7 however was easy and didn't suffer the bug
*shrug*.
For now I'm adding this bug to the release note page, as it seems
annoying enough to warrant it.
ken.
On Thu, May 22, 2014 at 2:39 PM, Sergey Arlashin
Reply all
Reply to author
Forward
0 new messages