Skip to content
This repository has been archived by the owner on Jan 16, 2024. It is now read-only.

There is some ERROR log message when wake up alexa when it paly music #129

Closed
sundq opened this issue Sep 1, 2017 · 2 comments
Closed

Comments

@sundq
Copy link

sundq commented Sep 1, 2017

When I ask alexa play music, before the music finish , I wake up alexa again and ask what's your name,The answer play finished and then music begin paly, when the music finished, the app will emit ERROR log message as follows:

2017-09-01 07:44:16.409 [ 4] E AudioPlayer:onFocusChangedFailed:reason=timedout,cause=executorTimeout
2017-09-01 07:44:16.409 [ 5] E AudioPlayer:onFocusChangedFailed:reason=timedout,cause=notFinished

and I check the code in AudioPlayer.cpp at line 584, the code is:

case FocusState::NONE:
            if (PlayerActivity::STOPPED == m_currentActivity) {
                break;
            }
            m_audioItems.clear();

            std::unique_lock<std::mutex> lock(m_playbackMutex);
            m_playbackFinished = false;

            /* Note: MediaPlayer::stop() calls onPlaybackFinished() synchronously, which results in a mutex deadlock
             * here if the lock his held for the executeStop() call.  Releasing the lock temporarily avoids the
             * deadlock.  If MediaPlayer is changed in the future to asynchronously call onPlaybackFinished (and
             * documented as such in MediaPlayerInterface), the unlock/lock calls can be removed. */
            lock.unlock();
            ACSDK_DEBUG9(LX("executeOnFocusChanged").d("action", "executeStop"));
            executeStop();
            lock.lock();

            if (!m_playbackConditionVariable.wait_for(lock, TIMEOUT, [this] { return m_playbackFinished; })) {
                ACSDK_ERROR(LX("onFocusChangedFailed").d("reason", "timedout").d("cause", "notFinished"));
            }
            break;

These code is called by onPlaybackFinished observer method, but onPlaybackFinished method will set m_playbackFinished to true then will call onFocuseChanged, so I think you will never wait_for the m_playbackFinished is true, because you have set m_playbackFinished to false at line 546

is it that?

@kencecka
Copy link
Contributor

kencecka commented Sep 1, 2017

Hi @sundq,

Thanks for pointing this out. It looks like this occurs at the end of any audio playback that runs to completion. The general flaw here is that executeOnFocusChanged() currently assumes that a focus change to NONE is happening during playback, tries to stop the playback, and then waits for confirmation that it stopped. The code needs to be modified to be aware of whether playback was already stopped at the time of the focus change so that it can skip the stop/wait.

I have filed a ticket internally to address this in a future release. For the current release, these errors should be harmless and you can disregard them.

Ken

jjishnu pushed a commit that referenced this issue Sep 20, 2017
    Changes in this update
    - Implemented `setOffSet` in `MediaPlayer`.
    - Updated `LoggerUtils.cpp` to address
      (#77).

    - Bug fix to address incorrect stop behavior caused when Audio Focus
      is set to `NONE` and released. This addresses
      (#129).
    - Bug fix for intermittent failure in `handleMultipleConsecutiveSpeaks`.
    - Bug fix for `jsonArrayExist` incorrectly parsing JSON when trying
      to locate array children.
    - Bug fix for ADSL test failures with `sendDirectiveWithoutADialogRequestId`.
    - Bug fix for `SpeechSynthesizer` showing the wrong UX state when a
      burst of `Speak` directives are received.
    - Bug fix for recursive loop in `AudioPlayer.Stop`.
@kclchan
Copy link
Contributor

kclchan commented Oct 2, 2017

Closing the issue. Please re-open if you are still having issues.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants