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

Volume control function is too slow during iHR playing for the request "Alexa, play kiss fm" #553

Closed
boyce-xx opened this issue Mar 12, 2018 · 5 comments
Closed

Volume control function is too slow during iHR playing for the request "Alexa, play kiss fm" #553

boyce-xx opened this issue Mar 12, 2018 · 5 comments

Comments

@boyce-xx
Copy link

boyce-xx commented Mar 12, 2018 •
edited
Loading

Hi,

I'm using SDK V1.6.0.

I want to add speaker control function in my product, I noticed that there have a SpeakerManager class to manage the operations like setVolume, adjustVolume or setMute. I encountered a problem when using SpeakerManager to adjust the volume by pressed a physical button: it will take about 13 seconds to finish the adjust operation during iHR playing(Alexa, play KissFM), but it just take about 40 milliseconds during idle or Amazon music playing or iHR playing(Alexa, Play lady gaga station on iHR).

Let me put a portion of the code here to display how did I do it:

      alexaClientSDK::avsCommon::sdkInterfaces::SpeakerInterface::SpeakerSettings settings;
      mWisCommon.sysLocalTime("******** getSpeakerSettings 1");
      std::future<bool> getSettings = mWisAvs.m_speakerManager->getSpeakerSettings(alexaClientSDK::avsCommon::sdkInterfaces::SpeakerInterface::Type::AVS_SYNCED, &settings);
      int currentSysVolume = 0;
      mWisCommon.sysLocalTime("******** getSpeakerSettings 2");
      if (getSettings.get()) {
        currentSysVolume = settings.volume;
        if (currentSysVolume + pendingVolumeLevel <= 0) {
          mWisCommon.sysLocalTime("******** setMute 1");
          std::future<bool> setMute = mWisAvs.m_speakerManager->setMute(alexaClientSDK::avsCommon::sdkInterfaces::SpeakerInterface::Type::AVS_SYNCED, true, false);
          if (setMute.get()) {
            printf("syncSpeakerVolumeToAVS:: Mute success!\n");
          }
          mWisCommon.sysLocalTime("******** setMute 2");
        }else {
          mWisCommon.sysLocalTime("******** setUnMute 1");
          std::future<bool> setUnMute = mWisAvs.m_speakerManager->setMute(alexaClientSDK::avsCommon::sdkInterfaces::SpeakerInterface::Type::AVS_SYNCED, false, false);
          if (setUnMute.get()) {
            printf("syncSpeakerVolumeToAVS:: UnMute success!\n");
          }
          mWisCommon.sysLocalTime("******** setUnMute 2");

          mWisCommon.sysLocalTime("******** adjustVolume 1");
          std::future<bool> adjustVolume =  mWisAvs.m_speakerManager->adjustVolume(alexaClientSDK::avsCommon::sdkInterfaces::SpeakerInterface::Type::AVS_SYNCED, pendingVolumeLevel, false);
          if (adjustVolume.get()) {
            printf("syncSpeakerVolumeToAVS:: Sync (adjust)volume success!\n");
          }
          mWisCommon.sysLocalTime("******** adjustVolume 2");
        }
      }

If I pressed the volumeDown key on the device during Amazon music playing, the log will like this:

		******** getSpeakerSettings 1 --> 2018-03-12 16:04:32:84
2018-03-12 08:04:32.085 [ 27] 9 SpeakerManager:getSpeakerSettingsCalled
		******** getSpeakerSettings 2 --> 2018-03-12 16:04:32:86
2018-03-12 08:04:32.086 [ 28] 9 SpeakerManager:executeGetSpeakerSettingsCalled
2018-03-12 08:04:32.087 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.087 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.088 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.088 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.089 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.089 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.090 [ 28] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-03-12 08:04:32.090 [ 28] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
		******** setUnMute 1 --> 2018-03-12 16:04:32:90
2018-03-12 08:04:32.092 [ 27] 9 SpeakerManager:setMuteCalled:mute=false
2018-03-12 08:04:32.094 [ 28] 9 SpeakerManager:executeSetMuteCalled:mute=false
2018-03-12 08:04:32.094 [ 28] 9 MediaPlayer:setMuteCalled
2018-03-12 08:04:32.094 [  2] 9 MediaPlayer:handleSetMuteCalled
2018-03-12 08:04:32.095 [ 28] 9 MediaPlayer:setMuteCalled
2018-03-12 08:04:32.095 [  2] 9 MediaPlayer:handleSetMuteCalled
2018-03-12 08:04:32.096 [ 28] 9 MediaPlayer:setMuteCalled
2018-03-12 08:04:32.096 [  2] 9 MediaPlayer:handleSetMuteCalled
2018-03-12 08:04:32.097 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.097 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.098 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.098 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.098 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.099 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.099 [ 28] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-03-12 08:04:32.099 [ 28] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2018-03-12 08:04:32.100 [ 28] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SYNCED
2018-03-12 08:04:32.100 [ 28] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Speaker,name=VolumeState
2018-03-12 08:04:32.101 [ 28] 9 SpeakerManager:executeNotifyObserverCalled
2018-03-12 08:04:32.102 [ 28] 9 SpeakerManager:executeSendSpeakerSettingsChangedEvent
2018-03-12 08:04:32.103 [ 28] 0 EventBuilder:buildJsonEventString:messageId=c6e9a085-b807-40da-a640-5545eb4ea061,namespace=Speaker,name=MuteChanged
AVSConnectionManager::sendMessage {"event":{"header":{"namespace":"Speaker","name":"MuteChanged","messageId":"c6e9a085-b807-40da-a640-5545eb4ea061"},"payload":{"volume":100,"muted":false}}}
2018-03-12 08:04:32.103 [ 28] 9 HTTP2Transport:enqueueRequest
2018-03-12 08:04:32.104 [  d] 0 HTTP2Transport:processNextOutgoingMessage
2018-03-12 08:04:32.104 [  d] 0 HTTP2StreamPool:getStream:streamId=121,numAcquiredStreams=2
2018-03-12 08:04:32.105 [  d] 9 HTTP2Transport:insertActiveStream:handle=0x9ca09208
syncSpeakerVolumeToAVS:: UnMute success!
		******** setUnMute 2 --> 2018-03-12 16:04:32:106
		******** adjustVolume 1 --> 2018-03-12 16:04:32:107
2018-03-12 08:04:32.107 [ 27] 9 SpeakerManager:adjustVolumeCalled:delta=-10
2018-03-12 08:04:32.107 [ 28] 9 SpeakerManager:executeAdjustVolumeCalled:delta=-10
2018-03-12 08:04:32.107 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.108 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.108 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.108 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.109 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.109 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.109 [ 28] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-03-12 08:04:32.109 [ 28] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2018-03-12 08:04:32.109 [ 28] 9 MediaPlayer:adjustVolumeCalled
2018-03-12 08:04:32.110 [  2] 9 MediaPlayer:handleAdjustVolumeCalled
2018-03-12 08:04:32.110 [ 28] 9 MediaPlayer:adjustVolumeCalled
2018-03-12 08:04:32.110 [  2] 9 MediaPlayer:handleAdjustVolumeCalled
2018-03-12 08:04:32.111 [ 28] 9 MediaPlayer:adjustVolumeCalled
2018-03-12 08:04:32.111 [  2] 9 MediaPlayer:handleAdjustVolumeCalled
2018-03-12 08:04:32.111 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.112 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.112 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.112 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.112 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:04:32.113 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:04:32.113 [ 28] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-03-12 08:04:32.113 [ 28] 9 SpeakerManager:validateSpeakerSettings:volume=90,mute=false
2018-03-12 08:04:32.113 [ 28] 0 SpeakerManager:executeAdjustVolumeSuccess:newVolume=90
2018-03-12 08:04:32.113 [ 28] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SYNCED
2018-03-12 08:04:32.114 [ 28] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Speaker,name=VolumeState
2018-03-12 08:04:32.114 [ 28] 9 SpeakerManager:executeNotifyObserverCalled
2018-03-12 08:04:32.114 [ 28] 9 SpeakerManager:executeSendSpeakerSettingsChangedEvent
2018-03-12 08:04:32.114 [ 28] 0 EventBuilder:buildJsonEventString:messageId=4fd8ba2d-0926-4800-b174-76290c80f6ab,namespace=Speaker,name=VolumeChanged
AVSConnectionManager::sendMessage {"event":{"header":{"namespace":"Speaker","name":"VolumeChanged","messageId":"4fd8ba2d-0926-4800-b174-76290c80f6ab"},"payload":{"volume":90,"muted":false}}}
2018-03-12 08:04:32.115 [ 28] 9 HTTP2Transport:enqueueRequest
syncSpeakerVolumeToAVS:: Sync (adjust)volume success!
		******** adjustVolume 2 --> 2018-03-12 16:04:32:115

But
If I pressed the volumeDown key on the device during iHR playing(Alexa, play KissFM), the log will like this:

		******** getSpeakerSettings 1 --> 2018-03-12 16:10:30:824
2018-03-12 08:10:30.826 [ 53] 9 SpeakerManager:getSpeakerSettingsCalled
		******** getSpeakerSettings 2 --> 2018-03-12 16:10:30:826
2018-03-12 08:10:30.827 [ 28] 9 SpeakerManager:executeGetSpeakerSettingsCalled
2018-03-12 08:10:30.827 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:30.839 [  d] 0 HTTP2Transport:processNextOutgoingMessage
2018-03-12 08:10:30.839 [  d] 0 HTTP2StreamPool:getStream:streamId=341,numAcquiredStreams=2
2018-03-12 08:10:30.840 [  d] 9 HTTP2Transport:insertActiveStream:handle=0x9ca02c18
2018-03-12 08:10:31.140 [  2] 9 AttachmentReaderSource:read:size=1400,status=0
2018-03-12 08:10:31.141 [  2] 9 AttachmentReaderSource:read:size=1196,status=0
2018-03-12 08:10:31.141 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:31.141 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:31.381 [  d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0afc9dfffe06c154-00004d51-0007a2c4-2f1d1c668855f128-4cd1bcc1-341
2018-03-12 08:10:31.383 [  d] 0 HTTP2Transport:cleanupFinishedStream:streamId=341,result=200
2018-03-12 08:10:31.383 [ 14] E AVSConnectionManager:receive
King message = {"directive":{"header":{"namespace":"TemplateRuntime","name":"RenderPlayerInfo","messageId":"827b61a8-190d-4d8b-844c-a1f5730e5b7b"},"payload":{"content":{"header":"106.1 KISS FM","provider":{"name":"iHeartRadio Live Radio","logo":{"sources":[{"url":"https://s3.amazonaws.com/music-provider-logos/IHeartRadio.svg"}]}},"art":{"sources":[{"size":"x-large","url":"https://i.iheart.com/v3/re/assets/images/3dc8bdbe-0b93-4322-bca1-045f75587ef4.png"}]},"mediaLengthInMilliseconds":0},"audioItemId":"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#f3b3166f-2b9d-4aad-95a7-f5bfd476aece:1","controls":[{"selected":false,"name":"PLAY_PAUSE","enabled":true,"type":"BUTTON"}]}}}, isSoundCuePlaying = 0
2018-03-12 08:10:31.384 [  d] 0 HTTP2StreamPool:releaseStream:streamId=341,numAcquiredStreams=1
2018-03-12 08:10:31.385 [ 14] 0 MessageInterpreter:receive:messageId=827b61a8-190d-4d8b-844c-a1f5730e5b7b:No dialogRequestId attached to message.
2018-03-12 08:10:31.385 [ 14] I DirectiveSequencer:onDirective:UnparsedDirective={"directive"\:{"header"\:{"namespace"\:"TemplateRuntime"\,"name"\:"RenderPlayerInfo"\,"messageId"\:"827b61a8-190d-4d8b-844c-a1f5730e5b7b"}\,"payload"\:{"content"\:{"header"\:"106.1 KISS FM"\,"provider"\:{"name"\:"iHeartRadio Live Radio"\,"logo"\:{"sources"\:[{"url"\:"https\://s3.amazonaws.com/music-provider-logos/IHeartRadio.svg"}]}}\,"art"\:{"sources"\:[{"size"\:"x-large"\,"url"\:"https\://i.iheart.com/v3/re/assets/images/3dc8bdbe-0b93-4322-bca1-045f75587ef4.png"}]}\,"mediaLengthInMilliseconds"\:0}\,"audioItemId"\:"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#f3b3166f-2b9d-4aad-95a7-f5bfd476aece\:1"\,"controls"\:[{"selected"\:false\,"name"\:"PLAY_PAUSE"\,"enabled"\:true\,"type"\:"BUTTON"}]}}}
...onDirectiveArrived...
2018-03-12 08:10:31.386 [ 15] W DirectiveRouter:handleDirectiveWithPolicyHandleImmediatelyFailed:messageId=827b61a8-190d-4d8b-844c-a1f5730e5b7b,reason=noHandlerRegistered
2018-03-12 08:10:31.387 [ 15] I DirectiveRouter:preHandleDirective:UnparsedDirective={"directive"\:{"header"\:{"namespace"\:"TemplateRuntime"\,"name"\:"RenderPlayerInfo"\,"messageId"\:"827b61a8-190d-4d8b-844c-a1f5730e5b7b"}\,"payload"\:{"content"\:{"header"\:"106.1 KISS FM"\,"provider"\:{"name"\:"iHeartRadio Live Radio"\,"logo"\:{"sources"\:[{"url"\:"https\://s3.amazonaws.com/music-provider-logos/IHeartRadio.svg"}]}}\,"art"\:{"sources"\:[{"size"\:"x-large"\,"url"\:"https\://i.iheart.com/v3/re/assets/images/3dc8bdbe-0b93-4322-bca1-045f75587ef4.png"}]}\,"mediaLengthInMilliseconds"\:0}\,"audioItemId"\:"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#f3b3166f-2b9d-4aad-95a7-f5bfd476aece\:1"\,"controls"\:[{"selected"\:false\,"name"\:"PLAY_PAUSE"\,"enabled"\:true\,"type"\:"BUTTON"}]}}}
2018-03-12 08:10:31.387 [ 15] W DirectiveRouter:preHandleDirectiveFailed:messageId=827b61a8-190d-4d8b-844c-a1f5730e5b7b,reason=noHandlerRegistered
2018-03-12 08:10:31.388 [ 15] I DirectiveSequencer:sendingExceptionEncountered:messageId=827b61a8-190d-4d8b-844c-a1f5730e5b7b
2018-03-12 08:10:31.389 [ 15] 0 EventBuilder:buildJsonEventString:messageId=751ed9a9-e8c2-40d9-a72e-3ffd1fd2a4fc,namespace=System,name=ExceptionEncountered
AVSConnectionManager::sendMessage {"context":[],"event":{"header":{"namespace":"System","name":"ExceptionEncountered","messageId":"751ed9a9-e8c2-40d9-a72e-3ffd1fd2a4fc"},"payload":{"unparsedDirective":"{\"directive\":{\"header\":{\"namespace\":\"TemplateRuntime\",\"name\":\"RenderPlayerInfo\",\"messageId\":\"827b61a8-190d-4d8b-844c-a1f5730e5b7b\"},\"payload\":{\"content\":{\"header\":\"106.1 KISS FM\",\"provider\":{\"name\":\"iHeartRadio Live Radio\",\"logo\":{\"sources\":[{\"url\":\"https://s3.amazonaws.com/music-provider-logos/IHeartRadio.svg\"}]}},\"art\":{\"sources\":[{\"size\":\"x-large\",\"url\":\"https://i.iheart.com/v3/re/assets/images/3dc8bdbe-0b93-4322-bca1-045f75587ef4.png\"}]},\"mediaLengthInMilliseconds\":0},\"audioItemId\":\"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#f3b3166f-2b9d-4aad-95a7-f5bfd476aece:1\",\"controls\":[{\"selected\":false,\"name\":\"PLAY_PAUSE\",\"enabled\":true,\"type\":\"BUTTON\"}]}}}","error":{"type":"UNSUPPORTED_OPERATION","message":"Unsupported operation"}}}}
2018-03-12 08:10:31.391 [ 15] 9 HTTP2Transport:enqueueRequest
2018-03-12 08:10:31.486 [  d] 0 HTTP2Transport:processNextOutgoingMessage
2018-03-12 08:10:31.487 [  d] 0 HTTP2StreamPool:getStream:streamId=343,numAcquiredStreams=2
2018-03-12 08:10:31.488 [  d] 9 HTTP2Transport:insertActiveStream:handle=0x9ca02c18
2018-03-12 08:10:31.539 [  2] 9 AttachmentReaderSource:read:size=2254,status=0
2018-03-12 08:10:31.786 [  d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0afc9dfffe06c154-00004d51-0007a2c4-2f1d1c668855f128-4cd1bcc1-343
2018-03-12 08:10:31.787 [  d] 0 HTTP2Transport:cleanupFinishedStream:streamId=343,result=204
2018-03-12 08:10:31.788 [  d] 0 HTTP2StreamPool:releaseStream:streamId=343,numAcquiredStreams=1
2018-03-12 08:10:31.788 [  d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2018-03-12 08:10:31.939 [  2] 9 AttachmentReaderSource:read:size=1400,status=0
2018-03-12 08:10:31.940 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:31.940 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:31.940 [  2] 9 AttachmentReaderSource:read:size=1279,status=0
2018-03-12 08:10:32.440 [  2] 9 AttachmentReaderSource:read:size=1400,status=0
2018-03-12 08:10:32.441 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:32.441 [ 28] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-03-12 08:10:32.441 [ 28] 9 SpeakerManager:validateSpeakerSettings:volume=90,mute=false
		******** setUnMute 1 --> 2018-03-12 16:10:32:442
2018-03-12 08:10:32.441 [  2] 9 AttachmentReaderSource:read:size=787,status=0
2018-03-12 08:10:32.442 [ 53] 9 SpeakerManager:setMuteCalled:mute=false
2018-03-12 08:10:32.443 [ 28] 9 SpeakerManager:executeSetMuteCalled:mute=false
2018-03-12 08:10:32.443 [ 28] 9 MediaPlayer:setMuteCalled
2018-03-12 08:10:32.740 [  2] 9 AttachmentReaderSource:read:size=1400,status=0
2018-03-12 08:10:32.740 [  2] 9 AttachmentReaderSource:read:size=1192,status=0
2018-03-12 08:10:32.741 [  2] 9 MediaPlayer:handleSetMuteCalled
2018-03-12 08:10:32.741 [ 28] 9 MediaPlayer:setMuteCalled
2018-03-12 08:10:33.167 [  2] 9 AttachmentReaderSource:read:size=2560,status=0
2018-03-12 08:10:33.557 [  2] 9 AttachmentReaderSource:read:size=2378,status=0
2018-03-12 08:10:33.557 [  2] 9 MediaPlayer:handleSetMuteCalled
2018-03-12 08:10:33.557 [ 28] 9 MediaPlayer:setMuteCalled
2018-03-12 08:10:33.942 [  2] 9 AttachmentReaderSource:read:size=2510,status=0
2018-03-12 08:10:34.396 [  2] 9 AttachmentReaderSource:read:size=2228,status=0
2018-03-12 08:10:34.397 [  2] 9 MediaPlayer:handleSetMuteCalled
2018-03-12 08:10:34.398 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
[Status]: RingBuffer rp wrapped(524160) count=640
get the ping content: PING avs-alexa-na.amazon.com (54.239.21.157): 56 data bytes
get the ping content: --- avs-alexa-na.amazon.com ping statistics ---
get the ping content: 5 packets transmitted, 5 packets received, 0% packet loss
WisCommon::isConnectedToInternet ->ping lost rate = 0%, network is available.
get the ping content: round-trip min/avg/max = 249.226/274.900/303.914 ms

mWisAvs.m_connectionStatusObserver->getConnectionStatus: status = 2, AVSCM::isEnabled = 1, AVSCM::isConnected = 1
2018-03-12 08:10:34.740 [  2] 9 AttachmentReaderSource:read:size=2597,status=0
WisCommon getIPAddress: 192.168.3.181
WisCommon::sendUDPDataToSender senderIPAddress is null, so ignore this send.
start to delay......
2018-03-12 08:10:35.216 [  2] 9 AttachmentReaderSource:read:size=1400,status=0
2018-03-12 08:10:35.217 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:35.217 [  2] 9 AttachmentReaderSource:read:size=1181,status=0
2018-03-12 08:10:35.217 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:35.537 [  2] 9 AttachmentReaderSource:read:size=2271,status=0
2018-03-12 08:10:36.035 [  2] 9 AttachmentReaderSource:read:size=2613,status=0
2018-03-12 08:10:36.036 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:36.036 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:36.338 [  2] 9 AttachmentReaderSource:read:size=2334,status=0
2018-03-12 08:10:36.854 [  2] 9 AttachmentReaderSource:read:size=2480,status=0
2018-03-12 08:10:36.854 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:36.854 [ 28] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-03-12 08:10:36.855 [ 28] 9 SpeakerManager:validateSpeakerSettings:volume=90,mute=false
2018-03-12 08:10:36.855 [ 28] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SYNCED
2018-03-12 08:10:36.855 [ 28] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Speaker,name=VolumeState
2018-03-12 08:10:36.855 [ 28] 9 SpeakerManager:executeNotifyObserverCalled
2018-03-12 08:10:36.855 [ 28] 9 SpeakerManager:executeSendSpeakerSettingsChangedEvent
2018-03-12 08:10:36.855 [ 28] 0 EventBuilder:buildJsonEventString:messageId=7a64464f-a233-435a-b3c8-6c9ef0e13273,namespace=Speaker,name=MuteChanged
AVSConnectionManager::sendMessage {"event":{"header":{"namespace":"Speaker","name":"MuteChanged","messageId":"7a64464f-a233-435a-b3c8-6c9ef0e13273"},"payload":{"volume":90,"muted":false}}}
2018-03-12 08:10:36.856 [ 28] 9 HTTP2Transport:enqueueRequest
syncSpeakerVolumeToAVS:: UnMute success!
		******** setUnMute 2 --> 2018-03-12 16:10:36:856
		******** adjustVolume 1 --> 2018-03-12 16:10:36:856
2018-03-12 08:10:36.856 [ 53] 9 SpeakerManager:adjustVolumeCalled:delta=-10
2018-03-12 08:10:36.857 [ 28] 9 SpeakerManager:executeAdjustVolumeCalled:delta=-10
2018-03-12 08:10:36.857 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:36.911 [  d] 0 HTTP2Transport:processNextOutgoingMessage
2018-03-12 08:10:36.911 [  d] 0 HTTP2StreamPool:getStream:streamId=345,numAcquiredStreams=2
2018-03-12 08:10:36.911 [  d] 9 HTTP2Transport:insertActiveStream:handle=0x9ca02c18
2018-03-12 08:10:37.138 [  2] 9 AttachmentReaderSource:read:size=2567,status=0
2018-03-12 08:10:37.307 [  d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0afc9dfffe06c154-00004d51-0007a2c4-2f1d1c668855f128-4cd1bcc1-345
2018-03-12 08:10:37.308 [  d] 0 HTTP2Transport:cleanupFinishedStream:streamId=345,result=204
2018-03-12 08:10:37.309 [  d] 0 HTTP2StreamPool:releaseStream:streamId=345,numAcquiredStreams=1
2018-03-12 08:10:37.309 [  d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2018-03-12 08:10:37.543 [  2] 9 AttachmentReaderSource:read:size=2334,status=0
2018-03-12 08:10:37.543 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:37.544 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:37.983 [  2] 9 AttachmentReaderSource:read:size=2561,status=0
2018-03-12 08:10:38.337 [  2] 9 AttachmentReaderSource:read:size=2236,status=0
2018-03-12 08:10:38.337 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:38.338 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:38.799 [  2] 9 AttachmentReaderSource:read:size=2670,status=0
2018-03-12 08:10:39.134 [  2] 9 AttachmentReaderSource:read:size=2504,status=0
2018-03-12 08:10:39.134 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:39.135 [ 28] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-03-12 08:10:39.135 [ 28] 9 SpeakerManager:validateSpeakerSettings:volume=90,mute=false
2018-03-12 08:10:39.135 [ 28] 9 MediaPlayer:adjustVolumeCalled
2018-03-12 08:10:39.638 [  2] 9 AttachmentReaderSource:read:size=2259,status=0
End to delay......

2018-03-12 08:10:39.943 [  2] 9 AttachmentReaderSource:read:size=2590,status=0
2018-03-12 08:10:39.944 [  2] 9 MediaPlayer:handleAdjustVolumeCalled
2018-03-12 08:10:39.945 [ 28] 9 MediaPlayer:adjustVolumeCalled
2018-03-12 08:10:40.333 [  2] 9 AttachmentReaderSource:read:size=2574,status=0
2018-03-12 08:10:40.845 [  2] 9 AttachmentReaderSource:read:size=2282,status=0
2018-03-12 08:10:40.846 [  2] 9 MediaPlayer:handleAdjustVolumeCalled
2018-03-12 08:10:40.847 [ 28] 9 MediaPlayer:adjustVolumeCalled
2018-03-12 08:10:41.132 [  2] 9 AttachmentReaderSource:read:size=2572,status=0
2018-03-12 08:10:41.574 [  2] 9 AttachmentReaderSource:read:size=2401,status=0
2018-03-12 08:10:41.574 [  2] 9 MediaPlayer:handleAdjustVolumeCalled
2018-03-12 08:10:41.575 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:41.938 [  2] 9 AttachmentReaderSource:read:size=2481,status=0
		combinationKeyDetect: wait a combination key------ --> 2018-03-12 16:10:42:41
2018-03-12 08:10:42.332 [  2] 9 AttachmentReaderSource:read:size=2572,status=0
2018-03-12 08:10:42.332 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:42.333 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:42.794 [  2] 9 AttachmentReaderSource:read:size=2275,status=0
2018-03-12 08:10:43.132 [  2] 9 AttachmentReaderSource:read:size=2563,status=0
2018-03-12 08:10:43.132 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:43.133 [ 28] 9 MediaPlayer:getSpeakerSettingsCalled
2018-03-12 08:10:43.612 [  2] 9 AttachmentReaderSource:read:size=2370,status=0
2018-03-12 08:10:43.931 [  2] 9 AttachmentReaderSource:read:size=2537,status=0
2018-03-12 08:10:43.931 [  2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-03-12 08:10:43.932 [ 28] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-03-12 08:10:43.932 [ 28] 9 SpeakerManager:validateSpeakerSettings:volume=80,mute=false
2018-03-12 08:10:43.932 [ 28] 0 SpeakerManager:executeAdjustVolumeSuccess:newVolume=80
2018-03-12 08:10:43.932 [ 28] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SYNCED
2018-03-12 08:10:43.932 [ 28] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Speaker,name=VolumeState
2018-03-12 08:10:43.932 [ 28] 9 SpeakerManager:executeNotifyObserverCalled
2018-03-12 08:10:43.932 [ 28] 9 SpeakerManager:executeSendSpeakerSettingsChangedEvent
2018-03-12 08:10:43.933 [ 28] 0 EventBuilder:buildJsonEventString:messageId=a06de11b-3ab0-49ac-a928-877c775aa1f3,namespace=Speaker,name=VolumeChanged
AVSConnectionManager::sendMessage {"event":{"header":{"namespace":"Speaker","name":"VolumeChanged","messageId":"a06de11b-3ab0-49ac-a928-877c775aa1f3"},"payload":{"volume":80,"muted":false}}}
2018-03-12 08:10:43.933 [ 28] 9 HTTP2Transport:enqueueRequest
syncSpeakerVolumeToAVS:: Sync (adjust)volume success!
		******** adjustVolume 2 --> 2018-03-12 16:10:43:934
@boyce-xx boyce-xx changed the title Volume control function is too slow during iHR playing Volume control function is too slow during iHR playing for the request "Alexa, play kiss fm" Mar 12, 2018
@scotthea-amazon
Copy link
Contributor

Hi boyce-xx,

This looks like another manifestation of issue 447. Can you try specifying a short timeout (e.g. 10 milliseconds) in AttachmentReaderSource.cpp's call to read() and let us know if that resolves the issue?

Thank you,
-SWH

@boyce-xx
Copy link
Author

Hi @scotthea-amazon ,
Yes, it works after I add a timeout in read function below:
auto size = m_reader->read(info.data, info.size, &status, std::chrono::milliseconds(10));

I noticed the solution was posted 2 months ago, may I know why the solution was not included in SDK V1.5.0 or V1.6.0?

I have another question: How can I modify the default volume of MediaPlayer, it will restore the volume to 100(AVS MAX volume) when I re-launch the APP.

Thanks.

@scotthea-amazon
Copy link
Contributor

Hi boyce-xx,

Sorry, but I don't have a good explanation for why a fix did not make it in to 1.5 or 1.6. It seems like it just got lost in the other tasks at hand.

As for persisting the volume, that is an interesting issue. I expect you could add persistence for the settings and restore them at start-up. I will add an item to our internal work queue to look in to doing that.

Thank you,
-SWH

@boyce-xx
Copy link
Author

Hi @scotthea-amazon ,
Thanks, I will be looking forward to your next SDK version.

@celinval
Copy link
Contributor

Thanks @boyce-xx. I'll close this issue for now.

visayamv added a commit that referenced this issue Apr 18, 2018
@visayamv
Version 1.7.0 of the avs-device-sdk
7bea05a 
Changes in this update:

**Enhancements**
* `AuthDelegate` and `AuthServer.py` have been replaced by `CBLAUthDelegate`, which provides a more straightforward path to authorization.
* Added a new configuration property called [`cblAuthDelegate`](https://github.com/alexa/avs-device-sdk/blob/master/Integration/AlexaClientSDKConfig.json#L2). This object specifies parameters for `CBLAuthDelegate`.
* Added a new configuration property called [`miscDatabase`](https://github.com/alexa/avs-device-sdk/blob/master/Integration/AlexaClientSDKConfig.json#L34), which is a generic key/value database to be used by various components.
* Added a new configuration property called [`dcfDelegate`](https://github.com/alexa/avs-device-sdk/blob/master/Integration/AlexaClientSDKConfig.json#L17) This object specifies parameters for `DCFDelegate`. Within this object, values were added for the 'endpoint' and `overridenDcfPublishMessageBody`. 'endpoint' is the endpoint to connect to in order to send device capabilities. `overridenDcfPublishMessageBody`is the message that will get sent out to the Capabilities API. Note: values within the `dcfDelegate` object will only work in `DEBUG` builds.
* Added a new configuration property called [`deviceInfo`](https://github.com/alexa/avs-device-sdk/blob/master/Integration/AlexaClientSDKConfig.json#L9) which specifies device-identifying information for use by the Device Capability Framework (DCF), and for authorization (CBLAuthDelegate).
* Updated the Directive Sequencer to support wildcard directive handlers. This allows a handler for a given AVS interface to register at the namespace level, rather than specifying the names of all directives within that namespace.
* Updated the Raspberry Pi installation script to include `alsasink` in the configuration file.
* Added `audioSink` as a configuration option. This allows users to override the audio sink element used in `Gstreamer`.
* Added an interface for monitoring internet connection status: `InternetConnectionMonitorInterface.h`.
* The Alexa Communications Library (ACL) is no longer required to wait until authorization has succeeded before attempting to connect to AVS. Instead, `HTTP2Transport` handles waiting for authorization to complete.
* Added the Device Capabilities Framework (DCF) delegate. Device capabilities can now be sent for each capability interface using DCF publish messages.
* The sample app has been updated to send DCF publish messages, which will automatically occur when the sample app starts. Note: a DCF publish message must be successfully sent in order for communication with AVS to occur.
* The SDK now supports HTTP PUT messages.
* Added support for opt-arg style arguments and multiple configuration files. Now, the sample app can be invoked by either of these commands: `SampleApp <configfile> <debuglevel>` OR `SampleApp -C file1 -C file2 ... -L loglevel`.

**Bug Fixes**
* Issues [447](#447) and [553](#553) Fixed the `AttachmentRenderSource`'s handling of `BLOCKING` `AttachmentReaders`.
* Updated the `Logger` implementation to be more resilient to `nullptr` string inputs.
* Fixed a `TimeUtils` utility-related compile issue.
* Fixed a bug in which alerts failed to activate if the system was restarted without network connection.
* Fixed Android 64-bit build failure issue.

**Known Issues**
* The `ACL` may encounter issues if audio attachments are received but not consumed.
* `SpeechSynthesizerState` currently uses `GAINING_FOCUS` and `LOSING_FOCUS` as a workaround for handling intermediate state. These states may be removed in a future release.
* Some ERROR messages may be printed during start-up event if initialization proceeds normally and successfully.
* If an unrecoverable authorization error or an unrecoverable DCF error is encountered, the sample app may crash on shutdown.
* If a non-CBL `clientId` is included in the `deviceInfo` section of `AlexaClientSDKConfig.json`, the error will be reported as an unrecoverable authorization error, rather than a more specific error.
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@boyce-xx @scotthea-amazon @celinval