Dart_PostCObject_DL has a noticeable latency

[MegatronKing]

In my flutter application, I frequently call dart code in a c++ thread. When the UI refreshes frequently, I observed that Dart_PostCObject_DL has a latency of more than 20ms, even 100ms. But I didn't send very big data, only 4 integer values.

[mkustermann]

I'd expect this to be much faster (it only has to allocate & initialize O(message-size) data structure to hold the message, then acquire a log and put it in a queue).

@MegatronKing How do you measure (before/after a call to Dart_PostCObject_DL or from posting until the isolate actually processes the message)? Could you provide a reproduction for us?

[MegatronKing]

I can not give you a demo project, but I can try to explain my code.

I called dart from a C++ thead, like this:

auto start = CurrentTimeMillis();
// Post data to dart with Dart_PostCObject_DL
CallDart();
// Waiting the reply from dart
std::unique_lock<std::mutex> lock(mLock);
if (mCondition.wait_for(lock, std::chrono::seconds(10)) == std::cv_status::timeout) {
  // Timeout
  return 1;
}
// Received the reply from dart
auto end = CurrentTimeMillis();
// Print the cost time
std::cout << "Bridge " << end - start << std::endl;

And receive the message in dart, like this:

final ReceivePort nativePort = ReceivePort();
nativePort.listen((message) {
   // Receive messages from C++
   // Do nothing here, and send a reply message to C++ immediately.
   // Call the C api with ffi method here
});

Receive dart reply messages in C++, like this:

// Notify to continue
std::unique_lock<std::mutex> lock(mLock);
mCondition.notify_one();

When the above steps are called frequently, I get the following logs:

logs.txt

While most of the time-consuming is stable, but still could find some noticeable latency:

// Line 637
Bridge 19
Bridge 45
Bridge 26
Bridge 3
Bridge 27
Bridge 3
Bridge 29

[mkustermann]

Thanks, that clears things up a little: So what you measure is right before Dart_PostCObject_DL() to the time Dart is handling the message.

The timings you see are as follows:

   2582 Bridge 0 (69% < 1 ms)
    735 Bridge 1 (89% < 2 ms)
    156 Bridge 2 (93% < 3 ms)
     69 Bridge 3 (95% < 4 ms)
     41 Bridge 4 (96% < 5 ms)
     22 Bridge 8
     19 Bridge 6
     18 Bridge 5
      ... Bridge ...

What we see here is that the vast majority of messages are handled with rather low latency (90% <= 2ms).

So this issue is about the tail latencies (very infrequently the messages get delayed by double-digit ms), for which there can be multiple reasons:

• When one thread posts a message M via Dart_PostCObject_DL() it doesn't mean that that's the first message that will get executed: There may be many more messages that have to be handled before handling M (as an isolate has a FIFO principle: The message that was first enqueued will be handled first).

  • Running any asynchronous code in Dart enqueues messages in the event loop (including any network / file I/O, timers, ...)
  • Flutter itself enqueues work into the Dart event loop at fixed intervals (for each frame to be drawn)

• Sometimes the garbage collector may run and collect young space objects which is a blocking operation (cannot handle messages until GC is done). This is usually single or low double-digit ms.

@MegatronKing I think the best for you to find out where these tail latencies are coming from would be to obtain a timeline for your app. Our DevTools has a timeline viewer built-in, see docs.flutter.dev/tools/devtools. You can emit custom events that will be visible in the timeline via APIs from dart:developer library. The best way may be to run in flutter-profile mode (which is AOT compiled and therefore close to production, but with profiling tools included, like timelines)

[MegatronKing]

Thanks for the reply, your explanation is make sense, I'll take a look in profile mode later. By the way, I need to call dart in c++ and get the execution result. Is there any other more stable and efficient way, even if the queue is busy.

[mkustermann]

By the way, I need to call dart in c++ and get the execution result. Is there any other more stable and efficient way, even if the queue is busy.

Calling into Dart from 3rd party threads and getting a result is currently not directly supported. We have been discussing whether we want to offer this or not (see #37022). For now we support making a 3rd party C thread be able to call into dart asynchronously without getting a result via dart:ffis newly introduced NativeCallable.listener((...) {}). We may add support for blocking synchronous calls at some point.

Depending on your use case, it may be possible to have other solutions. For example you can spawn an isolate and let your C code run on that thread, it can then use our synchronous callbacks into Dart on that thread.

[github-actions]

Without additional information we're not able to resolve this issue. Feel free to add more info or respond to any questions above and we can reopen the case. Thanks for your contribution!