DroidKaigi 2018 Apps のバグを爆速で直した話

DroidKaigi 2018、2日間おつかれさまでした&ありがとうございました。 その感想は末尾に。

ここでは、初日の午前に

「DroidKaigiアプリからフィードバック送信するとぐるぐるが消えない」

という不具合を修正した話をします(アプリリーダーの @takahirom さんから「爆速で修正してくれて─」と言っていただいたのでタイトル盛ってます)。

不具合の症状を確認

最初のセッションが終わったあとで TL から、

  • 「DroidKaigiアプリからフィードバック送信するとぐるぐるが消えない」
  • 「BACKで戻ってやり直そうとすると、送信済みになっている」

といったツイートが見られました。 はじめは「すぐに直されるだろう」と思いつつ、アプリには軽微な修正でコントリビュートしていたこともあり、ソースは既に取得済みだったので、「ちょっと見てみるか」と軽い気持ちで Android Studio を立ち上げました。

どこから調べるか

アプリが MVVM(AAC の VM) パターンを採用している ことは知っており、不具合は View(DataBinding) か ViewModel か それ以外(Model) のどこかで発生していることは間違いないわけです。

上記の症状「ぐるぐるは消えないが、送信はされているようだ」から想像するに、「View(DataBinding) で、 何らかの原因で ぐるぐる(ProgressBar) に visible = false ができていないのかな?」 と思い、まずそのソースを見てみました(ロジックの方から調査していくと、大抵はそちらの方が複雑なので、苦労して不具合を調べまくった後で DataBinding の簡単なミスであることが発覚すると精神が殺られます)。

View(DataBinding)を調べる

ぐるぐるの visible を変えているのは SessionsFeedbackFragment.kt の次の箇所です。

//SessionsFeedbackFragment.kt
sessionsFeedbackViewModel.isLoading.observeNonNull(this, {
    binding.progress.setVisible(it)
})

うん、これだけのコードで itfalse の時だけ動作しない、なんてありえない。 ここはシロだ、と判断しました。(setVisible() はこのアプリでの拡張関数なので、一応そちらも見つつ)

ViewModel を調べる

では次に ViewModel、 sessionsFeedbackViewModel.isLoadingfalse にならないのではないか? を疑います。

それは SessionsFeedbackViewModel.kt の次の箇所です。

//SessionsFeedbackViewModel.kt
fun submit(session: Session.SpeechSession, sessionFeedback: SessionFeedback) {
    repository.submitSessionFeedback(session, sessionFeedback)
            .doOnSubscribe { 
                isLoading.value = true 
            }.doOnDispose { 
                isLoading.value = false 
            }.doOnComplete {
                alertMessage.value = Alert(Alert.Type.Toast, R.string.submit_success)
            }
            .doOnError { alertMessage.value = Alert(Alert.Type.Toast, R.string.submit_failure) }
            .subscribeBy(onError = defaultErrorHandler())
            .addTo(compositeDisposable)

repository.submitSessionFeedback() は RxJava の Observable です(正確には Completable)。

doOnSubScribe(購読開始時) に true を、doOnDispose(購読終了?時)に false を設定しているので、なんだか問題なさそうです。

ということをツイートしてみると、 @MoyuruAizawa さんから、

というコメントがもらえました。ほうほう 「doOnDispose じゃなくて doFinally なのか!」と思いつつ、ここで初めてデバッグに取り掛かります。 isLoading.value = false の行にブレークポイントを置いて実行したら止まらないはずだ、と。

doOnSubscribedoOnDispose にブレークポイントを張って実行してみると、 doOnSubscribe では止まるけど doOnDispose では止まりません。 次に、 doOnDisposedoFinally に変えて再度チャレンジしてみると、状況は変わらず doFinally でも止まりません。

ならば doOnDispose でも doFinally でもない何かならうまくいくのか?と考えるより、 「submitSessionFeedback() の返値が、 ちゃんと Observable しているか? 」 を調べるのが先です。

おまけ: デバッグしやすくする

フィードバック画面の「送信」ボタンは、一度処理が成功したとみなされると disable になってしまいます。その情報は端末内に保持している(ユーザー認証のないアプリだからそれしかない)ので、アプリのデータを消すとまた押せるようになりますが、それも面倒なので ボタンの enable/disable を切り替えている箇所 を一時的に削除しました。これも DataBinding を使っていると知っていれば箇所はだいたいわかります。

もうひとつ気づいた事: LiveData と UIスレッド

RxJava 関連の処理の他に、もう一つ気づいたことがありました。それは isLoadingMutableLiveData<Boolean> なのですが、 isLoading.value = false と、 value プロパティを使用していることです。

どういうことかと言うと、 「MutableLiveData.setValue() は、UIスレッドから呼び出さないと例外を発生させる」 ということです。

これは、

に書いたとおり、 @kkagurazaka さんから教わっていたことで知っていたことです。 加えて RxJava は非同期処理を行うライブラリであり、処理開始(doOnSubscribe)はUIスレッドでも、終了時(doOnDispose)にUIスレッドである保証はありません。

ちょっと怪しげなので isLoading.value = falseisLoading.postValue(false) に直しました。

Model(Repository) を調べる

repository.submitSessionFeedback() をデバッグのステップインで掘っていくと、 SessionDataRepository.ktsaveSessionFeedback() までは到達していることが確認できます。

//SessionDataRepository.kt
@CheckResult override fun saveSessionFeedback(sessionFeedback: SessionFeedback): Completable =
        Completable.create { sessionDatabase.saveSessionFeedback(sessionFeedback) }
                .subscribeOn(schedulerProvider.io())

この処理をしばらく眺めていて、「!!ッ」と問題に気づきました。

それは、

  1. saveSessionFeedback は Completable を返す
  2. Completable は Observable である
  3. Observable は、それの "終了" を示すために onComplete() を呼び出さなければならない(またはエラーを示す onError() を呼び出さなければならない)
  4. しかしこのコードは onComplete() を呼び出していない

ということで確信の同意も得られ、実際に修正していきます。

//SessionDataRepository.kt
@CheckResult override fun saveSessionFeedback(sessionFeedback: SessionFeedback): Completable =
        Completable.create { emitter ->
            sessionDatabase.saveSessionFeedback(sessionFeedback)
            emitter.onComplete()
        }.subscribeOn(schedulerProvider.io())

こんな感じで。「Observable を返すのに onComplete または onError を呼ばない」というのは RxJava プログラミングのあるあるなミスなのですが、Kotlin では引数一つの匿名関数は { } と書けてしまう(明示的に引数を宣言しなくてもよい)ので、忘れる可能性が高くなっているのかも知れませんね。

その後、 @yanzm さんから、

という意見もいただきました。なるほど Completable.fromAction()Completable.fromCallable() は、自動的に onComplete() を呼び出してくれるのですね。

上記の修正は、

//SessionDataRepository.kt
@CheckResult override fun saveSessionFeedback(sessionFeedback: SessionFeedback): Completable =
        Completable.fromAction { sessionDatabase.saveSessionFeedback(sessionFeedback) }
        .subscribeOn(schedulerProvider.io())

と書いた方がよりスッキリします。.create() を使っている箇所は、代替メソッドを検討してみた方がよいでしょう(Lint で検出してもよいのかも)。

修正点まとめ

以上の修正をまとめると、

  1. doOnDisposedoFinally
  2. isLoading.value = falseisLoading.postValue(false)
  3. saveSessionFeedback()onComplete() を呼ぶように

の3点です。 すべての修正を含んだ状態で試して、問題が解消されていることが確認できました。 本来なら、 1. と 2. の修正が本当に必要かを確認してからコミットするべきなのですが、今回は時間がなかった(ランチの時間に突入していた)ので、このまま PR を送りました。

さっそくマージしてもらいアプリも更新され、

問題なさそうだったので 「Yesッッ!!!」 と喜びました。 ソースを見始めたのが AM11:20頃、PR を送ったのが 12:00、約40分間の出来事でした。

スタッフや登壇者のみなさんは本業で忙しかっただろうし、会場はセッションを聴くのに集中していた人が多かったと思うので、そういう状況でなければどなたかがもっと爆速で修正されていたと思います。

とはいえ、今回予定外の3つ目のPRが役に立てて嬉しかったです。ちょっとツイートするとすぐに反応がもらえ、一人で考えるよりも効率的だったと思います。

DroidKaigi 2018 に参加して

なんだかんだで皆勤賞してました。 今年も、

  • 今までできないと思っていたことができると分かったこと
  • 明日から使ってみたいと思ったこと
  • 明日からはムリだけど、半年後使いそうなこと
  • 今のところ予定はないけど、知っておいて損はないと思えること
  • 自分が知っている事でも、他の参加者の人は知らない(またはウケる)んだなーということ
  • ID でしか交流のなかった方々にごあいさつできたこと(地方エンジニアにとっては貴重)

などなど、価値のある体験ができました、本当にありがとうございました。 今年は CFP 採択されず割引価格で気楽にオーディエンスできましたが、次回は登壇返り咲きを目指そうと思います:muscle_tone2: