Fix audiosink issues on darwin6.4

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 <doris.verria@qt.io>
(cherry picked from commit 919b3d308b711c0b267808c783327f2c95233428)
Reviewed-by: Lars Knoll <lars@knoll.priv.no>

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<QFile>;
 
-    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<QAudio::State>());
+    }
+    result.append(']');
+    return result;
+}
+
 void tst_QAudioSink::generate_audiofile_testrows()
 {
     QTest::addColumn<FilePtr>("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<QAudio::State>(stateSignal.last().at(0)), QAudio::IdleState);
+    QTRY_COMPARE(qvariant_cast<QAudio::State>(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<QAudio::State>(stateSignal.last().at(0)), QAudio::IdleState);
+    QTRY_COMPARE(qvariant_cast<QAudio::State>(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<QAudio::State>(stateSignal.last().at(0)), QAudio::IdleState);
+    QTRY_COMPARE(qvariant_cast<QAudio::State>(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<QAudio::State>(stateSignal.last().at(0)), QAudio::IdleState);
+    QTRY_COMPARE(qvariant_cast<QAudio::State>(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<QIODevice> 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()");