How do I get log output in test kitchen?

Question

I have this in my recipe:

log mylog1 do
  level :info
  message 'WHY I NO SEE THIS?'
end
log mylog2 do
  level :info
  message 'WHY I NO SEE THIS?'
end

This is what I see when doing kitchen converge -l debug:

...
Converging 3 resources
Recipe: mybook::myrecipe
  * log[mylog1] action write
  * log[mylog1] action write
...

Answer 1

With a newer Kitchen you can also do kitchen test -D to trigger debug output for kitchen AND your chef-client run.

Answer 2

There are two parts of this question:

First, The log level passed to kitchen with "-l debug" is for the kitchen executable and not for the provisioner, in this case "chef-solo". Therefore, if you run the kitchen with debug option, you would see that, provisioner is running with log_level as "auto" as below, even when kitchen in debug mode:

[SSH] vagrant@127.0.0.1<{:user_known_hosts_file=>"/dev/null",
:paranoid=>false, :port=>"2222", :compression=>false, :compression_level=>0,
:keepalive=>true, :keepalive_interval=>60, :timeout=>15, :keys_only=>true,
:keys=>["/Users/mpriyada/myWorks/.kitchen/kitchen-vagrant/kitchen-default-centos/.vagrant/machines/default/virtualbox/private_key"],
:auth_methods=>["publickey"], :user=>"vagrant"}> (sh -c 'sudo -E /opt/chef/bin/chef-solo
--config /tmp/kitchen/solo.rb --log_level auto --force-formatter --no-color
--json-attributes /tmp/kitchen/dna.json')

Which means that, in chef-solo logging priority, "auto" comes par with "warn" level. And hence no output is logged if log level is set as info in the "log" resource. Try below code, you observe the difference:

log "mylog1" do
   level :warn
   message 'WHY I NO SEE THIS?'
end

log "mylog2" do
   level :info
   message 'WHY I NO SEE THIS?'
end

Output:

Recipe: test3::default
   * log[mylog1] action write[2016-08-17T03:55:16+00:00] WARN: WHY I NO SEE THIS?      

   * log[mylog2] action write
Running handlers:
Running handlers complete

Now, Second part, if you don't want to run your kitchen in "auto" log_level, you can go to "/opt/chefdk/embedded/lib/ruby/gems/2.1.0/gems/test-kitchen-1.10.0/lib/kitchen/provisioner/chef_base.rb" and change the hard coded log level from auto to whatever chef-solo logging permits https://docs.chef.io/config_rb_solo.html.

Answer 3

Since Kitchen 1.7.0 you can configure this in kitchen.yml:

provisioner:
  name: chef_zero
  log_level: info

See this page (doesn't seem to be linked to in the Kitchen docs)