Version 1.0.3 alexa-client-sdk

    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`.

AVSCommon/AVS/src/DialogUXStateAggregator.cpp

@@ -73,7 +73,7 @@ void DialogUXStateAggregator::onStateChanged(AudioInputProcessorObserverInterfac
         [this, state] () {
             switch (state) {
                 case AudioInputProcessorObserverInterface::State::IDLE:
-                    if (DialogUXStateObserverInterface::DialogUXState::THINKING == m_currentState) {
+                    if (DialogUXStateObserverInterface::DialogUXState::THINKING == m_currentState) { 
                         return;
                     }
                     setState(DialogUXStateObserverInterface::DialogUXState::IDLE);
@@ -109,6 +109,9 @@ void DialogUXStateAggregator::onStateChanged(SpeechSynthesizerObserver::SpeechSy
                     if (DialogUXStateObserverInterface::DialogUXState::SPEAKING != m_currentState) {
                         return;
                     }
+
+                    m_currentState = DialogUXStateObserverInterface::DialogUXState::FINISHED;
+
                     if (!m_multiturnSpeakingToListeningTimer.start(
                             SHORT_TIMEOUT, std::bind(
                                     &DialogUXStateAggregator::transitionFromSpeakingFinished, this)).valid()) {
@@ -161,7 +164,7 @@ void DialogUXStateAggregator::transitionFromThinkingTimedOut() {
 void DialogUXStateAggregator::transitionFromSpeakingFinished() {
     m_executor.submit(
         [this] () {
-            if (DialogUXStateObserverInterface::DialogUXState::SPEAKING == m_currentState) {
+            if (DialogUXStateObserverInterface::DialogUXState::FINISHED == m_currentState) {
                 setState(DialogUXStateObserverInterface::DialogUXState::IDLE);
             }
         }

AVSCommon/SDKInterfaces/include/AVSCommon/SDKInterfaces/DialogUXStateObserverInterface.h

@@ -44,7 +44,15 @@ class DialogUXStateObserverInterface {
         THINKING,
 
         /// Alexa is responding to a request with speech.
-        SPEAKING
+        SPEAKING,
+
+        /**
+         * Alexa has finished processing a SPEAK directive. In this state there
+         * are no notifications triggered. If the SPEAK directive is part of a
+         * speech burst UX moves back to the SPEAKING state. If it was the last
+         * SPEAK directive after timeout the UX state moves to the IDLE state.
+         */
+        FINISHED
     };
 
     /**
@@ -79,6 +87,8 @@ inline std::string DialogUXStateObserverInterface::stateToString(DialogUXState s
             return "THINKING";
         case DialogUXState::SPEAKING:
             return "SPEAKING";
+        case DialogUXState::FINISHED:
+            return "FINISHED";
     }
     return "Unknown State";
 }

AVSCommon/Utils/include/AVSCommon/Utils/MediaPlayer/MediaPlayerInterface.h

@@ -97,7 +97,15 @@ class MediaPlayerInterface {
             std::shared_ptr<std::istream> stream, bool repeat) = 0;
 
     /**
-     * TODO ACSDK-423: Implement setOffset behavior.
+     * Set the offset for playback. A seek will be performed to the offset at the next @c play() command.
+     *
+     * The following situations will reset the offset:
+     * # A seek attempt is made (ie. via play()).
+     * # A new source is set.
+     *
+     * @param offset The offset in milliseconds to seek to.
+     *
+     * @return @c SUCCESS if the offset was successfully set, and FAILURE for any error.
      */
     virtual MediaPlayerStatus setOffset(std::chrono::milliseconds offset) { return MediaPlayerStatus::FAILURE; }
 

AVSCommon/Utils/src/JSONUtils.cpp

@@ -199,8 +199,8 @@ bool convertToValue(const rapidjson::Value& documentNode, int64_t* value) {
 }
 
 bool jsonArrayExists(const rapidjson::Value & parsedDocument, const std::string & key) {
-    auto iter = parsedDocument.FindMember(key.c_str());
-    if (parsedDocument.MemberEnd() != iter) {
+    auto iter = parsedDocument.FindMember(key);
+    if (parsedDocument.MemberEnd() == iter) {
         ACSDK_ERROR(LX("lookupArrayExistsFailed").d("reason", "keyNotFound").d("key", key));
         return false;
     }

AVSCommon/Utils/src/Logger/LoggerUtils.cpp

@@ -18,6 +18,8 @@
 #include "AVSCommon/Utils/Logger/LoggerUtils.h"
 #include "AVSCommon/Utils/Logger/Logger.h"
 
+#include <cstdio>
+
 namespace alexaClientSDK {
 namespace avsCommon {
 namespace utils {
@@ -132,7 +134,7 @@ std::string formatLogString(
             std::chrono::duration_cast<std::chrono::milliseconds>(time.time_since_epoch()).count() % 
                     MILLISECONDS_PER_SECOND);
     char millisString[MILLIS_STRING_SIZE];
-    if (snprintf(millisString, sizeof(millisString), MILLIS_FORMAT_STRING, timeMillisPart) < 0) {
+    if (std::snprintf(millisString, sizeof(millisString), MILLIS_FORMAT_STRING, timeMillisPart) < 0) {
         millisecondFailure = true;
     }
 

CHANGELOG.md

@@ -1,4 +1,17 @@
 ## ChangeLog
+### [1.0.3] - 2017-09-19
+* **Enhancements**
+  * Implemented `setOffSet` in `MediaPlayer`.
+  * [Updated `LoggerUtils.cpp`](https://github.com/alexa/avs-device-sdk/issues/77).
+
+* **Bug Fixes**
+  * [Bug fix to address incorrect stop behavior caused when Audio Focus is set to `NONE` and released](https://github.com/alexa/avs-device-sdk/issues/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`.
+
 ### [1.0.2] - 2017-08-23
 * Removed code from AIP which propagates ExpectSpeech initiator strings to subsequent Recognize events.  This code will be re-introduced when AVS starts sending initiator strings.
 

CMakeLists.txt

@@ -1,7 +1,7 @@
 cmake_minimum_required(VERSION 3.1 FATAL_ERROR)
 
 # Set project information
-project(AlexaClientSDK VERSION 1.0.2 LANGUAGES CXX)
+project(AlexaClientSDK VERSION 1.0.3 LANGUAGES CXX)
 set(PROJECT_BRIEF "A cross-platform, modular SDK for interacting with the Alexa Voice Service")
 
 include(build/BuildDefaults.cmake)

CapabilityAgents/AudioPlayer/include/AudioPlayer/AudioPlayer.h

@@ -328,8 +328,17 @@ class AudioPlayer :
     /// Send a @c PlaybackMetadataExtracted event.
     void sendStreamMetadataExtractedEvent();
 
-    /// Get the media player offset.
-    std::chrono::milliseconds getMediaPlayerOffset();
+    /**
+     * Get the current offset in the audio stream.
+     *
+     * @note @c MediaPlayer has a getOffset function which only works while actively playing, but AudioPlayer needs to
+     *     be able to report its offset at any time, even when paused or stopped.  To address the gap, this function
+     *     reports the live offset from @c MediaPlayer when it is playing, and reports a cached offset when
+     *     @c MediaPlayer is not playing.
+     *
+     * @return The current offset in the stream.
+     */
+    std::chrono::milliseconds getOffset();
 
     /// @}
 
@@ -409,6 +418,13 @@ class AudioPlayer :
     /// This timer is used to send @c ProgressReportIntervalElapsed events.
     avsCommon::utils::timing::Timer m_intervalTimer;
 
+    /**
+     * This keeps track of the current offset in the audio stream.  Reading the offset from @c MediaPlayer is
+     * insufficient because @c MediaPlayer only returns a valid offset when it is actively playing, but @c AudioPlayer
+     * must return a valid offset when @c MediaPlayer is stopped.
+     */
+    std::chrono::milliseconds m_offset;
+
     /// @}
 
     /**

CapabilityAgents/AudioPlayer/src/AudioPlayer.cpp

@@ -260,7 +260,8 @@ AudioPlayer::AudioPlayer(
         m_playbackFinished{false},
         m_currentActivity{PlayerActivity::IDLE},
         m_starting{false},
-        m_focus{FocusState::NONE} {
+        m_focus{FocusState::NONE},
+        m_offset{std::chrono::milliseconds{std::chrono::milliseconds::zero()}} {
 }
 
 void AudioPlayer::doShutdown() {
@@ -483,7 +484,7 @@ void AudioPlayer::executeProvideState(bool sendToken, unsigned int stateRequestT
     state.AddMember(TOKEN_KEY, m_token, state.GetAllocator());
     state.AddMember(
             OFFSET_KEY,
-            std::chrono::duration_cast<std::chrono::milliseconds>(getMediaPlayerOffset()).count(),
+            std::chrono::duration_cast<std::chrono::milliseconds>(getOffset()).count(),
             state.GetAllocator());
     state.AddMember(ACTIVITY_KEY, playerActivityToString(m_currentActivity), state.GetAllocator());
 
@@ -506,7 +507,11 @@ void AudioPlayer::executeProvideState(bool sendToken, unsigned int stateRequestT
 }
 
 void AudioPlayer::executeOnFocusChanged(FocusState newFocus) {
-    ACSDK_DEBUG9(LX("executeOnFocusChanged").d("from", m_focus).d("to", newFocus));
+    ACSDK_DEBUG9(LX("executeOnFocusChanged")
+            .d("from", m_focus)
+            .d("to", newFocus)
+            .d("m_starting", m_starting)
+            .d("m_currentActivity", m_currentActivity));
     if (m_focus == newFocus) {
         return;
     }
@@ -572,9 +577,21 @@ void AudioPlayer::executeOnFocusChanged(FocusState newFocus) {
             }
             break;
         case FocusState::NONE:
-            if (PlayerActivity::STOPPED == m_currentActivity) {
-                break;
+            switch (m_currentActivity) {
+                case PlayerActivity::IDLE:
+                case PlayerActivity::STOPPED:
+                case PlayerActivity::FINISHED:
+                    // Nothing to more to do if we're already not playing; we got here because the act of stopping
+                    // caused the channel to be released, which in turn caused this callback.
+                    return;
+                case PlayerActivity::PLAYING:
+                case PlayerActivity::PAUSED:
+                case PlayerActivity::BUFFER_UNDERRUN:
+                    // If The focus change came in while we were in a 'playing' state, we need to stop because we are
+                    // yielding the channel.
+                    break;
             }
+
             m_audioItems.clear();
 
             std::unique_lock<std::mutex> lock(m_playbackMutex);
@@ -606,6 +623,7 @@ void AudioPlayer::executeOnPlaybackStarted() {
 }
 
 void AudioPlayer::executeOnPlaybackFinished() {
+    ACSDK_DEBUG9(LX("executeOnPlaybackFinished"));
     if (m_currentActivity != PlayerActivity::PLAYING ) {
         ACSDK_ERROR(LX("executeOnPlaybackFinishedError")
                 .d("reason", "notPlaying")
@@ -710,6 +728,7 @@ void AudioPlayer::executePlay(PlayBehavior playBehavior, const AudioItem& audioI
 }
 
 void AudioPlayer::playNextItem() {
+    ACSDK_DEBUG9(LX("playNextItem").d("m_audioItems.size", m_audioItems.size()));
     if (m_audioItems.empty()) {
         sendPlaybackFailedEvent(
                 m_token,
@@ -742,6 +761,7 @@ void AudioPlayer::playNextItem() {
         return;
     }
 
+    ACSDK_DEBUG9(LX("playNextItem").d("item.stream.offset", item.stream.offset.count()));
     if (item.stream.offset.count() && m_mediaPlayer->setOffset(item.stream.offset) == MediaPlayerStatus::FAILURE) {
         sendPlaybackFailedEvent(
                 m_token,
@@ -776,6 +796,7 @@ void AudioPlayer::playNextItem() {
 
 void AudioPlayer::executeStop(bool releaseFocus) {
     ACSDK_DEBUG9(LX("executestop").d("m_currentActivity", m_currentActivity));
+    auto stopStatus = MediaPlayerStatus::SUCCESS;
     switch (m_currentActivity) {
         case PlayerActivity::IDLE:
         case PlayerActivity::STOPPED:
@@ -788,9 +809,8 @@ void AudioPlayer::executeStop(bool releaseFocus) {
         case PlayerActivity::PLAYING:
         case PlayerActivity::PAUSED:
         case PlayerActivity::BUFFER_UNDERRUN:
-            if (m_mediaPlayer->stop() == MediaPlayerStatus::FAILURE) {
-                executeOnPlaybackError("stopFailed");
-            }
+            getOffset();
+            stopStatus = m_mediaPlayer->stop();
             break;
         default:
             break;
@@ -802,6 +822,9 @@ void AudioPlayer::executeStop(bool releaseFocus) {
         m_focusManager->releaseChannel(CHANNEL_NAME, shared_from_this());
     }
     changeActivity(PlayerActivity::STOPPED);
+    if (MediaPlayerStatus::FAILURE == stopStatus) {
+        executeOnPlaybackError("mediaPlayerStopFailed");
+    }
     sendPlaybackStoppedEvent();
 }
 
@@ -847,7 +870,7 @@ void AudioPlayer::sendEventWithTokenAndOffset(const std::string& eventName) {
     payload.AddMember(TOKEN_KEY, m_token, payload.GetAllocator());
     payload.AddMember(
             OFFSET_KEY,
-            std::chrono::duration_cast<std::chrono::milliseconds>(getMediaPlayerOffset()).count(),
+            std::chrono::duration_cast<std::chrono::milliseconds>(getOffset()).count(),
             payload.GetAllocator());
 
     rapidjson::StringBuffer buffer;
@@ -887,7 +910,7 @@ void AudioPlayer::sendPlaybackStutterFinishedEvent() {
     payload.AddMember(TOKEN_KEY, m_token, payload.GetAllocator());
     payload.AddMember(
             OFFSET_KEY,
-            std::chrono::duration_cast<std::chrono::milliseconds>(getMediaPlayerOffset()).count(),
+            std::chrono::duration_cast<std::chrono::milliseconds>(getOffset()).count(),
             payload.GetAllocator());
     auto stutterDuration = std::chrono::steady_clock::now() - m_bufferUnderrunTimestamp;
     payload.AddMember(
@@ -920,7 +943,9 @@ void AudioPlayer::sendPlaybackFailedEvent(
 
     rapidjson::Value currentPlaybackState(rapidjson::kObjectType);
     currentPlaybackState.AddMember(TOKEN_KEY, m_token, payload.GetAllocator());
-    currentPlaybackState.AddMember(OFFSET_KEY, m_mediaPlayer->getOffsetInMilliseconds(), payload.GetAllocator());
+    currentPlaybackState.AddMember(
+            OFFSET_KEY,
+            std::chrono::duration_cast<std::chrono::milliseconds>(getOffset()).count(), payload.GetAllocator());
     currentPlaybackState.AddMember(ACTIVITY_KEY, playerActivityToString(m_currentActivity), payload.GetAllocator());
 
     payload.AddMember("currentPlaybackState", currentPlaybackState, payload.GetAllocator());
@@ -965,12 +990,15 @@ void AudioPlayer::sendStreamMetadataExtractedEvent() {
     //TODO: Implement/call this once MediaPlayer exports metadata info (ACSDK-414).
 }
 
-std::chrono::milliseconds AudioPlayer::getMediaPlayerOffset() {
-    auto offset = m_mediaPlayer->getOffsetInMilliseconds();
-    if (offset < 0) {
-        offset = 0;
+std::chrono::milliseconds AudioPlayer::getOffset() {
+    if (PlayerActivity::PLAYING != m_currentActivity) {
+        return m_offset;
+    }
+    m_offset = std::chrono::milliseconds(m_mediaPlayer->getOffsetInMilliseconds());
+    if (m_offset < std::chrono::milliseconds::zero()) {
+        m_offset = std::chrono::milliseconds::zero();
     }
-    return std::chrono::milliseconds(offset);
+    return m_offset;
 }
 
 } // namespace audioPlayer

Integration/include/Integration/ConnectionStatusObserver.h

@@ -54,14 +54,13 @@ class ConnectionStatusObserver : public avsCommon::sdkInterfaces::ConnectionStat
      * @return true if expected connectionStatus is received within @c duration else false.
      */
     bool waitFor(const avsCommon::sdkInterfaces::ConnectionStatusObserverInterface::Status connectionStatus,
-                 const std::chrono::seconds duration = std::chrono::seconds(10));
+                 const std::chrono::seconds duration = std::chrono::seconds(15));
 
     /**
      * Function to check if the connection is broken due to Server side Disconnect.
      * @return true if the disconnect happens due to SERVER_SIDE_DISCONNECT else false.
      */
     bool checkForServerSideDisconnect();
-
 private:
     /// Mutex used internally to enforce thread safety and serialize read/write access to @c m_statusChanges.
     mutable std::mutex m_mutex;

Integration/include/Integration/TestMessageSender.h

@@ -24,15 +24,17 @@
 #include <mutex>
 
 #include <ACL/AVSConnectionManager.h>
-
-#include "AVSCommon/SDKInterfaces/MessageSenderInterface.h"
-#include "AVSCommon/SDKInterfaces/MessageObserverInterface.h"
+#include <AVSCommon/SDKInterfaces/MessageSenderInterface.h>
+#include <AVSCommon/SDKInterfaces/MessageObserverInterface.h>
+#include <AVSCommon/Utils/RequiresShutdown.h>
 
 namespace alexaClientSDK {
 namespace integration {
 namespace test {
 
-class TestMessageSender : public avsCommon::sdkInterfaces::MessageSenderInterface {
+class TestMessageSender :
+        public avsCommon::sdkInterfaces::MessageSenderInterface,
+        public avsCommon::utils::RequiresShutdown {
 public:
     /// Destructor.
     ~TestMessageSender() = default;
@@ -123,6 +125,8 @@ class TestMessageSender : public avsCommon::sdkInterfaces::MessageSenderInterfac
      */
     void synchronize();
 
+    void doShutdown() override;
+
 private:
     /// Mutex to protect m_queue.
     std::mutex m_mutex;

Integration/src/TestMessageSender.cpp

@@ -22,6 +22,7 @@ using namespace alexaClientSDK;
 using namespace acl;
 using namespace avsCommon::avs;
 using namespace avsCommon::sdkInterfaces;
+using namespace avsCommon::utils;
 
 namespace alexaClientSDK {
 namespace integration {
@@ -31,7 +32,7 @@ TestMessageSender::TestMessageSender(
         std::shared_ptr<acl::MessageRouterInterface> messageRouter,
         bool isEnabled,
         std::shared_ptr<ConnectionStatusObserverInterface> connectionStatusObserver,
-        std::shared_ptr<MessageObserverInterface> messageObserver) {
+        std::shared_ptr<MessageObserverInterface> messageObserver) : RequiresShutdown{"TestMessageSender"} {
     m_connectionManager = acl::AVSConnectionManager::create(messageRouter, isEnabled, { connectionStatusObserver },
             { messageObserver });
     // TODO: ACSDK-421: Remove the callback when m_avsConnection manager is no longer an observer to
@@ -118,6 +119,10 @@ void TestMessageSender::setAVSEndpoint(const std::string& avsEndpoint) {
         m_connectionManager->onStateChanged(StateSynchronizerObserverInterface::State::SYNCHRONIZED);
     }
 
+    void TestMessageSender::doShutdown() {
+        m_connectionManager->shutdown();
+    }
+
 } // namespace test
 } // namespace integration
 } // namespace alexaClientSDK