昨日、こういう Pull Request が Lokka に来てた。
「あれ、Lokka の master ブランチは Ruby 2.0 対応してないんじゃ」と思って Ruby 2.0.0-p0 で試してみたところ案の定 json.gem のインストールに失敗する。しかしものは試しにと思って、最新のパッチレベルの 2.0.0-p195 をインストールしてみたら Ruby 2.0 で Lokka 起動できた。
というわけでポータルシットは Ruby 2.0 で動いております。
ページキャッシングやってます
フッターのキャッシュとかフラグメントキャッシュはできたので、サイトのなかで一番重いアーカイブページのキャッシュを考えてみることにした。
当初はアーカイブページも、一番重い記事一覧表示部分をフラグメントキャッシュしてみていた。しかしあまり効果がなかった。Sinatra は仕組み上、コントローラーにいろいろ書いてしまいがちになり、アーカイブページのコントローラーが Fat になっていた。そのためフラグメントキャッシュをしたところでコントローラーの重い処理はビューがレンダリングされる前に走ってしまい、キャッシュの意味があまりない状態だった。
Rails だったらアクションキャッシュとかあるけど、先日から Folk して改造を進めている sinatra-cache でできるのはページキャッシュとフラグメントキャッシュだけなため、ページキャッシュをしてみることにした。
ページキャッシュの残念な点は Nginx 側の設定も必要なことだ。せっかく Lokka は Heroku や Sqale など Rack アプリケーション置ける PaaS にならどこにでも置けるのに、Nginx の設定変更を前提とした変更を行うと CMS for Cloud ではなくなってしまう。しかしこのブログは自分の勉強の場でもあるのでえいやっとやてみた。
sinatra-cache は Lokka + Nginx + Unicorn という環境であれば、LOKKA_ROOT/lib/lokka/app.rb を開いて以下のようにしてやれば使えるようになります。
require 'lokka'
require 'sinatra/cache' # <= 追加
module Lokka
class App < Sinatra::Base
configure do
# ...
register Sinatra::Cache # <= 追加
set :cache_enabled, true # <= 追加
# ...
end
# ...
end
endとかやってやれば、勝手に LOKKA_ROOT/public にキャッシュファイルを作るようになります。Nginx 側でキャッシュファイルがあれば Unicorn に proxy せずキャッシュファイルを返すようにすればページキャッシングで爆速になる。sinatra-cache は {$request_filename}.html という名前でキャッシュファイルを作るので Nginx の設定は以下のような感じになる。
server {
location {
root /var/wwww/portalshit/public;
# ...
if (!-f $request_filename.html) {
add_header Cache-Control public;
rewrite (.*) $1.html;
break;
}
# ...
}
}ポータルシットはトップページも重いのでトップページもページキャッシュしようかなと思ったけど、ページングとかあるのでいろいろ面倒くさいことになることに気がついた（キャッシュファイルがない状態で Google のクローラーが 35 ページ目とかをクローリングしてたら 35 ページ目の html が index.html としてキャッシュされてトップページに来た人が全員 35 ページ目を見ることになってしまう）のでやめた。
キャッシュ、レスポンスを速くしてくれるけど何でもキャッシュすれば良いわけではないし奥が深い。
Lokka でフラグメントキャッシュするようにした
Lokka でキャッシュしたいと書いてたけどキャッシュできるようになった。
結局 sinatra-cache を使った。sinatra-cache、2 年くらいメンテされてなくて全然だめかなと思ってたけどドキュメントが執拗なほど詳しく書かれてて使い方がわかりやすかったので使ってみることにした。フラグメントキャッシュがページごとに共有されなくて非効率的だったところは適当に改造した（morygonzalez/sinatra-cache · GitHub）。
footer 部分だけキャッシュするようにしてるのでトップページのレンダリングはあまり変わってないように感じる。個別記事ページは HTML が返ってくるまで 2, 3 秒かかってたのが 500ms から 600ms くらいになった。割とよいと思う。
いまのところ cache の有効期間みたいのを設定できないのでこれを任意の時間で設定できるようにしたい。しばらく使ってみて問題なさそうだったら Lokka 本体に Pull Request してもよいかも。
Lokka でキャッシュしたい
Lokka がすごく遅い
EC2 の micro で Lokka を運用してたけど、Unicorn が CPU 100% 近く使う状態が続き、リクエスト送ってレスポンスが返ってくるまでに 30 秒近くかかる状態になってて、AWS での運用を諦めざるを得なかった。さくら VPS に戻したところ、CPU 使用率もロードアベレージも落ち着いた。しかしレスポンスは遅くて、HTML が返ってくるまでに 5 秒くらいかかってる。
原因調べた
Newrelic を入れて調べてみた。Application が一番遅い。MySQL も遅いけど気になるレベルではないみたいだった。
- EC2 に Application
- さくら VPS に MySQL
という構成で運用していたのが遅い原因だったかも。App も DB も同じサーバーに置いたら Newrelic 上で Database が遅いと表示されなくなった。つまり Application をどうにかするしかない。
やろうとしてること
Lokka で動いててもそんなに遅くないページもある。komagata さんのブログは遅くない（heroku に置いてあるっぽいので heroku 側でキャッシュとかいろいろやってあるのもあると思う）。自分のブログに関してはテンプレートで最近の過去数ヶ月の月ごとの記事数表示したりタグクラウド出したりしてるところが遅そう。なので重い処理のところをフラグメントキャッシュしたい。
試したこと
sinatra-cache
導入できて動いた。勝手にページキャッシュする。フラグメントキャッシュできるけど、キャッシュのキーが URL のディレクトリベースのため、効率が悪い。
padrino-cache
導入できなかった。Padrino::Routing に依存してるっぽくて素の Sinatra で使いづらい。
落っこちてた gist (Simple fragment caching in sinatra)
これも Sinatra が前提。view から使うフラグメントキャッシュ専用ヘルパーメソッド。なんか Sinatra が内部的に使ってるインスタンス変数を上書きするというやり方みたい そのままでは Lokka で使えず <- ｲﾏｺｺ。
最後のやつが一番導入に近いところまで来てるっぽいけど、断片の部分だけ haml のコードを実行させて結果を取得させる、というところがなかなか難しい。Rails の ActionController::Caching のコードを見て参考にしようとしてみたけどちょっとよく分からなかった。
実は最近、仕事で Ruby 書かないおじさんになってしまったので週末に Ruby のコード見てもすんなり頭に入ってこない。ダメだなぁ。
Migration 忘れてデプロイして白画面になっててつらかった話
一月くらい前から Lokka の master ブランチを自分のブログ用のブランチに merge してサイトをデプロイすると謎の白画面が出るようになっていて困っていた。現象は極めて謎で、ローカルの開発環境（RACK_ENV='development'）では見られず、本番（RACK_ENV='production'）だけで発生した。HTTP ステータスコードは 1054 が返ってきたりする。なんか変な gem でも入れてしまったかなと休みの日に動作検証したりしていたんだけどついぞ分からなかった。
SQL 弱者なので気がついてなかったんだけど、2月15日の commit で Site モデルに新しいフィールドが追加されていた（Add default markup in admin/site/edit · 2243dc5 · lokka/lokka ※この機能便利すね）。なので bundle exec rake db:migrate しないといけなかったわけだった。ローカルで動いている開発環境（データベースは SQLite）では Migration なんて行ってないんだけどエラーは出なかった。本番は MySQL で動いていて、こちらでだけエラーが出るようだった。
しかしいざ migrate しようとすると失敗する。
bundle exec rake db:migrate
Upgrading Database...
rake aborted!
Invalid default value for 'updated_at'のようなエラーが出る。updated_at のデフォルト値がおかしいらしい。このときのテーブルの構造を見てみると以下のような感じだった。
mysql> desc entries;
+-----------------+--------------+------+-----+---------------------+-----------------------------+
| Field | Type | Null | Key | Default | Extra |
+-----------------+--------------+------+-----+---------------------+-----------------------------+
| id | int(11) | NO | PRI | NULL | auto_increment |
| user_id | int(11) | YES | | NULL | |
| category_id | int(11) | YES | | NULL | |
| slug | varchar(255) | YES | | NULL | |
| title | varchar(255) | YES | | NULL | |
| body | text | YES | | NULL | |
| type | text | NO | | NULL | |
| draft | tinyint(1) | YES | | 0 | |
| created_at | timestamp | NO | | 0000-00-00 00:00:00 | |
| updated_at | timestamp | NO | | CURRENT_TIMESTAMP | on update CURRENT_TIMESTAMP |
| frozen_tag_list | text | YES | | NULL | |
| markup | varchar(255) | YES | | NULL | |
+-----------------+--------------+------+-----+---------------------+-----------------------------+
調べてみたところ MySQL の Mode が NO_ZERO_DATE になっている場合、MySQL は timestamp 型のフィールドのデフォルト値に 0000-00-00 00:00:00 みたいな値を設定することを許さないらしい。 mysql - Invalid default value for 'create_date' timestamp field - Stack Overflow
検証用に別にテーブルを用意して bundle exec rake db:setup してみたところ、以下のような構造のテーブルができた。
mysql> desc entries;
+-----------------+------------------+------+-----+---------+----------------+
| Field | Type | Null | Key | Default | Extra |
+-----------------+------------------+------+-----+---------+----------------+
| id | int(10) unsigned | NO | PRI | NULL | auto_increment |
| user_id | int(11) | YES | | NULL | |
| category_id | int(11) | YES | | NULL | |
| slug | varchar(255) | YES | | NULL | |
| title | varchar(255) | YES | | NULL | |
| body | text | YES | | NULL | |
| markup | varchar(255) | YES | | NULL | |
| type | varchar(50) | NO | | NULL | |
| draft | tinyint(1) | YES | | 0 | |
| created_at | datetime | YES | | NULL | |
| updated_at | datetime | YES | | NULL | |
| frozen_tag_list | text | YES | | NULL | |
+-----------------+------------------+------+-----+---------+----------------+
created_at と updated_at は datetime 型になるらしい。なので以下のような ALTER 文を実行した。
mysql> alter table entries modify column created_at datetime, modify column updated_at datetime;
mysql> desc entries;
+-----------------+--------------+------+-----+---------+----------------+
| Field | Type | Null | Key | Default | Extra |
+-----------------+--------------+------+-----+---------+----------------+
| id | int(11) | NO | PRI | NULL | auto_increment |
| user_id | int(11) | YES | | NULL | |
| category_id | int(11) | YES | | NULL | |
| slug | varchar(255) | YES | | NULL | |
| title | varchar(255) | YES | | NULL | |
| body | text | YES | | NULL | |
| type | text | NO | | NULL | |
| draft | tinyint(1) | YES | | 0 | |
| created_at | datetime | YES | | NULL | |
| updated_at | datetime | YES | | NULL | |
| frozen_tag_list | text | YES | | NULL | |
| markup | varchar(255) | YES | | NULL | |
+-----------------+--------------+------+-----+---------+----------------+
これで最新のコードをデプロイしても真っ白画面になることはなくなった。以前遭遇した更新時に created_at の値が更新されてしまう問題 もフィールドの型が timestamp だったのが原因なのだと思う。SQLite から MySQL への移行は一筋縄では行かないことが分かった。
DataMapper はソースコード内の記述内容から動的に Migration を行えるけど、ActiveRecord みたいに $APP_ROOT/db/ ディレクトリに Migration ファイルを作ってくれたりしないので DB スキーマの変更が必要なことに気がつきにくい。便利だけど不便な感じがする。Rails で $APP_ROOT/db/ 以下にアホみたいにファイルが出来ていくの嫌だと思っていたけど、スキーマ変更に気がつかずコードをデプロイしてウェブアプリケーション停止みたいな自体は防げると思った。
ブログ書こうと思ってパソコン開いて「ついでに最新版の変更を取り込むか」とかやるとデプロイできなくなったりして書きたかった記事が書けず残念な感じになる。はてなブログでブログ書いてて画面が真っ白になったらひとでくんさんに不具合報告して直してもらえば良いので楽だと思う。
Syntax Highlight Plugin で Ajax をやめた
Lokka で Syntax Highlight するプラグイン（morygonzalez/lokka-pygmentize · GitHub）、これまで Ajax で Syntax Highlight させてたんだけど、HTTP リクエストが増えていけてないと感じたのでサーバーサイドでハイライトが完結するように変更した。Railscasts の #272 Markdown with Redcarpet - RailsCasts を参考にして、プラグインの中で Entry クラスを再オープンした。こんな感じ。
class Entry
def body
doc = Nokogiri::HTML(self.long_body)
doc.search("//pre").each do |pre|
code = pre.css("code")[0]
pre.replace Pygments.highlight(
code.text.rstrip,
:lexer => code[:class],
:options => { :encoding => 'utf-8' }
)
end
doc.to_s
end
end前の実装はだいぶいけてなかったと思うので随分マシになったと思う。あと この Pull Request でレンダリングエンジンに Redcarpet が追加されたので、GitHub と同じように
```ruby ```
みたいな感じの書き方でコードがハイライトされるようになった。便利。
追記1
ちゃんと動いてなかった…。夜直します…
追記2 2013/02/04 0:45
最終的にオープンした Entry クラスのコードは以下のようになった。
class Entry
alias_method :original_long_body, :body
def highlighted_long_body
syntax_highlight(self.original_long_body)
end
alias_method :body, :highlighted_long_body
alias_method :original_short_body, :short_body
def highlighted_short_body
syntax_highlight(self.original_short_body)
end
alias_method :short_body, :highlighted_short_body
def syntax_highlight(body)
doc = Nokogiri::HTML(body)
doc.search("//pre").each do |pre|
code = pre.css("code")[0]
lexer = if pre[:class].present?
pre[:class]
elsif code.present? && code[:class].present?
code[:class]
else
nil
end
begin
pre.replace Pygments.highlight(
code.text.rstrip,
:lexer => lexer,
:options => { :encoding => 'utf-8' }
) if code
rescue MentosError
next
end
end
doc.to_s
end
endLokka、結構メタプログラミングが多くて、Entry クラスのインスタンスの body メソッドは単なるゲッターではなく、 index アクションのときと show アクションのときで別々にエイリアスが設定されていて、index アクションのときは Entry#short_body 、show アクションのときは Entry#long_body が呼ばれるようになっていた。アラウンドエイリアス使って力業で解決したけど他のプラグインが同じように振る舞ったら破滅を招きそうな気がする…。それにしても『メタプログラミング Ruby』読んでなかったらどうすればいいか皆目検討付かなかっただろうなー。
Unicorn が暴走して困ってる
最近、cap deploy がしんどい。
こんな感じで、デプロイすると CPU の使用率が高まってしまう。Unicorn が暴走してるっぽい。シンボリックリンクとかはちゃんと置き換わってるんだけど、プロセスが古いままで、サイトの出力が新しくデプロイしたものに置き換わらない。こうなると cap deploy:restart とかやっても無反応で、ssh でログインして Unicorn を一旦停止し、手動で Lokka を再起動しないといけない。
拡散お願いしますアドベントカレンダー2012 に参加したとき、記事を公開してすぐサイトが落ちてしまって「やっぱりスモールマイクロインスタンスでは人気サイトポータルシットを運用するのは無理なのかな」と思ったのだけどどうもアクセスが集中して落ちたわけではないっぽい。
何なんだろう。