Error in Android -> E/AAudioStream: setState(3) tried to set to 11 but already CLOSING

I’ve just updated to FMOD 2.01.10 from 1.10.20, and while playing a sound sometimes it stutters and logcat shows the text I’m pasting below. Any idea? It was working fine for several years until I updated to FMOD 2:

2021-07-01 11:32:43.218 25729-25984/mypkg D/AAudio: AAudioStream_requestStop(s#3) called
2021-07-01 11:32:43.218 25729-26212/mypkg D/AudioStreamInternalPlay_Client: callbackLoop() exiting, result = 96, isActive() = 1 <<<<<<<<<<<<<<
2021-07-01 11:32:43.219 25729-25984/mypkg D/IsochronousClockModel: stop(nanos = 588397943124383) max lateness = 96 micros
2021-07-01 11:32:43.219 25729-25984/mypkg D/AAudioStream: setState(s#3) from 4 to 9
2021-07-01 11:32:43.282 25729-25984/mypkg D/mypkg: PlayerBase::stop() from IPlayer
2021-07-01 11:32:43.282 25729-26208/mypkg I/fmod: Thread::callback : FMOD mixer thread finished.
2021-07-01 11:32:43.283 25729-25984/mypkg D/AAudio: AAudioStream_close(s#3) called ---------------
2021-07-01 11:32:43.283 25729-25984/mypkg D/AAudioStream: setState(s#3) from 9 to 11
2021-07-01 11:32:43.385 25729-25984/mypkg D/AAudioStream: setState(s#3) from 11 to 11
2021-07-01 11:32:43.385 25729-25984/mypkg E/AAudioStream: setState(3) tried to set to 11 but already CLOSING
2021-07-01 11:32:43.385 25729-25984/mypkg D/AAudioStream: setState(s#3) from 11 to 12
2021-07-01 11:32:43.385 25729-25984/mypkg D/AAudioStream: ~AudioStream(s#3) mPlayerBase strongCount = 2
2021-07-01 11:32:43.385 25729-25984/mypkg D/AAudio: AAudioStream_close(s#3) returned 0 ---------
2021-07-01 11:32:43.386 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() called ----------------------------------------
2021-07-01 11:32:43.387 25729-25984/mypkg I/AudioStreamBuilder: rate = 0, channels = 0, format = 0, sharing = SH, dir = OUTPUT
2021-07-01 11:32:43.387 25729-25984/mypkg I/AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: OFF with frames = 0
2021-07-01 11:32:43.387 25729-25984/mypkg I/AudioStreamBuilder: usage = 14, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0
2021-07-01 11:32:43.387 25729-25984/mypkg I/AudioStreamBuilder: privacy sensitive = false
2021-07-01 11:32:43.387 25729-25984/mypkg D/mypkg: PlayerBase::PlayerBase()
2021-07-01 11:32:43.407 25729-25984/mypkg D/AudioStreamInternal_Client: open() original HW burst = 96, minMicros = 2000 => SW burst = 96
2021-07-01 11:32:43.407 25729-25984/mypkg D/AAudioStream: setState(s#4) from 0 to 2
2021-07-01 11:32:43.408 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#4 ----------------
2021-07-01 11:32:43.408 25729-25984/mypkg D/AAudio: AAudioStream_close(s#4) called ---------------
2021-07-01 11:32:43.408 25729-25984/mypkg D/AAudioStream: setState(s#4) from 2 to 11
2021-07-01 11:32:43.511 25729-25984/mypkg D/AAudioStream: setState(s#4) from 11 to 11
2021-07-01 11:32:43.511 25729-25984/mypkg E/AAudioStream: setState(4) tried to set to 11 but already CLOSING
2021-07-01 11:32:43.511 25729-25984/mypkg D/AAudioStream: setState(s#4) from 11 to 12
2021-07-01 11:32:43.511 25729-25984/mypkg D/AAudioStream: ~AudioStream(s#4) mPlayerBase strongCount = 2
2021-07-01 11:32:43.511 25729-25984/mypkg D/AAudio: AAudioStream_close(s#4) returned 0 ---------
2021-07-01 11:32:43.513 25729-25984/mypkg I/fmod: FMOD::supportsLowLatency : Low latency = true, Pro Audio = true, Bluetooth On = false, Acceptable Block Size = true (96)
2021-07-01 11:32:43.513 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() called ----------------------------------------
2021-07-01 11:32:43.513 25729-25984/mypkg I/AudioStreamBuilder: rate = 0, channels = 0, format = 0, sharing = SH, dir = OUTPUT
2021-07-01 11:32:43.513 25729-25984/mypkg I/AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 0
2021-07-01 11:32:43.513 25729-25984/mypkg I/AudioStreamBuilder: usage = 14, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0
2021-07-01 11:32:43.513 25729-25984/mypkg I/AudioStreamBuilder: privacy sensitive = false
2021-07-01 11:32:43.514 25729-25984/mypkg D/mypkg: PlayerBase::PlayerBase()
2021-07-01 11:32:43.530 25729-25984/mypkg D/AudioStreamInternal_Client: open() original HW burst = 96, minMicros = 2000 => SW burst = 96
2021-07-01 11:32:43.530 25729-25984/mypkg D/AAudioStream: setState(s#5) from 0 to 2
2021-07-01 11:32:43.532 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#5 ----------------
2021-07-01 11:32:43.532 25729-25984/mypkg D/AAudio: AAudioStream_close(s#5) called ---------------
2021-07-01 11:32:43.532 25729-25984/mypkg D/AAudioStream: setState(s#5) from 2 to 11
2021-07-01 11:32:43.634 25729-25984/mypkg D/AAudioStream: setState(s#5) from 11 to 11
2021-07-01 11:32:43.634 25729-25984/mypkg E/AAudioStream: setState(5) tried to set to 11 but already CLOSING
2021-07-01 11:32:43.634 25729-25984/mypkg D/AAudioStream: setState(s#5) from 11 to 12
2021-07-01 11:32:43.634 25729-25984/mypkg D/AAudioStream: ~AudioStream(s#5) mPlayerBase strongCount = 2
2021-07-01 11:32:43.634 25729-25984/mypkg D/AAudio: AAudioStream_close(s#5) returned 0 ---------
2021-07-01 11:32:43.634 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() called ----------------------------------------
2021-07-01 11:32:43.634 25729-25984/mypkg I/AudioStreamBuilder: rate = 0, channels = 0, format = 0, sharing = SH, dir = OUTPUT
2021-07-01 11:32:43.634 25729-25984/mypkg I/AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 0
2021-07-01 11:32:43.634 25729-25984/mypkg I/AudioStreamBuilder: usage = 14, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0
2021-07-01 11:32:43.634 25729-25984/mypkg I/AudioStreamBuilder: privacy sensitive = false
2021-07-01 11:32:43.634 25729-25984/mypkg D/mypkg: PlayerBase::PlayerBase()
2021-07-01 11:32:43.654 25729-25984/mypkg D/AudioStreamInternal_Client: open() original HW burst = 96, minMicros = 2000 => SW burst = 96
2021-07-01 11:32:43.654 25729-25984/mypkg D/AAudioStream: setState(s#6) from 0 to 2
2021-07-01 11:32:43.655 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#6 ----------------
2021-07-01 11:32:43.657 25729-25984/mypkg I/fmod: OutputAAudio::init : Sample rate: HW = 48000, SW = 24000 Block size: HW = 96, SW = 512.
2021-07-01 11:32:43.657 25729-25984/mypkg I/fmod: DownMix::init : dspbuffersize: 512 rate: 24000. output speaker mode: 3, input speaker mode 2
2021-07-01 11:32:43.657 25729-25984/mypkg I/fmod: DownMix::init : done.
2021-07-01 11:32:43.657 25729-25984/mypkg I/fmod: SystemI::startDriver : Output requires a sample rate of 48000Hz, resampling will occur.
2021-07-01 11:32:43.657 25729-25984/mypkg I/fmod: Thread::initThread : Init FMOD mixer thread. Affinity: 0x8000000000000001, Priority: 0xFFFF7FFA, Stack Size: 81920, Semaphore: Yes, Sleep Time: 0, Looping: Yes.
2021-07-01 11:32:43.658 25729-25984/mypkg D/AAudio: AAudioStream_requestStart(s#6) called --------------
2021-07-01 11:32:43.658 25729-25984/mypkg D/AAudioStream: setState(s#6) from 2 to 3
2021-07-01 11:32:43.760 25729-25984/mypkg D/mypkg: PlayerBase::start() from IPlayer
2021-07-01 11:32:43.761 25729-25984/mypkg D/AAudio: AAudioStream_requestStart(s#6) returned 0 ---------
2021-07-01 11:32:43.763 25729-26313/mypkg D/AudioStreamInternalPlay_Client: callbackLoop() entering >>>>>>>>>>>>>>>
2021-07-01 11:32:43.763 25729-26313/mypkg D/AudioStreamInternal_Client: onEventFromServer - got AAUDIO_SERVICE_EVENT_STARTED
2021-07-01 11:32:43.763 25729-26313/mypkg D/AAudioStream: setState(s#6) from 3 to 4
2021-07-01 11:32:44.846 25729-25984/mypkg D/AAudio: AAudioStream_requestStop(s#6) called
2021-07-01 11:32:44.846 25729-26313/mypkg D/AudioStreamInternalPlay_Client: callbackLoop() exiting, result = 96, isActive() = 1 <<<<<<<<<<<<<<
2021-07-01 11:32:44.846 25729-25984/mypkg D/IsochronousClockModel: stop(nanos = 588399570961316) max lateness = 75 micros
2021-07-01 11:32:44.846 25729-25984/mypkg D/AAudioStream: setState(s#6) from 4 to 9
2021-07-01 11:32:44.954 25729-25984/mypkg D/mypkg: PlayerBase::stop() from IPlayer
2021-07-01 11:32:44.955 25729-26309/mypkg I/fmod: Thread::callback : FMOD mixer thread finished.
2021-07-01 11:32:44.955 25729-25984/mypkg D/AAudio: AAudioStream_close(s#6) called ---------------
2021-07-01 11:32:44.956 25729-25984/mypkg D/AAudioStream: setState(s#6) from 9 to 11
2021-07-01 11:32:45.059 25729-25984/mypkg D/AAudioStream: setState(s#6) from 11 to 11
2021-07-01 11:32:45.059 25729-25984/mypkg E/AAudioStream: setState(6) tried to set to 11 but already CLOSING
2021-07-01 11:32:45.059 25729-25984/mypkg D/AAudioStream: setState(s#6) from 11 to 12
2021-07-01 11:32:45.059 25729-25984/mypkg D/AAudioStream: ~AudioStream(s#6) mPlayerBase strongCount = 2
2021-07-01 11:32:45.059 25729-25984/mypkg D/AAudio: AAudioStream_close(s#6) returned 0 ---------
2021-07-01 11:32:45.060 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() called ----------------------------------------
2021-07-01 11:32:45.060 25729-25984/mypkg I/AudioStreamBuilder: rate = 0, channels = 0, format = 0, sharing = SH, dir = OUTPUT
2021-07-01 11:32:45.060 25729-25984/mypkg I/AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: OFF with frames = 0
2021-07-01 11:32:45.060 25729-25984/mypkg I/AudioStreamBuilder: usage = 14, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0
2021-07-01 11:32:45.060 25729-25984/mypkg I/AudioStreamBuilder: privacy sensitive = false
2021-07-01 11:32:45.060 25729-25984/mypkg D/mypkg: PlayerBase::PlayerBase()
2021-07-01 11:32:45.081 25729-25984/mypkg D/AudioStreamInternal_Client: open() original HW burst = 96, minMicros = 2000 => SW burst = 96
2021-07-01 11:32:45.081 25729-25984/mypkg D/AAudioStream: setState(s#7) from 0 to 2
2021-07-01 11:32:45.082 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#7 ----------------
2021-07-01 11:32:45.082 25729-25984/mypkg D/AAudio: AAudioStream_close(s#7) called ---------------
2021-07-01 11:32:45.082 25729-25984/mypkg D/AAudioStream: setState(s#7) from 2 to 11
2021-07-01 11:32:45.185 25729-25984/mypkg D/AAudioStream: setState(s#7) from 11 to 11
2021-07-01 11:32:45.185 25729-25984/mypkg E/AAudioStream: setState(7) tried to set to 11 but already CLOSING
2021-07-01 11:32:45.185 25729-25984/mypkg D/AAudioStream: setState(s#7) from 11 to 12
2021-07-01 11:32:45.185 25729-25984/mypkg D/AAudioStream: ~AudioStream(s#7) mPlayerBase strongCount = 2
2021-07-01 11:32:45.185 25729-25984/mypkg D/AAudio: AAudioStream_close(s#7) returned 0 ---------
2021-07-01 11:32:45.188 25729-25984/mypkg I/fmod: FMOD::supportsLowLatency : Low latency = true, Pro Audio = true, Bluetooth On = false, Acceptable Block Size = true (96)
2021-07-01 11:32:45.188 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() called ----------------------------------------
2021-07-01 11:32:45.188 25729-25984/mypkg I/AudioStreamBuilder: rate = 0, channels = 0, format = 0, sharing = SH, dir = OUTPUT
2021-07-01 11:32:45.188 25729-25984/mypkg I/AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 0
2021-07-01 11:32:45.188 25729-25984/mypkg I/AudioStreamBuilder: usage = 14, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0
2021-07-01 11:32:45.188 25729-25984/mypkg I/AudioStreamBuilder: privacy sensitive = false
2021-07-01 11:32:45.188 25729-25984/mypkg D/mypkg: PlayerBase::PlayerBase()
2021-07-01 11:32:45.203 25729-25984/mypkg D/AudioStreamInternal_Client: open() original HW burst = 96, minMicros = 2000 => SW burst = 96
2021-07-01 11:32:45.203 25729-25984/mypkg D/AAudioStream: setState(s#8) from 0 to 2
2021-07-01 11:32:45.205 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#8 ----------------
2021-07-01 11:32:45.205 25729-25984/mypkg D/AAudio: AAudioStream_close(s#8) called ---------------
2021-07-01 11:32:45.205 25729-25984/mypkg D/AAudioStream: setState(s#8) from 2 to 11
2021-07-01 11:32:45.307 25729-25984/mypkg D/AAudioStream: setState(s#8) from 11 to 11
2021-07-01 11:32:45.307 25729-25984/mypkg E/AAudioStream: setState(8) tried to set to 11 but already CLOSING
2021-07-01 11:32:45.307 25729-25984/mypkg D/AAudioStream: setState(s#8) from 11 to 12
2021-07-01 11:32:45.307 25729-25984/mypkg D/AAudioStream: ~AudioStream(s#8) mPlayerBase strongCount = 2
2021-07-01 11:32:45.307 25729-25984/mypkg D/AAudio: AAudioStream_close(s#8) returned 0 ---------
2021-07-01 11:32:45.307 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() called ----------------------------------------
2021-07-01 11:32:45.307 25729-25984/mypkg I/AudioStreamBuilder: rate = 0, channels = 0, format = 0, sharing = SH, dir = OUTPUT
2021-07-01 11:32:45.307 25729-25984/mypkg I/AudioStreamBuilder: device = 0, sessionId = -1, perfMode = 12, callback: ON with frames = 0
2021-07-01 11:32:45.307 25729-25984/mypkg I/AudioStreamBuilder: usage = 14, contentType = 0, inputPreset = 0, allowedCapturePolicy = 0
2021-07-01 11:32:45.307 25729-25984/mypkg I/AudioStreamBuilder: privacy sensitive = false
2021-07-01 11:32:45.307 25729-25984/mypkg D/mypkg: PlayerBase::PlayerBase()
2021-07-01 11:32:45.324 25729-25984/mypkg D/AudioStreamInternal_Client: open() original HW burst = 96, minMicros = 2000 => SW burst = 96
2021-07-01 11:32:45.324 25729-25984/mypkg D/AAudioStream: setState(s#9) from 0 to 2
2021-07-01 11:32:45.325 25729-25984/mypkg I/AAudio: AAudioStreamBuilder_openStream() returns 0 = AAUDIO_OK for s#9 ----------------
2021-07-01 11:32:45.328 25729-25984/mypkg I/fmod: OutputAAudio::init : Sample rate: HW = 48000, SW = 24000 Block size: HW = 96, SW = 512.
2021-07-01 11:32:45.328 25729-25984/mypkg I/fmod: DownMix::init : dspbuffersize: 512 rate: 24000. output speaker mode: 3, input speaker mode 2
2021-07-01 11:32:45.328 25729-25984/mypkg I/fmod: DownMix::init : done.
2021-07-01 11:32:45.328 25729-25984/mypkg I/fmod: SystemI::startDriver : Output requires a sample rate of 48000Hz, resampling will occur.
2021-07-01 11:32:45.328 25729-25984/mypkg I/fmod: Thread::initThread : Init FMOD mixer thread. Affinity: 0x8000000000000001, Priority: 0xFFFF7FFA, Stack Size: 81920, Semaphore: Yes, Sleep Time: 0, Looping: Yes.
2021-07-01 11:32:45.328 25729-25984/mypkg D/AAudio: AAudioStream_requestStart(s#9) called --------------
2021-07-01 11:32:45.328 25729-25984/mypkg D/AAudioStream: setState(s#9) from 2 to 3
2021-07-01 11:32:45.430 25729-25984/mypkg D/mypkg: PlayerBase::start() from IPlayer
2021-07-01 11:32:45.430 25729-25984/mypkg D/AAudio: AAudioStream_requestStart(s#9) returned 0 ---------
2021-07-01 11:32:45.431 25729-26330/mypkg D/AudioStreamInternalPlay_Client: callbackLoop() entering >>>>>>>>>>>>>>>
2021-07-01 11:32:45.431 25729-26330/mypkg D/AudioStreamInternal_Client: onEventFromServer - got AAUDIO_SERVICE_EVENT_STARTED
2021-07-01 11:32:45.431 25729-26330/mypkg D/AAudioStream: setState(s#9) from 3 to 4

Hi sviudes,

Which device are you seeing this on?

So the setState calls are AAudio internal calls, so they would be based on the OS implementation. The already closing message is most likely from the call - setState(s#5) from 11 to 11 - failing to change the state.

In the log, you can see a series of :
AAudioStream_close
AAudioStreamBuilder_openStream
AAudioStream_close
AAudioStreamBuilder_openStream
AAudioStream_close
AAudioStreamBuilder_openStream
AAudioStream_requestStart
And that is repeated. The first calls to open/close stream, FMOD uses to gather information about the audio device. The last call before request start is to open the audio device stream before starting it for device playback.

The reason it is repeated happens either because the stream encounters an error (eg bluetooth headphones disconnected while playing out of them) or FMOD detects a change with the headphone jack (there is a separate check for this as some android devices do not invalidate the stream when unplugging headphones).

If the device has to restart the audio output device, that would lead to a brief stutter. So as long as its happening for a valid reason (eg bluetooth headphones connecting/disconnecting), its reasonable to expect this. Can you check for any cause that might be along these lines?

I’m using a Google Pixel 5. While testing no changes were done (no headphones or bluetooth devices connected / disconnected). If I can help by testing anything on my Pixel 5, just tell me and I’ll do it.

Hmm, that is unusual. We haven’t seen any issues previously with any pixel devices - typically we have encountered unusual stuttering on other handsets and have been unable to reproduce anything similar on Pixel devices. Will have to run through a few things to narrow it down:

  • Are you changing the dsp buffer size or count?
  • If you run oboe tester, can you reproduce this issue with any combination of settings?
  • Is this android 11?
  • If you change the output mode to openSL, do you see the same issue?

- Are you changing the dsp buffer size or count?
No, I’m using defaults. I see that buffer length is 512 and there are 4 buffers.

- If you run oboe tester, can you reproduce this issue with any combination of settings?
With default settings, I get “setState(n) tried to set to 11 but already CLOSING” error message only when I touch “open” button.

- Is this android 11?
Yes

- If you change the output mode to openSL, do you see the same issue?
It happens when using FMOD_OUTPUTTYPE_AUTODETECT or FMOD_OUTPUTTYPE_AAUDIO.
Using OpenSL I don’t see the same issue! Using AudioTrack works fine too.

Please let me know if you want more testing. Thank you.

So a fallback option would be to set the output mode to OpenSL - this is the output mode that would have been used for 1.10. Normally with AAudio issues, they have been bugs with the handset OS level. So there are some extra things to test:

  • Do the audio glitches happen if wifi is disabled?
  • How often do the audio glitches happen with FMOD?
  • With the oboe tester, can you run the auto glitch test and send us the log output? Ideally needs to be run in a quiet environment as it uses the phones microphone to check.

Sorry for the late reply.

Yes, the glitches happen if WiFi is disabled. The glitches happens so frequently.

Here is the auto glitch test result:

=== STARTED at Tue Jul 13 15:35:40 GMT+02:00 2021
AutoGlitch
OboeTester (47) v 1.6.5, Oboe v 1.6.0
Google, Pixel 5, redfin
RQ3A.210605.005
========================== #1
Requested:
INP-M, ID = 0, SR = 0, Perf = LL, EX, ch = 0/1
OUT-M, ID = 0, SR = 0, Perf = LL, EX, ch = 0/2
Actual:
INP-M, ID = 20, SR = 48000, Perf = LL, EX, ch = 0/1
OUT-M, ID = 4, SR = 48000, Perf = LL, EX, ch = 0/2
Result:
#glitches = 0, #resets = 5, max no glitch = 10.008 secs
SNR = 47,3 db, #locked = 465023, xruns = 0/0, PASS
========================== #2
Requested:
INP-M, ID = 0, SR = 0, Perf = LL, EX, ch = 0/2
OUT-M, ID = 0, SR = 0, Perf = LL, EX, ch = 0/1
Actual:
INP-M, ID = 20, SR = 48000, Perf = LL, EX, ch = 0/2
OUT-M, ID = 4, SR = 48000, Perf = LL, EX, ch = 0/1
Result:
#glitches = 0, #resets = 6, max no glitch = 9.991 secs
SNR = 41,1 db, #locked = 464291, xruns = 0/0, PASS
========================== #3
Requested:
INP-M, ID = 0, SR = 48000, Perf = LL, SH, ch = 0/1
OUT-M, ID = 0, SR = 48000, Perf = LL, SH, ch = 0/2
Actual:
INP-M, ID = 20, SR = 48000, Perf = LL, SH, ch = 0/1
OUT-M, ID = 4, SR = 48000, Perf = LL, SH, ch = 0/2
Result:
#glitches = 0, #resets = 7, max no glitch = 9.997 secs
SNR = 66,6 db, #locked = 464159, xruns = 72/0, PASS
========================== #4
Requested:
INP-M, ID = 0, SR = 48000, Perf = LL, SH, ch = 0/2
OUT-M, ID = 0, SR = 48000, Perf = LL, SH, ch = 0/1
Actual:
INP-M, ID = 20, SR = 48000, Perf = LL, SH, ch = 0/2
OUT-M, ID = 4, SR = 48000, Perf = LL, SH, ch = 0/1
Result:
#glitches = 0, #resets = 8, max no glitch = 9.949 secs
SNR = 42,6 db, #locked = 461855, xruns = 70/0, PASS
========================== #5
Requested:
INP-M, ID = 0, SR = 44100, Perf = LL, SH, ch = 0/1
OUT-M, ID = 0, SR = 44100, Perf = LL, SH, ch = 0/2
Actual:
INP-L, ID = 20, SR = 44100, Perf = NO, SH, ch = 0/1
OUT-L, ID = 4, SR = 44100, Perf = NO, SH, ch = 0/2
Result:
#glitches = 0, #resets = 9, max no glitch = 9.951 secs
SNR = 57,0 db, #locked = 395534, xruns = 0/0, PASS
========================== #6
Requested:
INP-M, ID = 0, SR = 44100, Perf = LL, SH, ch = 0/2
OUT-M, ID = 0, SR = 44100, Perf = LL, SH, ch = 0/1
Actual:
INP-L, ID = 20, SR = 44100, Perf = NO, SH, ch = 0/2
OUT-L, ID = 4, SR = 44100, Perf = NO, SH, ch = 0/1
Result:
#glitches = 0, #resets = 10, max no glitch = 10.023 secs
SNR = 40,1 db, #locked = 403775, xruns = 0/0, PASS
========================== #7
Requested:
INP-M, ID = 0, SR = 16000, Perf = LL, SH, ch = 0/1
OUT-M, ID = 0, SR = 16000, Perf = LL, SH, ch = 0/2
Actual:
INP-L, ID = 20, SR = 16000, Perf = NO, SH, ch = 0/1
OUT-L, ID = 4, SR = 16000, Perf = NO, SH, ch = 0/2
Result:
#glitches = 0, #resets = 11, max no glitch = 10.006 secs
SNR = 74,6 db, #locked = 139907, xruns = 0/0, PASS
========================== #8
Requested:
INP-M, ID = 0, SR = 16000, Perf = LL, SH, ch = 0/2
OUT-M, ID = 0, SR = 16000, Perf = LL, SH, ch = 0/1
Actual:
INP-L, ID = 20, SR = 16000, Perf = NO, SH, ch = 0/2
OUT-L, ID = 4, SR = 16000, Perf = NO, SH, ch = 0/1
Result:
#glitches = 1, #resets = 12, max no glitch = 8.568 secs
SNR = 43,7 db, #locked = 138550, xruns = 0/0, PASS
========================== #9
Requested:
INP-M, ID = 0, SR = 48000, Perf = NO, SH, ch = 0/1
OUT-M, ID = 0, SR = 48000, Perf = NO, SH, ch = 0/2
Actual:
INP-L, ID = 20, SR = 48000, Perf = NO, SH, ch = 0/1
OUT-L, ID = 4, SR = 48000, Perf = NO, SH, ch = 0/2
Result:
#glitches = 1, #resets = 13, max no glitch = 8.652 secs
SNR = 37,8 db, #locked = 417854, xruns = 0/0, PASS
========================== #10
Requested:
INP-M, ID = 0, SR = 48000, Perf = NO, SH, ch = 0/2
OUT-M, ID = 0, SR = 48000, Perf = NO, SH, ch = 0/1
Actual:
INP-L, ID = 20, SR = 48000, Perf = NO, SH, ch = 0/2
OUT-L, ID = 4, SR = 48000, Perf = NO, SH, ch = 0/1
Result:
#glitches = 1, #resets = 14, max no glitch = 8.614 secs
SNR = 36,1 db, #locked = 416212, xruns = 0/0, PASS
========================== #11
Requested:
INP-M, ID = 0, SR = 44100, Perf = NO, SH, ch = 0/1
OUT-M, ID = 0, SR = 44100,

Perf = NO, SH, ch = 0/2
Actual:
INP-L, ID = 20, SR = 44100, Perf = NO, SH, ch = 0/1
OUT-L, ID = 4, SR = 44100, Perf = NO, SH, ch = 0/2
Result:
#glitches = 0, #resets = 15, max no glitch = 9.943 secs
SNR = 43,8 db, #locked = 378688, xruns = 0/0, PASS
========================== #12
Requested:
INP-M, ID = 0, SR = 44100, Perf = NO, SH, ch = 0/2
OUT-M, ID = 0, SR = 44100, Perf = NO, SH, ch = 0/1
Actual:
INP-L, ID = 20, SR = 44100, Perf = NO, SH, ch = 0/2
OUT-L, ID = 4, SR = 44100, Perf = NO, SH, ch = 0/1
Result:
#glitches = 473, #resets = 16, max no glitch = 3.6 secs
SNR = 36,2 db, #locked = 356537, xruns = 0/0, FAIL !!!, glitch
========================== #13
Requested:
INP-M, ID = 0, SR = 16000, Perf = NO, SH, ch = 0/1
OUT-M, ID = 0, SR = 16000, Perf = NO, SH, ch = 0/2
Actual:
INP-L, ID = 20, SR = 16000, Perf = NO, SH, ch = 0/1
OUT-L, ID = 4, SR = 16000, Perf = NO, SH, ch = 0/2
Result:
#glitches = 0, #resets = 17, max no glitch = 10.002 secs
SNR = 39,6 db, #locked = 134821, xruns = 0/0, PASS
========================== #14
Requested:
INP-M, ID = 0, SR = 16000, Perf = NO, SH, ch = 0/2
OUT-M, ID = 0, SR = 16000, Perf = NO, SH, ch = 0/1
Actual:
INP-L, ID = 20, SR = 16000, Perf = NO, SH, ch = 0/2
OUT-L, ID = 4, SR = 16000, Perf = NO, SH, ch = 0/1
Result:
#glitches = 0, #resets = 18, max no glitch = 9.952 secs
SNR = 44,3 db, #locked = 134553, xruns = 0/0, PASS
Tests finished without exception.

==== SUMMARY ========

These tests FAILED:
Summary
------ #12
INP-L, ID = 20, SR = 44100, Perf = NO, SH, ch = 0/2
OUT-L, ID = 4, SR = 44100, Perf = NO, SH, ch = 0/1
#glitches = 473, #resets = 16, max no glitch = 3.6 secs
SNR = 36,2 db, #locked = 356537, xruns = 0/0, FAIL !!!, glitch


13 passed. 1 failed. 0 skipped.
== FINISHED at Tue Jul 13 15:38:13 GMT+02:00 2021

The xruns in 2 of the glitch tests are slightly concerning, but we don’t initialise in the same way as that test does, so we shouldn’t encounter the same issue.

One possibility is that the timeout restart is somehow being triggered. That should only happen in the case where there is over a second delay between mixes, but it’s worth considering.

I’ve added some additional logging that will be included in the next fmod release - if you try running again with that version, once it is released, using the logging version of FMOD and send us the log, hopefully we can get to the bottom of what is happening.

Thank you very much. When it’s released, I’ll capture the logs and I’ll send them to you. Will it be the version 2.01.11?

Yep, 2.01.11