MOB-LOG

モブおじの記録 (Programming, 統計・機械学習)

FlutterでDebug時は上手く動いたのにRelease/Profile では動かないってときには、どうデバッグすればよいか? →printデバッグすれば何とかなる

TL;DR

今回の場合は、Text オブジェクトのtoString() の内容がdebugモードとreleaseモードで異なっていることが原因でした(toString()自体の仕様なのかもっと複雑な原因があるのかは不明)。

Release/ProfileモードでDebug時には起きなかったバグ・挙動が発生したときは、Profileモードで実行してprintデバッグしましょう。以下の様にprofileモードで振舞いを確認するのが手っ取り早い(自分の場合はそうだった)。

  1. 機能しない箇所にあたりをつけ(追加・変更箇所)、 print()developer.log() などで手掛かりを出力(いわゆるprintデバッグ
  2. 標準・エラー出力を確認するためにProfileモードで起動して、変数や振舞いが期待通りかを確認する。
  3. (運よく見つけられたら)バグを修正

ここにきて printデバッグをするとは思わなかった。🤦‍♂️🤦🤦‍♀️

背景(なにが起こったか )

FlutterでDataTableを使用してFirebase上のデータを表示していて、ソート機能を追加していたが、releaseモードで実機で試したところ期待通りの動作が得られなかった。Debug時には上手く動いていたのに、なぜ?

今回は、Scoreカラムの “Total avg. score: {数値}” をStringのまま比較して、数値順にソートしようとしていました。

DataTableの一部。Scoreがソートされる対象で、ヘッダのScoreをタップすると昇順・降順か切り替わりソートされる。

DataTableで対象カラムにの値に対してソートするにはsortColumnIndex を指定して、そのカラムのヘッダー(columns)には以下のようにソートアルゴリズムが設定されたDataColumnを渡します(onSortに方法を記述する)。以下がソート対象のヘッダーのDataColumn

DataColumn(
  label: const Text('Score'),
  onSort: (columnIndex, ascending) {
    _sortByScore(columnIndex, ascending);
  })

で、以下がソートアルゴリズム (_sortByScore)

  void _sort<T>(Comparable<T> Function(DataRow) getField, int columnIndex,
      bool ascending) {
    _dataRows.sort((a, b) {
      final aValue = getField(a);
      final bValue = getField(b);
      return ascending
          ? Comparable.compare(aValue, bValue)
          : Comparable.compare(bValue, aValue);
    });

    setState(() {
      _sortColumnIndex = columnIndex;
      _isAscending = ascending;
    });
  
  void _sortByScore(int columnIndex, bool ascending) {
    _sort<String>((row) {
      dynamic _content = (row.cells[columnIndex].child as SizedBox).child;
      _content = _content is Column
          ? (_content as Column)
          : _content is Wrap
              ? (_content as Wrap)
              : null;

      _content = _content.children.first;
      Text _text = (_content is Text) ? _content : Text(_content.toString());
      // DateTime.parse(_text.data.toString().replaceAll('\n', ' '));
      return _text.toString();
    }, columnIndex, ascending);
  }

_sortByScore がrowの中から該当カラムの値 (Widget) を引っ張り出して内容を抽出し(スコアが記されたText)、スコアを_sortへ渡して比較・ソートしてもらう、という処理をやっています(WidgetがColumnだったりWrapだったりでごちゃごやです)。

このソート機能が、debugモードでは機能したのに(AndroidStudioでも実機でもちゃんとソートされていた)、Releaseモードでビルドして試すと全く機能せず、ソートしてくれない、という状況です。

解決策(なにを試したか)

ざっと調べたところによると 1 2 3 、DebugとReleaseとの主な違いはコンパイラであり、DebugモードではJiT (Just-in-Time) コンパイラ、Release/ProfileモードではAoT (Ahead-of-Time) コンパイラが使用されます。そして今回の様に挙動が異なる理由は、JiTとAoTコンパイラで実行される内容が若干異なること、実行速度が異なることでlate変数の評価が間に合うかどうか、などが考えられます。

なるほどAoTコンパラで実行時のいろいろな値が観れれば問題の原因が見つかるだろう、ということでprintデバッグすることにしました。以下の様に、ソート時の値をprintで標準出力させます(ソートできてないということなので比較対象の値を確認する)。

  void _sortByScore(int columnIndex, bool ascending) {
    _sort<String>((row) {
      dynamic _content = (row.cells[columnIndex].child as SizedBox).child;
      _content = _content is Column
          ? (_content as Column)
          : _content is Wrap
              ? (_content as Wrap)
              : null;

      _content = _content.children.first;
      print('_content: ${_content.runtimeType}'); // <= ここ
      Text _text = (_content is Text) ? _content : Text(_content.toString());

      print('\t${_text.toString()}'); // <= ここ
      return _text.toString();
    }, columnIndex, ascending);
  }

Releaseでは標準出力が確認できない (? ←ほかに方法はあるかも) ため profile モード(AoTコンパイラ)で実行します($ flutter run --profile)。

出力された値はこんな感じ。

デバッグ時 (期待通り動く場合)、

I/flutter ( 1188):      : Text("Total avg. score:    22.0")
I/flutter ( 1188): _content: RichText
I/flutter ( 1188):      : Text("RichText(softWrap: wrapping at box width, maxLines: unlimited, text: "No rating yet.")")
I/flutter ( 1188): _content: Text
I/flutter ( 1188):      : Text("Total avg. score:    21.0")
I/flutter ( 1188): _content: RichText
I/flutter ( 1188):      : Text("RichText(softWrap: wrapping at box width, maxLines: unlimited, text: "No rating yet.")")

各行の値として "Text("Total avg. score: 22.0")""Text("RichText(softWrap: wrapping at box width, maxLines: unlimited, text: "No rating yet.")")" というように、TextオブジェクトをtoString()した値がスコア値を含んでおり、それらが比較されソートされているとわかります。

そしてProfileモードでは、

I/flutter (31224):      : Instance of 'Text'
I/flutter (31224): _content: Text
I/flutter (31224):      : Instance of 'Text'
I/flutter (31224): _content: Text
I/flutter (31224):      : Instance of 'Text'
I/flutter (31224): _content: Text
I/flutter (31224):      : Instance of 'Text'

なんと、すべてが "Instance of 'Text'"というStringになってしまっていました。ソートできないはずですわ。

つまり AoTコンパイラでは TextをtoString()してもTextの内容まで出力してくれないため、ソートされるべき内容を評価できていなかったということです。

以下の様に text.toString()ではなくtext.dataと内容を直接参照することで、解決しました(正規表現なりで数値をパースしてfloatにしろってのはその通り!)。

  void _sortByScore(int columnIndex, bool ascending) {
      _sort<String>((row) {
          // 略
          return _text.data.toString();
    }, columnIndex, ascending);
  }

まとめ(反省・学び)

  • Release/ProfileモードでDebug時には起きなかったバグ・挙動が発生したときは、Profileモードで実行してprintデバッグすると手っ取り早い。
  • JiTコンパイラ (Debugモード ) と AoTコンパイラ (Release/Profile) で、やはり振舞い(処理・評価)が異なることがある様子。(今回は toString() がその中身であるdataを出力するかどうか)
  • デバッグ情報を確認するために「Profileモードでテストしましょう」と書いたがReleaseでもprintの標準出力では問題なく標準出力される様子 (コンソールから flutter run --releaseflutter run --profile)。developer.log() だとreleaseモードでは流れない。--profileで動かせば全部流れてくるのであまり考えずProfileを選べばよさそう。