From 03a44e5a6b6aa452143948e71c364d11f6b5992e Mon Sep 17 00:00:00 2001 From: Artem Dyomin Date: Thu, 2 Mar 2023 20:54:15 +0100 Subject: Fix audiosink issues on darwin Fixed problems: - Fix sound stucks on multiple resets/starts of QAudioSink. It was possible to reproduce on playback position change in mediaplayer. - Improve audiosink stop (reduce waiting time). The optimization is based on the fact that it's possible to call AudioOutputUnitStop from the thread where it was started. - add some auto test + imrove errors logging in tests. Tests work fine locally but still need some tune on CI Task-number: QTBUG-111567 Change-Id: I0eb5c32af4c12dfc0694ee8f5967b4960a0b4ab2 Reviewed-by: Doris Verria (cherry picked from commit 919b3d308b711c0b267808c783327f2c95233428) Reviewed-by: Lars Knoll --- src/multimedia/darwin/qdarwinaudiosink.mm | 65 +++++++--- src/multimedia/darwin/qdarwinaudiosink_p.h | 1 + .../auto/integration/qaudiosink/tst_qaudiosink.cpp | 144 +++++++++++++++++---- 3 files changed, 166 insertions(+), 44 deletions(-) diff --git a/src/multimedia/darwin/qdarwinaudiosink.mm b/src/multimedia/darwin/qdarwinaudiosink.mm index 340472671..f29b642c2 100644 --- a/src/multimedia/darwin/qdarwinaudiosink.mm +++ b/src/multimedia/darwin/qdarwinaudiosink.mm @@ -104,7 +104,7 @@ int QDarwinAudioSinkBuffer::available() const void QDarwinAudioSinkBuffer::reset() { m_buffer->reset(); - m_device = 0; + m_device = nullptr; m_deviceError = false; } @@ -582,7 +582,7 @@ bool QDarwinAudioSink::open() void QDarwinAudioSink::close() { if (m_audioUnit != 0) { - AudioOutputUnitStop(m_audioUnit); + audioDeviceStop(); AudioUnitUninitialize(m_audioUnit); AudioComponentInstanceDispose(m_audioUnit); } @@ -592,32 +592,61 @@ void QDarwinAudioSink::close() void QDarwinAudioSink::audioThreadStart() { - QMutexLocker lock(&m_mutex); startTimers(); - m_audioThreadState.storeRelaxed(Running); - AudioOutputUnitStart(m_audioUnit); + audioDeviceStart(); } void QDarwinAudioSink::audioThreadStop() { - QMutexLocker lock(&m_mutex); stopTimers(); - if (m_audioThreadState.testAndSetAcquire(Running, Stopped)) - m_threadFinished.wait(&m_mutex, 500); + + // It's common practice to call AudioOutputUnitStop + // from the thread where the audio output was started, + // so we don't have to rely on the stops inside renderCallback. + audioDeviceStop(); } void QDarwinAudioSink::audioThreadDrain() { - QMutexLocker lock(&m_mutex); stopTimers(); - if (m_audioThreadState.testAndSetAcquire(Running, Draining)) - m_threadFinished.wait(&m_mutex, 500); + + QMutexLocker lock(&m_mutex); + + if (m_audioThreadState.testAndSetAcquire(Running, Draining)) { + constexpr int MaxDrainWaitingTime = 500; + + m_threadFinished.wait(&m_mutex, MaxDrainWaitingTime); + + if (m_audioThreadState.fetchAndStoreRelaxed(Stopped) != Stopped) { + qWarning() << "Couldn't wait for draining; force stop"; + + AudioOutputUnitStop(m_audioUnit); + } + } +} + +void QDarwinAudioSink::audioDeviceStart() +{ + QMutexLocker lock(&m_mutex); + + const auto state = m_audioThreadState.loadAcquire(); + if (state == Stopped) { + m_audioThreadState.storeRelaxed(Running); + AudioOutputUnitStart(m_audioUnit); + } else { + qWarning() << "Unexpected state on audio device start:" << state; + } } void QDarwinAudioSink::audioDeviceStop() { - AudioOutputUnitStop(m_audioUnit); - m_audioThreadState.storeRelaxed(Stopped); + { + QMutexLocker lock(&m_mutex); + + AudioOutputUnitStop(m_audioUnit); + m_audioThreadState.storeRelaxed(Stopped); + } + m_threadFinished.wakeOne(); } @@ -626,10 +655,11 @@ void QDarwinAudioSink::audioDeviceIdle() if (m_stateCode != QAudio::ActiveState) return; - audioDeviceStop(); - m_errorCode = QAudio::UnderrunError; m_stateCode = QAudio::IdleState; + + audioDeviceStop(); + QMetaObject::invokeMethod(this, "deviceStopped", Qt::QueuedConnection); } @@ -638,10 +668,11 @@ void QDarwinAudioSink::audioDeviceError() if (m_stateCode != QAudio::ActiveState) return; - audioDeviceStop(); - m_errorCode = QAudio::IOError; m_stateCode = QAudio::StoppedState; + + audioDeviceStop(); + QMetaObject::invokeMethod(this, "deviceStopped", Qt::QueuedConnection); } diff --git a/src/multimedia/darwin/qdarwinaudiosink_p.h b/src/multimedia/darwin/qdarwinaudiosink_p.h index 4d528de79..5d5af2d68 100644 --- a/src/multimedia/darwin/qdarwinaudiosink_p.h +++ b/src/multimedia/darwin/qdarwinaudiosink_p.h @@ -133,6 +133,7 @@ private: void audioThreadStart(); void audioThreadStop(); void audioThreadDrain(); + void audioDeviceStart(); void audioDeviceStop(); void audioDeviceIdle(); void audioDeviceError(); diff --git a/tests/auto/integration/qaudiosink/tst_qaudiosink.cpp b/tests/auto/integration/qaudiosink/tst_qaudiosink.cpp index e3c869f02..a4416daa9 100644 --- a/tests/auto/integration/qaudiosink/tst_qaudiosink.cpp +++ b/tests/auto/integration/qaudiosink/tst_qaudiosink.cpp @@ -50,6 +50,8 @@ private slots: void pushSuspendResume_data(){generate_audiofile_testrows();} void pushSuspendResume(); + void pushResetResume(); + void pushUnderrun_data(){generate_audiofile_testrows();} void pushUnderrun(); @@ -59,8 +61,9 @@ private slots: private: using FilePtr = QSharedPointer; - QString formatToFileName(const QAudioFormat &format); + static QString formatToFileName(const QAudioFormat &format); void createSineWaveData(const QAudioFormat &format, qint64 length, int sampleRate = 440); + static QString dumpStateSignalSpy(const QSignalSpy &stateSignalSpy); void generate_audiofile_testrows(); @@ -130,6 +133,19 @@ void tst_QAudioSink::createSineWaveData(const QAudioFormat &format, qint64 lengt Q_ASSERT(m_buffer->open(QIODevice::ReadOnly)); } +QString tst_QAudioSink::dumpStateSignalSpy(const QSignalSpy& stateSignalSpy) { + QString result = "["; + bool first = true; + for (auto& params : stateSignalSpy) + { + if (!std::exchange(first, false)) + result += ','; + result += QString::number(params.front().value()); + } + result.append(']'); + return result; +} + void tst_QAudioSink::generate_audiofile_testrows() { QTest::addColumn("audioFile"); @@ -381,7 +397,10 @@ void tst_QAudioSink::pull() // Check that QAudioSink immediately transitions to ActiveState QTRY_VERIFY2((stateSignal.size() == 1), - QString("didn't emit signal on start(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit signal on start(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::ActiveState), "didn't transition to ActiveState after start()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after start()"); stateSignal.clear(); @@ -393,7 +412,7 @@ void tst_QAudioSink::pull() // Wait until playback finishes QTRY_VERIFY2(audioFile->atEnd(), "didn't play to EOF"); QTRY_VERIFY(stateSignal.size() > 0); - QCOMPARE(qvariant_cast(stateSignal.last().at(0)), QAudio::IdleState); + QTRY_COMPARE(qvariant_cast(stateSignal.last().at(0)), QAudio::IdleState); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transitions to IdleState when at EOF"); stateSignal.clear(); @@ -402,7 +421,10 @@ void tst_QAudioSink::pull() audioOutput.stop(); QTest::qWait(40); QVERIFY2((stateSignal.size() == 1), - QString("didn't emit StoppedState signal after stop(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit StoppedState signal after stop(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::StoppedState), "didn't transitions to StoppedState after stop()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error() is not QAudio::NoError after stop()"); @@ -433,11 +455,15 @@ void tst_QAudioSink::pullSuspendResume() audioOutput.start(audioFile.data()); // Check that QAudioSink immediately transitions to ActiveState QTRY_VERIFY2((stateSignal.size() == 1), - QString("didn't emit signal on start(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit signal on start(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::ActiveState), "didn't transition to ActiveState after start()"); - QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after start()"); - stateSignal.clear(); + QVERIFY2((audioOutput.error() == QAudio::NoError), + "error state is not equal to QAudio::NoError after start()"); + stateSignal.clear(); // Wait for half of clip to play QTest::qWait(500); @@ -446,7 +472,7 @@ void tst_QAudioSink::pullSuspendResume() QTRY_VERIFY2((stateSignal.size() == 1), QString("didn't emit SuspendedState signal after suspend(), got %1 signals instead") - .arg(stateSignal.size()).toUtf8().constData()); + .arg(dumpStateSignalSpy(stateSignal)).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::SuspendedState), "didn't transition to SuspendedState after suspend()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after suspend()"); stateSignal.clear(); @@ -462,7 +488,10 @@ void tst_QAudioSink::pullSuspendResume() // Check that QAudioSink immediately transitions to ActiveState QVERIFY2((stateSignal.size() == 1), - QString("didn't emit signal after resume(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit signal after resume(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::ActiveState), "didn't transition to ActiveState after resume()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after resume()"); stateSignal.clear(); @@ -470,7 +499,7 @@ void tst_QAudioSink::pullSuspendResume() // Wait until playback finishes QTRY_VERIFY2(audioFile->atEnd(), "didn't play to EOF"); QTRY_VERIFY(stateSignal.size() > 0); - QCOMPARE(qvariant_cast(stateSignal.last().at(0)), QAudio::IdleState); + QTRY_COMPARE(qvariant_cast(stateSignal.last().at(0)), QAudio::IdleState); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transitions to IdleState when at EOF"); stateSignal.clear(); @@ -479,7 +508,10 @@ void tst_QAudioSink::pullSuspendResume() audioOutput.stop(); QTest::qWait(40); QVERIFY2((stateSignal.size() == 1), - QString("didn't emit StoppedState signal after stop(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit StoppedState signal after stop(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::StoppedState), "didn't transitions to StoppedState after stop()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error() is not QAudio::NoError after stop()"); @@ -576,7 +608,10 @@ void tst_QAudioSink::push() // Check that QAudioSink immediately transitions to IdleState QTRY_VERIFY2((stateSignal.size() == 1), - QString("didn't emit signal on start(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit signal on start(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transition to IdleState after start()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after start()"); stateSignal.clear(); @@ -599,7 +634,7 @@ void tst_QAudioSink::push() // Check for transition to ActiveState when data is provided QVERIFY2((stateSignal.size() == 1), QString("didn't emit signal after receiving data, got %1 signals instead") - .arg(stateSignal.size()).toUtf8().constData()); + .arg(dumpStateSignalSpy(stateSignal)).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::ActiveState), "didn't transition to ActiveState after receiving data"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after receiving data"); firstBuffer = false; @@ -613,7 +648,7 @@ void tst_QAudioSink::push() QVERIFY2(audioFile->atEnd(), "didn't play to EOF"); QTRY_VERIFY(audioOutput.state() == QAudio::IdleState); QTRY_VERIFY(stateSignal.size() > 0); - QCOMPARE(qvariant_cast(stateSignal.last().at(0)), QAudio::IdleState); + QTRY_COMPARE(qvariant_cast(stateSignal.last().at(0)), QAudio::IdleState); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transitions to IdleState when at EOF"); stateSignal.clear(); @@ -622,7 +657,7 @@ void tst_QAudioSink::push() audioOutput.stop(); QTest::qWait(40); QVERIFY2((stateSignal.size() == 1), - QString("didn't emit StoppedState signal after stop(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit StoppedState signal after stop(), got %1 signals instead").arg(dumpStateSignalSpy(stateSignal)).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::StoppedState), "didn't transitions to StoppedState after stop()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error() is not QAudio::NoError after stop()"); @@ -655,7 +690,10 @@ void tst_QAudioSink::pushSuspendResume() // Check that QAudioSink immediately transitions to IdleState QTRY_VERIFY2((stateSignal.size() == 1), - QString("didn't emit signal on start(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit signal on start(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transition to IdleState after start()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after start()"); stateSignal.clear(); @@ -679,7 +717,7 @@ void tst_QAudioSink::pushSuspendResume() // Check for transition to ActiveState when data is provided QVERIFY2((stateSignal.size() == 1), QString("didn't emit signal after receiving data, got %1 signals instead") - .arg(stateSignal.size()).toUtf8().constData()); + .arg(dumpStateSignalSpy(stateSignal)).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::ActiveState), "didn't transition to ActiveState after receiving data"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after receiving data"); firstBuffer = false; @@ -693,7 +731,7 @@ void tst_QAudioSink::pushSuspendResume() QTRY_VERIFY2((stateSignal.size() == 1), QString("didn't emit SuspendedState signal after suspend(), got %1 signals instead") - .arg(stateSignal.size()).toUtf8().constData()); + .arg(dumpStateSignalSpy(stateSignal)).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::SuspendedState), "didn't transition to SuspendedState after suspend()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after suspend()"); stateSignal.clear(); @@ -713,7 +751,7 @@ void tst_QAudioSink::pushSuspendResume() // Check that QAudioSink immediately transitions to IdleState QVERIFY2((stateSignal.size() == 1), - QString("didn't emit signal after resume(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit signal after resume(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transition to IdleState after resume()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after resume()"); stateSignal.clear(); @@ -732,7 +770,7 @@ void tst_QAudioSink::pushSuspendResume() QVERIFY2(audioFile->atEnd(), "didn't play to EOF"); QTRY_VERIFY(stateSignal.size() > 0); - QCOMPARE(qvariant_cast(stateSignal.last().at(0)), QAudio::IdleState); + QTRY_COMPARE(qvariant_cast(stateSignal.last().at(0)), QAudio::IdleState); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transitions to IdleState when at EOF"); stateSignal.clear(); @@ -741,7 +779,10 @@ void tst_QAudioSink::pushSuspendResume() audioOutput.stop(); QTest::qWait(40); QVERIFY2((stateSignal.size() == 1), - QString("didn't emit StoppedState signal after stop(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit StoppedState signal after stop(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::StoppedState), "didn't transitions to StoppedState after stop()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error() is not QAudio::NoError after stop()"); @@ -750,6 +791,46 @@ void tst_QAudioSink::pushSuspendResume() audioFile->close(); } +void tst_QAudioSink::pushResetResume() +{ + auto audioFile = audioFiles.at(0); + auto audioFormat = testFormats.at(0); + + QAudioSink audioOutput(audioFormat, this); + + audioOutput.setBufferSize(8192); + audioOutput.setVolume(0.1f); + + audioFile->close(); + audioFile->open(QIODevice::ReadOnly); + audioFile->seek(QWaveDecoder::headerLength()); + + QPointer feed = audioOutput.start(); + + QTest::qWait(20); + + auto buffer = audioFile->read(audioOutput.bytesFree()); + feed->write(buffer); + + QTest::qWait(20); + QTRY_COMPARE(audioOutput.state(), QAudio::ActiveState); + + audioOutput.reset(); + QCOMPARE(audioOutput.state(), QAudio::StoppedState); + QCOMPARE(audioOutput.error(), QAudio::NoError); + + const auto processedUSecs = audioOutput.processedUSecs(); + + audioOutput.resume(); + QTest::qWait(40); + + // Nothing changed if resume after reset + QCOMPARE(audioOutput.state(), QAudio::StoppedState); + QCOMPARE(audioOutput.error(), QAudio::NoError); + + QCOMPARE(audioOutput.processedUSecs(), processedUSecs); +} + void tst_QAudioSink::pushUnderrun() { QFETCH(FilePtr, audioFile); @@ -774,7 +855,10 @@ void tst_QAudioSink::pushUnderrun() // Check that QAudioSink immediately transitions to IdleState QTRY_VERIFY2((stateSignal.size() == 1), - QString("didn't emit signal on start(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit signal on start(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transition to IdleState after start()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after start()"); stateSignal.clear(); @@ -799,7 +883,7 @@ void tst_QAudioSink::pushUnderrun() // Check for transition to ActiveState when data is provided QVERIFY2((stateSignal.size() == 1), QString("didn't emit signal after receiving data, got %1 signals instead") - .arg(stateSignal.size()).toUtf8().constData()); + .arg(dumpStateSignalSpy(stateSignal)).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::ActiveState), "didn't transition to ActiveState after receiving data"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after receiving data"); firstBuffer = false; @@ -814,7 +898,7 @@ void tst_QAudioSink::pushUnderrun() QVERIFY2((stateSignal.size() == 1), QString("didn't emit IdleState signal after suspend(), got %1 signals instead") - .arg(stateSignal.size()).toUtf8().constData()); + .arg(dumpStateSignalSpy(stateSignal)).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transition to IdleState, no data"); QVERIFY2((audioOutput.error() == QAudio::UnderrunError), "error state is not equal to QAudio::UnderrunError, no data"); stateSignal.clear(); @@ -829,7 +913,7 @@ void tst_QAudioSink::pushUnderrun() // Check for transition to ActiveState when data is provided QVERIFY2((stateSignal.size() == 1), QString("didn't emit signal after receiving data, got %1 signals instead") - .arg(stateSignal.size()).toUtf8().constData()); + .arg(dumpStateSignalSpy(stateSignal)).toUtf8().constData()); QVERIFY2((audioOutput.state() == QAudio::ActiveState), "didn't transition to ActiveState after receiving data"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error state is not equal to QAudio::NoError after receiving data"); firstBuffer = false; @@ -842,7 +926,10 @@ void tst_QAudioSink::pushUnderrun() // Wait until playback finishes QVERIFY2(audioFile->atEnd(), "didn't play to EOF"); QTRY_VERIFY2((stateSignal.size() == 1), - QString("didn't emit IdleState signal when at EOF, got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit IdleState signal when at EOF, got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::IdleState), "didn't transitions to IdleState when at EOF"); stateSignal.clear(); @@ -851,7 +938,10 @@ void tst_QAudioSink::pushUnderrun() audioOutput.stop(); QTest::qWait(40); QVERIFY2((stateSignal.size() == 1), - QString("didn't emit StoppedState signal after stop(), got %1 signals instead").arg(stateSignal.size()).toUtf8().constData()); + QString("didn't emit StoppedState signal after stop(), got %1 signals instead") + .arg(dumpStateSignalSpy(stateSignal)) + .toUtf8() + .constData()); QVERIFY2((audioOutput.state() == QAudio::StoppedState), "didn't transitions to StoppedState after stop()"); QVERIFY2((audioOutput.error() == QAudio::NoError), "error() is not QAudio::NoError after stop()"); -- cgit v1.2.3