Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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 sergeyarl.maill...@gmail.com wrote: 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? Problem client: # 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-ruby1.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.11.9.3.0-1ubuntu2.8 Libraries necessary to run Ruby 1.9.1 ii libruby1.9.1-dbg1.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 ruby4.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-ssh1:2.2.1-1 Ruby implementation of the SSH protocol ii ruby-parseconfig1.0.2-1 Config File Parser for Standard Unix/Linux Type Config Files ii ruby-rgen 0.6.5-1puppetlabs1A 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-1puppetlabs1Ruby 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.80.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
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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 sergeyarl.maill...@gmail.com wrote: 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 :( On May 21, 2014, at 11:54 PM, Ken Barber k...@puppetlabs.com wrote: 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. On Wed, May 21, 2014 at 6:41 PM, Ken Barber k...@puppetlabs.com wrote: 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. On Wed, May 21, 2014 at 5:29 PM, Ken Barber k...@puppetlabs.com wrote: 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 phillip.fenstermac...@gmail.com wrote: 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) On Wednesday, May 21, 2014 9:53:42 AM UTC-4, Ken Barber wrote: Catalogue size might be a factor, as templates get stored in the catalogue. On Wed, May 21, 2014 at 2:45 PM, Phil Fenstermacher phillip.fe...@gmail.com wrote: 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. On Tuesday, May 20, 2014 11:27:05 AM UTC-4, Sergey Arlashin wrote: 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:
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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. On Thu, May 22, 2014 at 1: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? ken. On Thu, May 22, 2014 at 5:06 AM, Sergey Arlashin sergeyarl.maill...@gmail.com wrote: 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 :( On May 21, 2014, at 11:54 PM, Ken Barber k...@puppetlabs.com wrote: 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. On Wed, May 21, 2014 at 6:41 PM, Ken Barber k...@puppetlabs.com wrote: 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. On Wed, May 21, 2014 at 5:29 PM, Ken Barber k...@puppetlabs.com wrote: 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 phillip.fenstermac...@gmail.com wrote: 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) On Wednesday, May 21, 2014 9:53:42 AM UTC-4, Ken Barber wrote: Catalogue size might be a factor, as templates get stored in the catalogue. On Wed, May 21, 2014 at 2:45 PM, Phil Fenstermacher phillip.fe...@gmail.com wrote: 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. On Tuesday, May 20, 2014
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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? Problem client: # cat /etc/issue Ubuntu 12.04.4 LTS \n \l # dpkg -l |grep -i ruby ii facter 2.0.1-1puppetlabs1Ruby 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-ruby1.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.11.9.3.0-1ubuntu2.8 Libraries necessary to run Ruby 1.9.1 ii libruby1.9.1-dbg1.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.8Ruby Interactive reference (for Ruby 1.9.1) ii ruby4.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-ssh1:2.2.1-1 Ruby implementation of the SSH protocol ii ruby-parseconfig1.0.2-1 Config File Parser for Standard Unix/Linux Type Config Files ii ruby-rgen 0.6.5-1puppetlabs1A 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.8Ruby 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-1puppetlabs1Ruby 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.80.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.81.4.1-8build1 Interface of shadow password for Ruby 1.8 ii libtcltk-ruby1.9.1 1.9.3.0-1ubuntu2.8Tcl/Tk interface for Ruby 1.9.1 ii ri1.9.1 1.9.3.0-1ubuntu2.8Ruby Interactive reference (for Ruby 1.9.1) ii ruby 4.8 Transitional package for ruby1.8 ii ruby-amq-protocol1.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
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
Catalogue size might be a factor, as templates get stored in the catalogue. On Wed, May 21, 2014 at 2:45 PM, Phil Fenstermacher phillip.fenstermac...@gmail.com wrote: 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. On Tuesday, May 20, 2014 11:27:05 AM UTC-4, Sergey Arlashin wrote: 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 10 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: 3/3 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
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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 phillip.fenstermac...@gmail.com wrote: 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) On Wednesday, May 21, 2014 9:53:42 AM UTC-4, Ken Barber wrote: Catalogue size might be a factor, as templates get stored in the catalogue. On Wed, May 21, 2014 at 2:45 PM, Phil Fenstermacher phillip.fe...@gmail.com wrote: 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. On Tuesday, May 20, 2014 11:27:05 AM UTC-4, Sergey Arlashin wrote: 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 10 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: 3/3 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
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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. On Wed, May 21, 2014 at 5:29 PM, Ken Barber k...@puppetlabs.com wrote: 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 phillip.fenstermac...@gmail.com wrote: 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) On Wednesday, May 21, 2014 9:53:42 AM UTC-4, Ken Barber wrote: Catalogue size might be a factor, as templates get stored in the catalogue. On Wed, May 21, 2014 at 2:45 PM, Phil Fenstermacher phillip.fe...@gmail.com wrote: 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. On Tuesday, May 20, 2014 11:27:05 AM UTC-4, Sergey Arlashin wrote: 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 10 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
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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. On Wed, May 21, 2014 at 6:41 PM, Ken Barber k...@puppetlabs.com wrote: 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. On Wed, May 21, 2014 at 5:29 PM, Ken Barber k...@puppetlabs.com wrote: 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 phillip.fenstermac...@gmail.com wrote: 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) On Wednesday, May 21, 2014 9:53:42 AM UTC-4, Ken Barber wrote: Catalogue size might be a factor, as templates get stored in the catalogue. On Wed, May 21, 2014 at 2:45 PM, Phil Fenstermacher phillip.fe...@gmail.com wrote: 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. On Tuesday, May 20, 2014 11:27:05 AM UTC-4, Sergey Arlashin wrote: 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}
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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 :( On May 21, 2014, at 11:54 PM, Ken Barber k...@puppetlabs.com wrote: 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. On Wed, May 21, 2014 at 6:41 PM, Ken Barber k...@puppetlabs.com wrote: 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. On Wed, May 21, 2014 at 5:29 PM, Ken Barber k...@puppetlabs.com wrote: 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 phillip.fenstermac...@gmail.com wrote: 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) On Wednesday, May 21, 2014 9:53:42 AM UTC-4, Ken Barber wrote: Catalogue size might be a factor, as templates get stored in the catalogue. On Wed, May 21, 2014 at 2:45 PM, Phil Fenstermacher phillip.fe...@gmail.com wrote: 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. On Tuesday, May 20, 2014 11:27:05 AM UTC-4, Sergey Arlashin wrote: 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]
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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 ? On May 20, 2014, at 9:43 AM, Sergey Arlashin sergeyarl.maill...@gmail.com wrote: 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/3 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]
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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 sergeyarl.maill...@gmail.com wrote: 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 ? On May 20, 2014, at 9:43 AM, Sergey Arlashin sergeyarl.maill...@gmail.com wrote: 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/3 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)
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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. On Tue, May 20, 2014 at 2:03 PM, Ken Barber k...@puppetlabs.com wrote: 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 sergeyarl.maill...@gmail.com wrote: 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 ? On May 20, 2014, at 9:43 AM, Sergey Arlashin sergeyarl.maill...@gmail.com wrote: 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/3 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
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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 10 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: 3/3 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
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
This looks like a puppetdb error. Can you check the PuppetDB logs and post any relevant errors? Thanks, Spencer On Mon, May 19, 2014 at 10:02 PM, Sergey Arlashin sergeyarl.maill...@gmail.com wrote: 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: 3/3 ms] htmlheadmeta http-equiv=Content-Type content=text/html;charset=ISO-8859-1/titleError 500 /title/headbodyh2HTTP ERROR: 500/h2pProblem accessing /v3/commands. Reason:prejava.util.concurrent.TimeoutException: Idle timeout expired: 3/3 ms/pre/phr /ismallPowered by Jetty:///small/i/body/html Does anybody know how I can get rid of this error? Thanks in advance! -- Best regards, Sergey Arlashin -- 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+unsubscr...@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 -- 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+unsubscr...@googlegroups.com. To view this discussion on the web visit https://groups.google.com/d/msgid/puppet-users/CADt6FWNbXASsOh6_hzcSQAeJjzu8cZYTPG4qkYxTBoe%2B6heLtw%40mail.gmail.com. For more options, visit https://groups.google.com/d/optout.
Re: [Puppet Users] puppetdb 2 : Idle timeout expired: 30000/30000 ms
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/3 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