プロジェクト

全般

プロフィール

致命的 #994

delayer-deferrd 1.1.0を使うと特定の操作でmikutterが落ちる

Satoshi Okuno5ヶ月前に追加. 5ヶ月前に更新.

ステータス:
新規
優先度:
通常
担当者:
-
対象バージョン:
開始日:
2017-03-14
期日:
進捗率:

0%

プラグイン名:
バックトレース:

・ポストボックスに文字列をコピペする
FiberError fiber called across stack rewinding barrier
{MIKUTTER_DIR}-xxx/vendor/bundle/ruby/2.4.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferred.rb:60:in `fiber'
{MIKUTTER_DIR}-xxx/vendor/bundle/ruby/2.4.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferredable.rb:69:in `block in _call'
{MIKUTTER_DIR}-xxx/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/procedure.rb:24:in `run'
{MIKUTTER_DIR}-xxx/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/extend.rb:58:in `run_once'
{MIKUTTER_DIR}-xxx/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/extend.rb:30:in `run'
{MIKUTTER_DIR}-xxx/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer.rb:43:in `method_missing'
{MIKUTTER_DIR}-xxx/core/plugin/gtk/delayer.rb:10:in `block in boot'
{MIKUTTER_DIR}-xxx/core/plugin/gtk/mainloop.rb:10:in `main'
{MIKUTTER_DIR}-xxx/core/plugin/gtk/mainloop.rb:10:in `mainloop'
mikutter.rb:66:in `boot!'
mikutter.rb:95:in `<main>'

・mikutter-uwm-hommageで追加されるポストボックス横のボタンを押下する。(ファイル選択ダイアログ表示)
FiberError fiber called across stack rewinding barrier
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferred.rb:60:in `fiber'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferredable.rb:69:in `block in _call'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/procedure.rb:24:in `run'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/extend.rb:58:in `run_once'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/extend.rb:30:in `run'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer.rb:43:in `method_missing'
{MIKUTTER_DIR}/core/plugin/gtk/delayer.rb:10:in `block in boot'
/Users/moguno/.mikutter/plugin/mikutter-uwm-hommage/penguin.rb:57:in `run'
/Users/moguno/.mikutter/plugin/mikutter-uwm-hommage/penguin.rb:57:in `choose_image_file'
/Users/moguno/.mikutter/plugin/mikutter-uwm-hommage/postbox.rb:216:in `block in initialize'
{MIKUTTER_DIR}/core/mui/gtk_extension.rb:33:in `block in safety_signal_connect'
{MIKUTTER_DIR}/core/plugin/gtk/mainloop.rb:10:in `main'
{MIKUTTER_DIR}/core/plugin/gtk/mainloop.rb:10:in `mainloop'
mikutter.rb:66:in `boot!'
mikutter.rb:95:in `<main>'

・設定画面から「リスト」ダイアログを表示
FiberError fiber called across stack rewinding barrier
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferred.rb:60:in `fiber'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferredable.rb:69:in `block in _call'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/procedure.rb:24:in `run'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/extend.rb:58:in `run_once'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer/extend.rb:30:in `run'
{MIKUTTER_DIR}/vendor/bundle/ruby/2.4.0/gems/delayer-0.0.2/lib/delayer.rb:43:in `method_missing'
{MIKUTTER_DIR}/core/plugin/gtk/delayer.rb:10:in `block in boot'
{MIKUTTER_DIR}/core/mui/gtk_mtk.rb:368:in `main'
{MIKUTTER_DIR}/core/mui/gtk_mtk.rb:368:in `dialog'
{MIKUTTER_DIR}/core/mui/gtk_mtk.rb:329:in `scrolled_dialog'
{MIKUTTER_DIR}/core/mui/gtk_crud.rb:181:in `popup_input_window'
{MIKUTTER_DIR}/core/mui/gtk_crud.rb:159:in `block in record_update'
{MIKUTTER_DIR}/core/mui/gtk_crud.rb:158:in `selected_each'
{MIKUTTER_DIR}/core/mui/gtk_crud.rb:158:in `record_update'
{MIKUTTER_DIR}/core/mui/gtk_crud.rb:37:in `block in update_button'
{MIKUTTER_DIR}/core/mui/gtk_extension.rb:33:in `block in safety_signal_connect'
{MIKUTTER_DIR}/core/plugin/gtk/mainloop.rb:10:in `main'
{MIKUTTER_DIR}/core/plugin/gtk/mainloop.rb:10:in `mainloop'
mikutter.rb:66:in `boot!'
mikutter.rb:95:in `<main>'

・mikutter-uwm-hommage で画像ファイル選択ダイアログが出てクリックしようとした時 その1 by tsutsui
/usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferred.rb:59:in `resume': fiber called across stack rewinding barrier
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferred.rb:59:in `fiber'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferredable.rb:69:in `block in _call'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer/procedure.rb:24:in `call'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer/procedure.rb:24:in `run'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer/extend.rb:58:in `run_once'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer/extend.rb:30:in `run'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer.rb:43:in `method_missing'
from /usr/pkg/share/mikutter/core/plugin/gtk/delayer.rb:10:in `block in boot'
from /home/tsutsui/.mikutter/plugin/mikutter-uwm-hommage/penguin.rb:57:in `call'
from /home/tsutsui/.mikutter/plugin/mikutter-uwm-hommage/penguin.rb:57:in `run'
from /home/tsutsui/.mikutter/plugin/mikutter-uwm-hommage/penguin.rb:57:in `choose_image_file'
from /home/tsutsui/.mikutter/plugin/mikutter-uwm-hommage/postbox.rb:216:in `block in initialize'
from /usr/pkg/share/mikutter/core/mui/gtk_extension.rb:33:in `call'
from /usr/pkg/share/mikutter/core/mui/gtk_extension.rb:33:in `block in safety_signal_connect'
from /usr/pkg/share/mikutter/core/plugin/gtk/mainloop.rb:10:in `call'
from /usr/pkg/share/mikutter/core/plugin/gtk/mainloop.rb:10:in `main'
from /usr/pkg/share/mikutter/core/plugin/gtk/mainloop.rb:10:in `mainloop'
from /usr/pkg/share/mikutter/mikutter.rb:64:in `boot!'
from /usr/pkg/share/mikutter/mikutter.rb:93:in `<main>'

・mikutter-uwm-hommage で画像ファイル選択ダイアログが出てクリックしようとした時 その2 by tsutsui

/usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferred.rb:59:in `fiber': fiber called across stack rewinding barrier (FiberError)
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-deferred-1.1.0/lib/delayer/deferred/deferredable.rb:69:in `block in _call'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer/procedure.rb:24:in `call'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer/procedure.rb:24:in `run'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer/extend.rb:58:in `run_once'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer/extend.rb:30:in `run'
from /usr/pkg/lib/ruby/gems/2.2.0/gems/delayer-0.0.2/lib/delayer.rb:43:in `method_missing'
from /usr/pkg/share/mikutter/core/plugin/gtk/delayer.rb:10:in `block in boot'
from /home/tsutsui/.mikutter/plugin/mikutter-uwm-hommage/penguin.rb:57:in `call'
from /home/tsutsui/.mikutter/plugin/mikutter-uwm-hommage/penguin.rb:57:in `run'
from /home/tsutsui/.mikutter/plugin/mikutter-uwm-hommage/penguin.rb:57:in `choose_image_file'
from /home/tsutsui/.mikutter/plugin/mikutter-uwm-hommage/postbox.rb:216:in `block in initialize'
from /usr/pkg/share/mikutter/core/mui/gtk_extension.rb:33:in `call'
from /usr/pkg/share/mikutter/core/mui/gtk_extension.rb:33:in `block in safety_signal_connect'
from /usr/pkg/share/mikutter/core/plugin/gtk/mainloop.rb:10:in `call'
from /usr/pkg/share/mikutter/core/plugin/gtk/mainloop.rb:10:in `main'
from /usr/pkg/share/mikutter/core/plugin/gtk/mainloop.rb:10:in `mainloop'
from /usr/pkg/share/mikutter/mikutter.rb:64:in `boot!'
from /usr/pkg/share/mikutter/mikutter.rb:93:in `<main>'

再現手順:

説明

下記の環境で、Fiber由来の例外が頻発するようになりました。

  • macOS Sierra
  • Ruby2.4.0p0(homebrew)
  • mikutter 3.5.4
  • delayer-deferrd 1.1.0

確実に再現するのは以下のパターンです。
それぞれバックトレースを付けています。

  • ポストボックスに文字列をコピペする
  • mikutter-uwm-hommageで追加されるポストボックス横のボタンを押下する。(ファイル選択ダイアログ表示)
  • 設定画面から「リスト」ダイアログを表示
ここまでの調査結果はこんな感じです。
  • delayer-deferrdを1.0.4にすると不再現になります。
  • この例外は、Fiber生成時とresume読み出し時において、スレッドがC言語レベルで持ってるメンバprotect_tagが異なる時に発生するようです。protect_tagはrb_protect()と言う「Procを実行して例外とか大域脱出が起きたか否かを返す」関数で更新されるようです。
  • 結局、何をやってるのかよくわからず、protect_tagが書き換わる条件が突き止められてない今日この頃です。

たちまちは調査継続しようと思います。


関連するチケット

関連している 致命的 #995: CPU使用率が常に100%になり、メモリを大量に確保しつづけることがある 進行中 2017-03-16

履歴

#1 toshi_a 初音5ヶ月前に更新

ポストボックスに文字列をコピペする

再現しませんでした。

mikutter-uwm-hommageで追加されるポストボックス横のボタンを押下する。(ファイル選択ダイアログ表示)

再現しませんでした。

・設定画面から「リスト」ダイアログを表示

再現しました。全く同じバックトレースが得られています。

一番目を除くと、ダイアログボックスを表示する処理なので、メインループが別の場所に奪われる箇所ですね。詳しく調査してみます。

#2 toshi_a 初音5ヶ月前に更新

Gtkのメインループ(=メインスレッド)の処理中にGtk.mainが再度呼ばれると、Delayerジョブの中でDelayerループが呼ばれる。
Deferredブロックの中でDeferredが呼ばれる可能性があるということで、Deferred 1.1.0からはDeferredのWorkerのFiberの中でWorkerのFiber#resumeを呼ぶということが起こりそう。その場合、FiberErrorが発生する。

Gtk.mainを呼び出して再帰メインループを作り出している全ての部分でこれが発生する可能性があるということ。Gtk.mainを呼び出しているのは以下の部分。
(正式なバグ報告はないが、本件と関係がありそうなツイートを見かけていたので、分かる範囲で参考程度に書いておいた。)

  • core/mui/gtk_mtk.rb
    • L306 (汎用のID/Passwordを問うアカウントダイアログを表示するユーティリティ)
    • L368 (汎用のOK/キャンセルダイアログを表示するユーティリティ)
      • 本チケットの3つ目のバックトレース「設定画面から「リスト」ダイアログを表示 」
  • core/plugin/gtk/mainloop.rb
    • L10 (mikutterのメインループ。おそらく今回の問題の対象外)
  • core/plugin/shortcutkey/shortcutkey_listview.rb
    • L127 (ショートカットキー設定画面の、キーバインドと割り当てるコマンドを設定するダイアログボックス)
  • core/plugin/bugreport/bugreport.rb
    • L45 (mikutter起動時に、前回クラッシュした時のレポートを送信するかを問うダイアログボックス)
  • core/plugin/change_account/account_control.rb
    • L85 (新規Twitterアカウントを追加する時のダイアログボックス)

バグレポートのダイアログボックスは、Delayer内部だがDeferred内部ではないのでクラッシュしていないと考えられる。他の箇所については、コールスタックが複雑なので個別に検証する必要がある。同じ部分でも、場合によってDeferredを経由するかどうかは変わる可能性があるので、検証の際には気をつける。

#3 Izumi Tsutsui5ヶ月前に更新

  • バックトレース を更新 (diff)

あまり参考にならないかもしれませんが、こちらで mikutter-uwm-hommage の操作で発生した時の状況と
バックトレースを付けておきます。

環境
  • NetBSD 7.1_RC2
  • ruby 2.2.6 (pkgsrc)
  • mikutter 3.5.4 (pkgsrc)
  • mikutter-uwm-hommage 353cdb862046ad98dad98280be819a93e7d17eaa
  • delayer-deferred-1.1.0
バックトレースに以下追加しています:
  • 「mikutter-uwm-hommage で画像ファイル選択ダイアログが出てクリックしようとした時 その1 by tsutsui」
  • 「mikutter-uwm-hommage で画像ファイル選択ダイアログが出てクリックしようとした時 その2 by tsutsui」

#4 toshi_a 初音約2ヶ月前に更新

  • 関連している 致命的 #995: CPU使用率が常に100%になり、メモリを大量に確保しつづけることがある を追加

他の形式にエクスポート: Atom PDF