Jira (PUP-1965) Clients are hung when server has intermittent service

[Michael Marod (JIRA)]

Title: Message Title

Michael Marod commented on PUP-1965   Re: Clients are hung when server has intermittent service Suffering from the same symptoms and am led to believe that setting http_read_timeout will resolve the problem. I hooked up gdb to one of our stuck puppet agents and grabbed a backtrace: (gdb) call (void) rb_backtrace() from /opt/puppetlabs/puppet/bin/puppet:5:in `<main>' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:73:in `execute' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util/command_line.rb:137:in `run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:375:in `run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/util.rb:661:in `exit_on_fail' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:375:in `block in run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/agent.rb:352:in `run_command' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application/agent.rb:390:in `main' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/daemon.rb:149:in `start' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/daemon.rb:193:in `run_event_loop' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/scheduler/scheduler.rb:11:in `run_loop' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/scheduler/scheduler.rb:34:in `run_ready' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/scheduler/scheduler.rb:34:in `each' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/scheduler/scheduler.rb:39:in `block in run_ready' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/scheduler/job.rb:49:in `run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/daemon.rb:170:in `block in run_event_loop' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:46:in `run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/application.rb:179:in `controlled_run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:48:in `block in run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:94:in `run_in_fork' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:94:in `fork' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:98:in `block in run_in_fork' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:49:in `block (2 levels) in run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:130:in `with_client' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:52:in `block (3 levels) in run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent/locker.rb:21:in `lock' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:58:in `block (4 levels) in run' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/timeout.rb:103:in `timeout' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/timeout.rb:93:in `block in timeout' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:59:in `block (5 levels) in run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:211:in `run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet.rb:260:in `override' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/context.rb:65:in `override' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:237:in `block in run' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:383:in `run_internal' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:382:in `ensure in run_internal' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/configurer.rb:419:in `send_report' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/indirection.rb:289:in `save' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/rest.rb:235:in `save' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/rest.rb:254:in `do_request' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/request.rb:220:in `do_request' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/rest.rb:254:in `block in do_request' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/rest.rb:236:in `block in save' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/rest.rb:146:in `http_put' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/indirector/rest.rb:151:in `http_request' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/connection.rb:118:in `put' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/connection.rb:174:in `do_request' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/connection.rb:174:in `upto' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/connection.rb:177:in `block in do_request' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/connection.rb:313:in `with_connection' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/pool.rb:31:in `with_connection' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/connection.rb:314:in `block in with_connection' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/connection.rb:180:in `block (2 levels) in do_request' from /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/network/http/connection.rb:302:in `execute_request' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/http.rb:1416:in `request' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/http.rb:1443:in `transport_request' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/http.rb:1443:in `catch' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/http.rb:1446:in `block in transport_request' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/http/response.rb:29:in `read_new' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/http/response.rb:40:in `read_status_line' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/protocol.rb:164:in `readline' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/protocol.rb:154:in `readuntil' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/protocol.rb:176:in `rbuf_fill' from /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/protocol.rb:176:in `wait_readable' strace'ing the pid gave: # strace -p 10907 strace: Process 10907 attached ppoll([{fd=8, events=POLLIN}], 1, NULL, NULL, 8 /opt/puppetlabs/puppet/lib/ruby/2.4.0/net/protocol.rb:176 171 def rbuf_fill 172 case rv = @io.read_nonblock(BUFSIZE, exception: false) 173 when String 174 return @rbuf << rv 175 when :wait_readable 176 @io.to_io.wait_readable(@read_timeout) or raise Net::ReadTimeout 177 # continue looping So it looks like its stuck waiting for read_timeout to hit which is unset (aka infinity) in our environment. We should be able to set the http_read_timeout value in the puppet agent config to toggle this setting. Its a little bit tricky to test but it looks like the solution. "runtimeout" in this case does nothing. If you follow the backtrace further you'll get to... /opt/puppetlabs/puppet/lib/ruby/vendor_ruby/puppet/agent.rb:59 52 lock do 53 # NOTE: Timeout is pretty heinous as the location in which it 54 # throws an error is entirely unpredictable, which means that 55 # it can interrupt code blocks that perform cleanup or enforce 56 # sanity. The only thing a Puppet agent should do after this 57 # error is thrown is die with as much dignity as possible. 58 Timeout.timeout(Puppet[:runtimeout], RunTimeoutError) do 59 client.run(client_args) 60 end 61 end The timeout set on line 58 in this case does nothing. We have runtimeout set to 1800s and it is ineffective.   Add Comment   This message was sent by Atlassian JIRA (v7.7.1#77002-sha1:e75ca93) -- You received this message because you are subscribed to the Google Groups "Puppet Bugs" group. To unsubscribe from this group and stop receiving emails from it, send an email to puppet-bugs+unsubscr...@googlegroups.com. To post to this group, send email to puppet-bugs@googlegroups.com. Visit this group at https://groups.google.com/group/puppet-bugs. For more options, visit https://groups.google.com/d/optout.