Crash with PDF on OS X
Opened this issue · 27 comments
OS XでPDFを表示すると落ちる。
詳細: https://gist.github.com/hiroyuki-sato/39aa614e6578709fa3a8
@hiroyuki-sato たぶん、PopplerでPDFを処理しているときに例外が発生して、それが誰にも処理されずトップレベルまでいって、Rubyが例外の詳細を出力して、終了するという流れになっていると思います。で、その、最後の終了するところでクラッシュしていると思います。
このクラッシュの仕方だとバックトレースを見れないので、自分でどこでクラッシュしているかを調べていく必要があります。私ならRabbit内にp
をたくさん入れてどこまでは動いている、どこからは動いていないというのを調べていくんですが、手元では再現しなかったのでそれはできません。
なので、とりあえず、Popplerで該当ファイルを読めるか確認してもらえませんか?以下のコマンドラインの結果を教えて欲しいです。
> ruby -r poppler -e 'p Poppler::Document.new("images/mail.pdf").pages'
ありがとうございます。
こんな感じになりました。
ruby -r poppler -e 'p Poppler::Document.new("images/mail.pdf").pages'
[#<Poppler::Page:0x7fbc93c3c830 ptr=0x7fbc92803880>]
バッチリですね!
とするとどこで落ちているかをデバッグプリントして絞り込んでいくしかないですね。。。
あたりをつけてもらえれば試しますよ。(おそらく)ここから~この間みたいな。
今どの辺を調べて良いかもよくわかっていないので..
ありがとうございます!
lib/rabbit/image/pdf.rb
の中のそれぞれのメソッドの最初と最後に仕込んで欲しいです。
例:
diff --git a/lib/rabbit/image/pdf.rb b/lib/rabbit/image/pdf.rb
index 92e80f0..0941c24 100644
--- a/lib/rabbit/image/pdf.rb
+++ b/lib/rabbit/image/pdf.rb
@@ -28,6 +28,7 @@ module Rabbit
end
def draw(canvas, x, y, params={})
+ p [__method__, :start]
if @document
default_params = {
:width => width,
@@ -37,6 +38,8 @@ module Rabbit
else
super
end
+ ensure
+ p [__method__, :end]
end
def pixbuf
ありがとうございます!。時間をとってやってみます。少しお待ちを
Out of memoryみたいです。
https://gist.github.com/hiroyuki-sato/05a04a0c28f59b27e250#file-gistfile1-txt-L86
cairo: stable 1.14.4 (bottled)
Backtraceをとってみました。
これでわかりますか?(ちょっと難しそうな気がしていますが...)
https://gist.github.com/hiroyuki-sato/05a04a0c28f59b27e250#file-backtrace-txt
ありがとうございます。
実は、欲しいのはRubyのバックトレースではなく、cairoがOut of memoryしたときのバックとレースなのです。。。
% G_DEBUG=fatal_warnings lldb ~/.rbenv/versions/2.2.3/bin/ruby -S rabbit ...
とするとOut of memoryになったところでクラッシュしてくれるかもしれないです。。。
いずれにしてもうまくいっていないっぽいのですが
https://gist.github.com/hiroyuki-sato/05a04a0c28f59b27e250#file-00lldb_backtrace-txt
- fatal_warningsではなく
fatal-warnings
でしょうか? - 実行手順は下記のようだと思いますがいかがでしょうか?(exportは不要かも)
% export G_MESSAGES_DEBUG=all
% export G_DEBUG=fatal-warnings
% G_MESSAGES_DEBUG=all G_DEBUG=fatal-warnings lldb ~/.rbenv/versions/2.2.3/bin/ruby
(lldb) target create "/path/to/home/.rbenv/versions/2.2.3/bin/ruby"
Current executable set to '/path/to/home/.rbenv/versions/2.2.3/bin/ruby' (x86_64).
(lldb) run -S ../rabbit/bin/rabbit
参照; https://developer.gnome.org/glib/stable/glib-running.html
あぁ、すみません。。。
ログレベルがINFO
なのでfatal_warnings
では止まりませんでした。。。
(実は、fatal-warnings
でもfatal_warnings
でも効くのです。)
cairoとPopplerをデバッグビルドしてデバッガーで追うしかないですね。。。
一応、デバッグ方法を書いておくと。。。
まず、エラーメッセージのcairo context error
でPopplerをgrepします。
すると、 http://cgit.freedesktop.org/poppler/poppler/tree/poppler/CairoOutputDev.cc#n199 だけがヒットします。
% grep -r -C5 'cairo context error' ./
./poppler/CairoOutputDev.cc-void CairoOutputDev::setCairo(cairo_t *cairo)
./poppler/CairoOutputDev.cc-{
./poppler/CairoOutputDev.cc- if (this->cairo != NULL) {
./poppler/CairoOutputDev.cc- cairo_status_t status = cairo_status (this->cairo);
./poppler/CairoOutputDev.cc- if (status) {
./poppler/CairoOutputDev.cc: error(errInternal, -1, "cairo context error: {0:s}\n", cairo_status_to_string(status));
./poppler/CairoOutputDev.cc- }
./poppler/CairoOutputDev.cc- cairo_destroy (this->cairo);
./poppler/CairoOutputDev.cc- assert(!cairo_shape);
./poppler/CairoOutputDev.cc- }
./poppler/CairoOutputDev.cc- if (cairo != NULL) {
これを見ると、引数で渡ってきたcairo_t
にエラーが設定されていればPopplerもエラーにしていることがわかります。
grepするとsetCairo
でNULL
以外を設定しているのはどれもcairo_create()
の結果を渡していることがわかります。
% grep -r -C5 'setCairo (cr)' poppler/CairoOutputDev.cc
saveImage (image);
if (imgDrawCbk && imgDrawCbk (numImages - 1, imgDrawCbkData)) {
surface = cairo_image_surface_create (CAIRO_FORMAT_ARGB32, width, height);
cr = cairo_create (surface);
setCairo (cr);
cairo_translate (cr, 0, height);
cairo_scale (cr, width, -height);
CairoOutputDev::drawImageMask(state, ref, str, width, height, invert, interpolate, inlineImg);
image->setImage (surface);
--
saveImage (image);
if (imgDrawCbk && imgDrawCbk (numImages - 1, imgDrawCbkData)) {
surface = cairo_image_surface_create (CAIRO_FORMAT_ARGB32, width, height);
cr = cairo_create (surface);
setCairo (cr);
cairo_translate (cr, 0, height);
cairo_scale (cr, width, -height);
CairoOutputDev::drawImageMask(state, ref, str, width, height, invert, inlineImg, gFalse);
if (state->getFillColorSpace()->getMode() == csPattern) {
--
saveImage (image);
if (imgDrawCbk && imgDrawCbk (numImages - 1, imgDrawCbkData)) {
surface = cairo_image_surface_create (CAIRO_FORMAT_ARGB32, width, height);
cr = cairo_create (surface);
setCairo (cr);
cairo_translate (cr, 0, height);
cairo_scale (cr, width, -height);
CairoOutputDev::drawImage(state, ref, str, width, height, colorMap, interpolate, maskColors, inlineImg);
image->setImage (surface);
--
saveImage (image);
if (imgDrawCbk && imgDrawCbk (numImages - 1, imgDrawCbkData)) {
surface = cairo_image_surface_create (CAIRO_FORMAT_ARGB32, width, height);
cr = cairo_create (surface);
setCairo (cr);
cairo_translate (cr, 0, height);
cairo_scale (cr, width, -height);
CairoOutputDev::drawSoftMaskedImage(state, ref, str, width, height, colorMap, interpolate,
maskStr, maskWidth, maskHeight, maskColorMap, maskInterpolate);
--
saveImage (image);
if (imgDrawCbk && imgDrawCbk (numImages - 1, imgDrawCbkData)) {
surface = cairo_image_surface_create (CAIRO_FORMAT_ARGB32, width, height);
cr = cairo_create (surface);
setCairo (cr);
cairo_translate (cr, 0, height);
cairo_scale (cr, width, -height);
CairoOutputDev::drawMaskedImage(state, ref, str, width, height, colorMap, interpolate,
maskStr, maskWidth, maskHeight, maskInvert, maskInterpolate);
なので、cairo_create()
でOut of memoryになっていると推測できます。
あとは、どのcairo_create()
のときにOut of memoryになっているかを見つけて、見つけたらそのcairo_create()
の中をステップ実行します。
ありがとうございます。試してみます。気長にお待ちを
ありがとうございます!ムリしない程度でお願いします!
ここの処理に注目しました。
https://gist.github.com/hiroyuki-sato/bee0d26d8353588df50a#file-00trace-txt-L151-L156
CairoOutputDev::restoreState ってところで呼び出されるのですが
https://gist.github.com/hiroyuki-sato/bee0d26d8353588df50a#file-cairooutputdev-cc-L311
restoreState関数はここしか読んでいないのに、ログがでないのはなんでしょうね?
https://gist.github.com/hiroyuki-sato/bee0d26d8353588df50a#file-cairooutputdev-cc-L1969
lldbやgdbで、rubyを実行してこのライブラリにブレークポイントって仕掛けられるかご存知でしょうか?
gdbだとrun
する前にb CairoOutputDev.cc:1969
してからrun
するとしかけられます!
OSXでgdbを動かすのに苦労しました。
http://qiita.com/takahashim/items/204ffa698afe09bd4e28
でやってみたのですが、ブレークポイントがうまく設定できないですね。
絶対通っているところに仕掛けてみたんですけどね。
困りました。
gdb /path/to/ruby
b CairoOutputDev.cc:315
run -I /tmp/ruby-gnome2/poppler/lib/ -I /tmp/ruby-gnome2/poppler/ext/poppler/ -I /tmp/rcairo/lib/ -I/tmp/rcairo/ext/cairo/ -S ../rabbit/bin/rabbit
これだとどうでしょうか!?
% gdb --args /path/to/ruby -I /tmp/ruby-gnome2/poppler/lib/ -I /tmp/ruby-gnome2/poppler/ext/poppler/ -I /tmp/rcairo/lib/ -I/tmp/rcairo/ext/cairo/ ../rabbit/bin/rabbit
(gdb) b CairoOutputDev::CairoOutputDev
(gdb) r
https://gist.github.com/hiroyuki-sato/21475340e8091f5b99e1
ブレークポイント設定できました。一歩前進です。
が
libpoppler-glibの関数の情報が取得できていませんね。
popplerのCFLAGS関連全部 -g を -ggdb3をしてみたんですが..
(gdb)
#0 0x000000010517de94 in ?? () from /tmp/poppler/lib/libpoppler-glib.8.dylib
#1 0x00007fff5fbf5e60 in ?? ()
#2 0x00000001090498f8 in Gfx::restoreState (this=0x10a1e1d30) at Gfx.cc:5468
#3 Gfx::opRestore (this=0x10a1e1d30, args=<optimized out>, numArgs=1219152)
at Gfx.cc:957
さてどうしたものでしょう..
Popplerに-ggdb3を指定した手順を教えてもらえますか?
./configureしたあと、
find . -name 'Makefile' -print | xargs perl -i -pe 's/ -g / -ggdb3 /g'
をしてmake clean ; makeです。
もうちょっと詳しく取得できました。
rubyがデバッグなしのものだったので、デバッグシンボルありのrubyでもう一度試しました。
b CairoOutputDev::setCairo
でトレースした結果です。
まだ詳しく見ていないのでまた明日以降に確認します。
https://gist.github.com/hiroyuki-sato/926742f5668abffdd1ee
これは、rg_renderでステップかけた方がいいでしょうか?
#0 0x00000001072a1632 in CairoOutputDev::setCairo(_cairo*) () from /usr/local/opt/poppler/lib/libpoppler-glib.8.dylib
#1 0x0000000107293cef in _poppler_page_render(_PopplerPage*, _cairo*, bool, PopplerPrintFlags) ()
from /usr/local/opt/poppler/lib/libpoppler-glib.8.dylib
#2 0x000000010727ecea in rg_render () from /tmp/ruby-gnome2/poppler/ext/poppler/poppler.bundle
glib/poppler-page.cc
と思いましたが、ここでブレークかけてもわかりませんね。
static void
_poppler_page_render (PopplerPage *page,
cairo_t *cairo,
GBool printing,
PopplerPrintFlags print_flags)
{
CairoOutputDev *output_dev;
g_return_if_fail (POPPLER_IS_PAGE (page));
output_dev = page->document->output_dev;
output_dev->setCairo (cairo);
output_dev->setPrinting (printing);
さらにrg_renderのところでも見てみましたが、ここでも分かりづらそうですね。
rbpoppler-page.c
static VALUE
rg_render(VALUE self, VALUE ps_file_or_cairo)
{
if (RVAL2CBOOL(rb_obj_is_kind_of(ps_file_or_cairo, cPSFile))) {
return page_render_to_ps(self, ps_file_or_cairo);
} else {
return page_render(self, ps_file_or_cairo);
}
}
おぉ!
#79 (comment) に書いた通り、ステップ実行するのはPopplerやpoppler gemの中ではなく、cairoのなかです。なので、PopplerレベルではsetCairo()
の引数のcairo_t
のcairo_status()
が0
じゃないことを確認できればOKです。確認できたらどこでcairo_t
のcairo_satus()
が0
以外になったのかを確認するためにステップ実行します!
こんな感じにしているのですが、
https://gist.github.com/hiroyuki-sato/05ce79f7b46609d938cc#file-cairooutputdev-cc-L900
CAIRO_CREATEってメッセージが出てこないんですよね。やり方は間違えていないとは思うのですが、うーんというところで調べ中です。
out of memoryにステータスを変えているのは、下記のsetCairoですね。
glib/poppler-page.cc
static void
_poppler_page_render (PopplerPage *page,
cairo_t *cairo,
GBool printing,
PopplerPrintFlags print_flags)
{
CairoOutputDev *output_dev;
g_return_if_fail (POPPLER_IS_PAGE (page));
output_dev = page->document->output_dev;
output_dev->setCairo (cairo);
output_dev->setPrinting (printing);
こいつは、poppler_page_renderからのみ呼び出されているようなので
poppler/ext/poppler/rbpoppler-page.c
の中で、問題となるpoppler_page_renderを呼び出しているところがどこかを
調べれば良さそうですね。
あ、失礼何が言いたいかというと、現在ブレークポイントをかけているのはスーテータスが変わってしまったところでかけています。
ステータスが変わる前はどこか?ということを調べるのにブレークポイントはどこに仕掛ければいいかな?と思っているところです。