Flutter sometimes not starting up -- app gets stuck on Android splash screen

[lukehutch]

Steps to reproduce

Sometimes when I start my Flutter app, after it has been evicted, it gets stuck on the Android splash screen (Flutter is never started).

Attaching a profiler shows that the app spends a lot of time handling messages in the event loop (the CPU is sitting around 15%).

Pausing in the debugger typically gives something like the following stacktrace:

dispatchMessage:99, Handler (android.os)
   => callback=android.view.Choreographer$FrameDisplayEventReceiver target=android.view.Choreographer$FrameHandler
loopOnce:232, Looper (android.os)
loop:317, Looper (android.os)
<obsolete>:-1, Activity thread (android.app)
invoke:-1, Method (java.lang.Object)
run:552, RuntimeInit$MethodAndArgsCaller (com.android.internal.os)
   => mArgs = ["seq=5682"]
   => mMethod = "public static void android.app.ActivityThread.main(java.lang.String[])"
main:878, ZygoteInit

So even though only the static Android animation screen is showing, somehow the ActivityThread.main method is spending a lot of time drawing an animation, rather than actually starting the app.

Expected results

The app should start.

Actual results

The app just sits there showing the Android launcher screen, using 15% CPU, rather than actually launching Flutter.

Code sample

N/A

Screenshots or Video

N/A

Logs

The logs don't show anything.

Flutter Doctor output

Doctor output

```console $ flutter doctor -v [✓] Flutter (Channel beta, 3.22.0-0.3.pre, on Fedora Linux 39 (Workstation Edition) 6.8.8-200.fc39.x86_64, locale en_US.utf8) • Flutter version 3.22.0-0.3.pre on channel beta at /opt/flutter • Upstream repository https://github.com/flutter/flutter.git • Framework revision 87b652410d (2 weeks ago), 2024-04-23 21:41:18 -0500 • Engine revision b4bfd45986 • Dart version 3.4.0 (build 3.4.0-282.3.beta) • DevTools version 2.34.3 [✓] Android toolchain - develop for Android devices (Android SDK version 34.0.0) • Android SDK at /home/luke/Android/Sdk • Platform android-34, build-tools 34.0.0 • Java binary at: /opt/android-studio/jbr/bin/java • Java version OpenJDK Runtime Environment (build 17.0.10+0-17.0.10b1087.21-11572160) • All Android licenses accepted. [✓] Chrome - develop for the web • Chrome at google-chrome [✓] Linux toolchain - develop for Linux desktop • clang version 17.0.6 (Fedora 17.0.6-2.fc39) • cmake version 3.27.7 • ninja version 1.11.1 • pkg-config version 1.9.5 [✓] Android Studio (version 2023.3) • Android Studio at /opt/android-studio • Flutter plugin version 79.0.2 • Dart plugin can be installed from: 🔨 https://plugins.jetbrains.com/plugin/6351-dart • Java version OpenJDK Runtime Environment (build 17.0.10+0-17.0.10b1087.21-11572160) [✓] VS Code (version 1.89.0) • VS Code at /usr/share/code • Flutter extension version 3.89.20240501 [✓] VS Code (version 1.90.0-insider) • VS Code at /usr/share/code-insiders • Flutter extension version 3.79.20231130 [✓] Connected device (3 available) • Pixel 7 Pro (mobile) • 29161FDH300BLP • android-arm64 • Android 14 (API 34) • Linux (desktop) • linux • linux-x64 • Fedora Linux 39 (Workstation Edition) 6.8.8-200.fc39.x86_64 • Chrome (web) • chrome • web-javascript • Google Chrome 124.0.6367.118 [✓] Network resources • All expected network resources are available. • No issues found! ```

[darshankawar]

Thanks for the report @lukehutch Does it occur in debug or in profile / release mode ? If you create a new Flutter app, does it show same behavior ? If not, then you can try to compare new Flutter project with your existing one and see what could be leading to this behavior.

[lukehutch]

@darshankawar this is for a debug build. Actually I have a hunch that this may only be caused when the debugger is attached and then detached (but I can't verify that)...

This happens only very sporadically, so I don't think I'll be able to find a reliable repro case, but I'll see what I can do.

[lukehutch]

@darshankawar This is still happening after trying a range of different things (switching Flutter channels, etc.), and I don't have a clue how to debug this further. Any suggestions?

[darshankawar]

You may try to narrow down by removing components one by one and see which one could be leading to the behavior. Also check in your manifest file if any setting could be causing it or not.

[lukehutch]

@darshankawar OK, I captured the adb log by plugging in the phone (after the app had been evicted), starting up Android Studio, filtering logcat for my package name, and then launching my app from the Android launcher. Notable log entries:

2024-05-15 17:50:24.022 23502-23685 flutter                 app.clicksocial                      I  The Dart VM service is listening on http://127.0.0.1:44525/8NYm_EqrBck=/
2024-05-15 17:50:24.027 23502-23502 app.clicksocial         app.clicksocial                      I  ************* MainActivity.configureFlutterEngine() *************
2024-05-15 17:50:24.056 23502-23502 app.clicksocial         app.clicksocial                      W  Accessing hidden method Landroid/view/accessibility/AccessibilityNodeInfo;->getSourceNodeId()J (unsupported,test-api, reflection, allowed)
2024-05-15 17:50:24.056 23502-23502 app.clicksocial         app.clicksocial                      W  Accessing hidden method Landroid/view/accessibility/AccessibilityRecord;->getSourceNodeId()J (unsupported, reflection, allowed)
2024-05-15 17:50:24.056 23502-23502 app.clicksocial         app.clicksocial                      W  Accessing hidden field Landroid/view/accessibility/AccessibilityNodeInfo;->mChildNodeIds:Landroid/util/LongArray; (unsupported, reflection, allowed)
2024-05-15 17:50:24.056 23502-23502 app.clicksocial         app.clicksocial                      W  Accessing hidden method Landroid/util/LongArray;->get(I)J (unsupported, reflection, allowed)
2024-05-15 17:50:24.063 23502-23502 app.clicksocial         app.clicksocial                      I  ************* MainActivity.onCreate() *************
2024-05-15 17:50:24.067 23502-23502 ContentCaptureHelper    app.clicksocial                      I  Setting logging level to OFF
2024-05-15 17:50:24.077 23502-23502 FIAM.Headless           app.clicksocial                      I  went foreground
2024-05-15 17:50:24.077 23502-23502 FIAM.Display            app.clicksocial                      I  Binding to activity: MainActivity
2024-05-15 17:50:24.077 23502-23502 FIAM.Headless           app.clicksocial                      I  Setting display event component
...
2024-05-15 17:50:24.187 23502-23502 VRI[MainActivity]       app.clicksocial                      D  Canceling draw. cancelDueToPreDrawListener=true cancelDueToSync=false
2024-05-15 17:50:24.187 23502-23502 SessionLifecycleClient  app.clicksocial                      D  Connected to SessionLifecycleService. Queue size 1
2024-05-15 17:50:24.188 23502-23565 SessionLifecycleClient  app.clicksocial                      D  Sending lifecycle 1 to service
2024-05-15 17:50:24.188 23502-23502 FlutterGeolocator       app.clicksocial                      D  Geolocator foreground service connected
2024-05-15 17:50:24.188 23502-23502 FlutterGeolocator       app.clicksocial                      D  Initializing Geolocator services
2024-05-15 17:50:24.188 23502-23502 FlutterGeolocator       app.clicksocial                      D  Flutter engine connected. Connected engine count 1
2024-05-15 17:50:24.188 23502-23695 SessionLifecycleService app.clicksocial                      D  Activity foregrounding at 91471803.
2024-05-15 17:50:24.188 23502-23695 SessionLifecycleService app.clicksocial                      D  Cold start detected.
2024-05-15 17:50:24.191 23502-23695 SessionLifecycleService app.clicksocial                      D  Generated new session <redacted>
2024-05-15 17:50:24.192 23502-23695 SessionLifecycleService app.clicksocial                      D  Broadcasting new session: SessionDetails(sessionId=<redacted>)
2024-05-15 17:50:24.197 23502-23596 SessionFirelogPublisher app.clicksocial                      D  Data Collection is enabled for at least one Subscriber
2024-05-15 17:50:24.201 23502-23502 SessionLifecycleClient  app.clicksocial                      D  Session update received: f6b7f59aa3164d2cb3e9409ab484e505
2024-05-15 17:50:24.203 23502-23586 SessionLifecycleClient  app.clicksocial                      D  Notified CRASHLYTICS of new session <redacted>
2024-05-15 17:50:24.208 23502-23620 TrafficStats            app.clicksocial                      D  tagSocket(154) with statsTag=0xffffffff, statsUid=-1
2024-05-15 17:50:24.230 23502-23600 EventGDTLogger          app.clicksocial                      D  Session Event: {"eventType":1,"sessionData":<redacted>}
2024-05-15 17:50:24.231 23502-23600 SessionFirelogPublisher app.clicksocial                      D  Successfully logged Session Start event: <redacted>

I don't see any other relevant log entries (even without filtering for my package name) after that.

Here's my MainActivity -- based on the logs, the Kotlin main activity code is running, and both of the overridden methods successfully complete:

package app.clicksocial

import android.os.Bundle
import io.flutter.embedding.android.FlutterActivity
import io.flutter.embedding.engine.FlutterEngine
import io.flutter.plugins.urllauncher.BuildConfig
import android.util.Log

class MainActivity: FlutterActivity() {
   override fun onCreate(savedInstanceState: Bundle?) {
       super.onCreate(savedInstanceState)
       Log.i("app.clicksocial", "************* MainActivity.onCreate() *************")
   }

   override fun configureFlutterEngine(flutterEngine: FlutterEngine) {
       super.configureFlutterEngine(flutterEngine)
       Log.i("app.clicksocial", "************* MainActivity.configureFlutterEngine() *************")
   }
}

However, the logs do not show the Dart code starting, which normally logs main() started on successful launch:

void main() async {
  logger.i('main() started');
  // ...
}

I have a theory that this may only be triggered if I am running the app on the device in debug mode, then change some code and do a hot reload, then unplug the cable and let the app get evicted. When the attempt is made to restore the state when the app is launched again, something about the hot reload causes Flutter to fail to start.

[lukehutch]

If I compare the logs from a successful launch to the logs from an unsuccessful launch, the unsuccessful launch does every single thing the same, modulo some nondeterminism in ordering, up to the point where main() is called. This last step is what is not happening on the unsuccessful runs.

[lukehutch]

Is there some way to instrument the startup of Dart?

[darshankawar]

https://pub.dev/packages/analyzer may probably help to instrument from Dart side.

[lukehutch]

@darshankawar I thought analyzer is just for static analysis. Where exactly is the Dart VM launched in an Android app, so that I can try to set up a breakpoint there?

[darshankawar]

See if this would be helpful to instrument the dart code https://dartcode.org/docs/logging/