MediaPlayer aborted with Promise already satisfied

[paragone]

hi,I got a problem while playing with MediaPlayer. log:

2017-09-25 06:16:27.288 [] I DirectiveSequencer:onDirective:directive={"namespace:"TemplateRuntime",name:"RenderPlayerInfo",messageId:"17a1c325-82b3-46c1-983d-57f7c8cac5a5",dialogRequestId:"4949f1d2-be01-4ec6-90e8-19caf668cd6f"}
2017-09-25 06:16:27.288 [] 9 MediaPlayer:playCalled
2017-09-25 06:16:27.288 [] W DirectiveRouter:preHandleDirectiveFailed:messageId=17a1c325-82b3-46c1-983d-57f7c8cac5a5,reason=noHandlerRegistered
2017-09-25 06:16:27.289 [] I DirectiveSequencer:sendingExceptionEncountered:messageId=17a1c325-82b3-46c1-983d-57f7c8cac5a5
2017-09-25 06:16:27.289 [] 0 MediaPlayer:handlePlayCalled
2017-09-25 06:16:27.289 [] 0 MediaPlayer:doStopSuccess:reason=alreadyStopped
2017-09-25 06:16:27.289 [] 9 MediaPlayer:doStopSuccess
2017-09-25 06:16:27.289 [] 0 MediaPlayer:handlePlay:supportsBuffering=0
2017-09-25 06:16:27.289 [] 0 EventBuilder:buildJsonEventString:messageId=4fc51536-7ec1-4a6f-91c2-1d7596863956,namespace=System,name=ExceptionEncountered
2017-09-25 06:16:27.295 [] 0 MediaPlayer:handlePlay:stateReturn=ASYNC
2017-09-25 06:16:27.295 [] 0 MediaPlayer:handlePlay:stateReturn11111=ASYNC
terminate called after throwing an instance of 'std::future_error'
what(): Promise already satisfied
Aborted

i add some logs,code,here is code:
auto stateChangeRet = gst_element_set_state(m_pipeline.pipeline, GST_STATE_PLAYING);
ACSDK_DEBUG(LX("handlePlay").d("stateReturn", gst_element_state_change_return_get_name(stateChangeRet)));
if (GST_STATE_CHANGE_FAILURE == stateChangeRet) {
ACSDK_ERROR(LX("handlePlayFailed").d("reason", "gstElementSetStateFailure"));
promise->set_value(MediaPlayerStatus::FAILURE);
} else if (GST_STATE_CHANGE_ASYNC == stateChangeRet) {
ACSDK_DEBUG(LX("handlePlay").d("stateReturn11111", gst_element_state_change_return_get_name(stateChangeRet)));
promise->set_value(MediaPlayerStatus::PENDING);
ACSDK_DEBUG(LX("handlePlay").d("stateReturn22222", gst_element_state_change_return_get_name(stateChangeRet)));
} else {
ACSDK_DEBUG(LX("handlePlay").d("stateReturn33333", gst_element_state_change_return_get_name(stateChangeRet)));
promise->set_value(MediaPlayerStatus::SUCCESS);
ACSDK_DEBUG(LX("handlePlay").d("stateReturn44444", gst_element_state_change_return_get_name(stateChangeRet)));
}
ACSDK_DEBUG(LX("handlePlay").d("stateReturn55555", gst_element_state_change_return_get_name(stateChangeRet)));

hope you can give me some advice.

[mradulan]

@paragone can you tell what were you trying to play, so that we can reproduce the issue.

[mradulan]

Hi @paragone , this has been observed and it will be resolved in our future release. Please refer to #153 and the solution there. Below is the snippet of the temporary solution from #153:

It looks like the crash is occurring because m_playlistParsedPromise in MediaPlayer/URLSource is being set twice. In MediaPlayer/include/UrlSource.h, could you add a boolean flag that indicates whether a callback has been received, as well as a mutex? For example, bool m_hasReceivedAPlaylistCallback and std::mutex m_mutex. Then in URLSource's constructor, initialize m_hasReceivedAPlaylistCallback to false. Finally, in UrlSource::onPlaylistParsed, you could add something like the following:

std::lock_guardstd::mutex lock{m_mutex};
if (!m_hasReceivedAPlaylistCallback) {
m_hasReceivedAPlaylistCallback = true;
m_playlistParsedPromise.set_value(urls);
}

[paragone]

hi mradulan,
I was playing sample music by saying 'play happy' ,'play sugar' .ect.
after playing more than 5 songs，it will crash.

[Roy20141120]

@mradulan
This issue seems diff from #153 , that is a global variable (promise), BUT in this issue, this is a local variable. detail as below:

2017-09-26 07:20:08.058 [] W DirectiveRouter:preHandleDirectiveFailed:messageId=e3652dc0-34dc-473b-ac0a-ac7336908c3f,reason=noHandlerRegistered
2017-09-26 07:20:08.058 [] I DirectiveSequencer:sendingExceptionEncountered:messageId=e3652dc0-34dc-473b-ac0a-ac7336908c3f
2017-09-26 07:20:08.058 [] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND
2017-09-26 07:20:08.058 [] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2017-09-26 07:20:08.058 [] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2017-09-26 07:20:08.058 [] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING
2017-09-26 07:20:08.058 [] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2017-09-26 07:20:08.058 [] 9 SpeechSynthesizer:startPlaying
2017-09-26 07:20:08.058 [] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader
LIUEH promise set value 41
LIUEH promise set value 41
2017-09-26 07:20:08.059 [] 0 MediaPlayer:handleSetSourceCalled
2017-09-26 07:20:08.059 [] 9 MediaPlayer:tearDownPipeline
2017-09-26 07:20:08.059 [] 0 EventBuilder:buildJsonEventString:messageId=c2b2660c-ab29-4cb5-bbc3-a2356bae1153,namespace=System,name=ExceptionEncountered
QUEUE_AVS_OR_SESSION_TO_EVENT messageQueueReceive msg->m_type = 2, msg->m_msg = 0, msg->m_length = 198
queueTask QUEUE_MESSAGE_TYPE_AVSJSON
queueTask QUEUE_MESSAGE_TYPE_AVSJSON cb = 0x22514
queueTask QUEUE_MESSAGE_TYPE_AVSJSON callback json
2017-09-26 07:20:08.063 [] E MediaPlayer:handlePlayFailed:LIUEH =promise set value 37
2017-09-26 07:20:08.063 [] 9 MediaPlayer:playCalled
2017-09-26 07:20:08.063 [] 0 MediaPlayer:handlePlayCalled
2017-09-26 07:20:08.063 [] 0 MediaPlayer:doStopSuccess:reason=alreadyStopped
2017-09-26 07:20:08.063 [] 9 MediaPlayer:doStopSuccess
2017-09-26 07:20:08.063 [] 0 MediaPlayer:handlePlay:supportsBuffering=0
messageQueueFree
2017-09-26 07:20:08.068 [] 0 MediaPlayer:handlePlay:stateReturn=ASYNC
2017-09-26 07:20:08.068 [] E MediaPlayer:handlePlayFailed:LIUEH =promise set value 13
2017-09-26 07:20:08.068 [] 9 BaseStreamSource:onNeedDataCalled:size=4096
term

promise here is a local variable

`MediaPlayerStatus MediaPlayer::play() {
ACSDK_DEBUG9(LX("playCalled"));
if (!m_source) {
ACSDK_ERROR(LX("playFailed").d("reason", "sourceNotSet"));
return MediaPlayerStatus::FAILURE;
}
m_source->preprocess();
std::promise promise;
auto future = promise.get_future();
std::function<gboolean()> callback = this, &promise {
handlePlay(&promise);
return false;
};
queueCallback(&callback);
return future.get();
}

auto stateChangeRet = gst_element_set_state(m_pipeline.pipeline, GST_STATE_PLAYING);
ACSDK_DEBUG(LX("handlePlay").d("stateReturn", gst_element_state_change_return_get_name(stateChangeRet)));
if (GST_STATE_CHANGE_FAILURE == stateChangeRet) {
ACSDK_ERROR(LX("handlePlayFailed").d("reason", "gstElementSetStateFailure"));
ACSDK_ERROR(LX("handlePlayFailed").d("LIUEH ", "promise set value 12"));
promise->set_value(MediaPlayerStatus::FAILURE);
} else if (GST_STATE_CHANGE_ASYNC == stateChangeRet) {
ACSDK_ERROR(LX("handlePlayFailed").d("LIUEH ", "promise set value 13"));
promise->set_value(MediaPlayerStatus::PENDING);
} else {
ACSDK_ERROR(LX("handlePlayFailed").d("LIUEH ", "promise set value 14"));
promise->set_value(MediaPlayerStatus::SUCCESS);
}
return;`

waiting for you reply online............

[mradulan]

which part of the debug code are you printing "promise set value 37" and "promise set value 37"

[mradulan]

@Roy20141120 , does it play any music for you and then it terminates with the error? It seems like the music never gets played because you get MediaPlayer:handlePlay:stateReturn=ASYNC

[kclchan]

Hi @paragone and @Roy20141120, there have been quite a few changes to MediaPlayer and AudioPlayer in release v1.1.0. Could you try your test case with this latest release and see if you are still seeing the issue? Thanks!

[paragone]

I test it with the latest release and it still exists,here is the log:

2017-10-12 09:14:28.333 [] 0 EventBuilder:buildJsonEventString:messageId=1036b6b1-821f-4e00-b1d3-606f97164775,namespace=System,name=ExceptionEncountered
2017-10-12 09:14:28.333 [] I DirectiveRouter:handleDirective:messageId=3239a6ca-df58-414b-beae-dd551c9bd3f3,action=calling
2017-10-12 09:14:28.333 [] 9 SpeechSynthesizer:handleDirective:messageId=3239a6ca-df58-414b-beae-dd551c9bd3f3
2017-10-12 09:14:28.333 [] I DirectiveRouter:preHandleDirective:messageId=428cbbdc-6a12-4a51-ae46-5918df1882f7,action=calling
2017-10-12 09:14:28.333 [] 0 CapabilityAgent:addingMessageIdToMap:messageId=428cbbdc-6a12-4a51-ae46-5918df1882f7
2017-10-12 09:14:28.333 [] 0 SpeechSynthesizer:executeHandle:messageId=3239a6ca-df58-414b-beae-dd551c9bd3f3
2017-10-12 09:14:28.333 [] I DirectiveSequencer:onDirective:directive={"namespace:"TemplateRuntime",name:"RenderPlayerInfo",messageId:"7bbcabf9-8362-4c9b-8d38-605d54be755f",dialogRequestId:"997baef2-208a-46c7-ba1f-c08bc93c1e6e"}
2017-10-12 09:14:28.334 [] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechSynthesizer.Speak
2017-10-12 09:14:28.334 [] W DirectiveRouter:preHandleDirectiveFailed:messageId=7bbcabf9-8362-4c9b-8d38-605d54be755f,reason=noHandlerRegistered
2017-10-12 09:14:28.334 [] I DirectiveSequencer:sendingExceptionEncountered:messageId=7bbcabf9-8362-4c9b-8d38-605d54be755f
2017-10-12 09:14:28.334 [] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2017-10-12 09:14:28.334 [] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2017-10-12 09:14:28.334 [] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2017-10-12 09:14:28.334 [] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND
2017-10-12 09:14:28.335 [] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING
2017-10-12 09:14:28.335 [] 9 SpeechSynthesizer:startPlaying
2017-10-12 09:14:28.335 [] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader
2017-10-12 09:14:28.335 [] 0 EventBuilder:buildJsonEventString:messageId=276c7fae-92e4-468a-ad0e-a958befc68a4,namespace=System,name=ExceptionEncountered
2017-10-12 09:14:28.335 [] 0 MediaPlayer:handleSetSourceCalled
2017-10-12 09:14:28.335 [] 9 MediaPlayer:tearDownTransientPipelineElements
2017-10-12 09:14:28.335 [] 0 MediaPlayer:doStopSuccess:reason=alreadyStopped
2017-10-12 09:14:28.335 [] 9 MediaPlayer:doStopSuccess
2017-10-12 09:14:28.337 [] 9 MediaPlayer:playCalled
2017-10-12 09:14:28.338 [] 0 MediaPlayer:handlePlayCalled
2017-10-12 09:14:28.338 [] 0 MediaPlayer:doStopSuccess:reason=alreadyStopped
2017-10-12 09:14:28.338 [] 9 MediaPlayer:doStopSuccess
2017-10-12 09:14:28.338 [] 0 MediaPlayer:handlePlay:attemptBuffering=0
2017-10-12 09:14:28.343 [] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC
2017-10-12 09:14:28.344 [] 9 BaseStreamSource:onNeedDataCalled:size=4096
terminate called after throwing an instance of 'std::future_error'
what(): Promise already satisfied
Aborted
134|root@android:/system/avs #

[sanjayrd]

Hi @paragone,

Our MediaPlayer component has gone through several big changes over the last 2 releases. Could you try again and see if the issue is still persisting? I'm going to close this issue for now since it's a bit stale, but please reopen if you're still seeing the issue.

Thanks,
Sanjay