Convergence fails with invalid character error

[jeffbyrnes]

With Guard running, and this Guardfile setup:

guard 'kitchen' do
  watch(%r{test/.+})
  watch(%r{^recipe/(.+)\.rb$})
  watch(%r{^attributes/(.+)\.rb$})
  watch(%r{^files/(.+)})
  watch(%r{^templates/(.+)})
  watch(%r{^providers/(.+)\.rb})
  watch(%r{^resources/(.+)\.rb})
end

I get this failure when I modify one of the files that should trigger a kitchen verify:

I, [2014-06-04T11:01:05.541400 #76669]  INFO -- Kitchen: -----> Starting Kitchen (v1.2.1)
I, [2014-06-04T11:01:06.423495 #76669]  INFO -- Kitchen: -----> Creating <default-ubuntu-1204>...
I, [2014-06-04T11:01:12.178537 #76669]  INFO -- Kitchen: -----> Creating <default-ubuntu-1404>...
I, [2014-06-04T11:01:15.709869 #76669]  INFO -- Kitchen: -----> Kitchen is finished. (0m10.17s)
I, [2014-06-04T11:01:32.102820 #76779]  INFO -- Kitchen: -----> Starting Kitchen (v1.2.1)
I, [2014-06-04T11:01:33.040862 #76779]  INFO -- Kitchen: -----> Converging <default-ubuntu-1204>...
I, [2014-06-04T11:01:33.041312 #76779]  INFO -- Kitchen: -----> Converging <default-ubuntu-1404>...
E, [2014-06-04T11:01:33.276741 #76779] ERROR -- Kitchen: ------Exception-------
E, [2014-06-04T11:01:33.276783 #76779] ERROR -- Kitchen: Class: Kitchen::ActionFailed
E, [2014-06-04T11:01:33.276809 #76779] ERROR -- Kitchen: Message: Failed to complete #converge action: ["\xC2" on US-ASCII]
E, [2014-06-04T11:01:33.276833 #76779] ERROR -- Kitchen: ---Nested Exception---
E, [2014-06-04T11:01:33.276856 #76779] ERROR -- Kitchen: Class: Encoding::InvalidByteSequenceError
E, [2014-06-04T11:01:33.276880 #76779] ERROR -- Kitchen: Message: "\xC2" on US-ASCII
E, [2014-06-04T11:01:33.276903 #76779] ERROR -- Kitchen: ------Backtrace-------
E, [2014-06-04T11:01:33.276925 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/2.1.0/json/common.rb:155:in `encode'
E, [2014-06-04T11:01:33.276949 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/2.1.0/json/common.rb:155:in `initialize'
E, [2014-06-04T11:01:33.276972 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/2.1.0/json/common.rb:155:in `new'
E, [2014-06-04T11:01:33.276995 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/2.1.0/json/common.rb:155:in `parse'
E, [2014-06-04T11:01:33.277018 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/ridley-3.1.0/lib/ridley/chef/cookbook/metadata.rb:458:in `from_json'
E, [2014-06-04T11:01:33.277041 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/ridley-3.1.0/lib/ridley/chef/cookbook/metadata.rb:29:in `from_json'
E, [2014-06-04T11:01:33.277064 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/ridley-3.1.0/lib/ridley/chef/cookbook.rb:36:in `from_path'
E, [2014-06-04T11:01:33.277087 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/cached_cookbook.rb:15:in `from_store_path'
E, [2014-06-04T11:01:33.277111 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/cookbook_store.rb:86:in `cookbook'
E, [2014-06-04T11:01:33.277145 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/dependency.rb:137:in `cached_cookbook'
E, [2014-06-04T11:01:33.277170 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/dependency.rb:113:in `installed?'
E, [2014-06-04T11:01:33.277197 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/installer.rb:124:in `each'
E, [2014-06-04T11:01:33.277221 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/installer.rb:124:in `all?'
E, [2014-06-04T11:01:33.277244 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/installer.rb:124:in `install_from_lockfile'
E, [2014-06-04T11:01:33.277268 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/installer.rb:37:in `run'
E, [2014-06-04T11:01:33.277292 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/berksfile.rb:371:in `install'
E, [2014-06-04T11:01:33.277315 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/berkshelf-3.1.2/lib/berkshelf/berksfile.rb:590:in `vendor'
E, [2014-06-04T11:01:33.277338 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/provisioner/chef/berkshelf.rb:55:in `block in resolve'
E, [2014-06-04T11:01:33.277361 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/thor-0.19.1/lib/thor/shell/basic.rb:20:in `mute'
E, [2014-06-04T11:01:33.277385 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/provisioner/chef/berkshelf.rb:51:in `resolve'
E, [2014-06-04T11:01:33.277408 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/provisioner/chef_base.rb:394:in `block in resolve_with_berkshelf'
E, [2014-06-04T11:01:33.277431 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/provisioner/chef_base.rb:393:in `synchronize'
E, [2014-06-04T11:01:33.277455 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/provisioner/chef_base.rb:393:in `resolve_with_berkshelf'
E, [2014-06-04T11:01:33.277487 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/provisioner/chef_base.rb:259:in `prepare_cookbooks'
E, [2014-06-04T11:01:33.277509 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/provisioner/chef_base.rb:120:in `create_sandbox'
E, [2014-06-04T11:01:33.277531 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/provisioner/chef_zero.rb:35:in `create_sandbox'
E, [2014-06-04T11:01:33.277552 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/driver/ssh_base.rb:40:in `converge'
E, [2014-06-04T11:01:33.277575 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/kitchen-vagrant-0.15.0/lib/kitchen/driver/vagrant.rb:75:in `converge'
E, [2014-06-04T11:01:33.277597 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:273:in `public_send'
E, [2014-06-04T11:01:33.277619 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:273:in `block in perform_action'
E, [2014-06-04T11:01:33.277647 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:308:in `call'
E, [2014-06-04T11:01:33.277671 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:308:in `synchronize_or_call'
E, [2014-06-04T11:01:33.277693 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:283:in `block in action'
E, [2014-06-04T11:01:33.277715 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/2.1.0/benchmark.rb:279:in `measure'
E, [2014-06-04T11:01:33.277737 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:282:in `action'
E, [2014-06-04T11:01:33.277759 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:273:in `perform_action'
E, [2014-06-04T11:01:33.277780 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:256:in `converge_action'
E, [2014-06-04T11:01:33.277802 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:246:in `block in transition_to'
E, [2014-06-04T11:01:33.277823 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:245:in `each'
E, [2014-06-04T11:01:33.277846 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:245:in `transition_to'
E, [2014-06-04T11:01:33.277867 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/instance.rb:141:in `verify'
E, [2014-06-04T11:01:33.277889 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/command.rb:109:in `public_send'
E, [2014-06-04T11:01:33.277911 #76779] ERROR -- Kitchen: /usr/local/var/rbenv/versions/2.1.1/lib/ruby/gems/2.1.0/gems/test-kitchen-1.2.1/lib/kitchen/command.rb:109:in `block (2 levels) in run_action'

I can, however, after guard-kitchen has created the VMs for me, run kitchen verify all -p myself without any issue, so I don't believe the issue lies with Test Kitchen or any of my configuration.

[shawncatz]

I get the same, with a slightly modified Guardfile, with the character "\xE2"
Only happens with guard-kitchen, kitchen itself works fine.

[trebolcinco]

Am having the same issue. Tried everything including grep all the files for the character and changing the encoding in the terminal but nothing works.

[buysse]

I have had similar problems in the past, and was able to "resolve" them by nuking the Berkshelf caches completely (from ~/.berkshelf, everything except config.json). I probably could have resolved being more selective, but the problem was metadata (or a Berksfile) in one of the cached cookbooks.

[acm1]

@buysse: I ran into this problem today and your solution worked for me ;)

[leonardoeloy]

+1 to @buysse's workaround

[lxndrp]

-1 to @buysse's workaround from my side. Even on a vanilla system, right after running running bundler in an isolated rbenv environment with a fresh gemset, I keep getting this error. Nuking ~/berkshelf/* didn't help, unfortunately.

[gregsymons]

So the problem here is that Mixlib::ShellOut (at least on my machine) seems to be resetting the LC_ALL environment variable to C. If I do the following monkey patch:

[2] guard(main)> module Guard
[2] guard(main)*   class Kitchen < Guard
[2] guard(main)*     def run_all
[2] guard(main)*       ::Guard::UI.info("Guard::Kitchen is running all tests")      
[2] guard(main)*       cmd = Mixlib::ShellOut.new(["kitchen", "verify"], :timeout => 10800, :env => { 'LC_ALL' => 'en_US.UTF-8' })
[2] guard(main)*       cmd.live_stream = STDOUT      
[2] guard(main)*       cmd.run_command      
[2] guard(main)*       begin      
[2] guard(main)*         test_cmd.error!        
[2] guard(main)*         cmd.error!        
[2] guard(main)*         Notifier.notify('Kitchen verify succeeded', :title => 'test-kitchen', :image => :success)        
[2] guard(main)*         ::Guard::UI.info("Kitchen verify succeeded")        
[2] guard(main)*       rescue Mixlib::ShellOut::ShellCommandFailed => e        
[2] guard(main)*         Notifier.notify('Kitchen verify failed', :title => 'test-kitchen', :image => :failed)        
[2] guard(main)*         ::Guard::UI.info("Kitchen verify failed with #{e.to_s}")        
[2] guard(main)*         throw :task_has_failed        
[2] guard(main)*       end        
[2] guard(main)*     end      
[2] guard(main)*   end  
[2] guard(main)* end  

everything works fine.

[gregsymons]

BTW, the key change there is the explicit setting of LC_ALL... switching from shell-exec to direct exec was an earlier attempt that I didn't realize slipped in.

[jeffbyrnes]

Looks like this never closed when #5 merged! Closing out.