Inconsistent playback of mic push/release sounds.

[bmmcginty]

Description

I have sounds enabled for key down and key up of my mic. If you press and release the PTT key, waiting even as much as 1 second between press/release and release/re-press, the key up/key down sound will eventually "miss a beat", or fail to sound. This can happen multiple times consecutively, and can take up to 30 seconds to show up. It can also happen when keying or unkeying, which can make it difficult to know when I'm transmitting for certain. I amusing the default mic up/down sounds that are provided with the client (on.ogg and off.ogg). I am using the PTT lock setting, threshold 300 MS. This issue occurs regardless of that lock setting, though, and i have tested same. Possibly related to #6359.

Steps to reproduce

Press the PTT key, hold for 1/4 second, and release. Wait 1/4 second, and repeat.

Mumble version

1.5.634

Mumble component

Client

OS

Windows

Reproducible?

Yes

Additional information

No response

Relevant log output

No response

Screenshots

No response

[Hartmnt]

This sounds exactly like #6359 Are your sound cue files .wav files? If so, try to convert it to another format e.g. .ogg

[bmmcginty]

These _are .ogg files; they are the default files provided upon install.

[Hartmnt]

These _are .ogg files; they are the default files provided upon install.

Oof, well then solving this is going to be difficult, because I can not reproduce this with the default sounds.

[tspivey]

I also have this issue.

I might've found it. I'm not too familiar with QT or C++, so could be missing something. Starting from AudioInput::encodeAudioFrame:

1. When the cue stops, its buffer is invalidated and freed in AudioOutput::handleInvalidatedBuffer.
2. The next time the audio cue is played, AudioInput::encodeAudioFrame calls ao->removeToken(m_activeAudioCue);.
3. That function calls AudioOutput::removeBuffer on the buffer, which emits bufferInvalidated.
4. The new sample is played in AudioInput::encodeAudioFrame and added to the playback queue.
5. The code responsible for bufferInvalidated runs, and if the new sample gets the address of the old one, removes it.

[Hartmnt]

5. The code responsible for bufferInvalidated runs, and if the new sample gets the address of the old one, removes it.

Oh good lord... So we have two handleInvalidateBuffercalls with the same address racing against the system specific memory allocator which is re-allocating the address after the first but before the second call to handleInvalidateBuffer? That sounds possible but extremely hard to trigger. Especially since OP stated you could have a delay of up to a second and still trigger the problem sometimes. I would imagine the queued calles to handleInvalidateBuffer would finish relatively quickly.

But this is at least a possible lead.

[tspivey]

This isn't hard to trigger at all. I added some debugging and got it on the first try.

<W>2024-10-23 10:17:01.284 Playing :/on.ogg, ptr 0x25c853fdaa0
<W>2024-10-23 10:17:01.383 Invalidated, erasing 0x25c853fdaa0
<W>2024-10-23 10:17:02.023 Removing token, m_buffer=0x25c853fdaa0
<W>2024-10-23 10:17:02.024 Playing :/off.ogg, ptr 0x25c853fdaa0
<W>2024-10-23 10:17:02.026 Invalidated, erasing 0x25c853fdaa0

And this one after a few tries (the first line is when on.ogg fininshes playing):

<W>2024-10-23 10:23:22.823 Invalidated, erasing 0x1a04d9af7d0
<W>2024-10-23 10:23:24.353 Removing token, m_buffer=0x1a04d9af7d0
<W>2024-10-23 10:23:24.354 Playing :/off.ogg, ptr 0x1a04d9af7d0
<W>2024-10-23 10:23:24.356 Invalidated, erasing 0x1a04d9af7d0

Looking at the addresses and timestamps, this seems to be what's happening.

[Hartmnt]

@tspivey Nice work confirming this!

Indeed, it makes sense now. The time between the calls is irrelevant because we keep the pointer in AudioInput::m_activeAudioCue. This also perfectly explains, why I can not reproduce this: It entirely depends on the system memory allocator reusing the same address in consecutive calls and Linux (or the specific std implementation I am using) seems to be unaffected by this.

So now we just have to figure out how to fix this :smiling_face_with_tear:

[Hartmnt]

@tspivey I have come up with something that should reduce the number of times this problem occurs: https://github.com/hartmnt/mumble/commit/c460e8ca4fb6425fdc128d76b4a4080759a26dd4

However, this will still race against a sample that is just finishing playing after the check was performed. So I don't consider this a proper fix for this problem. But I wanted to share this anyway for now.