16

I have a collection of spindumps focused on an app that need to be analyzed, however I'm not sure precisely how to analyze these. I've seen some other developers who are able to quickly parse these either mentally or with software and come back to me with details on where hangs are coming to play and so forth and I'm hoping to understand how to properly analyze these.

Where does one go to properly analyze spindumps?

2

2 Answers 2

21
+50

Generally:

  • with a crash report, you get a stack trace
  • with spindumps, you get multiple stack traces over a period of time together.

There are two cases in which you might want to examine a spindump:

  1. an infinite loop, probably calling the same function over and over
  2. deadlock.

The first case can be seen from the spindump by many calls to the same function over and over. A good thing to use in such situations is Activity Monitor – take sample of a hung process there and you can view it in several useful ways, hiding unimportant frames, etc.

The second case can be viewed by different threads waiting on locks at the same time.

Here is a little example:

+ 2663 start  (in MyApp) + 52  [0x100001bb4]
+   2663 main  (in MyApp) + 39  [0x100001be7]  main.m:65
+     2663 NSApplicationMain  (in AppKit) + 869  [0x7fff8ea27cb6]
+       2663 -[NSApplication run]  (in AppKit) + 517  [0x7fff8ea83283]
+         2663 -[NSApplication nextEventMatchingMask:untilDate:inMode:dequeue:]  (in AppKit) + 128  [0x7fff8ea8bed2]
+           2663 _DPSNextEvent  (in AppKit) + 685  [0x7fff8ea8c613]
+             2663 BlockUntilNextEventMatchingListInMode  (in HIToolbox) + 62  [0x7fff8dd53cd3]
+               2663 ReceiveNextEventCommon  (in HIToolbox) + 356  [0x7fff8dd53e42]
+                 2663 RunCurrentEventLoopInMode  (in HIToolbox) + 209  [0x7fff8dd540a4]
+                   2663 CFRunLoopRunSpecific  (in CoreFoundation) + 290  [0x7fff95dec6b2]
+                     2557 __CFRunLoopRun  (in CoreFoundation) + 1078  [0x7fff95decee6]
+                     ! 2556 __CFRunLoopServiceMachPort  (in CoreFoundation) + 195  [0x7fff95de7803]
+                     ! : 2556 mach_msg  (in libsystem_kernel.dylib) + 70  [0x7fff93630c42]
+                     ! :   2556 mach_msg_trap  (in libsystem_kernel.dylib) + 10  [0x7fff93631686]
+                     ! 1 __CFRunLoopServiceMachPort  (in CoreFoundation) + 199  [0x7fff95de7807]
+                     97 __CFRunLoopRun  (in CoreFoundation) + 728  [0x7fff95decd88]
+                     ! 97 __CFRunLoopDoObservers  (in CoreFoundation) + 369  [0x7fff95e11921]
+                     !   97 __CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__  (in CoreFoundation) + 23  [0x7fff95e119b7]
+                     !     97 __83-[NSWindow _postWindowNeedsDisplayOrLayoutOrUpdateConstraintsUnlessPostingDisabled]_block_invoke_01208  (in AppKit) + 46  [0x7fff8f05a971]
+                     !       90 _handleWindowNeedsDisplayOrLayoutOrUpdateConstraints  (in AppKit) + 738  [0x7fff8ea8f2ac]
+                     !       : 89 -[NSView displayIfNeeded]  (in AppKit) + 1830  [0x7fff8ea8fd73]

What this tells me, is that MyApp has gone through main, etc. and finally got into a function CFRunLoopRunSpecific, then __CFRunLoopRun – from there (2557) it called __CFRunLoopServiceMachPort, which called mach_msg and got into a trap at mach_msg_trap (calling a syscall) – when it got back, the stack trace returned to CFRunLoopRunSpecific, where __CFRunLoopRun was called, which then calls __CFRunLoopDoObservers, and so on.

Note that this isn't a spindump of any hanging process - you can sample this way any running process and view what functions were called during that sample. An infinite loop, however, will have a repeating calls to some function over and over again - there will be the same call tree over and over again. Of course, this can mean a simple for cycle, but that's where you can examine, if the for cycle isn't for some reason infinite. Unfortunately, these spin dumps are usually quite long, depending on what function you are calling, so it may take some time to examine

The + sign at the beginning of the row simply indicates a beginning of a line - lines without the + sign indicate a beginning of a new thread. The ! and : signs make a line, so it's easier for you to see subsequent calls - i.e. which calls are at the same level. Further, | character can be also used.

The numbers mean how long the app spent in that particular call - they are in the number of samples. The sampling works that the sampled app gets suspended every few millisecond and the stack frame is examined of each thread. If the app is still in the same function, the function gets +1.

6
  • 2
    How do you interpret the numeric headers for each line? What are the symbols indicative of (+, !, :)? Is there no software mechanism that you can pass these through that help parse these more meaningfully? I am primarily dealing with odd hangs and am attempting to isolate where these hangs are coming from. This is extremely valuable to understand as intimately as possible, but presently given the time differential I'm slightly out of context. Your answer makes sense given your example; I feel there is still a missing piece to properly interpreting these when I run into the problem again. Hmm
    – ylluminate
    Nov 22, 2012 at 9:58
  • For readers without a software development background: please, is the example of an infinite loop, or a deadlock? Nov 22, 2012 at 14:35
  • The + sign simply indicates a beginning of a line - lines without the + sign indicate a beginning of a new thread. The ! and : signs simply make a line, so it's easier for you to see subsequent calls - i.e. which calls are at the same level. Further, | character can be also used. The numbers mean how long the app spent in that particular call - probably in milliseconds, but that's not important. Nov 22, 2012 at 16:19
  • The example above is not from a hanging app at all, you can examine this way running apps to figure out how are they working. An infinite loop, however, will have a repeating calls to some function over and over again - there will be the same call tree over and over again. Of course, this can mean a simple for cycle, but that's where you can examine, if the for cycle isn't for some reason infinite. Unfortunately, these spin dumps are usually quite long, depending on what function you are calling, so it may take some time to examine. Nov 22, 2012 at 16:22
  • OK, now with that clarification there's an upvote from me. @CharlieMonroe maybe edit some of this commentary into your answer, if it doesn't change the essence – thanks. Nov 22, 2012 at 17:23
1

I found this when searching the Mac Developer Resources for 'spindump'. I've never seen one, but this TechNote referred to in the ReportCrash(8) manual page seems to show you how to read crash logs:

https://developer.apple.com/library/mac/#technotes/tn2004/tn2123.html

And ReportCrash(8) referred to Spindump(8), my apologies. https://developer.apple.com/library/mac/#documentation/Darwin/Reference/ManPages/man8/ReportCrash.8.html

But apparently this doesn't help you out. I'll leave it up here just as well.

Hope this helps someone out somehow.

2
  • That's useful for crashes but not for spindump. Apple's spindump(8) OS X Manual Page does not refer to ReportCrash(8). Nov 19, 2012 at 18:05
  • And, the spindump page only describes the utility to manually trigger the sampling, nothing about the output.
    – Rick Berge
    Dec 16, 2015 at 16:38

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.