2

I'm having a simple Flutter plugin that communicates through a MethodChannel with some native Android code. Here's a simple example how the methods provided by the plugin look like:

Future<void> doSomethingImportant(int address, SomeImportantData importantData) async {
    String jsonButStillImportant = jsonEncode(importantData.toJson());
    return methodChannel.invokeMethod('doSomethingImportant', {"address": address, "data": jsonButStillImportant});
  }

When the doSomethingImportant() (java) method is done, it delivers the result to Flutter by calling:

public void onSuccess(Result result, Object value) {
    new Handler(Looper.getMainLooper()).post(new Runnable() {
        @Override
            public void run() {
                result.success(value);
                Log.d("Debug", "Why does this occasionally cause a timeout at Flutter?!?");
            }
    });
}

Then, during tests, the method is called like this:

void _someTestMethod() async {
  await doSomethingImportant(anAddress, theMostImportantDataInTheWorld).timeout(const Duration(seconds: 1)).catchError((e) {
    print("Something's wrong here: "+e.toString());
    return;
  });
}

This is working well most of the time. Sometimes, however, the test fails because doSomethingImportant() runs into a timeout, and the following shows up at logcat:

2021-12-15 19:56:50.919 D/Debug: Why does this occasionally cause a timeout at Flutter?!?" 
2021-12-15 19:56:51.697 I/flutter: Something's wrong here: TimeoutException after 0:00:01.000000: Future not completed

Now I'm wondering what can possibly cause the timeout and how to prevent it. What's noticeable is that the timeout message always appears about 700-800 milliseconds after result.success() was called.

Edit 1: The problem is that sometimes the future does not complete, even though result.success() is called. This happens only sporadically, but if it does, the timeouts purpose is to gracefully exit the calling function. Simply removing the timeout is unfortunately not an option, because it would block forever.


Edit 2 - some more background information: Please note that the above code snippets of doSomethingImportant() and _someTestMethod() are just examples to illustrate how the methods look like. (Except onSuccess(), this one's an exact copy from the production code).

The actual plugin controls a Bluetooth Mesh network. _someTestMethod() sends and receives data to verify that the mesh network and the firmware running on the individual nodes are doing what they are supposed to do. The logic in _someTestMethod() looks like this:

  1. Send data into the mesh.
  2. Read data from the mesh.
  3. Verify that the read data matches the expected result.

The await/timeout() approach has been chosen because each step depends on the successful completion of the previous step. Nesting those calls in .then() callbacks would be an alternative, but I simply prefer the top-to-bottom await/timeout()-spaghetti-code to nested .then() callbacks.

The problem is, that every now and then, MethodChannel.Result.success() is called at Android, but Flutter does not complete the Future. If that happens, the Future stays uncompleted for all of eternity and logcat does not tell anything neither.

Again, this happens only sporadically. Most of the time it is working just fine.

Now the question is, what's wrong here? Is there any other way to convince the Future to complete? Any ideas are welcome Thank you!

SePröbläm
  • 5,142
  • 6
  • 31
  • 45

1 Answers1

1

Now I'm wondering what can possibly cause the timeout and how to prevent it. What's noticeable is that the timeout message always appears about 700-800 milliseconds after result.success() was called.

Do you have any ideas how to fix (or even debug) the source of this timeout? Thank you!

You are using .timeout(const Duration(seconds: 1)), so it times out. If you don't want it to timeout, remove that code.

Can you clarify what the issue you are facing is? Are you dissapointed that your work is not completed within 1 second, or have you just not realized you added the timeout?


After your edit:

Using await + timeout does not gracefully exit the function, it literally throws an error. To "gracefully" handle this situation where a Future might not immediately complete, instead of using await, use .then instead. That way, any code below your platform method invocation won't be delayed. Of course, you won't have the result in your platform method. If you need that result immediately, then neither await + timeout + catchError nor .then will help you.

Arbitrarily choosing 1 second (or any other time) to run the code and then throw an error is guaranteed to bring issues, especially in a production app with users using all sorts of devices. On slow devices, this could legitimately happen, you should handle it gracefully. It might also hurt debugging, lets say you make a platform method invocation and then pause at a breakpoint, the code will throw the error, because the timer still runs. What an awful debugging experience. I highly recommend not using timeout in this case.

To help debug:

  • Open the android project window in Android Studio, and either:
    • Run the debugger from this window (which launches the Android app) with the debugger attached
    • Run the debugger from Flutter window, and attach the android project window debugger to your running app. app
  • Place a breakpoint on line result.success(value);, and observe if it is being called.
    • Perhaps new Handler(Looper.getMainLooper()).post(new Runnable() { is never being called, in that case you have to understand why that runnable is never posted. I'm not sure if you actually ran your example posted above, or if you're just trying to debug a more complex application.
    • Perhaps another issue is happening, and a more useful error could be shown. (You didn't share many logs, check out logcat or pidcat.). A wild guess would be that the Main thread is busy right now, doing some work that you shouldn't have made it do on the main thread , or just doing Flutter work (less likely).
Ben Butterworth
  • 22,056
  • 10
  • 114
  • 167
  • 1
    Can you account for the 778 milliseconds between the two logcat messages? Why didn't `doSomethingImportant` complete in that 778 ms, causing the timeout to fire? Native code had called `result.success`, yet the Dart future didn't complete? Surely 778 ms is more than enough time for that reply to get through the channel. I submit it's not coming, because something's broken by the unusual "calling result.xxx on a callback" pattern. – Richard Heap Dec 15 '21 at 23:33
  • 1
    Why don't the author try removing the timeout and confirm if it "never" returning, or if it's just happening after 1s. – Ben Butterworth Dec 15 '21 at 23:59
  • Question updated. Thanks for your help. Removing the timeout would block the calling method forever, which is what the timeout is supposed to prevent. – SePröbläm Dec 16 '21 at 09:03
  • I've elaborated the answer. To summarize, don't use `await` + `timeout`, solve the underlying problem. Debug the Android side and try to discover why your Runnable is not being posted. If you provide more information, I'd be happy to help. – Ben Butterworth Dec 16 '21 at 09:27
  • @BenButterworth Thank you very much for you advise. That's a really strange behavior - maybe it's a bug in `MethodChannel.Result.success()` - somehow doubt it though, it's happening too frequently (once every few dozens of calls) to go unnoticed. – SePröbläm Dec 16 '21 at 12:27