How to Diagnose App Hang?

smoothmango · July 6, 2016, 6:27pm

My app runs fine for a few hours, but will eventually hang. I get a beachball when my app is in the foreground, and the app is frozen (though OSX is not, I can switch apps, look at Xcode, etc…).

How do I diagnose where in my code this is happening? Activity Monitor says my app is “not responding”. The Xcode debug info doesn’t show anything amiss. I have xcode set to break on “all exceptions”, but no exception was triggered. I presume I’m stuck in an infinite loop somewhere, but how do I figure out where? My console messages don’t show anything odd.

Help!

If helpful, here’s the top of the OSX crash report when I force quit the app:

Heaviest stack for the main thread of the target process:
  43  start + 52 (MEDIUM + 7764) [0x100001e54]
  43  main + 423 (main.cpp:19,2 in MEDIUM + 8199) [0x100002007]
  43  ofRunApp(ofBaseApp*) + 75 (ofAppRunner.cpp:153,9 in MEDIUM + 5497675) [0x10053e34b]
  43  ofRunApp(std::__1::shared_ptr<ofBaseApp>) + 86 (ofAppRunner.cpp:173,13 in MEDIUM + 5497846) [0x10053e3f6]
  43  ofMainLoop::loop() + 62 (ofMainLoop.cpp:121,4 in MEDIUM + 5701662) [0x10057001e]
  43  ofMainLoop::loopOnce() + 187 (ofMainLoop.cpp:139,4 in MEDIUM + 5701899) [0x10057010b]
  43  ofAppGLFWWindow::update() + 23 (ofAppGLFWWindow.cpp:346,2 in MEDIUM + 6103943) [0x1005d2387]
  43  ofCoreEvents::notifyUpdate() + 22 (ofEventUtils.h:222,3 in MEDIUM + 5517942) [0x100543276]
  43  ofEvent<ofEventArgs, std::__1::recursive_mutex>::notify(void const*, ofEventArgs&) + 257 (functional:1793,12 in MEDIUM + 5524577) [0x100544c61]
  43  std::__1::__function::__func<std::__1::shared_ptr<of::priv::Function<ofEventArgs, std::__1::recursive_mutex> > ofEvent<ofEventArgs, std::__1::recursive_mutex>::make_function<ofBaseApp>(ofBaseApp*, void (ofBaseApp::*)(ofEventArgs&), int)::'lambda'(void const*, ofEventArgs&), std::__1::allocator<std::__1::shared_ptr<of::priv::Function<ofEventArgs, std::__1::recursive_mutex> > ofEvent<ofEventArgs, std::__1::recursive_mutex>::make_function<ofBaseApp>(ofBaseApp*, void (ofBaseApp::*)(ofEventArgs&), int)::'lambda'(void const*, ofEventArgs&)>, bool (void const*, ofEventArgs&)>::operator()(void const*&&, ofEventArgs&) + 37 (ofEvent.h:237,4 in MEDIUM + 5707157) [0x100571595]
  43  ofApp::update() + 21 (ofApp.cpp:46,5 in MEDIUM + 15845) [0x100003de5]
  43  MedPhraseAnimator::update() + 41 (MedPhraseAnimator.cpp:92,5 in MEDIUM + 39961) [0x100009c19]
  43  MedPhraseAnimator::run_state_machine_lead(MedPhraseAnimator::State&) + 1771 (MedPhraseAnimator.cpp:207,44 in MEDIUM + 41931) [0x10000a3cb]
  43  -[ofAVFoundationVideoPlayer setPosition:] + 122 (ofAVFoundationVideoPlayer.m:1303,3 in MEDIUM + 5585962) [0x100553c2a]
  43  -[ofAVFoundationVideoPlayer seekToTime:] + 80 (ofAVFoundationVideoPlayer.m:1159,2 in MEDIUM + 5583792) [0x1005533b0]
  43  -[ofAVFoundationVideoPlayer seekToTime:withTolerance:] + 116 (ofAVFoundationVideoPlayer.m:1176,2 in MEDIUM + 5583924) [0x100553434]
  43  -[AVAssetReader cancelReading] + 336 (AVFoundation + 111870) [0x7fff97c414fe]
  43  ??? (MediaToolbox + 3463524) [0x7fff8f470964]
  43  -[__NSArrayM dealloc] + 205 (CoreFoundation + 186541) [0x7fff885288ad]
  43  CFRelease + 371 (CoreFoundation + 102563) [0x7fff885140a3]
  43  ??? (MediaToolbox + 3506388) [0x7fff8f47b0d4]
  43  ??? (MediaToolbox + 1331814) [0x7fff8f268266]
  43  VMC2Invalidate + 103 (MediaToolbox + 431659) [0x7fff8f18c62b]
  43  ??? (MediaToolbox + 432557) [0x7fff8f18c9ad]
  43  VTDecompressionSessionInvalidate + 73 (VideoToolbox + 40199) [0x7fff8a5a7d07]
  43  ??? (VideoToolbox + 692280) [0x7fff8a647038]
  43  FigSemaphoreWaitRelative + 163 (CoreMedia + 317851) [0x7fff95d6b99b]
  43  WaitOnConditionTimed + 89 (CoreMedia + 319818) [0x7fff95d6c14a]
  43  __psynch_cvwait + 10 (libsystem_kernel.dylib + 93874) [0x7fff9304aeb2]
 *43  psynch_cvcontinue + 0 (pthread + 30218) [0xffffff7f80fd660a]


Process:         MEDIUM [1152]
Path:            /Users/USER/Documents/*/MEDIUM.app/Contents/MacOS/MEDIUM
Architecture:    x86_64
Parent:          Xcode [480]
Responsible:     Xcode [480]
UID:             501
Task size:       235598 pages (-6)
CPU Time:        0.001s
Note:            Unresponsive for 892 seconds before sampling
Note:            2 idle work queue threads omitted

  Thread 0x6f3e           DispatchQueue 1         43 samples (1-43)       priority 46 (base 46)   cpu time 0.001s
  <thread QoS user interactive (requested user interactive), process unclamped, process received importance donation from WindowServer [159], IO policy important>
  43  start + 52 (MEDIUM + 7764) [0x100001e54] 1-43
    43  main + 423 (main.cpp:19,2 in MEDIUM + 8199) [0x100002007] 1-43
      43  ofRunApp(ofBaseApp*) + 75 (ofAppRunner.cpp:153,9 in MEDIUM + 5497675) [0x10053e34b] 1-43
        43  ofRunApp(std::__1::shared_ptr<ofBaseApp>) + 86 (ofAppRunner.cpp:173,13 in MEDIUM + 5497846) [0x10053e3f6] 1-43
          43  ofMainLoop::loop() + 62 (ofMainLoop.cpp:121,4 in MEDIUM + 5701662) [0x10057001e] 1-43
            43  ofMainLoop::loopOnce() + 187 (ofMainLoop.cpp:139,4 in MEDIUM + 5701899) [0x10057010b] 1-43
              43  ofAppGLFWWindow::update() + 23 (ofAppGLFWWindow.cpp:346,2 in MEDIUM + 6103943) [0x1005d2387] 1-43
                43  ofCoreEvents::notifyUpdate() + 22 (ofEventUtils.h:222,3 in MEDIUM + 5517942) [0x100543276] 1-43
                  43  ofEvent<ofEventArgs, std::__1::recursive_mutex>::notify(void const*, ofEventArgs&) + 257 (functional:1793,12 in MEDIUM + 5524577) [0x100544c61] 1-43
                    43  std::__1::__function::__func<std::__1::shared_ptr<of::priv::Function<ofEventArgs, std::__1::recursive_mutex> > ofEvent<ofEventArgs, std::__1::recursive_mutex>::make_function<ofBaseApp>(ofBaseApp*, void (ofBaseApp::*)(ofEventArgs&), int)::'lambda'(void const*, ofEventArgs&), std::__1::allocator<std::__1::shared_ptr<of::priv::Function<ofEventArgs, std::__1::recursive_mutex> > ofEvent<ofEventArgs, std::__1::recursive_mutex>::make_function<ofBaseApp>(ofBaseApp*, void (ofBaseApp::*)(ofEventArgs&), int)::'lambda'(void const*, ofEventArgs&)>, bool (void const*, ofEventArgs&)>::operator()(void const*&&, ofEventArgs&) + 37 (ofEvent.h:237,4 in MEDIUM + 5707157) [0x100571595] 1-43
                      43  ofApp::update() + 21 (ofApp.cpp:46,5 in MEDIUM + 15845) [0x100003de5] 1-43
                        43  MedPhraseAnimator::update() + 41 (MedPhraseAnimator.cpp:92,5 in MEDIUM + 39961) [0x100009c19] 1-43
                          43  MedPhraseAnimator::run_state_machine_lead(MedPhraseAnimator::State&) + 1771 (MedPhraseAnimator.cpp:207,44 in MEDIUM + 41931) [0x10000a3cb] 1-43
                            43  -[ofAVFoundationVideoPlayer setPosition:] + 122 (ofAVFoundationVideoPlayer.m:1303,3 in MEDIUM + 5585962) [0x100553c2a] 1-43
                              43  -[ofAVFoundationVideoPlayer seekToTime:] + 80 (ofAVFoundationVideoPlayer.m:1159,2 in MEDIUM + 5583792) [0x1005533b0] 1-43
                                43  -[ofAVFoundationVideoPlayer seekToTime:withTolerance:] + 116 (ofAVFoundationVideoPlayer.m:1176,2 in MEDIUM + 5583924) [0x100553434] 1-43
                                  43  -[AVAssetReader cancelReading] + 336 (AVFoundation + 111870) [0x7fff97c414fe] 1-43
                                    43  ??? (MediaToolbox + 3463524) [0x7fff8f470964] 1-43
                                      43  -[__NSArrayM dealloc] + 205 (CoreFoundation + 186541) [0x7fff885288ad] 1-43
                                        43  CFRelease + 371 (CoreFoundation + 102563) [0x7fff885140a3] 1-43
                                          43  ??? (MediaToolbox + 3506388) [0x7fff8f47b0d4] 1-43
                                            43  ??? (MediaToolbox + 1331814) [0x7fff8f268266] 1-43
                                              43  VMC2Invalidate + 103 (MediaToolbox + 431659) [0x7fff8f18c62b] 1-43
                                                43  ??? (MediaToolbox + 432557) [0x7fff8f18c9ad] 1-43
                                                  43  VTDecompressionSessionInvalidate + 73 (VideoToolbox + 40199) [0x7fff8a5a7d07] 1-43
                                                    43  ??? (VideoToolbox + 692280) [0x7fff8a647038] 1-43
                                                      43  FigSemaphoreWaitRelative + 163 (CoreMedia + 317851) [0x7fff95d6b99b] 1-43
                                                        43  WaitOnConditionTimed + 89 (CoreMedia + 319818) [0x7fff95d6c14a] 1-43
                                                          43  __psynch_cvwait + 10 (libsystem_kernel.dylib + 93874) [0x7fff9304aeb2] 1-43
                                                           *3   psynch_cvcontinue + 0 (pthread + 30218) [0xffffff7f80fd660a] 1-3
  <os_trace: Activity 0x37 ??? (VideoToolbox + 692263)>
                                                           *10  psynch_cvcontinue + 0 (pthread + 30218) [0xffffff7f80fd660a] 4-13
  <os_trace: Activity 0x37 ??? (VideoToolbox + 692263)>
                                                           *10  psynch_cvcontinue + 0 (pthread + 30218) [0xffffff7f80fd660a] 14-23
  <os_trace: Activity 0x37 ??? (VideoToolbox + 692263)>
                                                           *10  psynch_cvcontinue + 0 (pthread + 30218) [0xffffff7f80fd660a] 24-33
  <os_trace: Activity 0x37 ??? (VideoToolbox + 692263)>
                                                           *10  psynch_cvcontinue + 0 (pthread + 30218) [0xffffff7f80fd660a] 34-43

zach · July 6, 2016, 6:45pm

I would run it in debug and then when it freezes, hit the pause button in xcode and see where the debugger takes you. when I see voodoo in applications I usually look for memory errors / array access / uninitialized variables, etc.

if it’s helpful, I’ve used this as a tool to detect hangs and restart the app:

you might be able to use this to detect the hang and notify you ? (I’ve recently started to use slack / messaging for monitoring long running apps – I get a DM when my app restarts, etc)

smoothmango · July 6, 2016, 8:58pm

Thanks @zach!

I installed ofxWatchdog, and it did indeed catch an error: ofxWatchdog [parent] detects hangup.

My understanding is that this indicates I have some code taking too long to return? Possibly an infinite loop? Or perhaps a function with high latency? Any further advice on how to drill down into this? As of now, I’m not sure if this is due to something I did, or some code buried in a library somewhere.

smoothmango · July 6, 2016, 11:44pm

@zach Wowa - now I noticed an even weirder thing.

When I use ofxWatchdog, my memory usage is about 9MB and stable. Before I added ofxWatchdog, my memory usage was ~100MB right off the bat, and would slowly climb until it would be crash the system for lack of memory after about 24 hours (if it didn’t hang first, which was the reason that initially prompted this thread). This is super weird.

It’s literally the difference between having the ofxWatchdog line in main.cpp commented out or in.

smoothmango · July 7, 2016, 5:51pm

I’ve narrowed the problem down to when I call stop() on a pointer to a movie. Not sure why this is hanging the app (sometimes). I started a thread Hang on movie stop() to discuss this more focused question.