chef + test-kitchen の複雑系コンビを追い詰めていくまでに使った手管を残しておきます。
chef-client が実行したコマンドを確認する手順
kitchen create でインスタンスを作成する 
インスタンスが作成されます（kitchen-vagrant なら、Vagrant インスタンス）:
$ bundle exec kitchen create
chef-client 関連のコードを書き換える 
chef-client が最終的に実行しているコマンドを捕らえるために、次のように実行したコマンドを外部ファイルへ書き出すように書き換えます:
$ bundle exec kitchen login
$ whoami
vagrant
$ sudoedit /opt/chef/embedded/lib/ruby/gems/2.3.0/gems/mixlib-shellout-2.2.7/lib/mixlib/shellout.rb
--- /dev/fd/11 2016-09-16 22:21:40.000000000 +0900
+++ /dev/fd/12 2016-09-16 22:21:40.000000000 +0900
@@ -252,10 +252,6 @@
# * CommandTimeout when the command does not complete
# within +timeout+ seconds (default: 600s)
def run_command
+ open("/tmp/ran_commands.log", "a") { |f|
+ log_message = (log_tag.nil? ? "" : "#@log_tag ") << "sh(#@command)"
+ f.write(log_message)
+ }
if logger
log_message = (log_tag.nil? ? "" : "#@log_tag ") << "sh(#@command)"
logger.send(log_level, log_message)
kitchen converge で recipe を適用する 
$ bundle exec kitchen converge
結果を確認する 
$ bundle exec kitchen login
$ whoami
vagrant
$ cat /tmp/ran_commands.log
sh(locale -a)
sh(df -P)
sh(df -iP)
sh(mount)
sh(lsblk -P -n -o NAME,FSTYPE)
sh(lsblk -P -n -o NAME,UUID)
...
ヨッシャ、デバッグが捗るぞい 
解説
test-kitchen (+ kitchen-vagrant)の仕組み
test-kitchen では、cookbook をいろいろな環境で試すことができます。
例えば、azure 上で試したりといった感じです:
$ bundle exec kitchen driver discover
Gem Name Latest Stable Release
jackal-kitchen-slack 0.1.2
kitchen-all 0.2.0
kitchen-ansible 0.45.4
kitchen-ansiblepush 0.4.0
kitchen-appbundle-updater 0.1.2
kitchen-azure 0.1.0
kitchen-azurerm 0.7.0
...
また、とくに指定がなければ、kitchen-vagrant による Vagrant 上でのテストになっているはずです。
これを使えばマシン1台で手軽に試せるので、kitchen-vagrant を使うことにしましょう。
さて、kitchen-vagrant は cookbook のディレクトリに .kitchen/kitchen-vagrant というディレクトリをこっそり用意して、そこに Vagrantfile を準備します:
$ cat .kitchen/kitchen-vagrant/kitchen-chef-jenkins-master-default-centos-72/Vagrantfile
Vagrant.configure("2") do |c|
c.berkshelf.enabled = false if Vagrant.has_plugin?("vagrant-berkshelf")
c.vm.box = "bento/centos-7.2"
c.vm.hostname = "default-centos-72"
c.vm.synced_folder ".", "/vagrant", disabled: true
c.vm.provider :virtualbox do |p|
end
end
なので、このディレクトリまで行けば、vagrant ssh で SSH ログインできます。
kitchen-vagrant 使用時の kitchen のサブコマンドの意味
-
kitchen create -
.kitchen.ymlで指定された Vagrant イメージを準備する（vagrant up相当） -
kitchen converge -
.kitchen.ymlで指定されたrun_listに従って、インスタンスに recipe を適用する（knife zero converge相当） -
kitchen verify -
.kitchen.ymlで指定されたverifierに従って、インスタンス上でテストを実行する -
kitchen destroy - Vagrant インスタンスを破棄する（
vagrant destroy相当） -
kitchen login - Vagrant インスタンスへ SSH ログインする（
vagrant ssh相当）
また、kitchen test では次のように順番にコマンドを実行します（より丁寧な解説 or 公式）:
kitchen createkitchen convergekitchen verifykitchen destroy
そのため、レシピを適用した状態のインスタンスに SSH ログインしたければ、kitchen create && kitchen converge した後、kitchen login すればよいのです！！！！
他にも
recipe 内なら log
recipe 内のコードであれば、log とか Chef::Log とかが使えます：
$ cat recipes/default.rb
...
require 'json'
log 'ndenv' do
message JSON.generate(node['ndenv'])
level :error
end
...
$ bundle exec kitchen converge
...
Recipe: test_useradd::default
* log[ndenv] action write[2016-09-16T11:45:05+00:00] ERROR: {"user":"ndenv","group":"ndenv","manage_home":true,"user_home":"/home/ndenv"}
...
実行されている様子を観察する
ログインして ps コマンドとかで監視すると、どのユーザーがどんな感じで実行しているか見えてきて便利です1:
$ bundle exec kitchen login
$ whoami
vagrant
$ watch -n 0.5 'ps auxf --sort -pid'
Every 0.5s: ps auxf --sort -pid
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 1 0.0 1.6 57572 7504 ? Ss 13:11 0:00 /usr/lib/systemd/systemd --switched-root --system --deserialize 21
root 12819 0.0 0.2 125400 1088 ? Ss 14:01 0:00 /usr/sbin/anacron -s
root 1061 0.0 0.4 91064 2084 ? Ss 13:11 0:00 /usr/libexec/postfix/master -w
postfix 1098 0.0 0.8 91236 3904 ? S 13:11 0:00 \_ qmgr -l -t unix -u
postfix 1097 0.0 0.8 91168 3880 ? S 13:11 0:00 \_ pickup -l -t unix -u
root 866 0.0 0.7 82488 3576 ? Ss 13:11 0:00 /usr/sbin/sshd -D
root 13406 0.1 1.0 131056 4760 ? Ss 14:17 0:00 \_ sshd: vagrant [priv]
vagrant 13409 0.0 0.4 131056 2040 ? S 14:17 0:00 | \_ sshd: vagrant@pts/1
vagrant 13410 0.0 0.4 115352 2036 pts/1 Ss+ 14:17 0:00 | \_ -bash
root 12856 0.0 1.0 131056 4764 ? Ss 14:11 0:00 \_ sshd: vagrant [priv]
...
-
topとかでもできるかもですが、引数表示とか諸々psの方が慣れてる感あるのでこっちでやりました。 ↩