Crash with PDF on OS X

[kou]

OS XでPDFを表示すると落ちる。

詳細： https://gist.github.com/hiroyuki-sato/39aa614e6578709fa3a8

[kou]

@hiroyuki-sato たぶん、PopplerでPDFを処理しているときに例外が発生して、それが誰にも処理されずトップレベルまでいって、Rubyが例外の詳細を出力して、終了するという流れになっていると思います。で、その、最後の終了するところでクラッシュしていると思います。

このクラッシュの仕方だとバックトレースを見れないので、自分でどこでクラッシュしているかを調べていく必要があります。私ならRabbit内にpをたくさん入れてどこまでは動いている、どこからは動いていないというのを調べていくんですが、手元では再現しなかったのでそれはできません。

なので、とりあえず、Popplerで該当ファイルを読めるか確認してもらえませんか？以下のコマンドラインの結果を教えて欲しいです。

> ruby -r poppler -e 'p Poppler::Document.new("images/mail.pdf").pages'

[hiroyuki-sato]

ありがとうございます。

こんな感じになりました。

ruby -r poppler -e 'p Poppler::Document.new("images/mail.pdf").pages'
[#<Poppler::Page:0x7fbc93c3c830 ptr=0x7fbc92803880>]

[kou]

バッチリですね！
とするとどこで落ちているかをデバッグプリントして絞り込んでいくしかないですね。。。

[hiroyuki-sato]

あたりをつけてもらえれば試しますよ。(おそらく)ここから~この間みたいな。
今どの辺を調べて良いかもよくわかっていないので..

[kou]

ありがとうございます！
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

[hiroyuki-sato]

ありがとうございます!。時間をとってやってみます。少しお待ちを

[hiroyuki-sato]

Out of memoryみたいです。

https://gist.github.com/hiroyuki-sato/05a04a0c28f59b27e250#file-gistfile1-txt-L86

cairo: stable 1.14.4 (bottled)

[hiroyuki-sato]

Backtraceをとってみました。

これでわかりますか？(ちょっと難しそうな気がしていますが...)

https://gist.github.com/hiroyuki-sato/05a04a0c28f59b27e250#file-backtrace-txt

[kou]

ありがとうございます。
実は、欲しいのはRubyのバックトレースではなく、cairoがOut of memoryしたときのバックとレースなのです。。。

% G_DEBUG=fatal_warnings lldb ~/.rbenv/versions/2.2.3/bin/ruby -S rabbit ...

とするとOut of memoryになったところでクラッシュしてくれるかもしれないです。。。

[hiroyuki-sato]

いずれにしてもうまくいっていないっぽいのですが

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

[kou]

あぁ、すみません。。。
ログレベルが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()の中をステップ実行します。

[hiroyuki-sato]

ありがとうございます。試してみます。気長にお待ちを

[kou]

ありがとうございます！ムリしない程度でお願いします！

[hiroyuki-sato]

ここの処理に注目しました。
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を実行してこのライブラリにブレークポイントって仕掛けられるかご存知でしょうか？

[kou]

gdbだとrunする前にb CairoOutputDev.cc:1969してからrunするとしかけられます！