【Flutter】バッテリー問題の原因を深掘りしていったらDart標準ライブラリの奥地に辿り着いた話

前回の記事で一旦は落ち着きを見せたバッテリーパフォーマンスでしたが、その後しばらくして、再度「iOSで動画を見ていると発熱することがある」という報告が上がってきました。

 

原因の切り分け

改めてXcodeのプロファイラを覗くと、なんとCPU使用率が100%を超えていました

初めは、その直前に実装された『再生位置を保存しておく機能』によるものだと思いました。
「API呼び出しの頻度が高すぎるか……? あるいはAPIクライアントのキャッシュ更新を手動で呼び出す処理が実は重く、あんまり高頻度で呼んではいけないのではないか……?」
しかし、その機能を丸ごとコメントアウトしても発生したり、逆に元に戻したら発生しなくなったりしました。
どうやら原因は別のところにあるらしい……そして、厄介なことに、これは確率的に発生するバグであるらしいということがわかりました(体感では、動画を開くたびに40%〜60%くらいの確率で発生していました)。

原因を切り分けるために動画プレイヤー以外の要素を1つずつ消していきましたが、プレイヤー以外のすべてを消し去ってもなお、バグは発生しました。
無効なURLを渡して動画の読み込みを失敗させるようにしてようやくバグは発生しなくなったため、どうやら動画再生そのものにバグが潜んでいるらしい……ということになりました。

 

原因を求めてさらに深淵へ…

ここまで絞り込めはしたものの、原因は全く思い当たりませんでした。
バグが発生したときとそうでないときで、動画ファイルのリクエストなどの様子も目にわかる違いは見られませんでした。

しかし、全く手掛かりがないわけでもありませんでした。
CPU使用率が高くなる際、謎のスレッドが立って裏で動き続けているということがわかったのです。Isolate処理を書いた覚えはないんですが……(というか、このとき初めてDartの並列処理がIsolateと呼ばれていることを知ったくらいです)。

プロファイラのスクリーンショット。io.flutter.1.ui、io.flutter.1.profilerのほかに、DartWorkerという名前のスレッドが3つ動き続けている。
動画再生を止めてもなお動き続ける謎のDartWorker

こうなったらCPUを圧迫している処理を直接覗くしかない。
どの関数が原因なのか特定するため、CPUプロファイラから実行されている関数を覗くことにしました。

初めは、Dartの関数を特定するのだからFlutter DevToolsを使ったほうがいいだろうと思ってDevToolsのプロファイラを使ってみたのですが、CPU使用率が高くなった途端に接続が切断されてしまい、データが取れませんでした(どうやらCPUが圧迫されることでDevToolsのプロセスが落とされてしまうらしいです)。
DevToolsの使用は諦めて、XcodeのInstruments1から覗いてみることにしました。

ほとんどがタイマー関係と見られる処理ばかりでしたが、一箇所、SSLFilter::ProcessFilterRequest が呼び出されているのが気になりました。
そして、動画のURLをHTTPのものに差し替えてみると、バグは発生しなくなりました。どうやらSSL(TLS)が関係しているようです。

実は本アプリでは、動画を再生する際、認証トークンの更新のために内部にローカルサーバーを立てています。
動画の視聴は有料のため、サーバーに動画ファイルをリクエストする際に認証が必要になるのですが、iOSの動画プレイヤーであるAVPlayerでは再生しながら動画のソースを変更することができないからです。
動画プレイヤーからサーバーにファイルを直接要求するのではなく、ローカルサーバーに向けてリクエストし、ローカルサーバーが認証情報を付与してサーバーにリクエストを送るという構成になっています2

Flutterの動画アプリで同じ構成になっている事例はネット上には見つからなかったので、もしかしたら初めて踏み抜いたバグかもしれない……と思いながら、情報収集しました。
しかし、類似する症状のIssueは数件あったものの、今回の件とは条件が異なりそうなものばかりでした。最も近いのがこのIssueでしたが、特に問題が解決しないままCloseされていました……。

 

解決

リリース予定日も迫るなか、いまだ原因すら掴めていないバグそのものの修正は難しそうだと考え、バグの発生を回避する方針に切り替えることになりました。
SSLFilter::ProcessFilterRequestが呼ばれているということは、少なくともDartの標準ライブラリの実装の問題のはずです。DartのHttpClientに依存しないクライアントならバグは起きないかもしれません。

そして、そのようなクライアントがあります。CupertinoClientです!

藁をも掴む思いで、HttpClientをCupertinoClientに差し替えました。
10回再生する。20回再生する。30回再生してもCPU使用率はハネない! やった!!!

Slackのログ「ずっとアーカイブ動画を再生し続けてるけどバッテリー減ってないから大丈夫そう」

 

その後

今回発見したバグについて、DartのリポジトリにIssueを立てました

Issueを立てるにあたって再現コードをまとめたのですが、Flutterアプリ内だけでなく、開発用に使っているマシンでdartコマンドから実行した場合でも再現しました。

macのアクティビティモニターのスクリーンショット。dartのプロセスのCPU使用率が172.4%になっている。
一瞬で跳ね上がるCPU使用率。ファンも全力で回っていました。

そして、このバグはどうやら『ネイティブアプリの動画プレイヤーからリクエストされたHTTPSのHLS動画をプロキシするためにHttpClientでリクエストする』場合に発生するらしいです。
VLCなどのプレイヤーでMacから再生したり、Safariのvideo要素から再生したりする場合には発生しませんでした。
さすがにそれなら、これまで見つかってなくても仕方ないな……と思いました。

 

  1. https://developer.apple.com/jp/xcode/features/ ↩︎
  2. AndroidのExoPlayerであれば、ResolvingDaraSourceがありますが、残念ながらiOSでは他の手段はないようです↩︎