dispatch_async_f does not return immediatly

Hi, I work on a game for iOS and the framerate decreases progressively when the debugger is attached. Running it for 2mins, it went from 30 to 1 FPS while rendering a simple static scene.

I narrowed it down to a call to dispatch_async_f which takes longer to execute over time.

clock_t t1 = clock();
dispatch_async_f(queue, context, function);
clock_t t2 = clock();
double duration = (double)(t2 -t1)/(double)CLOCKS_PER_SEC;

Dodumentation says dispatch_async_f is supposed to return immediatly. So what could explain duration to increases in debug? Am i measuring this incorrectly?

The game is written in mixed C++ and ObjC. It uses Metal as graphic API and GCD for dispatching jobs. I have Xcode 13.4.1 and test on an iPhone 13 Pro with iOS 15.7.

Thanks.

Answered by DTS Engineer in 733835022

Is the game doing something wrong to cause this?

No.

This feature is super cool. It allows various tools, including the debugger, to backtrace across Dispatch calls. So, if you stop in the debugger you’ll get the backtrace of the thread up to the point where the block was run by Dispatch and then it’ll show you the backtrace of the thread that enqueued the block on the queue and so on. If you disable this feature, you lose everything except the initial backtrace.

Now, this doesn’t come for free. There’s always a cost to this feature. However, I’m surprised that the cost is steadily increasing as your app runs. If you can distill this down into a small test project that demos the problem, file a bug with that project so that the tools team can investigate.

Please post your bug number, just for the record.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Is the queue you are using a serial queue or a concurrent type? And is the code you are calling running in the same queue?

I also want to suggest using CACurrentMediaTime() since it's more accurate in macOS than using clock() and CLOCKS_PER_SEC.

double t1 = CACurrentMediaTime();
dispatch_async_f(queue, context, function);
clock_t t2 = CACurrentMediaTime();
double duration = t2 -t1;

Do the functions that you enqueue actually run?

I could imagine that if you enqueue many functions but they never run, then adding more to the queue could get slow.

If you randomly press Pause in the debugger, do you find it often inside that dispatch call? If not, maybe you aren't measuring what you think you're measuring.

Hi,

@Apple Graphics The queue is serial type. The code calling dispatch_async_f does not run on the same queue. It's running on a separate worker thread. I used CACurrentMediaTime() to measure duration of dispatch_async_f. Duration still increases progressively from almost instant to 3ms while rendering a static scene for 2mins.

@endecotp Yes the functions I enqueue do run. If i pause randomly, I land in this dispatch_async_f 50% of the times. Call statck shows dispatch_async_f()->dispatch_async_f_slow()->ulockWait().

Thanks

@endcopt I made i mistake. The actual callstack is dispatch_async_f()->dispatch_async_f_slow()->gcd_queue_item_enqueue_hook

Accepted Answer

gcd_queue_item_enqueue_hook

That looks like Xcode’s queue debugger kicking in. Try this:

  1. Navigate to the Options tab of the scheme editor.

  2. Disable Queue Debugging > Enable backtrace recording.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Thanks @eskimo! That fixed the issue. Is the game doing something wrong to cause this?

Is the game doing something wrong to cause this?

No.

This feature is super cool. It allows various tools, including the debugger, to backtrace across Dispatch calls. So, if you stop in the debugger you’ll get the backtrace of the thread up to the point where the block was run by Dispatch and then it’ll show you the backtrace of the thread that enqueued the block on the queue and so on. If you disable this feature, you lose everything except the initial backtrace.

Now, this doesn’t come for free. There’s always a cost to this feature. However, I’m surprised that the cost is steadily increasing as your app runs. If you can distill this down into a small test project that demos the problem, file a bug with that project so that the tools team can investigate.

Please post your bug number, just for the record.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

I have looked far and wide for the cause of the GCD hang. It was Xcode all along. queueDebuggingEnabled = "No" should be the default choice. That option should be off unless debugging a dispatched work issue. It really hurts performance. It can eventually cause the GCD kernel thread explosion issue without any reasonable way to debug it with Xcode or Instruments.

After scouring documentation, rewatching all of the WWDC sessions, attempting to guess solutions, and crawling the forums, I greatly appreciate this answer as I have truly sunk a great deal of time trying to appease the GCD. I realize the feature is super cool that it works, but it has not been useful for debugging any of my applications as you typically only have a couple DispatchQueues to juggle.

Here is an appropriate reproduction: Use CoreBluetooth with Combine to plot data in real-time with Swift Charts without blocking the main thread. Run for hours, it will happen as long as you are dispatching on and off the main queue. It may only take an hour before it is unusable if your notification rate is high enough. In my experience with several of the frameworks, a real-world bluetooth streaming application would be of great benefit to the acceptance testing suite. There are several long existing hangs and degradations that would be exercised by including such a test in the standard testing procedures.

Once again thanks for your accurate answer Eskimo!

I’m glad this helped.

Given that you can reproduce this so easily, I’d appreciate you filing a bug about that. That way the folks responsible will have something concrete to investigate.

Please post your bug number, just for the record.

Share and Enjoy

Quinn “The Eskimo!” @ Developer Technical Support @ Apple
let myEmail = "eskimo" + "1" + "@" + "apple.com"

Once again thanks for your prolific efforts!

I filed FB15092842

For those that follow, here is an example of the trace that led me here. You can use the Time Profiler in Instruments to see that GCD is doing something, but I am not aware of any other tools to help track this problem down.

dispatch_async_f does not return immediatly
 
 
Q