tdiary/tdiary-core — pull request #213 by minimum2scp (2012-10-18 16:28:28+00:00)
Title: RSS生成時に無限ループすることがある

日記本文にRDスタイルで ```(())``` という間違ったリンクをはって日記を更新すると、
update.rb が CPU 使用率100％になってレスポンスが帰ってきません。
（update.rbはApache2 + CGIで動作、tdiaryはgit master最新）

検証を進めたところ、RDスタイルかどうかは関係なく、どのスタイルでもHTMLとして
```hoge```
のような間違ったリンクが生成される場合、かつ makerss.rb が有効になっている場合に
発生することことがわかりました。
（なお日記本文自体は保存されています）

以下詳細です。

日記を更新してupdate.rbを1プロセス暴走させたあと、もう1回、別な画面から日記を更新すると、
例外をはいてくれてバックトレースを採取できました。
（以下はApache2+CGIではなく、検証のためにunicornで動作させて取得したログです）

```
E, [2012-10-19T00:49:40.841279 #12171] ERROR -- : app error: No such file or directory - data//cache/makerss.cache (Errno::ENOENT)
E, [2012-10-19T00:49:40.841352 #12171] ERROR -- : (plugin/makerss.rb):251:in `unlink'
E, [2012-10-19T00:49:40.841388 #12171] ERROR -- : (plugin/makerss.rb):251:in `rescue in makerss_update'
E, [2012-10-19T00:49:40.841422 #12171] ERROR -- : (plugin/makerss.rb):186:in `makerss_update'
E, [2012-10-19T00:49:40.841455 #12171] ERROR -- : (plugin/makerss.rb):401:in `block (2 levels) in load_plugin'
E, [2012-10-19T00:49:40.841488 #12171] ERROR -- : /tmp/tdiary-core/tdiary/plugin.rb:131:in `call'
E, [2012-10-19T00:49:40.841541 #12171] ERROR -- : /tmp/tdiary-core/tdiary/plugin.rb:131:in `block in update_proc'
E, [2012-10-19T00:49:40.841577 #12171] ERROR -- : /tmp/tdiary-core/tdiary/plugin.rb:130:in `each'
E, [2012-10-19T00:49:40.841609 #12171] ERROR -- : /tmp/tdiary-core/tdiary/plugin.rb:130:in `update_proc'
E, [2012-10-19T00:49:40.841640 #12171] ERROR -- : /tmp/tdiary-core/tdiary.rb:509:in `block in do_eval_rhtml'
E, [2012-10-19T00:49:40.841674 #12171] ERROR -- : /tmp/tdiary-core/tdiary.rb:509:in `instance_eval'
E, [2012-10-19T00:49:40.841706 #12171] ERROR -- : /tmp/tdiary-core/tdiary.rb:509:in `do_eval_rhtml'
E, [2012-10-19T00:49:40.841738 #12171] ERROR -- : /tmp/tdiary-core/tdiary.rb:162:in `eval_rhtml'
E, [2012-10-19T00:49:40.841771 #12171] ERROR -- : /tmp/tdiary-core/tdiary/dispatcher/update_main.rb:31:in `run'
E, [2012-10-19T00:49:40.841805 #12171] ERROR -- : /tmp/tdiary-core/tdiary/dispatcher/update_main.rb:6:in `run'
E, [2012-10-19T00:49:40.841841 #12171] ERROR -- : /tmp/tdiary-core/tdiary/dispatcher.rb:21:in `dispatch_cgi'
E, [2012-10-19T00:49:40.841874 #12171] ERROR -- : /tmp/tdiary-core/tdiary/application.rb:39:in `dispatch_request'
E, [2012-10-19T00:49:40.841906 #12171] ERROR -- : /tmp/tdiary-core/tdiary/application.rb:24:in `call'
E, [2012-10-19T00:49:40.841938 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/auth/basic.rb:25:in `call'
E, [2012-10-19T00:49:40.841970 #12171] ERROR -- : /tmp/tdiary-core/tdiary/rack/auth/basic.rb:23:in `call'
E, [2012-10-19T00:49:40.842000 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/builder.rb:134:in `call'
E, [2012-10-19T00:49:40.842031 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/urlmap.rb:64:in `block in call'
E, [2012-10-19T00:49:40.842062 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `each'
E, [2012-10-19T00:49:40.842093 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/urlmap.rb:49:in `call'
E, [2012-10-19T00:49:40.842124 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/omniauth-1.1.1/lib/omniauth/builder.rb:48:in `call'
E, [2012-10-19T00:49:40.842156 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:205:in `context'
E, [2012-10-19T00:49:40.842195 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/session/abstract/id.rb:200:in `call'
E, [2012-10-19T00:49:40.842228 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/rack-1.4.1/lib/rack/reloader.rb:44:in `call'
E, [2012-10-19T00:49:40.842262 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/unicorn-4.4.0/lib/unicorn/http_server.rb:535:in `process_client'
E, [2012-10-19T00:49:40.842294 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/unicorn-4.4.0/lib/unicorn/http_server.rb:610:in `worker_loop'
E, [2012-10-19T00:49:40.842329 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/unicorn-4.4.0/lib/unicorn/http_server.rb:491:in `spawn_missing_workers'
E, [2012-10-19T00:49:40.842362 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/unicorn-4.4.0/lib/unicorn/http_server.rb:141:in `start'
E, [2012-10-19T00:49:40.842393 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/gems/unicorn-4.4.0/bin/unicorn:121:in `'
E, [2012-10-19T00:49:40.842425 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/bin/unicorn:23:in `load'
E, [2012-10-19T00:49:40.842459 #12171] ERROR -- : /tmp/tdiary-core/vendor/bundle/ruby/1.9.1/bin/unicorn:23:in `

'
```

makerss_update で例外が起きているということなのですが、rescue して 何度も
retry するようになっていてここで無限ループしているように見えました。
retryしないようにして、どんな例外が起きているかを調べました。

```
diff --git a/misc/plugin/makerss.rb b/misc/plugin/makerss.rb
index ccf70d4..1eb8f77 100644
--- a/misc/plugin/makerss.rb
+++ b/misc/plugin/makerss.rb
@@ -248,8 +248,7 @@ def makerss_update
end
end
rescue ArgumentError
-	File.unlink( "#{@cache_path}/makerss.cache" )
-	retry
+	raise $!
end

if @conf.banner and not @conf.banner.empty?
```

この状態でもう一度日記を更新してRSSを生成させたところ、以下のバックトレースが採取できました:

```
ArgumentError
bad argument (expected URI object or URI string)
/usr/lib/ruby/1.9.1/uri/generic.rb:1202:in `rescue in merge'
/usr/lib/ruby/1.9.1/uri/generic.rb:1199:in `merge'
(plugin/makerss.rb):725:in `block in absolutify'
(plugin/makerss.rb):708:in `gsub'
(plugin/makerss.rb):708:in `absolutify'
(plugin/makerss.rb):366:in `makerss_body'
(plugin/makerss.rb):238:in `block (3 levels) in makerss_update'
(plugin/makerss.rb):237:in `each'
(plugin/makerss.rb):237:in `block (2 levels) in makerss_update'
(plugin/makerss.rb):235:in `each'
(plugin/makerss.rb):235:in `each_with_index'
(plugin/makerss.rb):235:in `block in makerss_update'
/usr/lib/ruby/1.9.1/pstore.rb:325:in `block (2 levels) in transaction'
/usr/lib/ruby/1.9.1/pstore.rb:324:in `catch'
/usr/lib/ruby/1.9.1/pstore.rb:324:in `block in transaction'
:10:in `synchronize'
/usr/lib/ruby/1.9.1/pstore.rb:316:in `transaction'
/tmp/tdiary-core/tdiary/compatible.rb:20:in `transaction'
(plugin/makerss.rb):187:in `makerss_update'
（以下略）
```

これは makerss.rb の absolutify メソッドの以下の場所で起きた例外でした。

```
elsif not uri.host
path = uri.path
path += '?' + uri.query if uri.query
path += '#' + uri.fragment if uri.fragment
location = (baseuri + path).to_s
end
```

```foo:bar://baz```のようなリンクの場合 ```uri.path``` が nil になっていたため、
```baseuri + path``` (URI::Generic#merge) で ArgumentError 例外となっていました。

そしてabsolutifyメソッドを呼び出したmakerss_updateに戻ってrescueされて
retryされて無限ループになっていた、ということです。

どのように修正するべきなのか迷いましたが、単純に ```uri.path``` もチェックする
ようにしています。