chef-client が実行したコマンドを確認する《技》

chef + test-kitchen の複雑系コンビを追い詰めていくまでに使った手管を残しておきます。


# chef-client が実行したコマンドを確認する手順
## `kitchen create` でインスタンスを作成する :factory:

インスタンスが作成されます（kitchen-vagrant なら、Vagrant インスタンス）:

```console
$ bundle exec kitchen create
```

## chef-client 関連のコードを書き換える :innocent:

chef-client が最終的に実行しているコマンドを捕らえるために、次のように実行したコマンドを外部ファイルへ書き出すように書き換えます:

```console
$ 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
```

```diff
--- /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 を適用する :boom: :bomb: :boom: :gun: :dash:

```console
$ bundle exec kitchen converge
```


## 結果を確認する :secret: :eyes: :eyes: :eyes: 

```console
$ 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)
...
```

ヨッシャ、デバッグが捗るぞい :tada: 


# 解説
## test-kitchen (+ kitchen-vagrant)の仕組み

test-kitchen では、cookbook をいろいろな環境で試すことができます。
例えば、azure 上で試したりといった感じです:

```console
$ 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` を準備します:

```console
$ 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 のサブコマンドの意味

<dl>
<dt><code>kitchen create</code>
<dd><code>.kitchen.yml</code> で指定された Vagrant イメージを準備する（<code>vagrant up</code> 相当）
<dt><code>kitchen converge</code>
<dd><code>.kitchen.yml</code> で指定された <code>run_list</code> に従って、インスタンスに recipe を適用する（<code>knife zero converge</code> 相当）
<dt><code>kitchen verify</code>
<dd><code>.kitchen.yml</code> で指定された <code>verifier</code> に従って、インスタンス上でテストを実行する
<dt><code>kitchen destroy</code>
<dd>Vagrant インスタンスを破棄する（<code>vagrant destroy</code> 相当）
<dt><code>kitchen login</code>
<dd>Vagrant インスタンスへ SSH ログインする（<code>vagrant ssh</code> 相当）
</dl>

また、`kitchen test` では次のように順番にコマンドを実行します（[より丁寧な解説](http://qiita.com/sawanoboly/items/9f560bd63ad0712b17ba) or [公式](http://kitchen.ci/docs/getting-started/getting-help)）:

1. `kitchen create`
2. `kitchen converge`
3. `kitchen verify`
4. `kitchen destroy `

そのため、レシピを適用した状態のインスタンスに SSH ログインしたければ、`kitchen create && kitchen converge` した後、`kitchen login` すればよいのです！！！！


# 他にも
## recipe 内なら `log`

recipe 内のコードであれば、[`log` とか `Chef::Log`](https://docs.chef.io/resource_log.html) とかが使えます：

```console
$ 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]:

```console
$ 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]
...
```

[^1]: `top` とかでもできるかもですが、引数表示とか諸々 `ps` の方が慣れてる感あるのでこっちでやりました。