iOS - How to measure thread wakeups?

Viewed 7280

I have an app that's crashing due to too many "thread wakeups". For example:

45004 wakeups over the last 220 seconds (205 wakeups per second average), exceeding limit of 150 wakeups per second over 300 seconds

This is difficult to debug because I know of no direct way to measure thread wakeups. The closest I've found is an Instruments template called System Trace that will show you number of blocked thread events. Presumably, this is closely related since a blocked thread means that that thread will sleep and then wake up when it becomes unblocked.

The weird thing about this is that the number of blocked threads is in the 10,000's range per second when the app is running normally and doesn't crash. My assumption is that a blocked, sleeping thread only counts towards your "wakeups" limit in certain circumstances - e.g. I would expect that a thread that is locked due to a mutex lock counts, whereas the OS simply transitioning to other threads in normal operation doesn't.

It would be amazing to me if Instruments had a Thread Wakeups template. The only documentation I can find is here - https://developer.apple.com/library/content/technotes/tn2151/_index.html:

The exception subtype WAKEUPS indicates that threads in the process are being woken up too many times per second, which forces the CPU to wake up very often and consumes battery life.

Typically, this is caused by thread-to-thread communication (generally using peformSelector:onThread: or dispatch_async) that is unwittingly happening far more often than it should be. Because the sort of communication that triggers this exception is happening so frequently, there will usually be multiple background threads with very similar Backtraces - indicating where the communication is originating.

3 Answers

Here’s some Objective-C code based on Ivan’s answer you can copy + paste somewhere into your project (e.g. your applicationDidFinishLaunching: method) to log the number of wakeups per second (works on Mac and iOS):

__block NSUInteger lastWakeups = 0;
[NSTimer scheduledTimerWithTimeInterval:1.0 repeats:YES block:^(NSTimer * _Nonnull timer) {
    struct task_power_info info = {0};
    mach_msg_type_number_t count = TASK_POWER_INFO_COUNT;
    kern_return_t ret = task_info(current_task(), TASK_POWER_INFO, (task_info_t)&info, &count);
    if (ret == KERN_SUCCESS) {
        NSUInteger wakeups = info.task_interrupt_wakeups + info.task_timer_wakeups_bin_1 + info.task_timer_wakeups_bin_2;
        NSLog(@"WAKEUPS: %lu per second", (unsigned long)(wakeups - lastWakeups));
        lastWakeups = wakeups;
    } else {
        NSLog(@"Error: unable to get CPU wakeups (%d)", ret);
    }
}];

Please, take a look here https://developer.apple.com/forums/thread/124180 There is a description of a code of getting wakeup count in your app, not only in the instrument. May help you:

#include <mach/task.h>
#include <mach/mach.h>
BOOL GetSystemWakeup(NSInteger *interrupt_wakeup, NSInteger *timer_wakeup) {
  struct task_power_info info = {0};
  mach_msg_type_number_t count = TASK_POWER_INFO_COUNT;
  kern_return_t ret = task_info(current_task(), TASK_POWER_INFO, (task_info_t)&info, &count);
  if (ret == KERN_SUCCESS) {
    if (interrupt_wakeup) {
      *interrupt_wakeup = info.task_interrupt_wakeups;
    }
    if (timer_wakeup) {
      *timer_wakeup = info.task_timer_wakeups_bin_1 + info.task_timer_wakeups_bin_2;
    }
    return true;
  }
  else {
    if (interrupt_wakeup) {
      *interrupt_wakeup = 0;
    }
    if (timer_wakeup) {
      *timer_wakeup = 0;
    }
    return false;
  }
}

Also there you can find some reasons why wakeups occur too much times.

The "Energy Efficiency Guide for Mac Apps" at the end mentions a command-line utility called timerfires that can be used to see what is causing wakeups.

However, the utility seems to be outdated on macOS 12 Monterey, as I was getting errors like the following when I first tried to run it:

probe description fbt::thread_dispatch:entry does not match any probes

I had to copy the utility and edit it to remove all the DTrace methods that are no longer available to get the tool working.

Once that was done, the tool will show each timer invocation, which is very helpful to track down timers in order to reduce wakeups.

Related