2015年9月24日木曜日

【トピックス】Chefエラーメッセージの読み方

こんにちは。佐藤です。

Chefのエラーメッセージは非常に詳細なので、デバッグしているときはありがたいのですが、普段は詳細すぎて読みにくかったりします。
今回はそんなエラーメッセージとの戦い方について、開発中にはまった経験を元に色々紹介したいと思います。

Chefを有効活用する上で参考なれば幸いです。


エラーの出るタイミングについて

ChefCookbookは以下の二段階で実行されます。
● レシピのコンパイル(内部形式への変換)
● 実行
なので、エラーもそれぞれの段階で出ます。出力形式がそれぞれで違うので、両方紹介します。

コンパイルエラー編
その1

Starting Chef Client, version 12.4.1
resolving cookbooks for run list: ["lkinstall"]
Synchronizing Cookbooks:
  - lkinstall
Compiling Cookbooks... 
=================================================
Recipe Compile Error in /var/chef/cache/cookbooks/lkinstall/recipes/default.rb
================================================= 
NoMethodError
-------------
undefined method `[]' for nil:NilClass
Cookbook Trace:
---------------
  /var/chef/cache/cookbooks/lkinstall/recipes/default.rb:60:in `from_file'
Relevant File Content:
----------------------
/var/chef/cache/cookbooks/lkinstall/recipes/default.rb:
 53:  packages = []
 54:  node.run_context.cookbook_collection[cookbook_name].manifest["files"].each { |f|
 55:    name = f['name']
 56:    packages << name if /\.rpm$/ =~ name
 57:  }
 58:
 59:  files = packages
 60>> files += node[node[:hostname]]['licenses']
 61:
 62:  files.each { |file|
 63:    cookbook_file "#{Chef::Config[:file_cache_path]}/#{file}" do
 64:      source file
 65:    end
 66:  }
 67:
 68:  install_pkgs(packages).each { |pkg|
 69:    package pkg do
Running handlers:
[2015-08-28T15:56:45+09:00] ERROR: Running exception handlers
Running handlers complete
[2015-08-28T15:56:45+09:00] ERROR: Exception handlers complete
Chef Client failed. 0 resources updated in 2.378495397 seconds
[2015-08-28T15:56:45+09:00] FATAL: Stacktrace dumped to /var/chef/cache/chef-stacktrace.out
[2015-08-28T15:56:45+09:00] ERROR: undefined method `[]' for nil:NilClass
[2015-08-28T15:56:46+09:00] FATAL: Chef::Exceptions::ChildConvergeError: Chef run process exited unsuccessfully (exit code 1)

色を変えた部分に注目します。
この場合はnode[node[:hostname]]nilなのでエラーになっています。

node[]変数はアトリビュートファイルから定義を持ってきている変数なので、まずlkinstallのアトリビュートを見ます。

default['LKROOT'] = "/opt/LifeKeeper"
default[‘host1']['licenses'] = ["LKLinux-Core_04-Jan-2016.lic"]

’host1’というノードに対して"LKLinux-Core_04-Jan-2016.lic"というライセンスを適用することになっています。なので、このエラーはnode[:hostname]が、期待している’host1’を返していないのであろうと想像できます。

この変数の値はChefが定義しているので、Chefに問い合わせればどうなっているか確認できます。該当ノードで以下のコマンドを実行します。
 
  ohai|grep hostname
  "hostname": "host11",

ohaiコマンドはnode変数の定義を返してくるコマンドです。大量に出力されるのでgrepで絞り込んでいます。
この例ではnode[:hostname]’node11’と定義されることがわかります。

ということで、アトリビュートの定義と実際のホスト名が食い違っているために、変数が期待した結果を返さずエラーになっていることがわかりました。

したがって、アトリビュートのホスト名を正しくすれば解決することが出来ます。

コンパイルエラー編
その2


Starting Chef Client, version 12.4.1
resolving cookbooks for run list: ["lkinstall"]
Synchronizing Cookbooks:
  - lkinstall
Compiling Cookbooks...
================================================
Recipe Compile Error in /var/chef/cache/cookbooks/lkinstall/attributes/default.rb
================================================
NoMethodError
-------------
Undefined node attribute or method `bash' on `node'
Cookbook Trace:
---------------
  /var/chef/cache/cookbooks/lkinstall/attributes/default.rb:37:in `from_file'
Relevant File Content:
----------------------
/var/chef/cache/cookbooks/lkinstall/attributes/default.rb:
 30:        next
 31:      end
 32:    }
 33:    ret += files
 34:    return ret
 35:  end
 36:
 37>> bash "rmlk" do
 38:    user "root"
 39:    code <<EOF
 40:  if [ -x #{node['LKROOT']}/bin/rmlk ]
 41:  then
 42:    #{node['LKROOT']}/bin/lkstop
 43:    while [ -f #{node['LKROOT']}/IN_IS_ON ]
 44:    do
 45:            sleep 1
 46:    done
Running handlers:
[2015-08-28T16:36:41+09:00] ERROR: Running exception handlers
Running handlers complete
[2015-08-28T16:36:41+09:00] ERROR: Exception handlers complete
Chef Client failed. 0 resources updated in 2.534198241 seconds
[2015-08-28T16:36:41+09:00] FATAL: Stacktrace dumped to /var/chef/cache/chef-stacktrace.out
[2015-08-28T16:36:41+09:00] ERROR: Undefined node attribute or method `bash' on `node'
[2015-08-28T16:36:41+09:00] FATAL: Chef::Exceptions::ChildConvergeError: Chef run process exited unsuccessfully (exit code 1)


色を変えた部分に注目します。
bashというメソッドがないと言われています。
が、レシピであればそれはありえないので、正しくレシピとして実行されているか確認します。

レシピと認識されているかはRelevant File Content:を見ると確認できるので、そこの結果を見ます。
この例ではattributeとあるので、レシピではなくアトリビュートファイルとして読み込まれていることがわかります。
なので、このエラーはファイルを取り違えて配置したのがエラーの原因であるとわかります。

コンパイルエラーについては、エラーになった場所が的確に出力されるので、その部分と原因をきちんと読めば対応は容易だと思います。

実行時エラー編

Starting Chef Client, version 12.4.1
resolving cookbooks for run list: ["resource"]
Synchronizing Cookbooks:
  - resource
Compiling Cookbooks...
Converging 37 resources
Recipe: resource::default
  * bash[rmins] action run
    - execute "bash"  "/tmp/chef-script20150821-27229-1dt3n0s"
  * bash[dr_create-datarep-DataKeeperA] action run
    - execute "bash"  "/tmp/chef-script20150821-27229-1xvc9q9"
  * bash[fs_create-/FS/DataKeeperA] action run
    - execute "bash"  "/tmp/chef-script20150821-27229-19w8xdt"
  * bash[ip_create-IP-A] action run
    ==================================================
    Error executing action `run` on resource 'bash[ip_create-IP-A]'
    ==================================================
    Mixlib::ShellOut::ShellCommandFailed
    ------------------------------------
    Expected process to exit with [0], but received '1'
    ---- Begin output of "bash"  "/tmp/chef-script20150821-27229-as4wuh" ----    STDOUT:
    STDERR: BEGIN create of "IP-A"
    LifeKeeper application=comm on a130.
    LifeKeeper communications resource type= ip on a130.
    Creating resource instance with id IP-10.125.139.201 on machine a130
    Resource successfully created on a130
    BEGIN restore of "IP-A"
    IP address seems to still exist somewhere else.
    END failed "restore" of "IP-A" with return value of 1
    restore of resource "IP-A" has failed
    create ip hierarchy failure: perform_action failed
    END failed create of "IP-A".
    ---- End output of "bash"  "/tmp/chef-script20150821-27229-as4wuh" ----
    Ran "bash"  "/tmp/chef-script20150821-27229-as4wuh" returned 1
    Resource Declaration:
    ---------------------
    # In /var/chef/cache/cookbooks/resource/recipes/default.rb
     49:     bash "ip_create-#{tag}" do
     50:       user "root"
     51:       code <<EOF
     52: #{LKROOT}/lkadm/subsys/comm/ip/bin/creIPhier #{primach}
#{ipaddr} #{priif} #{mask} "none" #{switchback} #{tag}
     53: EOF
     54:     end
     55: # DataKeeper
    Compiled Resource:
    ------------------
    # Declared in
/var/chef/cache/cookbooks/resource/recipes/default.rb:49:in `block in
from_file'
    bash("ip_create-IP-A") do
      action [:run]
      retries 0
      retry_delay 2
      default_guard_interpreter :default
      command "ip_create-IP-A"
      backup 5
      returns 0
      user "root"
      code "/etc/default/LifeKeeper\n/opt/LifeKeeper/lkadm/subsys/comm/ip/bin/creIPhier
  a130 10.125.139.201 eth0 255.254.0.0 \"none\" INTELLIGENT IP-A \n"
        interpreter "bash"
      declared_type :bash
      cookbook_name "resource"
      recipe_name "default"
    end
Running handlers:
[2015-08-21T19:13:04+09:00] ERROR: Running exception handlers
Running handlers complete
[2015-08-21T19:13:04+09:00] ERROR: Exception handlers complete
Chef Client failed. 3 resources updated in 10.27878 seconds
[2015-08-21T19:13:04+09:00] FATAL: Stacktrace dumped to
/var/chef/cache/chef-stacktrace.out
[2015-08-21T19:13:04+09:00] ERROR: bash[ip_create-IP-A]
(resource::default line 49) had an error:
Mixlib::ShellOut::ShellCommandFailed: Expected process to exit with
[0], but received '1'
---- Begin output of "bash"  "/tmp/chef-script20150821-27229-as4wuh" ----
STDOUT:
STDERR: BEGIN create of "IP-A"
LifeKeeper application=comm on a130.
LifeKeeper communications resource type= ip on a130.
Creating resource instance with id IP-10.125.139.201 on machine a130
Resource successfully created on a130
BEGIN restore of "IP-A"
IP address seems to still exist somewhere else.
END failed "restore" of "IP-A" with return value of 1
restore of resource "IP-A" has failed
create ip hierarchy failure: perform_action failed
END failed create of "IP-A".
---- End output of "bash"  "/tmp/chef-script20150821-27229-as4wuh" ----
Ran "bash"  "/tmp/chef-script20150821-27229-as4wuh" returned 1
[2015-08-21T19:13:04+09:00] FATAL:


ものすごく長いですが、見るべきところはこの2箇所です。

これで
● どのリソースを作るときに
● なぜ失敗したか

を特定できます。


今回の場合はIPリソースの”IP-A"を作ろうとしたら、STDERRにある

IP address seems to still exist somewhere else.

というエラーで失敗したということが読み取れます。
STDERRに出るメッセージはLifeKeeper GUIで表示されるものと同じなので、エラーへの対応方法についてはマニュアルを参照してください。

今回のエラーはIPアドレスの重複なので、それを解消して再実行すれば問題は解決します。
まとめ

● Chefのエラーには2つのパターンがある
● コンパイルエラーはまずアトリビュートを確認する
● 実行時エラーはSTDERRを見る
の3点をおさえてください。

例を見てもらうとわかるように、うんざりするほど長いメッセージが出てきます。
が、パターンが定型で見るべきポイントは少ないので、要点を押さえることができれば問題解決は簡単です。

0 件のコメント:

コメントを投稿