Uploading cookbooks to chef-zero using berks often crashes when Request timeout is 300

[poliva83]

Starting in version 4.8.0 the default request timeout for WEBrick timeout was increased from 30 to 300 (see #137).

The increase in timeout seems to cause problems when using berks to upload to chef-zero server. See stack trace below which happened when using all gems packaged in latest chefdk (0.17.17).

Uploaded apt (2.9.2) to: 'http://localhost:4000/'
Uploaded apt-chef (0.2.0) to: 'http://localhost:4000/'
Uploaded bb_apt (3.3.4) to: 'http://localhost:4000/'
Uploaded bb_chef_server_cluster (0.7.0) to: 'http://localhost:4000/'
Uploaded bb_chef_server_cluster_test (0.1.0) to: 'http://localhost:4000/'
Uploaded bb_cron (0.1.6) to: 'http://localhost:4000/'
Uploaded bb_lvm (0.1.3) to: 'http://localhost:4000/'
Uploaded bb_nsupdate (2.1.0) to: 'http://localhost:4000/'
Uploaded bb_sudo (0.2.1) to: 'http://localhost:4000/'
Uploaded bb_sysctl (0.1.0) to: 'http://localhost:4000/'
Uploaded bb_unbound (0.1.1) to: 'http://localhost:4000/'
Uploaded bb_users (3.0.4) to: 'http://localhost:4000/'
Uploaded build-essential (3.2.0) to: 'http://localhost:4000/'
Uploaded chef-client (4.5.3) to: 'http://localhost:4000/'
Uploaded chef-ingredient (0.19.0) to: 'http://localhost:4000/'
Uploaded chef-vault (1.3.3) to: 'http://localhost:4000/'
Celluloid::Task::TerminatedError: task was terminated
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:345:in `each'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:345:in `cleanup'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:329:in `shutdown'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:321:in `handle_crash'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:166:in `rescue in run'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:148:in `run'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor.rb:130:in `block in start'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/thread_handle.rb:13:in `block in initialize'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/actor_system.rb:32:in `block in get_thread'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/internal_pool.rb:130:in `call'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/internal_pool.rb:130:in `block in create'
        from (celluloid):0:in `remote procedure call'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/calls.rb:92:in `value'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/celluloid-0.16.0/lib/celluloid/proxies/sync_proxy.rb:33:in `method_missing'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/berkshelf-4.3.5/lib/berkshelf/uploader.rb:55:in `block (2 levels) in upload'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/berkshelf-4.3.5/lib/berkshelf/uploader.rb:51:in `each'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/berkshelf-4.3.5/lib/berkshelf/uploader.rb:51:in `block in upload'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/ridley-4.6.1/lib/ridley/client.rb:38:in `open'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/ridley-4.6.1/lib/ridley.rb:56:in `open'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/berkshelf-4.3.5/lib/berkshelf.rb:145:in `ridley_connection'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/berkshelf-4.3.5/lib/berkshelf/uploader.rb:50:in `upload'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/berkshelf-4.3.5/lib/berkshelf/uploader.rb:37:in `run'
        from /opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/berkshelf-4.3.5/lib/berkshelf/berksfile.rb:592:in `upload'
        from (irb):21
        from /opt/chefdk/embedded/bin/irb:11:in `<main>'irb(main):022:0>

Here is code to reproduce the issue (assumes your running at top-level directory of cookbook):

puts "Starting Chef Zero server"
require 'chef_zero/server'
server = ChefZero::Server.new(port: 4000..5000)
server.start_background

puts "Uploading cookbooks"
require 'berkshelf'
options = {}
berkfname = 'Berksfile'
berksfile = Berkshelf::Berksfile.from_file(berkfname)

# Delete Berksfile.lock and call `Berks install` to reset cookbook dependency graph
File.file?("#{berkfname}.lock") ? File.delete("#{berkfname}.lock") : nil
berksfile.install

options[:freeze]    = false
options[:validate]  = false
options[:server_url] = "http://localhost:#{server.port}"

berksfile.upload(options.symbolize_keys)

The interesting part is if you rerun berksfile.upload(options.symbolize_keys) enough times eventually all the cookbooks do get uploaded successfully.

When I set server.server.config[:RequestTimeout] = 30 after starting chef-zero server in background I don't hit the issue anymore.

[poliva83]

My particular use case is my provisioning workstation (Jenkins) is using a Rakefile to start a chef-zero server, load cookbooks via berks. After chef-zero server is running we trigger a chef-provisioning chef-client run pointed at this chef-zero server. Multiple jenkins jobs can be executed at same time (hence multiple chef-zero servers could be running on different ports).

[lamont-granquist]

my guess would be underlying perf bug in chef-fs?

[lamont-granquist]

This needs to get re-replicated and opened as a fresh issue if it still affects berkshelf 7 without ridley+celluloid involvement.

Also could use a better repro case.