Test for dispatch.h presence before using

[evanmiller]

Allows building on ancient OS X systems.

[kcat]

What kind of performance impact does this have? The reason the dispatch API is used on macOS is because macOS's POSIX semaphores don't properly put the thread to sleep while waiting, causing high CPU load. What happens on these systems without the dispatch API?

[evanmiller]

How do you suggest testing or what comparison would you like to see?

[kcat]

Basically get an app that uses OpenAL and you know doesn't use much CPU power, that the percentage it uses of the CPU cores is relatively low while the device is open. Then with this change, run the app and look at how much it's using the CPU with an open device. If one of the threads has a core constantly pegged at or near 100%, it's not properly sleeping while waiting on semaphores.

[evanmiller]

@kcat You are correct; even running openal-info pretty well pegs the CPU. Should I abandon hope for these systems, or is there another non-dispatch path forward here?

[kcat]

openal-info wouldn't be a good test since it doesn't rest. It opens the device, queries some stuff and prints it out, then closes. The main thread would be doing constant work while the device is open, unless you modified it to sleep after opening the device. alstream or altonegen may be a better test since they should sleep more often than doing work. It'd be one of the background threads that won't sleep properly.

Presuming it is an issue though, I'd think there would be an alternative somewhere. Maybe an alternate or lower-level API. Semaphores aren't that uncommon, so it would be weird for earlier versions of macOS to not have a way to do them properly.

[evanmiller]

Here's a snippet from sampling altonegen -t 1, which seems stuck and is using 99% CPU

# Report 0 - Timed Samples for altonegen (process 2161)
Stacks at 2021-11-01 11:25:30 -0400
Samples (displayed/total): 771/771
Call graph:
    257 mach_msg_trap
      257 mach_msg_trap
        257 mach_msg
          257 __CFRunLoopRun
            257 CFRunLoopRunSpecific
              257 HALRunLoop::OwnThread(void*)
                257 CAPThread::Entry(CAPThread*)
                  257 _pthread_body
                    0 Thread_5513
    230 semaphore_timedwait_signal_trap
      230 semaphore_timedwait_signal_trap
        230 pthread_cond_timedwait_relative_np
          230 CAGuard::WaitFor(unsigned long long)
            230 CAGuard::WaitUntil(unsigned long long)
              230 HP_IOThread::WorkLoop()
                230 HP_IOThread::ThreadEntry(HP_IOThread*)
                  230 CAPThread::Entry(CAPThread*)
                    230 _pthread_body
                      0 Thread_5a03
    44 uw_update_context_1
      44 uw_update_context_1
        44 uw_update_context
          44 _Unwind_RaiseException_Phase2
            44 _Unwind_Resume
              44 ALCdevice::ALCdevice[not-in-charge](DeviceType)
                44 alcCreateContext
                  44 InitAL
                    44 main
                      44 _start
                        44 start
                          0 Thread_5607

Let me know if I can provide more.

[kcat]

That backtrace doesn't make much sense, if I'm reading it correctly. The InitAL method used by the example is calling alcCreateContext (as expected), but alcCreateContext looks like it's somehow calling the ALCdevice constructor, which should be impossible, which itself is trying to unwind the stack (a crash? abort?), though I don't think anything complicated enough is happening for that to happen.

[evanmiller]

@kcat Is there other information I can generate to help debug this? Maybe turn on logging?

[kcat]

Logging and trying a debug build may help, which should allow getting line numbers and stack variable information.

[evanmiller]

Here is the log before the hang occurs

[ALSOFT] (II) Initializing library v1.21.1-unknown UNKNOWN
[ALSOFT] (II) Supported backends: core, null, wave
[ALSOFT] (II) Loading config /etc/openal/alsoft.conf...
[ALSOFT] (II) Loading config /etc/xdg/alsoft.conf...
[ALSOFT] (II) Loading config .alsoftrc...
[ALSOFT] (II) Loading config .config/alsoft.conf...
[ALSOFT] (WW) Failed to readlink /proc/curproc/file: No such file or directory
[ALSOFT] (II) Key disable-cpu-exts not found
[ALSOFT] (II) Extensions: -none-
[ALSOFT] (II) Key rt-prio not found
[ALSOFT] (II) Key resampler not found
[ALSOFT] (II) Key trap-al-error not found
[ALSOFT] (II) Key trap-alc-error not found
[ALSOFT] (II) Key reverb/boost not found
[ALSOFT] (II) Key drivers not found
[ALSOFT] (II) Initialized backend "core"
[ALSOFT] (II) Added "core" for playback
[ALSOFT] (II) Added "core" for capture
[ALSOFT] (II) Key excludefx not found
[ALSOFT] (II) Key default-reverb not found
[ALSOFT] (II) Key channels not found
[ALSOFT] (II) Key sample-type not found
[ALSOFT] (II) Key frequency not found
[ALSOFT] (II) Key period_size not found
[ALSOFT] (II) Key periods not found
[ALSOFT] (II) Key sources not found
[ALSOFT] (II) Key slots not found
[ALSOFT] (II) Key sends not found
[ALSOFT] (II) Key ambi-format not found
[ALSOFT] (II) Created device 0x9a010, "CoreAudio Default"
[ALSOFT] (II) Key hrtf not found
[ALSOFT] (II) Pre-reset: Stereo, Float32, 44100hz, 882 / 2646 buffer
[ALSOFT] (II) Post-reset: Stereo, Float32, 44100hz, 882 / 2646 buffer
[ALSOFT] (II) Key stereo-mode not found
[ALSOFT] (II) Key cf_level not found
[ALSOFT] (II) Key stereo-encoding not found
[ALSOFT] (II) Stereo rendering
[ALSOFT] (II) Channel config, Main: 3, Real: 2
[ALSOFT] (II) Allocating 5 channels, 20480 bytes
[ALSOFT] (II) Enabling single-band first-order ambisonic decoder
[ALSOFT] (II) Max sources: 256 (255 + 1), effect slots: 64, sends: 2
[ALSOFT] (II) Key dither not found
[ALSOFT] (II) Key dither-depth not found
[ALSOFT] (II) Dithering disabled
[ALSOFT] (II) Key output-limiter not found
[ALSOFT] (II) Output limiter disabled
[ALSOFT] (II) Fixed device latency: 0ns

[evanmiller]

A few related backtraces when I Control-C the process (three separate runs):

#0  0x9143c240 in uw_update_context_1 ()
#1  0x9143c540 in uw_update_context ()
#2  0x9143c940 in _Unwind_RaiseException_Phase2 ()
#3  0x9143ca18 in _Unwind_Resume ()
#4  0x00229c98 in _ZN10ALCcontextC4EN2al13intrusive_ptrI9ALCdeviceEE ()
#5  0x0022fa64 in alcCreateContext ()
#6  0x000037f4 in InitAL (argv=0xbfffeafc, argc=0xbfffeaf8) at examples/common/alhelpers.c:190
#7  0x00004640 in main (argc=0, argv=0x0) at examples/altonegen.c:330

#0  0x9143d068 in read_encoded_value_with_base ()
#1  0x9143e264 in _Unwind_Find_FDE ()
#2  0x9143b3b8 in uw_frame_state_for ()
#3  0x9143c8c8 in _Unwind_RaiseException_Phase2 ()
#4  0x9143ca18 in _Unwind_Resume ()
#5  0x00229c98 in _ZN10ALCcontextC4EN2al13intrusive_ptrI9ALCdeviceEE ()
#6  0x0022fa64 in alcCreateContext ()
#7  0x000037f4 in InitAL (argv=0xbfffeafc, argc=0xbfffeaf8)

#0  0x9002d640 in _keymgr_set_and_unlock_processwide_ptr ()
#1  0x9143e570 in _Unwind_Find_FDE ()
#2  0x9143b3b8 in uw_frame_state_for ()
#3  0x9143c8c8 in _Unwind_RaiseException_Phase2 ()
#4  0x9143ca18 in _Unwind_Resume ()
#5  0x00229c98 in _ZN10ALCcontextC4EN2al13intrusive_ptrI9ALCdeviceEE ()
#6  0x0022fa64 in alcCreateContext ()
#7  0x000037f4 in InitAL (argv=0xbfffeafc, argc=0xbfffeaf8)

[kcat]

Well, that's certainly confusing. I can only guess some kind of memory corruption, though since it's the first call, I don't see how. Do any other apps using OpenAL Soft work? Is it just altonegen freezing/crashing like this, or are some other apps doing the same?

[evanmiller]

To my eyes it looks like the hang is occurring while attempting to handle an exception. Possibly the C++ run-time is buggy on this platform (it's 32-bit PPC running OS X 10.4.11; bugs in modern C++ run-times are fairly common here). I'll poke around and see if I can gather any more clues about the exception and go from there.

[evanmiller]

@kencu Any ideas on this one? Do the unwind backtraces here look familiar?

[kencu]

Iain mentioned he has had to replace some bits of libgcc on these old systems to make unwinding work properly, so the toolchain is possibly the culprit.

re: the problem... libdispatch is available as a buildable separate project; I had considered trying to add it to Tiger and Leopard. Not sure if gcc will support blocks, though, and I think libdispatch requires them, so maybe no happiness that route in the end...not certain.

May have to just patch this in MacPorts and live with the outcome?

[kcat]

Ultimately the question will be if having a core constantly pegged at 100% utilization while a device is open is acceptable, since that seems to be what happens with Mac's sem_wait.

As far as OpenAL Soft is concerned, all that's really needed here is a kind of 'sticky signal'. It doesn't have to hold a count like a real semaphore would, just a binary state with methods to set (this one being real-time safe), wait_and_clear, and test_and_clear (this one not really necessary, since the corresponding try_wait isn't used at the moment). On Linux, a futex with FUTEX_WAIT and FUTEX_WAKE would probably be a better fit, the only reason it's not used is because it isn't portable and I wanted to keep down the number of system-specific paths. But if BSD or Mac has a similar feature, that would be something I could look at.

[barracuda156]

@evanmiller This should also add a case of 10.6 ppc (whether native or Rosetta), since while a header is there, libdispatch is unsupported for the arch.

[barracuda156]

@evanmiller @kcat If a case of 10.6/ppc could be added to the check (i.e. when the dispatch.h is present, but build is for ppc, where dispatch does not work regardless), I will drop dispatch commit from my PR in favor of this – but we still need a fix for inttypes there.