How do I interpret hang / CPU usage diagnostic files for macOS? Documentation?

Question

Created Sep ’20

Replies 1

Boosts 0

Views 1.5k

Participants 2

Cross-posted on Stack Overflow.

If my Mac app hangs, it generates diagnostic files that end in .hang or .cpu_resource.diag. They look somewhat like crash reports, but with deep tab-indented hierarchies of what looks like process samples.

Example:

Code Block Powerstats for:  MyApp [13095] thread 0x9b152
UUID:            35BE255F-F3B3-3188-B1E4-12E96CAAD397
Start time:      2020-09-26 15:37:35 -0500
End time:        2020-09-26 15:39:03 -0500
Parent:          launchd
Microstackshots: 55 samples (47%)
Primary state:   52 samples Frontmost App, User mode, Thread QoS User Interactive
User Activity:   0 samples Idle, 55 samples Active
Power Source:    0 samples on Battery, 55 samples on AC
  55 start + 1 (libdyld.dylib) [0x7fff8bed55ad]
    55 main + 121 (MyApp) [0x108ee8d5f]
      55 NSApplicationMain + 1176 (AppKit) [0x7fff8ffed368]
        55 -[NSApplication run] + 682 (AppKit) [0x7fff90023d80]
          55 -[NSApplication _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 454 (AppKit) [0x7fff9002f226]
            55 _DPSNextEvent + 1067 (AppKit) [0x7fff9002fdf6]
              55 _BlockUntilNextEventMatchingListInModeWithFilter + 71 (HIToolbox) [0x7fff866e35af]
                55 ReceiveNextEventCommon + 184 (HIToolbox) [0x7fff866e3677]
                  55 RunCurrentEventLoopInMode + 235 (HIToolbox) [0x7fff866e3935]
                    55 CFRunLoopRunSpecific + 328 (CoreFoundation) [0x7fff973d5e48]
                      55 CFRunLoopDoObservers + 391 (CoreFoundation) [0x7fff973f6f37]
                        55 CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION + 23 (CoreFoundation) [0x7fff973f6fc7]
                          55 CA::Transaction::observer_callback(CFRunLoopObserver*, unsigned long, void*) + 71 (QuartzCore) [0x7fff99fcf863]
...and on and on, much deeper

How do I interpret these diagnostic files? Can someone link to some Apple documentation of them?

Boost

Answer 1

DTS Engineer OP

Apple

Sep ’20

I don’t think we have any formal docs explaining these logs but I can help out here.

Code Block  Microstackshots: 55 samples (47%)

This means that the system took 55 samples of your process while it was hung.

Code Block  Primary state:   52 samples Frontmost App …

This means that your app was at the front for 52 of them (the hang log was probably generate during a front-to-back transition, or vice versa).

Code Block  55 start + 1 (libdyld.dylib) [0x7fff8bed55ad]
  55 main + 121 (MyApp) [0x108ee8d5f]
    55 NSApplicationMain + 1176 (AppKit) [0x7fff8ffed368]
      …

This is the backtrace of the main thread, where the leading number is the count of samples that were in this frame. So, in all 55 samples the main thread’s backtrace contained NSApplicationMain (not a huge surprise there).

Note Unlike normal backtraces, this runs from least recent to most recent.

You should look down this list to find the location of the hang. You typically see one of two things:

All 55 samples being in a single blocking call, like a blocking network request
Most of the samples doing down one ‘path’ with a scattering of other samples elsewhere

The first option is easy to investigate: Just work out why that blocking call blocked. The second option is a bit trickier. The log doesn’t represent a simple backtrace but a weighted tree of backtraces.

If you have any further question, post a snippet of the bottom of this backtrace. If it’s stupidly large, use a text attachment to avoid clogging up the timeline.

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

0