Causes of hard-to-find bugs

「また、やっちゃった。発見困難なバグの原因（は自分）」

数十枚の画像を次々に切り貼りして保存するプログラムを書いた際に、少しでも高速に処理するため、VCLのBmpをGDI+のBmpに変換して保存する方法を採用した。その際、var宣言に画像処理用の変数を、付け足し、付け足し･･･してプログラムを書いたら、自ら発見困難なバグを作り出してしまった･･･というお話。

１．不思議な現象が発生（バグその１）
２．原因を解明（したはずだった）
３．さらに不思議な現象が発生（バグその２）
４．バグ作成の元になった状況を再現
５．Createしないで使った場合は･･･
６．まとめ
７．お願いとお断り

１．不思議な現象が発生（バグその１）

TImageに数十枚の画像を切り貼りする処理は、それなりに時間がかかる。なので、処理が完了するまでは、ButtonのEnabledプロパティをFalseに設定して、気の短いユーザーに何度もボタンをクリックされるのを防止する。

このような場合、try ～ finally ～ end; を使って･･･

begin
  Button1.Enabled := False;
  try
    //処理
  finally
    Button1.Enabled := True;
  end;
end;

処理の途中で、なにかエラーがあっても、最終的にはTButtonのEnabledプロパティがTrueになるように組むことが基本だと学んだ。

同様に、TImageをマウスでクリックした際のイベントを拾う処理でも、間違ったクリックを拾うのを防止するため、ユーザーのクリックを拾った場合はTImageのEnabledプロパティを、一時的にFalseに設定して、メッセージを表示し、ユーザーの受け答えに応じてEnabledプロパティをTrue／Falseのいずれかに設定するようにしたのだが、この処理のどこかでTImageのEnabledプロパティがFalseのままになってしまって、いて･･･。

そのため「ある特定の画像処理手続き（その１）」を実行した後では、TImageのEnabledプロパティがFalseになっているから、TImageの画像をクリックすると走る「ある特定の画像処理手続き（その２）」が絶対に実行できない。プログラムを再起動して、手続き（その１）を実行せずに、手続き（その２）を実行した場合は、何でもなかったかのように問題なく手続き（その２）が実行できる。･･･という、理由がわかってみれば当たり前なんだけど、原因がわかるまでは何とも摩訶不思議な現象が発生（これがSetFocusならエラーが発生するから、話はまた別なんだけど･･･）。

２．原因を解明（したはずだった）

プログラムが完成に近づいたところで、（なんでかなー？）って、真剣に考えてようやくTImageのEnabledプロパティ設定の切り替え忘れだと気づき、あわててTImageに対する処理の直前に Image1.Enabled := True; を入れてプログラムを修正。

こんなことにならないよう、画像処理（その２）の手続きの最初に、先に述べたように、Image1.Enabled := True; と記述して強制的にエラー防止策をとるか、「TImageのEnabledプロパティがFalseで変更できません！」みたいなエラーメッセージが表示されるよう、if not Image1.Enabled then のようなエラー回避の処理を入れておくべきだったのだ。そうすれば、もっと早く間違いを発見できたと思うのだが、実際には、EnabledプロパティがFalse状態のTImageをクリックしても「何も起こらない」（もちろんエラーも起きない）ので、Enabledプロパティの設定が原因だと気づくまでに（なんでかなー？）っと、考えに考え、それなりに時間がかかってしまったのだ。

これで原因は解明され、バグは消えた（･･･と僕は思っていた）。

３．さらに不思議な現象が発生（バグその２）

TImageのEnabledプロパティ設定を修正したプログラムを実行してみると、今度は画像処理（その１）を行ったあと、連続して画像処理（その２）を確実に実行できるようになった。

MyPCで最初にテストした時は、画像処理（その１）に続けて、画像処理（その３）も確かにエラーなく実行できた。何回か、その後もMyPCでテストを繰り返し、僕は問題が完全に解決できたと信じ、MyPCではない、このプログラムを実際に実行（運用）する予定の業務用ノートPCで試しにプログラムを動かしてみた。すると･･･

MyPCではエラーを起こしたことは１回もなかったのに、業務用のノートPCでは画像処理（その３）で時々エラーが発生する。しかも、それが毎回必ず発生するわけではなく、起きる時と、起きない時があり、どちらかと言えば、起きるほうが少ない。画像処理（その３）は数十枚の画像に変更を加えて、さらにそれを１枚ずつ保存する時間のかかる重たい処理なので、途中で何らかの障害が発生してエラーになるのかと思ったが、エラーが起きなくても（エラーメッセージが明示的に表示されなくても）、画像に対して行った変更が「まったく保存されていない場合がある」ことにも気づく。同じループの中で処理した画像なのに、変更が保存される場合と、されない場合の２通りがあるなんて！ しかも、ランダムに。これはもう、完全に想定外。･･･てか、Delphi環境下、Object Pascalで書いたプログラムで、まさか、こんなことが起きるなんて･･･信じられない。Delphiとの思い出を過去20年遡って、こんなエラーを、僕は、これまでに経験したことが「ない」。

混乱の中で思いついたことは、GDI+を使った保存処理の記述のどこかに問題があるのは間違いないから、いったん、GDI+で処理していた部分をコメント化して、旧来のオーソドックスなJpeg画像の保存処理に変更してみることだった。これでエラーが起こらずに、変更を加えた画像データがきちんと保存できれば、最後の一手だけは確保できる。

procedure TForm1.ButtonXClick(Sender: TObject);
var
  jpg: TJPEGImage;
  s, strText: string;
begin
  //エラーが発生しても処理を止めない
  try
    for i := 1 to StringGrid1.RowCount-1 do
    begin
      S := ChangeFileExt(ListBox2.Items[i-1], '.jpg');
      Jpeg := TJPEGImage.Create;
      try
        //Jpeg.Assign(Image1.Picture.Bitmap);
        Jpeg.Assign(Image1.Picture.Graphic);
        Jpeg.Compress;
        Jpeg.SaveToFile(S);
      finally
        Screen.Cursor := crDefault;
        Jpeg.Free;
      end;
    end;
  except
    //エラー発生時の処理
    on E: Exception do begin
      strText := E.ClassName + sLineBreak + E.Message;
      Application.MessageBox(PChar(strText), '情報', MB_ICONINFORMATION);
    end;
  end;
end;

期待した通り、これなら、まったくエラーは起きない。ただし、GDI+を使った画像の高速な保存処理に慣れてしまった自分には、耐え難いほど処理速度が遅い･･･

すごく悩む。
時々、エラーは起こすけど、とりあえず動くし、何より速いGDI+のままで行くか、
それとも、遅いけど、確実に動作する旧来のJpeg画像の保存方法に変えるか、
それとも、いっそのこと、ユーザーが画像の保存処理方法を選択できるようにするか、
それとも、エラーが起きた時だけ、旧来の保存方法に戻そうか、
でも、明示的なエラーが起こらずに、変更した画像が保存されてない場合もあるし･･･

どうしよう･･･

困ったことにGDI+を使った方法では、もし明示的なエラーが発生しても、続けてもう一度保存処理を実行すれば「何事もなかったか」のようにプログラムは走り、多くの場合、「何事もなかったか」のように画像が保存されるのだ。ただ、ループ処理１０回に１回くらいの割合で、エラーが出ないにもかかわらず、しかも同一ループの中で保存処理する画像全部ではなく、そのうちの数枚だけ、加えた変更が「なぜか、反映されない」不思議な現象がランダムに起こってしまう。

いくらGDI+で保存する処理のプログラムを眺めても、原因が見出せない。
（この時はVCLからGDI+へのビットマップの変換部分に原因があると思っていた）

GDI+の保存処理のどこに原因があるのか、それがどうしてもわからなくて困った僕は、要するにJpegで保存するから、圧縮に時間がかかって遅いんだと考え、試しにビットマップ画像で保存する処理も試してみることにした。

  S:=ChangeFileExt(ListBox2.Items[i-1], '.bmp');
  tmpBmp:=TBitmap.Create;
  try
    tmpBmp.Assign(Image1.Picture.graphic);
    tmpBmp.SaveToFile(S);
  finally
    tmpBmp.Free;
  end;

エラーも出ず、全ての画像が確実に保存され、かつ、処理速度も速い。
ただ、Jpegで保存すれば、１枚あたり数百KBしかなかった画像が、わずか１枚で10MBを超える容量を食ってしまう･･･。ここさえ目をつぶればBMPも「あり」なんだけど。

だが、作業する度にとんでもない容量を食いつぶす画像データが生成されることを考えると、いくらGBオーダーのSSDを積んでるって言っても、やっぱりBMPでの保存は無理だ。

ここにきて、ようやく僕はTImageのEnabledプロパティの設定以外の、より重大で、深刻なバグが自分の書いたプログラムのどこかに潜んでいることに気づく。

溺れる者は何とかで（せめて、毎回、確実にエラーが起きてくれれば･･･）と、とんでもないことまで考えてしまう（これまでいろんなプログラムを作ったけれど、エラーが発生して欲しいと、心から願ったことは多分なかった気がする･･･）。

何度、プログラムの怪しいと思われる（ビットマップへの変換処理）部分を見返しても原因がわからない。援けてくれる人は誰もいない。泣いても、喚いても、自分で何とかするしかない。今までにも数限りなく、これを繰り返してきたんだけれど、ここでまた･･･

選択肢は次のいずれか。
GDI+をあきらめる、か、あきらめないか　だ。
自分で決めるしかない。どちらをとる？　決心するための、自問自答を繰り返す。

（ あきらめたら、僕は、もう、よくなれない ）

答えは一つしかない。それは最初からわかっている。大量の画像を保存するから、処理速度が速いことが、絶対条件だ。ならば、今、自分が知っている最良・最速の処理方法であるGDI+を使うしかない。GDI+のプログラム自体に間違いがあるとは思えないから、データの保存処理の記述を見直して、誤りを発見・修正し、その保存の確実性を100％にすればいいだけだ。少なくとも、今、画像データの保存処理のどこかに重大な問題が隠れていることだけは、わかった。

（ きっと、もう少しだ ）

このプログラムより先にGDI+を使って書いた１枚の画像を保存する処理は、確実に成功して、エラーが発生したことは１度もない。だから、GDI+のプログラム自体には絶対に間違いはない。自分の書き方のどこかに問題がある。もし、GDI+の使用をあきらめないなら、時々エラーになるその原因を探し、修正すること以外に、その解決方法はない。

（ いま、僕に、できることは･･･？ ）
（ 原因がわかるまで、最初から１行ずつ、プログラムを見直すんだ･･･。 ）

そう決心した僕は、試しに書いたTJPEGImageを使う保存手続きをコメント化して、もう一度、GDI+を使った保存手続きを最初から１行ずつ、読んでみることに決めた。

４．バグ作成の元になった状況を再現

次のプログラムが「バグ作成！の元になった状況を再現」したもの。どこに重大な問題があるのか、すぐに気がつかないのは僕だけかもしれないが･･･。
（実際には、この他にもその他の変数の宣言、数々のエラー処理や、ループの中で複数の画像を加工する処理が書かれている。また、ファイルの保存パスはプログラム内で明示的に指定し、SaveDialogは使用していない）

重要　コピペ厳禁！！（このプログラムには重大な誤りがあります）

implementation

uses
  System.IOUtils,
  Winapi.GDIPAPI, Winapi.GDIPOBJ, Winapi.GDIPUTIL;

  //System.IOUtilsはPathから拡張子を取得するTPath.GetExtensionを使うために追加
  //GDIPAPI, GDIPOBJ はGDI+を利用した描画に資料するために必要
  //GDIPUTILを宣言すればGetEncoderClsid関数を利用してGUIDを取得できる

{$R *.dfm}

procedure TForm1.Button1Click(Sender: TObject);
var
  //TImageへの画像読み込み用に使用
  bmp:TGPBitmap;
  //VCL TBitmapからGDI+ Bitmapへの変換に使用
  Graphics:TGPGraphics;
  srcBMP:TBitmap;
  dstBMP:TGPBitmap;
  stream:TMemoryStream;
  //拡張子を取得するために使用
  dotExt, strExt:string;
  //GetEncoderClsid関数の利用とTGUIDを使用するには、usesにWinapi.GDIPUTILが必要
  ImgGUID:TGUID;
begin

  //Create
  bmp:=TGPBitmap.Create;
  try
    //TImageへ画像を読み込む処理
  finally
    //確実に解放
    bmp.Free;
  end;

  {TImageに読み込んだ画像に数々の変更を加える処理}

  //SaveDialogのプロパティはExecuteする前に設定しておくこと
  With SaveDialog1 do begin
    //デフォルトのファイル名を設定
    FileName:='Test';
    //表示するファイルの種類をcsvに設定
    //Filter:='コンマ区切りテキストファイル(*.csv)|*.csv';
    //表示するファイルの種類を設定
    //Filter:='JPEG Files (*.jpg, *.jpeg)|*.jpg;*.jpeg';
    Filter:='画像ファイル|*.png;*.jpg;*.gif;*.bmp;*.tif;*.emf;*.wmf;*.ico' +
    '|*.png|*.png' +
    '|*.jpg|*.jpg' +
    '|*.gif|*.gif' +
    '|*.bmp|*.bmp' +
    '|*.tif|*.tif';
    //データの読込先フォルダを指定
    InitialDir:=ExtractFilePath(Application.ExeName)+'Data';
    //拡張子の指定がなかった場合に付加される拡張子を指定
    DefaultExt:='jpg';
    //上書き保存の確認の設定
    Options:=[ofOverWritePrompt];
  end;

  if not SaveDialog1.Execute then Exit; //キャンセルに対応

  //保存（VCL TBitmap -> GDI+ Bitmap）
  srcBMP:=TBitmap.Create;
  srcBMP.Width:=Image1.Width;
  srcBMP.Height:=Image1.Height;
  srcBMP.Assign(Image1.Picture.graphic);
  //データ受け渡し用のストリームを生成して保存
  stream:=TMemoryStream.Create;
  srcbmp.SaveToStream(stream);
  //保存GDI+のBMPを生成
  dstbmp:=TGPBitmap.Create(TStreamAdapter.Create(stream));
  ////変更できるのはBitmapを含む画像のみですのエラーが発生
  //Graphics:=TGPGraphics.Create(Image1.Canvas.Handle);
  //これならエラーは発生しない
  Graphics:=TGPGraphics.Create(Image1.Picture.Bitmap.Canvas.Handle);
  try
    Graphics.DrawImage(dstbmp,0,0);
    //拡張子を小文字に変換して取得（.XXX形式：Dotが付いている）
    dotExt:=LowerCase(TPath.GetExtension(SaveDialog1.FileName));
    //JPEGに対応する
    if dotExt='.jpg' then begin
      strExt:='jpeg';
    end;
    //指定された拡張子を付けて保存
    if GetEncoderClsid('image/'+strExt, ImgGUID) >= 0 then
    begin
      bmp.Save(ChangeFileExt(SaveDialog1.FileName, dotExt), ImgGUID);
    end;
  finally
    Graphics.Free;
    srcbmp.Free;
    dstBMP.Free;
    stream.Free;
  end;
end;

上のコードのもとのプログラムは、SaveDialogでファイル名を含めた保存パスを取得してGDI+で保存処理するものだった。だから、ビットマップ変換用の変数は必要なく、一つだけ、ビットマップデータを入れるTGPBitmap型の変数bmpを用意すれば事足りた。

GDI+を使った画像の保存処理を実現するために、どうしても必要だったのが「VCLのビットマップ」を「GDI+のビットマップ」に変換する作業で、これが出来なかった僕はさんざん悩みながら、Web上の情報に援けてもらって、この変換処理を行う方法を学んだ（その詳細は、次のリンク先を参照）。

Bitmap Conversion

で、僕はビットマップ変換処理用に、srcBMP:TBitmap; dstBMP:TGPBitmap; stream:TMemoryStream; 等の変数を今回のプログラムに追加した。

GDI+で書いた元々のプログラムは、ファイルとして存在する画像データをOpenDialogを使ってGDI+ビットマップに読み込み、SaveDialogでファイル名を含めて保存パスを指定して処理するものだった。だから、ビットマップ変換用の変数は必要なく、bmp:TGPBitmap; として、ビットマップデータを入れる変数を１つだけ var 宣言して、もちろん、読み込み時にも、書き込み時にも、それぞれの手続きで同じように、これをローカル変数として使用した。

読み込み、書き込みの手続きはそれぞれ独立していたから try 文のfinallyブロックで、bmp.Free として最後に確実に解放すれば、何も問題は起きなかった。

しかし、このプログラムの保存手続きでは、GDI+を利用して、高速にTImageへ画像を読み込み、その画像に変更を加え、TImageのVCLのビットマップからGDI+のビットマップに変換して、保存処理を行っている。

１行ずつプログラムを確認して行く。そして、ついにバグの原因に気づく。

var
  //TImageへの画像読み込み用に使用
  bmp:TGPBitmap;
  //VCL TBitmapからGDI+ Bitmapへの変換に使用
  dstBMP:TGPBitmap;
  ･･･ 省略 ･･･
begin
  //Create
  bmp:=TGPBitmap.Create;
  try
    //TImageへ画像を読み込む処理
  finally
    //確実に解放
    bmp.Free;
  end;

画像の読み込み完了時に、変数bmpは解放済みだから、この変数は再度Createしない限り、もう使えない。しかし、この手続き内で有効な変数としてvar宣言してあるので、Freeした後の保存手続き内でうっかり（Createの有無にかかわらず）記述してしまっても、「未定義の識別子エラー」にはならない。もちろん、コンパイルも警告なしで通る･･･。

【誤りのあるコード】

    //指定された拡張子を付けて保存
    if GetEncoderClsid('image/'+strExt, ImgGUID) >= 0 then
    begin
      bmp.Save(ChangeFileExt(SaveDialog1.FileName, dotExt), ImgGUID);
    end;

【正しいコード】

    //指定された拡張子を付けて保存
    if GetEncoderClsid('image/'+strExt, ImgGUID) >= 0 then
    begin
      //bmp.Save(ChangeFileExt(SaveDialog1.FileName, dotExt), ImgGUID);
      dstbmp.Save(ChangeFileExt(SaveDialog1.FileName, dotExt), ImgGUID);
    end;

同じ手続き内の最後の部分で、僕は間違えて（というか、おそらくビットマップ変換処理を追加した際に書き換えるのを忘れて）本来、ここでは使えないはずの変数bmpを指定したまま、そのSaveメソッドを使った画像の保存処理を書いてしまっている（正しくは、ビットマップ変換用に用意した変数dstbmpを指定しなければならない）。

論理的に明らかな誤りを含んだこのプログラムは、しかし、記述時に「未定義の識別子エラー」は出ず、実行時のコンパイルも問題なく通る。

（その理由は僕にはわからないが）
さらに恐ろしいことに、かなりの確率でデータの保存にも成功！してしまう。
明示的なエラーが発生するのは、ループを数百回まわして１回程度。

元にした保存処理のコードが確実に動作することは確認済みだから、（間違ってない）ビットマップ変換のどこかに誤りがあることを疑いはしても、まさかSaveメソッドの変数名が「誤り」で、バグの原因になっているとは（そこは絶対！大丈夫）と思い込んでいるから、疑ってもみない･･･。

絶対、大丈夫。
そう思っていた部分に誤りがあったことは、これまでにも無数にあったのに。

５．Createしないで使った場合は･･･

手続き最初の画像読み込み部分をコメント化して実行した場合は、Createしていないからインスタンスのない変数bmpのSaveメソッドを使うことになるので、次のような警告が表示され、さらに、プログラムで保存の手続きを実行した場合は、ほとんどの場合（明示的なエラーは発生せずに）ファイルの保存に成功するが、プログラム終了後に、しばらくしてからエラーメッセージが表示される。

  //Create
  {
  bmp:=TGPBitmap.Create;
  try
    //何らかの処理

  finally
    //解放してしまう
    bmp.Free;
  end;
  }
コンパイルは通っても警告がきちんと表示される。
プログラムを終了してしばらくすると、エラーメッセージが表示される。

６．まとめ

Createして使用後、Freeした変数を再宣言しないで使うと使えてしまうことがあることをこの例から初めて学んだ。この場合は、Delphiのデフォルト設定のままでは、警告も、エラーメッセージも出ない。さらに、その理由はわからないが、多くの場合Saveメソッドは成功し、データは実際に保存される（時々、保存されないこともある）。明らかに誤りのあるロジックを構築したのは僕だから、Delphiのコンパイラにはまったく責任はない。コーディングの決まりを無視して、想定外のコードを書いたのは僕自身だ。今回の問題解決の経験から、あらためて、Delphiのコンパイラが発見困難なバグの真の原因は自分が作り出していることを学んだ。

たまたま、偶然、変数の修正を忘れたままになっていることに気がつけたからよかったが･･･（不幸中の幸いとは、まさにこのこと）。万一、真の原因が解明できないまま、バグの原因究明をあきらめて、誤りを含んだまま、このプログラムをユーザーに配布していたらと思うと･･･。

あらためて、思った･･･。
少しでも不具合がある場合は、徹底的に原因を解明して100％確実に動作する状態であることを確認しなきゃいけないって。僕は、自分自身と大切な約束を交わした。それは･･･

バグ探しのポイントは、（絶対、大丈夫）と思い込んでる場所を重点的に確認すること。

なぜ、MyPCではまったくエラーが起きなかったのに、業務用のPCではそれなりにエラーが起きたのか、それは今でも謎のままなんだけれど･･･（その後、MyPCでもテスト中に明示的なエラーが発生することを１回確認）。

MyPCで動作確認して問題なかったプログラムが、業務用PCで走らせるとエラーを起こす不思議は、これまでにも何回もあった。職場の業務用PCに、明日、（ありがとう）って感謝の気持ちを伝えよう。

７．お願いとお断り

このサイトの内容を利用される場合は、自己責任でお願いします。記載した内容を利用した結果、利用者および第三者に損害が発生したとしても、このサイトの管理者は一切責任を負えません。予め、ご了承ください。