操作
バグ #1137
完了
3.6.0 で画像プレビュー表示に失敗することがある
Izumi Tsutsui さんがほぼ7年前に追加. ほぼ7年前に更新.
プラグイン名:
ブランチ:
クラッシュする:
説明
例によって NetBSD + pkgsrc という特殊環境なので環境依存の問題かもしれませんが
3.6.0-develop で Twitter TL の添付画像の URL をクリックしてプレビューウインドウを開いた場合、
表示に失敗して「error」の画像表示になることがあります。感覚的に 3回に1回くらい。
「error」の表示についても、
一瞬正しい画像が表示されてから「error」になる場合、
いきなり「error」になる場合、とがあります。
--debug オプションつきで起動して「error」が発生した時の出力は以下のような感じです。
mikutter-preview-log.txt
何度も失敗を繰り返していると、そのうち ruby が SEGV で死んでしまうようです。
画像を開かない場合は落ちることはないようです。
関係あるかわかりませんが ruby-gnome2 のバージョンは 3.2.1 です。
ファイル
| mikutter-preview-log.txt (5.48 KB) mikutter-preview-log.txt | Izumi Tsutsui, 2017-12-24 22:41 | ||
| openimg-segv-akkie.txt (86.3 KB) openimg-segv-akkie.txt | Akira Ouchi, 2017-12-25 11:08 | ||
| window.rb.diff (957 Bytes) window.rb.diff | Izumi Tsutsui, 2018-01-02 13:10 |
Akira Ouchi さんがほぼ7年前に更新
私も確認できたので貼ります。特定の画像出必ず起きるといった感じではないようでした（落ちたときに開いた画像を次に開いてら大丈夫だった）。
Izumi Tsutsui さんがほぼ7年前に更新
あひる焼きメモ¶
某スレより
https://social.mikutter.hachune.net/@moguno/99249760559208235
画像プレビューの奴rectがとちゅうでnilにならないと有り得ない？
https://social.mikutter.hachune.net/@ahiru/99249833279294838
pixbufloader.ssc(:area_updated, self)のブロックを評価中にrect = nilが実行され、rect[:left]の評価の次の瞬間にrect = nilとなり rect[:top]で例のエラーが発生とか…？
https://social.mikutter.hachune.net/@ahiru/99249835672532434
エラーのログを信じるならそうなってしまいそう
https://social.mikutter.hachune.net/@ahiru/99249857713652180
Thread.new ブロック内で Delayer.new ブロック作ってて、それはいいんだけど、その中で rect = nil にしてるのが見た目上怪しいが
https://social.mikutter.hachune.net/@ahiru/99249858551978788
どういったタイミングで起こりうるのかはまだ追ってない
https://social.mikutter.hachune.net/@moguno/99250000549630839
Delayerってメインスレッドが暇にならないと動かないはずだけと、法則が崩れる要素がある？
https://social.mikutter.hachune.net/@ahiru/99250023582251888
この辺把握してないのよな
たしかに openimg/window.rb の start_loading で rect が途中で nil になっている感じはしますが、
source:core/plugin/openimg/window.rb@ce152e52#L16
なにかしら atomic 的なロックがいるんですかね
Izumi Tsutsui さんがほぼ7年前に更新
- ファイル window.rb.diff window.rb.diff を追加
激しくテキトーな修正でエラーになっている箇所の処理で rect を別変数に入れてみると、
window.rb.diff
何度画像プレビューをクリックしても error になることはないようです。
Izumi Tsutsui さんがほぼ7年前に更新
理屈がわかっていないので闇雲に調べた結果のメモにしかなりませんが
こんな感じに rect 更新の前後に notice の表示を入れてそれぞれどのように呼ばれているかを見てみました。
--- core/plugin/openimg/window.rb.orig 2017-12-23 01:57:54.000000000 +0900
+++ core/plugin/openimg/window.rb 2018-01-02 19:34:48.000000000 +0900
@@ -17,23 +17,28 @@
Thread.new {
Plugin.filtering(:openimg_pixbuf_from_display_url, photo, nil, nil)
}.next { |_, pixbufloader, complete_promise|
+ notice "start_loading: #{photo}"
if pixbufloader.is_a? GdkPixbuf::PixbufLoader
rect = nil
pixbufloader.ssc(:area_updated, self) do |_, x, y, width, height|
if rect
+ notice "start_loading: start updating rect"
rect[:left] = [rect[:left], x].min
rect[:top] = [rect[:top], y].min
rect[:right] = [rect[:right], x+width].max
rect[:bottom] = [rect[:bottom], y+height].max
+ notice "start_loading: end updating rect"
else
rect = {left: x, top: y, right: x+width, bottom: y+height}
Delayer.new do
+ notice "start_loading: start rect in Delayer"
progress(pixbufloader.pixbuf,
x: rect[:left],
y: rect[:top],
width: rect[:right] - rect[:left],
height: rect[:bottom] - rect[:top])
rect = nil
+ notice "start_loading: end rect in Delayer"
end
end
true end
すると、このような結果↓で、 if rect の成立側と非成立側がほぼ同時に呼ばれてる感じがします。
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:20:in `block in start_loading': start_loading: #<Plugin::Photo::Photo:0xb8a9cf00>
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:34:in `block (3 levels) in start_loading': start_loading: start rect in Delayer
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:25:in `block (2 levels) in start_loading': start_loading: start updating rect
/usr/pkg/share/mikutter/core/plugin/openimg/window.rb:26:in `block (2 levels) in start_loading': undefined method `[]' for nil:NilClassnotice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:41:in `block (3 levels) in start_loading': start_loading: end rect in Delayer
from /usr/pkg/share/mikutter/core/mui/gtk_extension.rb:33:in `block in safety_signal_connect'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/gobject-introspection-3.2.1/lib/gobject-introspection/loader.rb:576:in `invoke'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/gobject-introspection-3.2.1/lib/gobject-introspection/loader.rb:576:in `block in define_method'
from /usr/pkg/share/mikutter/core/plugin/openimg/openimg.rb:42:in `block (3 levels) in <top (required)>'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block (3 levels) in download_mainloop'
from /usr/pkg/lib/ruby/2.3.0/set.rb:306:in `each_key'
from /usr/pkg/lib/ruby/2.3.0/set.rb:306:in `each'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block (2 levels) in download_mainloop'
from /usr/pkg/share/mikutter/core/utils.rb:278:in `block in atomic'
from /usr/pkg/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'
from /usr/pkg/share/mikutter/core/utils.rb:278:in `atomic'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block in download_mainloop'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:142:in `loop'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:142:in `download_mainloop'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:128:in `block in download_routine'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:155:in `open_uri'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:717:in `open'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:35:in `open'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:127:in `download_routine'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:113:in `cache_read_or_download'
from /usr/pkg/share/mikutter/core/serialthread.rb:70:in `block in new_thread'
error: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:49:in `block (2 levels) in start_loading': exit
from /usr/pkg/lib/ruby/gems/2.3.0/gems/glib2-3.2.1/lib/glib2.rb:46:in `exit'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/glib2-3.2.1/lib/glib2.rb:46:in `exit_application'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/gobject-introspection-3.2.1/lib/gobject-introspection/loader.rb:576:in `invoke'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/gobject-introspection-3.2.1/lib/gobject-introspection/loader.rb:576:in `block in define_method'
from {MIKUTTER_DIR}/core/plugin/openimg/openimg.rb:42:in `block (3 levels) in <top (required)>'
from {MIKUTTER_DIR}/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block (3 levels) in download_mainloop'
from /usr/pkg/lib/ruby/2.3.0/set.rb:306:in `each_key'
from /usr/pkg/lib/ruby/2.3.0/set.rb:306:in `each'
from {MIKUTTER_DIR}/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block (2 levels) in download_mainloop'
from {MIKUTTER_DIR}/core/utils.rb:278:in `block in atomic'
from /usr/pkg/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'
from {MIKUTTER_DIR}/core/utils.rb:278:in `atomic'
from {MIKUTTER_DIR}/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block in download_mainloop'
from {MIKUTTER_DIR}/core/lib/diva_hacks/mixin/photo_mixin.rb:142:in `loop'
from {MIKUTTER_DIR}/core/lib/diva_hacks/mixin/photo_mixin.rb:142:in `download_mainloop'
from {MIKUTTER_DIR}/core/lib/diva_hacks/mixin/photo_mixin.rb:128:in `block in download_routine'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:155:in `open_uri'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:717:in `open'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:35:in `open'
from {MIKUTTER_DIR}/core/lib/diva_hacks/mixin/photo_mixin.rb:127:in `download_routine'
from {MIKUTTER_DIR}/core/lib/diva_hacks/mixin/photo_mixin.rb:113:in `cache_read_or_download'
from {MIKUTTER_DIR}/core/serialthread.rb:70:in `block in new_thread'
error: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:60:in `block in start_loading': JPEG 画像ファイル (Improper call to JPEG library in state 205) の解釈でエラー
from /usr/pkg/lib/ruby/gems/2.3.0/gems/gobject-introspection-3.2.1/lib/gobject-introspection/loader.rb:576:in `invoke'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/gobject-introspection-3.2.1/lib/gobject-introspection/loader.rb:576:in `block in define_method'
from {MIKUTTER_DIR}/core/plugin/openimg/window.rb:53:in `block (2 levels) in start_loading'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/chain/base.rb:18:in `activate'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/worker.rb:93:in `block (2 levels) in wait_and_activate'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/worker.rb:87:in `catch'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/worker.rb:87:in `block in wait_and_activate'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/worker.rb:86:in `catch'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/worker.rb:86:in `wait_and_activate'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/worker.rb:76:in `block (2 levels) in fiber'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/worker.rb:75:in `loop'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/delayer-deferred-2.0.0/lib/delayer/deferred/worker.rb:75:in `block in fiber'
また、条件によっては start_loading が何度も呼ばれる現象が起きているようです。
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:20:in `block in start_loading': start_loading: #<Plugin::Photo::Photo:0xb8ac796c>
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:25:in `block (2 levels) in start_loading': start_loading: start updating rect
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:30:in `block (2 levels) in start_loading': start_loading: end updating rect
[738回くらい繰り返し]
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:25:in `block (2 levels) in start_loading': start_loading: start updating rect
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:34:in `block (3 levels) in start_loading': start_loading: start rect in Delayer
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:41:in `block (3 levels) in start_loading': start_loading: end rect in Delayer
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:30:in `block (2 levels) in start_loading': start_loading: end updating rect
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:25:in `block (2 levels) in start_loading': start_loading: start updating rect
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:30:in `block (2 levels) in start_loading': start_loading: end updating rect
[1600回くらい繰り返し]
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:30:in `block (2 levels) in start_loading': start_loading: end updating rect
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:25:in `block (2 levels) in start_loading': start_loading: start updating rect
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:41:in `block (3 levels) in start_loading': start_loading: end rect in Delayer
notice: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:25:in `block (2 levels) in start_loading': start_loading: start updating rect
/usr/pkg/share/mikutter/core/plugin/openimg/window.rb:26:in `block (2 levels) in start_loading': undefined method `[]' for nil:NilClass
from /usr/pkg/share/mikutter/core/mui/gtk_extension.rb:33:in `block in safety_signal_connect'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/gobject-introspection-3.2.1/lib/gobject-introspection/loader.rb:576:in `invoke'
from /usr/pkg/lib/ruby/gems/2.3.0/gems/gobject-introspection-3.2.1/lib/gobject-introspection/loader.rb:576:in `block in define_method'
from /usr/pkg/share/mikutter/core/plugin/openimg/openimg.rb:42:in `block (3 levels) in <top (required)>'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block (3 levels) in download_mainloop'
from /usr/pkg/lib/ruby/2.3.0/set.rb:306:in `each_key'
from /usr/pkg/lib/ruby/2.3.0/set.rb:306:in `each'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block (2 levels) in download_mainloop'
from /usr/pkg/share/mikutter/core/utils.rb:278:in `block in atomic'
from /usr/pkg/lib/ruby/2.3.0/monitor.rb:214:in `mon_synchronize'
from /usr/pkg/share/mikutter/core/utils.rb:278:in `atomic'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:146:in `block in download_mainloop'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:142:in `loop'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:142:in `download_mainloop'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:128:in `block in download_routine'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:155:in `open_uri'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:717:in `open'
from /usr/pkg/lib/ruby/2.3.0/open-uri.rb:35:in `open'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:127:in `download_routine'
from /usr/pkg/share/mikutter/core/lib/diva_hacks/mixin/photo_mixin.rb:113:in `cache_read_or_download'
from /usr/pkg/share/mikutter/core/serialthread.rb:70:in `block in new_thread'
error: {MIKUTTER_DIR}/core/plugin/openimg/window.rb:49:in `block (2 levels) in start_loading': exit
rect の設定と Delayer まわりの意図を理解できていないので
何がどうあるべきなのかわかっていませんが、どんなもんでしょう。
Izumi Tsutsui さんがほぼ7年前に更新
Delayer 内で rect=nil にしている記述をコメントアウトすると
ここまる1日ほどエラーは発生せず特に副作用もなく動いているようなのですが、
回避策としてはありなのでしょうか。
--- core/plugin/openimg/window.rb.orig 2017-12-23 01:57:54.000000000 +0900
+++ core/plugin/openimg/window.rb 2018-01-02 22:47:39.000000000 +0900
@@ -33,7 +33,7 @@
y: rect[:top],
width: rect[:right] - rect[:left],
height: rect[:bottom] - rect[:top])
- rect = nil
+ #rect = nil
end
end
true end
toshi_a 初音 さんがほぼ7年前に更新
スマフォでコード見ただけですが、area_updateが呼び出される頻度が高いと nil#[] を呼んでしまうバグがありそうですね。今まで起こらなかったのはgdkpixbufなどのアップデートなどが原因かもしれません。いずれにせよこの実装には問題があるので検証します
Izumi Tsutsui さんがほぼ7年前に更新
ruby-gnome2 や gdkpixbuf2 のバージョンは 3.5.15 を動かしていたときと同一で、
その時は問題は起きておらず、3.6.0 にしたらプレビューの問題が発生するようになった、
という状況です。（要すれば再度検証してみます）
ログからすると
core/lib/diva_hacks/mixin/photo_mixin.rb
あたりが新規っぽかったので何か呼び出し方法変わったのかなと思っていたのですが
ちゃんと読んでいないので見当違いなことを書いているかもしれません。
toshi_a 初音 さんがほぼ7年前に更新
以下のパッチで、確実に再現させることが出来るようになりました。
diff --git a/core/plugin/openimg/window.rb b/core/plugin/openimg/window.rb
index d1bdcf88..872d4104 100644
--- a/core/plugin/openimg/window.rb
+++ b/core/plugin/openimg/window.rb
@@ -18,8 +18,10 @@ module Plugin::Openimg
Plugin.filtering(:openimg_pixbuf_from_display_url, photo, nil, nil)
}.next { |_, pixbufloader, complete_promise|
if pixbufloader.is_a? GdkPixbuf::PixbufLoader
+ mainthread_only
rect = nil
pixbufloader.ssc(:area_updated, self) do |_, x, y, width, height|
+ mainthread_only
if rect
rect[:left] = [rect[:left], x].min
rect[:top] = [rect[:top], y].min
@@ -28,6 +30,7 @@ module Plugin::Openimg
else
rect = {left: x, top: y, right: x+width, bottom: y+height}
Delayer.new do
+ mainthread_only
progress(pixbufloader.pixbuf,
x: rect[:left],
y: rect[:top],
上記のコードは、全て単一のスレッドで動くことを前提にしていましたが、area_updateシグナルのブロックが異なるスレッドで呼ばれているということがわかりました。従ってよくあるマルチスレッドのデータレースが起こりうるので、報告されたクラッシュレポートとも辻褄が合います。
toshi_a 初音 さんがほぼ7年前に更新
- ステータス を 新規 から レビュー待ち に変更
- 担当者 を Izumi Tsutsui にセット
全く同じ状況では再現できなかったので確認できないので、再現する環境で試してもらってフィードバックをもらいたいです。
topic/1137-pixbufloader-error ブランチにpushしました。チケットにコメントを来れた人を中心に確認してもらえますか。
Izumi Tsutsui さんがほぼ7年前に更新
- 担当者 を Izumi Tsutsui から toshi_a 初音 に変更
mikutter 3.6.0 相当のツリーに 8d84308c の window.rb の atomic 追加差分を当てて、
その修正版の起動後に Twitter 添付画像プレビューを 100回超試行して、
error 発生はありませんでした。修正できていると判断して良いと思います。
チケットのステータスは「master へマージされた時点で解決」としたほうがいいですかね。
操作