年末大掃除の一環で、学生時代に書いてたOSSライブラリのレポジトリを sourceforge、google codes から Github に移行した。

• https://github.com/sonots/pukiwiki-plugin
  • 昔書いてた PukiWiki のプラグイン群。かつては PHPer だったらしい。
• https://github.com/sonots/opencvx
  • 院生時代に書いてた OpenCV のヘルパーメソッドとか、論文読んで実装してみたライブラリとか。かつては C++er だったらしい。
• https://github.com/sonots/cvprtoolbox
  • 院生時代に書いてた Computer Vision and Pattern Recognition 系の Matlab ライブラリ。かつては Matlaber (?) だったらしい。

久しぶりにみたら、コメントとか付いてたのに今更気づいたりして、完全に申し訳ない感じだった。

とはいえ、メンテナンスする環境がない(Matlab とかもはや持ってない)状態なので、メンテナ募集中です。どれだけ使ってる人いるか知らないけど。

重い腰をあげて社内の kvm な仮想サーバを vagrant box に変換する方法を調べたのでメモ。

流れ

kvm イメージ => virtualbox イメージ => vagrant box という変換の流れになるようだ。

ちなみに vagrant-kvm というものもあるようだが、 kvm はそもそも linux 前提なので、mac 上の vagrant で動かすことも考えると、やはり virtual box 形式に変換する必要がある。

kvm イメージを VirtualBox イメージに変換する

VirtualBox の VBoxManage コマンドを使って、vdi 形式に変換する。 kvm イメージはデフォルトなら kvm ホストの /var/lib/libvirt/images 以下にあるはず。

VBoxManage convertfromraw OrenoImage.img OrenoImage.vdi

TIPS: VirtualBox は vmdk (VMWare 形式) も扱えるので、OrenoImage.vmdk と指定しても良い。Vagrant Box にすると最終的に vmdk になってしまうので、この段階でどちらにすべきか気にしても無駄なようだ。

VirtualBox 上で VM を作る

VirtualBox の GUI から設定しても良いが、コマンドでやる場合はこう。

VBoxManage createvm --name OrenoImage --register
VBoxManage modifyvm OrenoImage --memory 1024 --acpi on --nic1 nat
VBoxManage modifyvm OrenoImage --ostype Linux_64
VBoxManage storagectl OrenoImage --name "IDE Controller" --add ide
VBoxManage modifyvm OrenoImage --hda OrenoImage.vdi

cf. http://mizzy.org/blog/2013/03/11/1/

ネットワーク周りの設定をいじる

VirtualBox の NAT 設定を使うとする。

udev のルールを削除する必要がある。そのままだと kvm 時代の eth0 設定と conflict するため(古い Mac アドレスの記述が残っているので邪魔になる)。自動生成もされないように /dev/null に symbolic link を貼ってしまう。

ln -sf /dev/null /etc/udev/rules.d/70-persistent-net.rules

ネットワーク設定を dhcp にする。

vi /etc/sysconfig/network-scripts/ifcfg-eth0
DEVICE=eth0
ONBOOT=yes
BOOTPROTO=dhcp

HOSTNAME, GATEWAY なども vagrant 流儀に合わせる。

vi /etc/sysconfig/network
NETWORKING=yes
NETWORKING_IPV6=yes
HOSTNAME=localhost.localdomain
RES_OPTIONS="single-request-reopen"

確認

/etc/init.d/network restart
curl http://www.google.com

TIPS: DHCPを使うと /etc/resolv.conf が自動で書き換えられ、DNS サーバに 10.0.2.3 が指定される。手動で設定したい場合は、/etc/sysconfig/network-scripts/ifcfg-eth0 に PEERDNS=no を追記すると、/etc/resolv.conf が自動で書き換えられなくなるので、好きな DNS サーバを指定できるようになる。

vagrant ユーザを作る

vagrant ssh コマンドですぐ入れるように vagrant ユーザを作り、パスワードを vagrant に設定する。sudo 権限を与える。vagrant デフォルトの鍵を登録する

useradd vagrant
passwd vagrant
visudo

以下を末尾に追加

vagrant ALL=(ALL) NOPASSWD:ALL

vagrant デフォルトの鍵を登録する

$ sudo su - vagrant
$ mkdir .ssh
$ curl https://raw.githubusercontent.com/mitchellh/vagrant/master/keys/vagrant.pub > .ssh/authorized_keys
# proxy認証ではねられるときは --insecureオプションをつける。
$ chmod 0755 .ssh
$ chmod 0644 .ssh/authorized_keys

TIPS: Vagrantfile で config.ssh.username = "xxxx" と指定すると vagrant ssh 時のユーザを vagrant ユーザ以外に設定することができる。

Vagrant Box を作成する

vagrant コマンドで VM を vagrant box ファイルに変換する

vagrant package --base OrenoImage --output OrenoImage.box

この box ファイルをどこかで共有するかんじ。

Vagrant を起動する

vagrant に box を登録して、Vagrantfile を作って起動する

vagrant box add OrenoImage OrenoImage.box
vagrant init OrenoImage # Vagrantfile ができる。
vagrant up

ssh できれば成功

vagrant ssh

TIPS: synced_folder の設定をしていないので vagrant up 時にエラーが出ているかもしれない。無効にするには Vagrantfile に config.vm.synced_folder ".", "/vagrant", disabled: true の記述を追加する。

まとめ

kvm イメージ => Virtual Box => Vagrant Box という流れで変換できた。 大体 mizzy さんのこの記事の手の平の上だった。

あとは以下に、道中ハマったトラブルのシューティングメモを書いて終わろうと思う。

トラブルシューティング

vagrant up で missing or invalid 'ovf:id'

Bringing machine 'default' up with 'virtualbox' provider...
==> default: Importing base box 'centos62_x86_64_plain'...
There was an error while executing `VBoxManage`, a CLI used by Vagrant
for controlling VirtualBox. The command and stderr is shown below.
Command: ["import", "-n", "/Users/seo.naotoshi/.vagrant.d/boxes/centos62_x86_64_plain/0/virtualbox/box.ovf"]
Stderr: 0%...
Progress state: VBOX_E_FILE_ERROR
VBoxManage: error: Appliance read failed
VBoxManage: error: Error reading "/Users/seo.naotoshi/.vagrant.d/boxes/centos62_x86_64_plain/0/virtualbox/box.ovf": missing or invalid 'ovf:id' attribute in operating system section element, line 18
VBoxManage: error: Details: code VBOX_E_FILE_ERROR (0x80bb0004), component Appliance, interface IAppliance
VBoxManage: error: Context: "int handleImportAppliance(HandlerArg*)" at line 304 of file VBoxManageAppliance.cpp

どうやら ostype が Unkown だったせいらしい。VM 作成の手順に

VBoxManage modifyvm centos62_x86_64_plain --ostype Linux_64

を追加して直った。

キーボード配列がホストOSと一致していない

ssh ではなく virtualbox ごしに直接入った場合の話。/etc/sysconfig/keyboard の修正が必要。

http://qiita.com/yoshiken/items/b06a97dd8958f3a6dd09

vagrant up で timeout

vagrant ユーザの作成、鍵設定が正しくできていない

http://dev.akinaka.net/2013/12/31/vagrant-up

VM を更新して Box を作り直したはずなのに更新されていない

vagrant package せずに vagrant box add して作り直した気になっている可能性大

VirtualBox のイメージはどこに保存される？

デフォルトでは ~/VirtualBox\ VMs にファイルがたくさんできる (sahara で作ったスナップショットもここにできる) 。

VirtualBox を起動して GUI から確認できる。削除もできる。

Vagrant の Box イメージはどこに保存される？

~/.vagrand.d 以下に vagrant add box したものが登録されている。

結論からいうと sudo が悪かった。2012 年に直ってる。

発生状況

こんなかんじの Ruby コードを書く(最初、ruby の問題かと思っていた)

Signal.trap('INT') { puts 'foo' }

10.times do
  sleep 1 
end

普通に実行すると期待通りに trap される

$ ruby test.rb
[Ctrl-c]
foo
[Ctrl-c]
foo

sudo を付けると trap が繰り返される

$ sudo ruby test.rb
[Ctrl-c]
foo
foo
そのあと１秒ごとに foo 出力 

調査

$ ps auxwwwf | grep test.rb
root      9112  0.0  0.1   8848  1772 pts/7    T    Dec15   0:00  |   \_ sudo ruby test.rb
root      9113  0.0  0.3   9628  4924 pts/7    Tl   Dec15   0:00  |   |   \_ ruby test.rb

子供に attach して、SIGINT が毎秒送られることを確認。誰が送っている？

$ sudo strace -p 9113 -etrace=signal
Process 9113 attached - interrupt to quit
--- SIGINT (Interrupt) @ 0 (0) ---rt_sigreturn(0x8f1ec38)                 = -1 EINTR (Interrupted system call)
--- SIGINT (Interrupt) @ 0 (0) ---rt_sigreturn(0x8f1ec38)                 = -1 EINTR (Interrupted system call)
--- SIGINT (Interrupt) @ 0 (0) ---rt_sigreturn(0x8f1ec38)                 = -1 EINTR (Interrupted system call)

親 (sudo). 親が繰り返し kill していた。

$ sudo strace -p 9112
Process 9112 attached - interrupt to quit
--- SIGINT (Interrupt) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
kill(9113, SIGINT)                      = 0
kill(9113, SIGINT)                      = 0
kill(9113, SIGINT)                      = 0

どうやら 2012 年に修正された問題らしい > http://comments.gmane.org/gmane.comp.tools.sudo.user/3766 

sudo は前にも別の固まる問題に遭遇したし、できるだけ避けたほうがいい印象高まってきている。常に最新を追っていればいいのかもしれないけど。

もう root になって実行するしかない。root 実行サイコーー!! (ヒドイ

前置き: この記事は俺たちのブログ企画で書いた記事の転用です。

「EFK (Elasticsearch + Fluentd + Kibana) なんて甘えですよ、漢は黙って awk | sort | uniq -c ですよ」と誰かが言ってたような言ってなかったような気がするのでログさらう時に自分がよく使う awk 芸について書きます。

想定データサンプル

こんなフォーマットで出る TSV 形式の Web アプリケーションログがあったとします。[TAB] はタブ文字です。

時間[TAB]ステータス[TAB]HTTPメソッド[TAB]URI[TAB]リクエストタイム

例えばこんな感じです。このログを awk 芸で処理していきます。

access.log

2014-12-05 12:00:00[TAB]200[TAB]GET[TAB]/api/v1/ping[TAB]0.017832
2014-12-05 12:00:01[TAB]200[TAB]POST[TAB]/api/v1/auth[TAB]1.001628
2014-12-05 12:10:00[TAB]404[TAB]GET[TAB]/favicon.ico[TAB]0.017832
2014-12-05 12:10:01[TAB]500[TAB]POST[TAB]/api/v1/login[TAB]5.00003

１分あたりアクセス量を調べる

１分あたりのアクセス量はこんなかんじで調べられるでしょう。

$ awk '{print $2}' access.log | awk -F: '{print $1 ":" $2}' | sort | uniq -c
   2 12:00
   2 12:10

解説しておくと、最初の awk で時刻フィールドを抜き出しています。

$ awk '{print $2}' access.log
12:00:00
12:00:01
12:10:00
12:10:01

デフォルトの空白文字、タブ文字を区切り文字として、 {print $2} のようにして第2フィールドを print しています。今回の場合は時刻のフィールドが出力されます。

パイプでつなげた次の awk で「時:分:秒」を「時:分」に変換しています。 -F オプションを使って区切り文字を : に変更し、第１フィールド(時)、:、第２フィールド(分) を print しています。

$ awk '{print $2}' access.log | awk -F: '{print $1 ":" $2}'
12:00
12:00
12:10
12:10

あとは慣用句と言っても良い sort | uniq -c に渡して、ユニークな値の数をカウントして出力しています。

$ awk '{print $2}' access.log | awk -F: '{print $1 ":" $2}' | sort | uniq -c
   2 12:00
   2 12:10

ちなみに、上の例では awk を２回使いましたが、awk には substr 関数なんかもあったりするので、以下のようにすると１発で書けたりもします。 使い捨てワンライナーなので、覚えやすい方を使えば良いかと思います。

$ awk '{print substr($2,1,5)}' access.log
12:00
12:00
12:10
12:10

1秒以上時間がかかっているアクセスをリストアップする

今回のログフォーマットでは、一番最後のフィールドがリクエストタイムでした。 一番最後のフィールドは $NF で指定することができます。

$ awk '{print $NF}' access.log
0.017832
1.001628
0.017832
5.00003

で、そのフィールドに条件を指定して、1秒以上時間がかかっている行のみに絞り混んでみます。次のようにします。

$ awk '$NF > 1.0' access.log
2014-12-05 12:00:01 200 POST    /api/v1/auth    1.001628
2014-12-05 12:10:01 500 POST    /api/v1/login   5.00003

これは以下のコマンドと同等です。 {} を省略した場合、デフォルトで {print $0} (全フィールドの表示) になります。

$ awk '$NF > 1.0 {print $0}' access.log
2014-12-05 12:00:01 200 POST    /api/v1/auth    1.001628
2014-12-05 12:10:01 500 POST    /api/v1/login   5.00003

おまけ：一番最後から１個前のフィールドは $(NF-1) で指定することができます。 ２個前なら $(NF-2) ですね。例えば、こんなかんじでつかいます。

$ awk '$NF > 1.0 {print $(NF-1)}' access.log
/api/v1/auth
/api/v1/login

5xx ステータスコードのアクセスをリストアップする

ステータスコード 500 の行を抜き出すには次のようにすればよいでしょう。

$ awk '$3 == 500' access.log
2014-12-05 12:10:01 500 POST    /api/v1/login   5.00003

正規表現を使うこともできて、5xx な行を抜き出したい場合には次のようにすればよいです。

$ awk '$3 ~ /^5/' access.log
2014-12-05 12:10:01 500 POST    /api/v1/login   5.00003

こちらでも、{print フィールド番号} とすれば指定したフィールドだけ出力させることができます。

$ awk '$3 ~ /^5/ {print $5}' access.log
/api/v1/login

おまけ：正規表現マッチはフィールドを指定しない場合、行全体($0) に対する正規表現マッチ($0 ~ /正規表現/)となるので、以下のように書くと grep のような効果を出せます。

$ awk '/500/' access.log
2014-12-05 12:10:01 500 POST    /api/v1/login   5.00003

合計リクエストタイムを求める

アクセスログのうち合計リクエストタイムを求めるには、ちょっとめんどくさいですが、次のようにします。

$ awk 'BEGIN{sum=0}{sum+=$NF}END{print sum}' access.log
6.03732

変数はデフォルトで 0 に初期化されるので、BEGIN{sum=0} は省略可能です。

最大値を求めたい場合は、

$ awk '{if($NF > max)max=$NF}END{print max}' access.log
5.00003

とかですかね。めんどくさいですが、まぁそんなもんですね。

LTSV なログを処理する

最近は LTSV フォーマットが人気ですが、ラベル:値 のフィールドを分離して 値 だけを取り出した TSV 形式に変換しないと awk では扱いづらいです。例えば、次のような LTSV ログがあったとして、

time:2014-08-13T14:10:10Z[TAB]status:200
time:2014-08-13T14:10:12Z[TAB]status:500

status フィールドの値だけを awk で抜き出そうとするとこんなかんじになるでしょうか。 面倒ですね。

$ awk -F\t '{split($2, status, ":"); print status[2]}' ltsv.log
200
500

awk でも扱いやすくするために皆さん、色々試行錯誤されているようです。

• awkとシェルでLTSVの取り扱いを簡単にするフィルタを書いてみた
• LTSV のログを jq でフィルタする
• lltsv という LTSV の特定キーだけ取り出す golang アプリケーションを書いた

こちらの lltsv というツールを使うと

$ lltsv -k time,status -K ltsv.log
2014-08-13T14:10:10Z    200
2014-08-13T14:10:12Z    500

のように値を取り出す事ができるので、そのまま awk につなげて

$ lltsv -k time,status -K ltsv.log | awk '$2 == 500'
2014-08-13T14:10:12Z    500

のように扱えるようです。便利っぽいですね。

おわりに

いやー、awk サイコーですね。ログを手打ちで awk コマンド打って集計するなんて幸せすぎて泣けてきますね。Enjoy happy awk life!

追記: awk 芸の高みへ

「統計屋のためのAWK入門」の記事が大変参考になるので物足りない方は読むと良いと思いますね！

rails アプリを複数台にデプロイする時に考えなければならない静的ファイルの配布について整理。社内用のつもりだったが、公開して困るものでもないのでここに書く。

前提知識

capistrano で rails アプリをデプロイした時の動き、rails の静的ファイルの扱いについて説明する。

アセットプリコンパイル

rails には静的ファイルを扱う仕組みとしてアセットプリコンパイルというものがある。この前処理によって、javascript, css ファイルを結合、minify したり、coffee script を javascript に変換したりする。

$ rake assets:precompile

生成されるファイルには以下のようにファイルの内容を元にしたダイジェスト値が付加される。 これはファイルの内容が変わった場合に、キャッシュされるのを防ぐためである。

public/application-908e25f4bf641868d8683022a5b62f54.css

capistrano-rails でのデプロイ

一般的に capistrano-rails プラグインを使って rails アプリをデプロイすると以下のようなディレクトリ構成ができる。

.
|-- current -> /home/sonots/sample/releases/20141203182648
|-- releases
|   |-- 20140806104707
|   |   |-- log -> /home/sonots/sample/shared/log
|   |   |-- pids -> /home/sonots/sample/shared/pids
|   |   `-- public -> /home/sonots/sample/shared/public
|   |-- 20140806104750
|   |-- 20141203181125
|   |-- 20141203182305
|   `-- 20141203182648
└── shared
    ├── log
    ├── pids
    └── public

rake assets:precompile によって生成した静的ファイルは current ディレクトリで実行され、shared/public ディレクトリに配置される。デプロイのたびに上書きで新しいファイルが積み上げられていく。

ポイントは内容が変わればダイジェスト値が変わるため古いファイルが上書きされないという点である。

なお、古いファイルは rake assets:clean を実行することで、最新と直近２つ(デフォルト)の assets を残して掃除することができる。 capistrano-rails 的には  cap deploy:cleanup_assets であるし、 cap deploy でも自動的に実行される。

capistrano-bundle_rsync の場合

さて、自作プラグインの話であるが、capistrano-bundle_rsyncでは、 デプロイサーバ上で git clone、bundle install を実行し、rake assets:precompile して生成された静的ファイルを以下のようにしてそれぞれのホストの shared/public ディレクトリに配信する。

rsync -az -e ssh .local_repo/releases/YYYYYMMDDXXXXXXX/public/ #{host}:/home/sonots/sample/shared/public

ポイントは --delete オプションを付けずに上書き同期している点である。古いファイルを消さない。

タスクの定義の仕方は README.md に書いているのでそちらを参照してもらいたい。

補足: ここでは releases/*/public -> shared/public に symlink を貼らないようにしています。また、nginx が参照するパスを shared/public  にして、全ての静的ファイルを shared/public に集めているということです。

アプリのデプロイ

では、複数サーバにアプリをデプロイすることについて考える。また、古い静的ファイルをお掃除することについても同時に考えたい。

Akamai のような CDN は使わずにアプリサーバ上の nginxで静的ファイルも配信するようなシチュエーションを想定している。アプリサーバが A, B 2台あり、その2台には LB (別のnginx インスタンスかもしれないし、Big IP のような箱物かもしれない)を通してラウンドロビンで負荷分散しているものとする。

だめなパターン

1. A にアプリをデプロイ、再起動
2. B にアプリをデプロイ、再起動

これはダメである。

なぜならば、1. の時点で A のアプリが再起動されると、A の画面は更新され、新しい静的ファイルを要求するようになるが、 その静的ファイルを取得するためのリクエストは A, B どのサーバに振り分けられるのかわからない。ここで、B に振り分けられてしまった場合、静的ファイルが B にはまだ存在せず問題となる。

＊ 再起動 = ホットリスタート、または「サービスアウト => 再起動 => サービスイン」とする。

大丈夫なパターン

1. A, B の順にアプリをデプロイ
2. A, B の順にアプリを再起動

このような手順にすると、1. の段階で A, B 全てに最新静的ファイル、および古い静的ファイルが配置される。 そのため、2. の段階で A のアプリのみが再起動されたとしても、全サーバに新しい静的ファイルが配置されているのだから、 静的ファイルのリクエストはどのサーバに向けられても問題がない。古い静的ファイルのリクエストが来た場合でも同じである。

古い静的ファイルのお掃除

最後に、古い静的ファイルのお掃除について考えたい。shared/public ディレクトリには静的ファイルを積み上げる方式となっているため、古いファイルがどんどん溜まっていってしまう。 いつ、どのように消すのかについて考える。

これは次のような手順にすればよいだろう。2. で全てのアプリが再起動されていれば、もう古い静的ファイルにはリクエストが来ないため、消してしまって良いということだ。

1. A, B の順にアプリをデプロイ
2. A, B の順にアプリを再起動
3. A, B の順に古い静的ファイルを消す

古い静的ファイルを消すには、以下のようにすると簡単である。各ホストで以下を実行する。

rsync -az --delete /home/sonots/sample/releases/*/public/ /home/sonots/sample/shared/public

capistrano-bundle_rsync で README 通りにデプロイした場合、releases ディレクトリの下にそのバージョンの静的ファイルが残っている。それを shared/public に --delete オプションつきで同期をとることで、古いファイルを削除している。

releases ディレクトリに残っている静的ファイルは全て残すように * と書いている。さきほど「もう古い静的ファイルにはリクエストが来ない」と言ったが、クライアントでのキャッシュを考えると可能性もないとは言い切れない。そこで、念のため１世代前、ついでに releases に残っている全世代(デフォルトで５世代)の静的ファイルを shared に残すようにした。クライアントがアプリ画面はキャッシュしていて、静的ファイルはキャッシュしていないなんて状況は通常ないと思うので心配しすぎかもしれない。