App hangs on MacOS High Sierra

Hello again. First off thanks to all for your quick responses to our earlier issue today. It’s nice to know there’s a helpful community we can rely on.

Another issue we’re experiencing: on MacOS High Sierra, our app will hang at a particular time. We know exactly how to reproduce the issue. We’ve tried to set breakpoints in parts of the code that may be executing like Timers and Shell events. None of the breakpoints activate and the app simply freezes. This occurs in both debug and release builds.

Is there a way to help us identify where in the code the issue may be occurring?

sounds like you may have a race-condition (if it were recursion, it would crash after a minute or two)
use some type of profiler (Im sure someone will reccomend on)… this might tell you where (approximately) the program is spending (wasting) all it time

When you force quite the application, it will generate a report and buried in that report will the function that it froze at. Once you’ve gotten the report, paste it here so we can help you track it down. Since Yosemite, Apple’s care with their OS updates has gradually gone down hill, so don’t be surprised if it’s an issue with High Sierra.

Just create an empty Xcode project and attach to the running process. Now press the pause button and you can look where it hangs. It works well.

Thomas - we can reproduce the issue when running the app in debug mode in the IDE. Nothing happens when we click the Pause button. The app continues to run and the IDE does not pause execution.

Here is the report, thanks!

Date/Time: 2018-01-12 11:09:38 -0800
OS Version: Mac OS X 10.13.1 (Build 17B48)
Architecture: x86_64h
Report Version: 26

Data Source: Stackshots

Command: ***
Path: /Users/USER///Contents/MacOS/*
Version: ??? (???)
Parent: launchd [1]
PID: 44617

Event: hang
Duration: 1.00s (process was unresponsive for 221 seconds before sampling)
Steps: 10 (100ms sampling interval)

Hardware model: MacBookPro11,5
Active cpus: 8

Time Awake Since Boot: 2400000s
Time Since Wake: 2100s

Fan speed: 2166 rpm


Timeline format: stacks are sorted chronologically
Use -i and -heavy to re-report with count sorting

Heaviest stack for the main thread of the target process:
10 start + 1 (libdyld.dylib + 4421) [0x7fff5a071145]
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1895395) [0x104740be3]
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1909070) [0x10474414e]
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 873795) [0x104647543]
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 2430987) [0x104ab580b]
10 -[NSApplication run] + 764 (AppKit + 223281) [0x7fff300a0831]
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 864296) [0x104937028]
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 2438367) [0x104ab74df]
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 335397) [0x1045c3e25]
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 864447) [0x1049370bf]
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 864379) [0x10493707b]
10 -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 3044 (AppKit + 8220268) [0x7fff30840e6c]
10 _DPSNextEvent + 2085 (AppKit + 268835) [0x7fff300aba23]
10 _BlockUntilNextEventMatchingListInModeWithFilter + 64 (HIToolbox + 193364) [0x7fff31dae354]
10 ReceiveNextEventCommon + 613 (HIToolbox + 194006) [0x7fff31dae5d6]
10 RunCurrentEventLoopInMode + 286 (HIToolbox + 194662) [0x7fff31dae866]
10 CFRunLoopRunSpecific + 483 (CoreFoundation + 544675) [0x7fff32a8efa3]
10 __CFRunLoopRun + 2427 (CoreFoundation + 547755) [0x7fff32a8fbab]
10 __CFRunLoopDoTimers + 346 (CoreFoundation + 583082) [0x7fff32a985aa]
10 __CFRunLoopDoTimer + 1095 (CoreFoundation + 584359) [0x7fff32a98aa7]
10 CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION + 20 (CoreFoundation + 585268) [0x7fff32a98e34]
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 2471023) [0x104abf46f]
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1387678) [0x1046c4c9e]
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1661444) [0x104707a04]
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1721460) [0x104716474]
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 807766) [0x104637356]
10 ??? (<15E1D2F9-479E-3C01-9187-34D9B9D577CC> + 13650) [0x10756d552]
10 write + 10 (libsystem_kernel.dylib + 121698) [0x7fff5a1c2b62]
*10 hndl_unix_scall64 + 22 (kernel + 121206) [0xffffff800021d976]
*10 unix_syscall64 + 600 (kernel + 6347336) [0xffffff800080da48]
*10 write_nocancel + 218 (kernel + 5610922) [0xffffff8000759daa]
*10 ??? (kernel + 5611377) [0xffffff8000759f71]
*10 ??? (kernel + 2917834) [0xffffff80004c85ca]
*10 VNOP_WRITE + 112 (kernel + 2976352) [0xffffff80004d6a60]
*10 spec_write + 748 (kernel + 3021804) [0xffffff80004e1bec]
*10 ??? (kernel + 5674427) [0xffffff80007695bb]
*10 ??? (kernel + 5513014) [0xffffff8000741f36]
*10 lck_mtx_sleep + 126 (kernel + 501262) [0xffffff800027a60e]
*10 thread_block_reason + 175 (kernel + 548255) [0xffffff8000285d9f]
*10 ??? (kernel + 552247) [0xffffff8000286d37]
*10 machine_switch_context + 205 (kernel + 1590445) [0xffffff80003844ad]

Continued:

Process: ***
Path: /Users/USER///*
Architecture: x86_64
Parent: launchd [1]
UID: 501
Task size: 69.65 MB
Note: Unresponsive for 221 seconds before sampling
Note: 2 idle work queue threads omitted

Thread 0x40b9878 DispatchQueue 1 10 samples (1-10) priority 46 (base 46)
<thread QoS user interactive (requested user interactive), process unclamped, process received importance donation from WindowServer [77559], IO tier 0>
10 start + 1 (libdyld.dylib + 4421) [0x7fff5a071145] 1-10
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1895395) [0x104740be3] 1-10
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1909070) [0x10474414e] 1-10
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 873795) [0x104647543] 1-10
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 2430987) [0x104ab580b] 1-10
10 -[NSApplication run] + 764 (AppKit + 223281) [0x7fff300a0831] 1-10
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 864296) [0x104937028] 1-10
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 2438367) [0x104ab74df] 1-10
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 335397) [0x1045c3e25] 1-10
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 864447) [0x1049370bf] 1-10
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 864379) [0x10493707b] 1-10
10 -[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:] + 3044 (AppKit + 8220268) [0x7fff30840e6c] 1-10
10 _DPSNextEvent + 2085 (AppKit + 268835) [0x7fff300aba23] 1-10
10 _BlockUntilNextEventMatchingListInModeWithFilter + 64 (HIToolbox + 193364) [0x7fff31dae354] 1-10
10 ReceiveNextEventCommon + 613 (HIToolbox + 194006) [0x7fff31dae5d6] 1-10
10 RunCurrentEventLoopInMode + 286 (HIToolbox + 194662) [0x7fff31dae866] 1-10
10 CFRunLoopRunSpecific + 483 (CoreFoundation + 544675) [0x7fff32a8efa3] 1-10
10 __CFRunLoopRun + 2427 (CoreFoundation + 547755) [0x7fff32a8fbab] 1-10
10 __CFRunLoopDoTimers + 346 (CoreFoundation + 583082) [0x7fff32a985aa] 1-10
10 __CFRunLoopDoTimer + 1095 (CoreFoundation + 584359) [0x7fff32a98aa7] 1-10
10 CFRUNLOOP_IS_CALLING_OUT_TO_A_TIMER_CALLBACK_FUNCTION + 20 (CoreFoundation + 585268) [0x7fff32a98e34] 1-10
10 ??? (<707581D4-4AD3-3A45-A1AA-F0E248464D51> + 2471023) [0x104abf46f] 1-10
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1387678) [0x1046c4c9e] 1-10
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1661444) [0x104707a04] 1-10
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 1721460) [0x104716474] 1-10
10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E> + 807766) [0x104637356] 1-10
10 ??? (<15E1D2F9-479E-3C01-9187-34D9B9D577CC> + 13650) [0x10756d552] 1-10
10 write + 10 (libsystem_kernel.dylib + 121698) [0x7fff5a1c2b62] 1-10
*10 hndl_unix_scall64 + 22 (kernel + 121206) [0xffffff800021d976] 1-10
*10 unix_syscall64 + 600 (kernel + 6347336) [0xffffff800080da48] 1-10
*10 write_nocancel + 218 (kernel + 5610922) [0xffffff8000759daa] 1-10
*10 ??? (kernel + 5611377) [0xffffff8000759f71] 1-10
*10 ??? (kernel + 2917834) [0xffffff80004c85ca] 1-10
*10 VNOP_WRITE + 112 (kernel + 2976352) [0xffffff80004d6a60] 1-10
*10 spec_write + 748 (kernel + 3021804) [0xffffff80004e1bec] 1-10
*10 ??? (kernel + 5674427) [0xffffff80007695bb] 1-10
*10 ??? (kernel + 5513014) [0xffffff8000741f36] 1-10
*10 lck_mtx_sleep + 126 (kernel + 501262) [0xffffff800027a60e] 1-10
*10 thread_block_reason + 175 (kernel + 548255) [0xffffff8000285d9f] 1-10
*10 ??? (kernel + 552247) [0xffffff8000286d37] 1-10
*10 machine_switch_context + 205 (kernel + 1590445) [0xffffff80003844ad] 1-10

Thread 0x40b989a Thread name “com.apple.NSURLConnectionLoader” 10 samples (1-10) priority 31 (base 31)
<thread QoS default (requested default), process unclamped, process received importance donation from WindowServer [77559], IO tier 0>
10 thread_start + 13 (libsystem_pthread.dylib + 11357) [0x7fff5a2fac5d] 1-10
10 _pthread_start + 377 (libsystem_pthread.dylib + 13677) [0x7fff5a2fb56d] 1-10
10 _pthread_body + 340 (libsystem_pthread.dylib + 14017) [0x7fff5a2fb6c1] 1-10
10 NSThread__start + 1197 (Foundation + 194264) [0x7fff34b4d6d8] 1-10
10 +[NSURLConnection(Loader) _resourceLoadLoop:] + 357 (CFNetwork + 26210) [0x7fff31a07662] 1-10
10 CFRunLoopRunSpecific + 483 (CoreFoundation + 544675) [0x7fff32a8efa3] 1-10
10 __CFRunLoopRun + 1783 (CoreFoundation + 547111) [0x7fff32a8f927] 1-10
10 __CFRunLoopServiceMachPort + 341 (CoreFoundation + 550357) [0x7fff32a905d5] 1-10
10 mach_msg_trap + 10 (libsystem_kernel.dylib + 77430) [0x7fff5a1b7e76] 1-10
*10 ipc_mqueue_receive_continue + 0 (kernel + 336384) [0xffffff8000252200] 1-10

Thread 0x40b989b 10 samples (1-10) priority 37 (base 37)
<thread QoS user initiated (requested user initiated), process unclamped, process received importance donation from WindowServer [77559], IO tier 0>
10 thread_start + 13 (libsystem_pthread.dylib + 11357) [0x7fff5a2fac5d] 1-10
10 _pthread_start + 377 (libsystem_pthread.dylib + 13677) [0x7fff5a2fb56d] 1-10
10 _pthread_body + 340 (libsystem_pthread.dylib + 14017) [0x7fff5a2fb6c1] 1-10
10 void* std::__1::__thread_proxy<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_deletestd::__1::__thread_struct >, void ()(bmalloc::AsyncTask<bmalloc::Heap, void (bmalloc::Heap::)()>), bmalloc::AsyncTask<bmalloc::Heap, void (bmalloc::Heap::)()>> >(void) + 40 (JavaScriptCore + 11321080) [0x7fff36549ef8] 1-10
10 bmalloc::AsyncTask<bmalloc::Heap, void (bmalloc::Heap::*)()>::threadRunLoop() + 139 (JavaScriptCore + 11320267) [0x7fff36549bcb] 1-10
10 void std::__1::condition_variable_any::wait<std::__1::unique_lockbmalloc::Mutex >(std::__1::unique_lockbmalloc::Mutex&) + 86 (JavaScriptCore + 11320470) [0x7fff36549c96] 1-10
10 std::__1::condition_variable::wait(std::__1::unique_lockstd::__1::mutex&) + 18 (libc++.1.dylib + 27824) [0x7fff580adcb0] 1-10
10 __psynch_cvwait + 10 (libsystem_kernel.dylib + 114302) [0x7fff5a1c0e7e] 1-10
*10 psynch_cvcontinue + 0 (pthread + 38977) [0xffffff7f829f8841] 1-10

Thread 0x40b98b3 Thread name “com.apple.NSEventThread” 10 samples (1-10) priority 46 (base 46)
<thread QoS user interactive (requested user interactive), process unclamped, process received importance donation from WindowServer [77559], IO tier 0>
10 thread_start + 13 (libsystem_pthread.dylib + 11357) [0x7fff5a2fac5d] 1-10
10 _pthread_start + 377 (libsystem_pthread.dylib + 13677) [0x7fff5a2fb56d] 1-10
10 _pthread_body + 340 (libsystem_pthread.dylib + 14017) [0x7fff5a2fb6c1] 1-10
10 _NSEventThread + 184 (AppKit + 1569489) [0x7fff301e92d1] 1-10
10 CFRunLoopRunSpecific + 483 (CoreFoundation + 544675) [0x7fff32a8efa3] 1-10
10 __CFRunLoopRun + 1783 (CoreFoundation + 547111) [0x7fff32a8f927] 1-10
10 __CFRunLoopServiceMachPort + 341 (CoreFoundation + 550357) [0x7fff32a905d5] 1-10
10 mach_msg_trap + 10 (libsystem_kernel.dylib + 77430) [0x7fff5a1b7e76] 1-10
*10 ipc_mqueue_receive_continue + 0 (kernel + 336384) [0xffffff8000252200] 1-10

The last few functions are hidden “10 ??? (<4A2BD49C-DBCB-3A3A-9C95-98F6F4722D9E>”.

Are you using sockets in your application to connect to the ‘net’?

Have you tried to add logging in the forma of currentMethodName at the beginning and end of each function? With this you can see what happening when the breakpoints don’t fire.

Do the hangs go away when you don’t do the thread? What exactly are you doing in the timers and threads?

I think I see that you do something with IPC in the app. Is this correct?

We’re not doing anything with IPC in the app. We do have a shell instance running and we are using HTTPSocket. The only way to reproduce the crash requires having the shell instance running so we can’t easy remove that. We’ll try removing the HTTPSocket code to see if that fixes the issue. We’ll also consider the logging you suggest. Thanks!

Removing the HTTPSocket code did not resolve the issue. We’ll try adding logging.

Ok adding logging helped us identify the code causing the hang: it’s the WriteLine() function in our Shell instance. Is this a known issue? We’re investigating now.

After doing some searching on the forum, we tried creating a thread and calling the WriteLine function from the thread. It didn’t make a difference. Somehow calling WriteLine() is locking up the entire app. We also checked the text that is passed to WriteLine() and it’s a small piece of JSON without any unusual characters. In fact, the exact same text is passed to WriteLine many times without issues, prior to the freeze occurring.

Clue: we have a timer that runs and send JSON to the shell. This timer was set to a 1000ms interval. When we set the timer to a 500ms interval, the app hung in just over half the time. Is there some sort of buffer that may be overflowing?

What’s strange is that in order to reproduce this hang, we have to send a particular command to the Shell that change the behavior of the shell app. Further, the command needs to be sent at a particular time. If we don’t send the command, the hang does not occur. If we send it earlier or later, the hang does not occur. If we send it at the right time, the hang occurs after some number of additional commands are sent to the shell. The timer I mentioned above control the frequency at which those additional commands are sent. The faster those additional commands are sent, the faster the hang will occur. So it seems that a particular command puts the app in state where it’s going to eventually hang, and then sending some number of additional commands triggers the hang. All commands are JSON strings sent via Shell.WriteLine().

This looks to be an issue with our Java app that’s running in the Shell. It’s locking up for some time and causing the Xojo app to freeze. Not a Xojo issue unless you consider the Shell instance locking up an issue.

Can you elaborate on “… and attach to the running process”?

This sounds like a good trick to have in the bag, but I’m not entirely sure how to do what you suggest.

In Xcode you can use “Attach to process…” in Debug menu. Then you can pause the process similar to Xojo and look at the current stacks in the used threads.

FYI we did identify the issue with the console app that was running in the Shell instance. It was some sort of deadlock related to thread wait/notify in Java. We actually couldn’t address the issue directly and ended up coding up a workaround. The app no longer locks up and the issue has gone away. It is strange, as I mentioned above, that a lock up inside the shell app would cause Xojo to hang as well.

That is actually documented behavior and is to be expected of synchronous Shell instances:
http://documentation.xojo.com/index.php/Shell.Mode

“Synchronous shells block the main UI thread, even when they are in a thread themselves. For long-running shell processes, use one of the other shell modes instead.”