障害報告内容

どこかの会社のようなフォーマットですが......。

発生事象

Movable Type 4のCAPTCHAが稼働していない。CAPTCHA画像が表示されず、当該URIにアクセスするとHTTP 500が帰る。

発見経緯

2009-07-25T03:00:00+0900頃、エラーログを眺めていて発見した。

影響範囲

Eorzea Lounge内の、コメント投稿可能な全てのウェブログ記事およびウェブページで、コメントを投稿出来ない。ただし、Open ID, LiveJournal, Vox, Yahoo, Yahoo Japan, Livedoor, AIM, hatena, WordPress.comの外部認証を使った場合は除く（それらによる認証時にはコメント投稿が可能である）。

暫定対応

代替策があった他、根本対応をすぐに行えたため、CAPTCHAを取り外すなどの対応は行わなかった。また、閲覧者が少ないこともあり、対外的な報告の類も差し控えた。

推定原因

XREAのドメインウェブを設定し、/virtual/eorzea/public_html/mt/のシンボリックリンクを触っていることが原因と推定されるが、後述の通りうやむやなままとした（核爆）。

根本対応

後述の「対応内容」の通り。

再発防止策

外部アプリケーションパッケージを使用する場合は、主要な機能の稼働確認を行う。Movable Typeでは、コメントの投稿もテスト項目に加える。

対応内容

原因調査

Perlモジュールの導入確認（確認済）

eorzea@s345:~> perl -MImage::Magick -MCrypt::DH -e 'print "hoge\n"'
hoge

取り敢えずモジュールは揃っていますね。

MT環境変数の追加（実効なし）

MT4 FAQにあるように、mt-config.cgiに以下の指定を施しても駄目でした。

CaptchaSourceImageBase /virtual/eorzea/public_html/mt/mt-static/images/captcha-source

上記ディレクトリにファイルが存在することは確認済みです。

eorzea@s345:~> ls /virtual/eorzea/public_html/mt/mt-static/images/captcha-source
2.png  6.png  a.png            background4.png  d.png  h.png  l.png  p.png  t.png  x.png
3.png  7.png  background1.png  background5.png  e.png  i.png  m.png  q.png  u.png  y.png
4.png  8.png  background2.png  b.png            f.png  j.png  n.png  r.png  v.png  z.png
5.png  9.png  background3.png  c.png            g.png  k.png  o.png  s.png  w.png

そもそも管理画面で「CAPTCHAプロバイダがありません」エラーが出ているわけではないので、ここまでの対応はあくまで念のための確認といったところでした。

CGIエラーの確認(1)

単にアクセスするだけでは変わりません。

eorzea@s345:~> perl -MWWW::Mechanize -e "print WWW::Mechanize->new->get('http://blog.eorze
a.asia/mt/mt-comments.cgi/captcha/1/yQ9aiqJJKLy5tHRxz7kHJborIMsAtVgPAun9AMR7')->as_string;
"
HTTP/1.1 500 Internal Server Error
Connection: close
Date: Fri, 24 Jul 2009 18:37:06 GMT
Server: Apache
Content-Type: text/html
Client-Date: Fri, 24 Jul 2009 18:37:11 GMT
Client-Peer: 59.139.29.101:80
Client-Response-Num: 1
Client-Transfer-Encoding: chunked

Script Error
The script did not produce proper HTTP headers. Please see the error log to see the detail of the errors. Depending on the server configuration, you can also run thisscript under CGIWrap debugging. Usually, either rename or linkthe script temporarily to a file which ends with .cgidextension, or add a AddHandler cgi-script-debug .cgiline to your .htaccess file.

CGIエラーの確認(2)

cgidという拡張子にして試しますが、結果をどう解釈した物やら（笑）。一応PNGイメージは出て来てしまっています。

eorzea@s345:~> cp -ip ./public_html/mt/mt-comments.cgi ./public_html/mt/mt-comments.cgid
eorzea@s345:~> chmod 700 ./public_html/mt/mt-comments.cgid
eorzea@s345:~> perl -MWWW::Mechanize -e "print WWW::Mechanize->new->get('http://blog.eorzea.asia/mt/mt-comments.cgid/captcha/1/yQ9aiqJJKLy5tHRxz7kHJborIMsAtVgPAun9AMR7')->as_string;"

Initializing Logging
Redirecting STDERR to STDOUT

Setting SIGXCPU to default behaviour

Limiting (cpu time) to (300)

Limiting (total available memory) to (160000000)

Limiting (resident set size) to (160000000)

Limiting (number of processes) to (15)


Environment Variables:
     QUERY_STRING: ''
      SCRIPT_NAME: '/mt/mt-comments.cgid'
        PATH_INFO: '/-/mt/mt-comments.cgid/captcha/1/yQ9aiqJJKLy5tHRxz7kHJborIMsAtVgPAun9AMR7'
    DOCUMENT_ROOT: '/virtual/eorzea/public_html/blog.eorzea.asia'
  PATH_TRANSLATED: '/virtual/eorzea/public_html/blog.eorzea.asia/captcha/1/yQ9aiqJJKLy5tHRxz7kHJborIMsAtVgPAun9AMR7'
      REMOTE_USER: ''
      REMOTE_HOST: ''
      REMOTE_ADDR: '61.210.86.128'

User Data Retrieved:
     UserID: 'eorzea'
        UID: '11028'
        GID: '20000'
   Home Dir: '/virtual/eorzea'

Script Base Directory:  '/virtual/eorzea/public_html/blog.eorzea.asia'
Trying to extract script from PATH_INFO
    Script Relative Path:  'mt/mt-comments.cgid'
    Script Absolute Path:  '/virtual/eorzea/public_html/blog.eorzea.asia/mt/mt-comments.cgid'

Fixing Environment Variables.

Environment Variables:
     QUERY_STRING: ''
      SCRIPT_NAME: '/mt/mt-comments.cgid'
        PATH_INFO: '/captcha/1/yQ9aiqJJKLy5tHRxz7kHJborIMsAtVgPAun9AMR7'
    DOCUMENT_ROOT: '/virtual/eorzea/public_html/blog.eorzea.asia'
  PATH_TRANSLATED: '/virtual/eorzea/public_html/blog.eorzea.asia/captcha/1/yQ9aiqJJKLy5tHRxz7kHJborIMsAtVgPAun9AMR7'
      REMOTE_USER: ''
      REMOTE_HOST: ''
      REMOTE_ADDR: '61.210.86.128'


UIDs/GIDs Changed To:
   RUID: '11028'
   EUID: '11028'
   RGID: '20000'
   EGID: '20000'

Changing current directory to '/virtual/eorzea/public_html/blog.eorzea.asia/mt'



argv[0] =  'cgiwrapd'
Executing  '/virtual/eorzea/public_html/blog.eorzea.asia/mt/mt-comments.cgid'
Output of script follows:
=====================================================
Error: /invalidfont in /findfont
Operand stack:
   Times-Roman-ISO   Times-Roman-ISO   Times-Roman
Execution stack:
   %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--   false   1   %stopped_push   1905   1   3   %oparray_pop   1904   1   3   %oparray_pop   1888   1   3   %oparray_pop   1771   1   3   %oparray_pop   --nostringval--   %errorexec_pop   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   1863   3   3   %oparray_pop
Dictionary stack:
   --dict:1151/1684(ro)(G)--   --dict:0/20(G)--   --dict:72/200(L)--
Current allocation mode is local
Last OS error: 2
Current file position is 263
GPL Ghostscript 8.61: Unrecoverable error, exit code 1
Error: /invalidfont in /findfont
Operand stack:
   Times-Roman-ISO   Times-Roman-ISO   Times-Roman
Execution stack:
   %interp_exit   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   --nostringval--   false   1   %stopped_push   1905   1   3   %oparray_pop   1904   1   3   %oparray_pop   1888   1   3   %oparray_pop   1771   1   3   %oparray_pop   --nostringval--   %errorexec_pop   .runexec2   --nostringval--   --nostringval--   --nostringval--   2   %stopped_push   --nostringval--   --nostringval--   1863   3   3   %oparray_pop
Dictionary stack:
   --dict:1151/1684(ro)(G)--   --dict:0/20(G)--   --dict:72/200(L)--
Current allocation mode is local
Last OS error: 2
Current file position is 263
GPL Ghostscript 8.61: Unrecoverable error, exit code 1
Status: 200
Expires: Fri, 24 Jul 2009 18:43:05 GMT
Date: Fri, 24 Jul 2009 18:43:06 GMT
Pragma: no-cache
Cache-control: no-cache
Content-Type: image/png

（以下略：PNG画像が出来ているようです）

eorzea@s345:~> rm -i ./public_html/mt/mt-comments.cgid
rm: remove regular file `./public_html/mt/mt-comments.cgid'? y

スクリプトの変更（解決）

結局、半ば禁じ手ですが、CORESERVERでMovableType4のCaptchaを使うを参考にして、MTコアである/lib/MT/Util/Captcha.pmの187-188行目（Movable Type Pro 4.261）をいじることにしました。

    # my $im = $imbase->Montage(geometry => $geometry_str,
    #                           tile     => $tile_geom);
    my $im = $imbase->Append(stack => '');

Image::Magick自体は私は使ったことのないモジュールなので、今はカプセル化の美名の下にブラックボックスとして「おまじない」を使うことにします。怖いのが、バージョンアップ時の対応漏れですので、バージョンアップ時チェックリストのようなものに追加しておこうと思います。

XREAでの稼働報告がいくつもあることから、上記の通り/virtual/eorzea/public_html/mt/へのシンボリックリンクを/virtual/eorzea/public_html/blog.eorzea.asia/mt/から張っていることが原因の一つのように思えますが、まああまり本筋から離れたところで時間を費やすのも問題なので、この対策でしばらく行ってみようと思います。