読者です 読者をやめる 読者になる 読者になる

おがさわらなるひこのオープンソースとかプログラミングとか印刷技術とか

おがさわらなるひこ @naru0ga が技術系で興味を持ったりなんだりしたことをたまーに書くブログです。最近はてなダイアリー放置しすぎて記事書くたびにはてな記法忘れるのではてなブログに移行しました。

クリエイティブ・コモンズ・ライセンス
特に断りがない場合は、本ブログの筆者によるコンテンツは クリエイティブ・コモンズ 表示 - 継承 4.0 国際 ライセンスの下に提供されています。

Common Printing Dialog をデバッグしてみよう (その2)

Linux Programming Printing

d:id:naruoga:20090528:1243491493 のつづき。


ということで、Common Printing Dialog がバグってるということが分かったので、ではどこでバグってるかを探してみましょう。

その前に、今までコマンドラインから gdb を使ってきましたが、「ふつー emacsgdb モード使うだろ」ってことで今回から emacs にしてみ……たら、なんか上手く動かないので (猛烈に遅くて帰ってこない ><) 泣く泣くコマンドラインでやります。


さらにさらに、ぼんやりしてたら最新のレポジトリ (6/11 コミット) だと現象が変わってました。しくしく。なんの意図の変更なんだか bzr を使い慣れないのでよくわかりませんので、とりあえず古いバージョンでやってみますね。


まずは前回同様、kde4-dialog/kde4-cpd をバックグラウンドで起動しておいてから、gdb を起動します。

$ kde4-dialog/kde4-cpd &
$ gdb kde4-dialog/view-dialog
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "i486-linux-gnu"...
(gdb) run
Starting program: /home/naruhiko/common-printing-dialog/build/kde4-dialog/view-dialog 
[Thread debugging using libthread_db enabled]
[New Thread 0xb5f19940 (LWP 19299)]
ASSERT failure in QVector<T>::operator[]: "index out of range", file /usr/include/qt4/QtCore/qvector.h, line 335

Program received signal SIGABRT, Aborted.
[Switching to Thread 0xb5f19940 (LWP 19299)]
0xb800b422 in __kernel_vsyscall ()
(gdb) 

QtCore の QVector (まぁ名前のとおりベクタっていうかコンテナクラスなんでしょう) というクラスで [] オペレータの処理で転けてるということですね。

私はぶっちゃけ Qt は全然分からないのですが、さすがにこんなに基本的なクラスに虫がいるというのは考えにくい。当然、呼んでる側がバグってる可能性が高いということですね。
つーことで呼び出し関係を見るのに backtrace を見てみましょう。

(gdb) bt
#0  0xb800b422 in __kernel_vsyscall ()
#1  0xb66286d0 in raise () from /lib/tls/i686/cmov/libc.so.6
#2  0xb662a098 in abort () from /lib/tls/i686/cmov/libc.so.6
#3  0xb7658595 in qt_message_output () from /usr/lib/libQtCore.so.4
#4  0xb7658681 in qFatal () from /usr/lib/libQtCore.so.4
#5  0xb765872c in qt_assert_x () from /usr/lib/libQtCore.so.4
#6  0x08064941 in QVector<CommonPrinting::CUPSDestination>::operator[] (
    this=0xa0aef84, i=0) at /usr/include/qt4/QtCore/qvector.h:335
#7  0x0805dc40 in CPDialogWidget::initWidgets (this=0xa0aef50)
    at /home/naruhiko/common-printing-dialog/kde4-dialog/cpd_dialog_widget.cpp:861
...

ということで CPDialogWidget::initWidget() の中の QVector の呼び出しで転けていると。

もちょっと詳しく見るために、CPDialogWidget::initWidget() の先頭にブレークポイントをかけて逐次実行してみます。なんで直接 cpd_dialog_widget.cpp:861 を見ないかといういうと、さすがにロジックを追っていかないとバグの意味が分からないからです (^^;)。

(gdb) b CPDialogWidget::initWidgets()

Breakpoint 1 at 0x805db19: file /home/naruhiko/common-printing-dialog/kde4-dialog/cpd_dialog_widget.cpp, line 855.
(gdb) run
The program being debugged has been started already.
Start it from the beginning? (y or n) y

Starting program: /home/naruhiko/common-printing-dialog/build/kde4-dialog/view-dialog 
[Thread debugging using libthread_db enabled]
[New Thread 0xb5eac940 (LWP 19668)]
[Switching to Thread 0xb5eac940 (LWP 19668)]

Breakpoint 1, CPDialogWidget::initWidgets (this=0x892b120)
    at /home/naruhiko/common-printing-dialog/kde4-dialog/cpd_dialog_widget.cpp:855
855		presetLabel = new QLabel("Quick Presets:");
(gdb) n
859		        printerbox->insertItem(i + 1, printers[i].name());
(gdb) n
855		presetLabel = new QLabel("Quick Presets:");
(gdb) n
856		printerbox = new QComboBox;
(gdb) n
857		printers = CUPSSupport::getDests();
(gdb) n
858		for(int i = 0; i < printers.size(); i++) {
(gdb) n
861		currentPrinter = &(printers[0]);
(gdb) n
862		changerButton = new QPushButton("Control printing aspects");
(gdb) n
861		currentPrinter = &(printers[0]);
(gdb) n
ASSERT failure in QVector<T>::operator[]: "index out of range", file /usr/include/qt4/QtCore/qvector.h, line 335

Program received signal SIGABRT, Aborted.
0xb7f9e422 in __kernel_vsyscall ()

まずは b (breakpoint) コマンドで CPDialogWidget::initWidgets() の先頭にブレークポイントをかけます。ご存知のとおり b で関数名だけ指定するとその先頭にブレークポイントが設定されます*1

んで run すると「実行中のがあるけど再実行しちゃっていいの?」と聞かれるので y と答えて最初から実行。さっき設定したブレークポイントで止まります。
んで n (next) でステップオーバーしながらどこで死ぬかを見つけます。同じところを何回か実行してるように見えますが、これは最適化でシンボルと実際のコードにズレがあるからでしょう。

ということで死んでるのは先ほどのバックトレースのとおり 861 行目。printers[0] のアクセスで死んでいることが分かります。
ではこの printers とは? まぁ、わざわざ調べなくてもわかりそうなものですが、せっかくなのでもう一度復習。上のステップ実行のなかで、

857		printers = CUPSSupport::getDests();

ってのがあります。CUPSSupport クラスを調べるのはめんどうなので省略しますが、メソッド名から察するにプリントキューを列挙して printers にぶっこむという処理をするのでしょう。
試しにこの行を実行して printers の中を見てみると、

857		printers = CUPSSupport::getDests();
(gdb) n
858		for(int i = 0; i < printers.size(); i++) {
(gdb) print printers
$1 = {{p = 0x8070670, d = 0x8070670}}
(gdb) print printers.size()
$2 = 0

printers.size() は 0。つまりこのベクタ型は空っぽということです。そらそうですね、プリントキュー一個もないんだもん。

んでま、QVector のリファレンス を見ますと、

T & QVector::operator[] ( int i )

Returns the item at index position i as a modifiable reference.

i must be a valid index position in the vector (i.e., 0 <= i < size()).

とありますので、size() = 0 のときにこのオペレータ呼んじゃダメってことですね。


ということで非常に簡単な例ではありましたが、gdb を使ってバグの原因を突き止めることはできたと。満足満足。


ほんとはこのあと、「せっかくだからバグ直してみた」「Bugzilla に直した結果を投稿してみた」と続く予定だったんですが、今思いっきり修正中のようなので、それはまた別の機会に。
もっともこのバグ、printers.size() == 0 のときにアラート出して死ぬ以外に直しようないんですけどね。

*1:ところでクラス名 (CPDialogWidget) にはタブ補完が効くのだけど、メソッド名には効かないのはなぜかしら。