Fluentd が終了しないことがある

1
Sadayuki Furuhashi @frsyuki

@repeatedly @sonots @tagomoris fluentdが終了しないときがある問題ですが、ここのところの例外処理あやしくないですかね? https://t.co/ywBBH7HKqm https://t.co/eo2hRAS0fN

2013-10-03 16:34:45
Sadayuki Furuhashi @frsyuki

@repeatedly @sonots @tagomoris 正しく終了しなかったケースって、out_exec_filterかin_exec使ってました?使っていたとしたら、先のコードで各種例外をrescueするようにしないと、shutdownが例外吐いてしまってマズい疑惑です。

2013-10-03 16:36:17
tagomoris @tagomoris

@frsyuki @repeatedly @sonots なるほど。out_exec_filter 使ってました。それかもですね。

2013-10-03 16:37:52
Sadayuki Furuhashi @frsyuki

@repeatedly @sonots @tagomoris 確かErrno::ESRCHの他にErrno::ECHILDが発生する可能性があって、それ考慮すると実はErrno::EPERMとか色々と発生する可能性があるはず。結局全部rescueしないとマズい

2013-10-03 16:38:49
そのっつ (Naotoshi Seo) @sonots

@frsyuki @repeatedly @tagomoris うーん、自分は out_exec_filter 使ってないですね ...

2013-10-03 16:38:58
そのっつ (Naotoshi Seo) @sonots

@frsyuki @repeatedly @tagomoris あー、なるほど。ここかもしれないですねー。

2013-10-03 16:41:58
tagomoris @tagomoris

@repeatedly ログが出ない原因は正直よくわかんなくて、ロガーがどっかで死亡してるかどこかで無限ループしてるかだろうとは思うけど、ちゃんと調べてないす

2013-10-03 17:01:34
Sadayuki Furuhashi @frsyuki

@repeatedly @tagomoris @sonots よく考えたらこのtrap直下の$logはロガーがemitするので例外を吐く可能性があるのでは。特にshutdown中でoutputが既に閉じていると起こる。https://t.co/QzH9hKb8nq

2013-10-03 17:03:06
tagomoris @tagomoris

@frsyuki @repeatedly @sonots んー、もしかして例外発生が無限連鎖する?

2013-10-03 17:03:40
tagomoris @tagomoris

shutdown のときはロガーがemitしないような変更入れなかったっけ

2013-10-03 17:04:07
Sadayuki Furuhashi @frsyuki

@repeatedly @tagomoris @sonots ここで例外になるとログも何も出ない。ロガーが例外を吐くと結構ヤバイ感じがあるので、Log#warnとかには全部rescueを入れた方が良いとか https://t.co/pkAtM1rZXL

2013-10-03 17:04:25
SKS rep @repeatedly

@frsyuki @sonots @tagomoris それadhocな対応だけど,shutdownシーケンスとかの流れを整理したほうがいい気も?emitしないログとか吐けるんだっけ?

2013-10-03 17:08:28
SKS rep @repeatedly

threads_exclude_eventsってshutdownの時に操作してるんだっけ?

2013-10-03 17:09:46
tagomoris @tagomoris

@repeatedly @frsyuki @sonots emitしないログはスレッド側からセットできる Log#disable_events(threads) ので、Engine#shutdown でThreadを起動したらまずこれをセットすればいいんでは

2013-10-03 17:09:56
Sadayuki Furuhashi @frsyuki

@tagomoris @repeatedly @sonots シグナルハンドラは他のスレッドの処理に割り込んで動くので、ハンドラ内でdisableしたらハンドラ終了後にどこかのスレッドでeventが出てこなくなるのと、trap直下にあるロギングは#shutdownに到達前に走るす

2013-10-03 17:11:49
SKS rep @repeatedly

問題点は大きく二つ? 1: exec系でshutdown時のSignal周りの例外処理が足りないんじゃないか疑惑.一通り関連キャッチすべき 2: shutdown時のログ周りで例外起きた時のハンドリングが甘いかも

2013-10-03 17:13:59
SKS rep @repeatedly

@frsyuki serverengineだとシグナルハンドラ処理用のスレッドがいて,この手の問題回避してるんだっけ?

2013-10-03 17:14:42
tagomoris @tagomoris

@repeatedly exec系の問題はSignal関係なく、子プロセスの処理まわりで起きる例外が多数想定されるので全部rescueして捨てていいんじゃねという話かな

2013-10-03 17:15:23
SKS rep @repeatedly

@tagomoris あ,シグナルじゃなくて子プロセスでした.混じった

2013-10-03 17:15:57
Sadayuki Furuhashi @frsyuki

@repeatedly そうです。必ず特定のスレッドにシグナルハンドラを実行させるために、一旦キューに積む処理がある。あとそのスレッドは全例外を勝手にrescueしてログはいて無視する。

2013-10-03 17:16:23
tagomoris @tagomoris

@frsyuki @repeatedly v10でそこまでの大改造をこれからやるかどうか、という問題な気がしますね

2013-10-03 17:16:54
SKS rep @repeatedly

@tagomoris @frsyuki 面倒くさいのでログ絵ミット時の例外握りつぶすで良い気がしますね!

2013-10-03 17:17:55
Sadayuki Furuhashi @frsyuki

@tagomoris @repeatedly たしかに。とりあえず怪しげな箇所にrescueを仕込む対応で良いのでは

2013-10-03 17:18:02
SKS rep @repeatedly

多分レアケースだし,v10では多めに見てもらって,serverengineベースのv11で,というのがコスト的に低そう

2013-10-03 17:19:09
SKS rep @repeatedly

1の解決策: Process.killしている所のrescueでESRCH以外もキャッチするようにする, 2の解決策: シグナルハンドラ用のスレッド作るのは面倒なので,とるあえず終了時のログの例外はにぎりつぶす, くらいかな?

2013-10-03 17:21:47