Volume control function is too slow during iHR playing for the request "Alexa, play kiss fm"
boyce-xx opened this issue · 5 comments
boyce-xx commented
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
scotthea-amazon commented
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 commented
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 commented
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 commented
Hi @scotthea-amazon ,
Thanks, I will be looking forward to your next SDK version.