alexa / avs-device-sdk

An SDK for commercial device makers to integrate Alexa directly into connected products.
https://developer.amazon.com/alexa/alexa-voice-service
Apache License 2.0
1.26k stars 604 forks source link

avs-sdk-crash in speaking/thinking state #391

Closed dhananjayj29 closed 6 years ago

dhananjayj29 commented 6 years ago

Hi , I have built avs-sdk and sample app for my Linux embedded system environment. sdk version : 1.2.1 while running the sample app through command line interface , am getting the crash after every 2-3 queries . below are the detailed logs and stack trace for my crash .

below are the logs , SDK is crashing so frequently here:

2018-01-08 23:18:36.847 [ a] 9 MediaPlayer:playCalled 2018-01-08 23:18:36.848 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1 2018-01-08 23:18:36.848 [ 2] 0 MediaPlayer:handlePlay:attemptBuffering=0 2018-01-08 23:18:36.864 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2018-01-08 23:18:36.864 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.864 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.864 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.865 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.865 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.865 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.867 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.867 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.867 [ 2] 9 MediaPlayer:State Change:oldState=NULL,newState=READY,pendingState=PLAYING 2018-01-08 23:18:36.867 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.867 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.867 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2018-01-08 23:18:36.867 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.868 [ 14] 9 BaseStreamSource:onNeedDataCalled:size=4096 2018-01-08 23:18:36.868 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2018-01-08 23:18:36.868 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.868 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2018-01-08 23:18:36.868 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:36.868 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2018-01-08 23:18:36.868 [ 2] 9 BaseStreamSource:handleNeedDataCalled 2018-01-08 23:18:36.868 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=16 2018-01-08 23:18:36.869 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2018-01-08 23:18:36.869 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2018-01-08 23:18:36.869 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2018-01-08 23:18:36.869 [ 2] 9 AttachmentReaderSource:read:size=3185,status=0 2018-01-08 23:18:36.930 [ 14] 9 MediaPlayer:onPadAddedCalled 2018-01-08 23:18:37.223 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2018-01-08 23:18:37.224 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.224 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.224 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.224 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.224 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.224 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.225 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2018-01-08 23:18:37.225 [ 2] 9 MediaPlayer:handlePadAddedSignalCalled 2018-01-08 23:18:37.244 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2018-01-08 23:18:37.245 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.245 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2018-01-08 23:18:37.247 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-start 2018-01-08 23:18:37.529 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2018-01-08 23:18:37.529 [ 10] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS 2018-01-08 23:18:37.530 [ 10] 0 HTTP2Transport:cleanupFinishedStream:streamId=9,result=200 2018-01-08 23:18:37.530 [ 2] 9 MediaPlayer:messageReceived:messageType=latency 2018-01-08 23:18:37.530 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2018-01-08 23:18:37.530 [ 2] 9 MediaPlayer:messageReceived:messageType=tag 2018-01-08 23:18:37.530 [ 2] 0 MediaPlayer:callingOnTags 2018-01-08 23:18:37.531 [ 2] 9 MediaPlayer:messageReceived:messageType=tag 2018-01-08 23:18:37.531 [ 2] 0 MediaPlayer:callingOnTags 2018-01-08 23:18:37.531 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.531 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.531 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.531 [ 2] 9 MediaPlayer:State Change:oldState=READY,newState=PAUSED,pendingState=PLAYING 2018-01-08 23:18:37.531 [ 2] 9 MediaPlayer:messageReceived:messageType=async-done 2018-01-08 23:18:37.532 [ 2] 9 MediaPlayer:messageReceived:messageType=new-clock 2018-01-08 23:18:37.530 [ 10] 0 HTTP2StreamPool:releaseStream:streamId=9,numAcquiredStreams=1 2018-01-08 23:18:37.532 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.532 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.532 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.532 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.533 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.533 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.533 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.533 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.533 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.533 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.533 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.533 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2018-01-08 23:18:37.534 [ 2] 9 MediaPlayer:State Change:oldState=PAUSED,newState=PLAYING,pendingState=VOID_PENDING 2018-01-08 23:18:37.534 [ 2] 0 MediaPlayer:callingOnPlaybackStarted:currentId=1 2018-01-08 23:18:37.534 [ 2] 9 SpeechSynthesizer:onPlaybackStarted:callbackSourceId=1 2018-01-08 23:18:37.534 [ a] 0 SpeechSynthesizer:executePlaybackStarted 2018-01-08 23:18:37.534 [ 2] 9 MediaPlayer:messageReceived:messageType=tag 2018-01-08 23:18:37.534 [ a] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0 2018-01-08 23:18:37.534 [ a] 9 MediaPlayer:getOffsetCalled 2018-01-08 23:18:37.534 [ 2] 0 MediaPlayer:callingOnTags 2018-01-08 23:18:37.534 [ 2] 9 AttachmentReaderSource:read:size=1388,status=0 2018-01-08 23:18:37.535 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=1,currentId=1 2018-01-08 23:18:37.537 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"amzn1.as-ct.v1.Domain:Application:Knowledge#ACRI#1681976a-a9b0-48d7-9905-d9600e680406#Alexa3P:1.0/2e 2018-01-08 23:18:37.537 [ 13] 9 SpeechSynthesizer:onFocusChangedSuccess 2018-01-08 23:18:37.537 [ a] 0 EventBuilder:buildJsonEventString:messageId=5e253201-b5df-47ae-9663-105c8ad1889d,namespace=SpeechSynthesizer,name=SpeechStarted 2018-01-08 23:18:37.537 [ a] 9 HTTP2Transport:enqueueRequest:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechStarted","messageId":"5e253201-b5df-47ae-9663-105c8ad1889} 2018-01-08 23:18:37.538 [ 2] I InProcessAttachmentReader:readFailed:reason=SDS is closed 2018-01-08 23:18:37.878 [ 2] 9 AttachmentReaderSource:read:size=0,status=3 2018-01-08 23:18:37.878 [ 2] 9 BaseStreamSource:signalEndOfDataCalled 2018-01-08 23:18:37.878 [ 10] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechStarted","messageId":"5e253201-b5df-47ae-9663} 2018-01-08 23:18:37.879 [ 10] 0 HTTP2StreamPool:getStream:streamId=11,numAcquiredStreams=2 2018-01-08 23:18:37.879 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=16 terminate called after throwing an instance of 'std::future_error' 2018-01-08 23:18:37.879 [ 10] 9 HTTP2

(gdb) bt

0 __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:57

1 0xb6a52950 in __GI_abort () at abort.c:89

2 0xb6c3a58c in __gnu_cxx::__verbose_terminate_handler () atgcc-4.8.2-r0/gcc-4.8.2/libstdc++-v3/libsupc++/vterminate.cc:95

3 0xb6c383d8 in cxxabiv1::terminate (handler=) at /gcc-4.8.2/libstdc++-v3/libsupc++/eh_terminate.cc:38

4 0xb6c38400 in std::terminate () at /gcc-4.8.2-r0/gcc-4.8.2/libstdc++-v3/libsupc++/eh_terminate.cc:48

5 0xb6c8ca84 in std::(anonymous namespace)::execute_native_thread_routine (__p=)

atmp-eglibc/work-shared/gcc-4.8.2-r0/gcc-4.8.2/libstdc++-v3/src/c++11/thread.cc:92

6 0xb6eeb040 in start_thread (arg=0xae2ff440) at pthread_create.c:314

7 0xb6af10e0 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/clone.S:92 from //lib/libc.so.6

8 0xb6af10e0 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/clone.S:92 fromlib/libc.so.6

Backtrace stopped: previous frame identical to this frame (corrupt stack?)

Can someone help to find out root cause and possible fix for this issue.

dhananjayj29 commented 6 years ago

I have ran MediaPlayer test and below are the logs for the similar crash:

2017-12-09 08:08:28.013 [ 1] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:28.014 [ 1] 0 MediaPlayer:handleSetSourceCalled 2017-12-09 08:08:28.018 [ 1] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1 2017-12-09 08:08:28.018 [ 1] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-09 08:08:28.048 [ 1] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-09 08:08:28.140 [ 1] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:28.140 [ 1] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:28.147 [ 1] 0 MediaPlayer:callingOnPlaybackStarted:currentId=1 2017-12-09 08:08:28.149 [ 1] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:30.835 [ 1] 0 MediaPlayer:callingOnPlaybackFinished:currentId=1 [ OK ] MediaPlayerTest.testStartPlayWaitForEnd (4199 ms) [ RUN ] MediaPlayerTest.testStartPlayForUrl 2017-12-09 08:08:30.860 [ 2] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:30.860 [ 3] 0 MediaPlayer:handleSetSourceForUrlCalled 2017-12-09 08:08:30.861 [ 3] 0 UrlSource:initCalledForUrlSource 2017-12-09 08:08:30.862 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=2,currentId=2 2017-12-09 08:08:30.862 [ 2] 0 MediaPlayer:handlePlay:attemptBuffering=1 2017-12-09 08:08:30.881 [ 2] 0 MediaPlayer:handlePlay:startingState=PAUSED,stateReturn=FAILURE 2017-12-09 08:08:30.881 [ 2] E MediaPlayer:handlePlayFailed:reason=gstElementSetStateFailure 2017-12-09 08:08:30.881 [ 2] 0 MediaPlayer:callingOnPlaybackError:type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=MediaPlayer\:handlePlayFailed\:reason\=gstElementSetStateFailure,currentId=2 2017-12-09 08:08:30.881 [ 2] E MediaPlayerTest:onPlaybackError:type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=MediaPlayer\:handlePlayFailed\:reason\=gstElementSetStateFailure /home/dhananjay/AVSDevelopement/git_repos/avs-device-sdk/MediaPlayer/test/MediaPlayerTest.cpp:629: Failure Value of: m_playerObserver->waitForPlaybackStarted(sourceId) Actual: false Expected: true [ FAILED ] MediaPlayerTest.testStartPlayForUrl (5024 ms) [ RUN ] MediaPlayerTest.testSetSourceEmptyUrl 2017-12-09 08:08:35.883 [ 4] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:35.884 [ 5] 0 MediaPlayer:handleSetSourceForUrlCalled 2017-12-09 08:08:35.884 [ 5] 0 UrlSource:initCalledForUrlSource 2017-12-09 08:08:35.884 [ 5] E UrlSource:initFailed:reason=startingParsePlaylistFailed 2017-12-09 08:08:35.884 [ 5] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name=UrlSource 2017-12-09 08:08:35.885 [ 5] E MediaPlayer:handleSetSourceForUrlFailed:reason=sourceIsNullptr [ OK ] MediaPlayerTest.testSetSourceEmptyUrl (10 ms) [ RUN ] MediaPlayerTest.testConsecutiveSetSource 2017-12-09 08:08:35.892 [ 6] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:35.893 [ 7] 0 MediaPlayer:handleSetSourceForUrlCalled 2017-12-09 08:08:35.893 [ 7] 0 UrlSource:initCalledForUrlSource 2017-12-09 08:08:35.893 [ 7] E UrlSource:initFailed:reason=startingParsePlaylistFailed 2017-12-09 08:08:35.893 [ 7] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name=UrlSource 2017-12-09 08:08:35.893 [ 7] E MediaPlayer:handleSetSourceForUrlFailed:reason=sourceIsNullptr 2017-12-09 08:08:35.894 [ 8] 0 MediaPlayer:handleSetSourceForUrlCalled 2017-12-09 08:08:35.894 [ 8] 0 UrlSource:initCalledForUrlSource 2017-12-09 08:08:35.895 [ 6] 0 MediaPlayer:handlePlayCalled:idPassed=3,currentId=3 2017-12-09 08:08:35.895 [ 6] 0 MediaPlayer:handlePlay:attemptBuffering=1 2017-12-09 08:08:35.911 [ 6] 0 MediaPlayer:handlePlay:startingState=PAUSED,stateReturn=FAILURE 2017-12-09 08:08:35.911 [ 6] E MediaPlayer:handlePlayFailed:reason=gstElementSetStateFailure 2017-12-09 08:08:35.911 [ 6] 0 MediaPlayer:callingOnPlaybackError:type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=MediaPlayer\:handlePlayFailed\:reason\=gstElementSetStateFailure,currentId=3 2017-12-09 08:08:35.911 [ 6] E MediaPlayerTest:onPlaybackError:type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=MediaPlayer\:handlePlayFailed\:reason\=gstElementSetStateFailure /home/dhananjay/AVSDevelopement/git_repos/avs-device-sdk/MediaPlayer/test/MediaPlayerTest.cpp:653: Failure Value of: m_playerObserver->waitForPlaybackStarted(id) Actual: false Expected: true [ FAILED ] MediaPlayerTest.testConsecutiveSetSource (5030 ms) [ RUN ] MediaPlayerTest.testStartPlayWaitForEndStartPlayAgain 2017-12-09 08:08:40.922 [ 9] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:40.923 [ 9] 0 MediaPlayer:handleSetSourceCalled 2017-12-09 08:08:40.926 [ 9] 0 MediaPlayer:handlePlayCalled:idPassed=4,currentId=4 2017-12-09 08:08:40.926 [ 9] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-09 08:08:40.937 [ 9] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-09 08:08:41.019 [ 9] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:41.020 [ 9] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:41.025 [ 9] 0 MediaPlayer:callingOnPlaybackStarted:currentId=4 2017-12-09 08:08:41.027 [ 9] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:43.735 [ 9] 0 MediaPlayer:callingOnPlaybackFinished:currentId=4 2017-12-09 08:08:43.758 [ 9] 0 MediaPlayer:handleSetSourceCalled 2017-12-09 08:08:43.760 [ 9] 0 MediaPlayer:handlePlayCalled:idPassed=5,currentId=5 2017-12-09 08:08:43.760 [ 9] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-09 08:08:43.772 [ 9] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-09 08:08:43.850 [ 9] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:43.851 [ 9] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:43.854 [ 9] 0 MediaPlayer:callingOnPlaybackStarted:currentId=5 2017-12-09 08:08:43.860 [ 9] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:46.575 [ 9] 0 MediaPlayer:callingOnPlaybackFinished:currentId=5 [ OK ] MediaPlayerTest.testStartPlayWaitForEndStartPlayAgain (5679 ms) [ RUN ] MediaPlayerTest.testStopPlay 2017-12-09 08:08:46.603 [ a] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:46.603 [ a] 0 MediaPlayer:handleSetSourceCalled 2017-12-09 08:08:46.605 [ a] 0 MediaPlayer:handlePlayCalled:idPassed=6,currentId=6 2017-12-09 08:08:46.606 [ a] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-09 08:08:46.616 [ a] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-09 08:08:46.693 [ a] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:46.694 [ a] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:46.698 [ a] 0 MediaPlayer:callingOnPlaybackStarted:currentId=6 2017-12-09 08:08:46.712 [ a] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:51.705 [ a] 0 MediaPlayer:handleStopCalled:idPassed=6,currentId=6 2017-12-09 08:08:51.727 [ a] 0 MediaPlayer:callingOnPlaybackStopped:currentId=6 [ OK ] MediaPlayerTest.testStopPlay (5135 ms) [ RUN ] MediaPlayerTest.testStartPlayCallAfterStopPlay 2017-12-09 08:08:51.737 [ b] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:51.738 [ b] 0 MediaPlayer:handleSetSourceCalled 2017-12-09 08:08:51.740 [ b] 0 MediaPlayer:handlePlayCalled:idPassed=7,currentId=7 2017-12-09 08:08:51.740 [ b] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-09 08:08:51.751 [ b] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-09 08:08:51.827 [ b] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:51.827 [ b] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:51.830 [ b] 0 MediaPlayer:callingOnPlaybackStarted:currentId=7 2017-12-09 08:08:51.835 [ b] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:53.854 [ b] 0 MediaPlayer:handleStopCalled:idPassed=7,currentId=7 2017-12-09 08:08:53.867 [ b] 0 MediaPlayer:callingOnPlaybackStopped:currentId=7 2017-12-09 08:08:53.867 [ c] E MediaPlayer:playFailed:reason=sourceNotSet [ OK ] MediaPlayerTest.testStartPlayCallAfterStopPlay (2139 ms) [ RUN ] MediaPlayerTest.testStartPlayCallAfterStopPlayDifferentSource 2017-12-09 08:08:53.877 [ d] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:53.877 [ d] 0 MediaPlayer:handleSetSourceCalled 2017-12-09 08:08:53.879 [ d] 0 MediaPlayer:handlePlayCalled:idPassed=8,currentId=8 2017-12-09 08:08:53.879 [ d] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-09 08:08:53.889 [ d] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-09 08:08:53.970 [ d] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:53.970 [ d] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:53.972 [ d] 0 MediaPlayer:callingOnPlaybackStarted:currentId=8 2017-12-09 08:08:53.977 [ d] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:54.985 [ d] 0 MediaPlayer:handleStopCalled:idPassed=8,currentId=8 2017-12-09 08:08:54.998 [ d] 0 MediaPlayer:callingOnPlaybackStopped:currentId=8 2017-12-09 08:08:54.999 [ d] 0 MediaPlayer:handleSetSourceCalled 2017-12-09 08:08:55.001 [ d] 0 MediaPlayer:handlePlayCalled:idPassed=9,currentId=9 2017-12-09 08:08:55.001 [ d] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-09 08:08:55.011 [ d] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-09 08:08:55.090 [ d] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:55.090 [ d] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:55.102 [ d] 0 MediaPlayer:callingOnPlaybackStarted:currentId=9 2017-12-09 08:08:55.103 [ d] 0 MediaPlayer:callingOnTags 2017-12-09 08:08:56.114 [ d] 0 MediaPlayer:handleStopCalled:idPassed=9,currentId=9 2017-12-09 08:08:56.135 [ d] 0 MediaPlayer:callingOnPlaybackStopped:currentId=9 [ OK ] MediaPlayerTest.testStartPlayCallAfterStopPlayDifferentSource (2268 ms) [ RUN ] MediaPlayerTest.testPauseDuringPlay 2017-12-09 08:08:56.146 [ e] 0 MediaPlayer:handleSetObserverCalled 2017-12-09 08:08:56.146 [ e] 0 MediaPlayer:handleSetSourceCalled 2017-12-09 08:08:56.149 [ e] 0 MediaPlayer:handlePlayCalled:idPassed=10,currentId=10 terminate called after throwing an instance of 'std::future_error' what(): Promise already satisfied Stack Strace:

(gdb) bt

0 __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:57

1 0xb6be6950 in __GI_abort () at abort.c:89

2 0xb6d5d58c in __gnu_cxx::__verbose_terminate_handler () at /libsupc++/vterminate.cc:95

3 0xb6d5b3d8 in cxxabiv1::terminate (handler=) at /libsupc++/eh_terminate.cc:38

4 0xb6d5b400 in std::terminate () at eh_terminate.cc:48

5 0xb6d5b73c in cxxabiv1::cxa_throw (obj=0xb4a05ec8, tinfo=, dest=)

at /u02/yoctobms/build/info3-low/tmp-eglibc/work-shared/gcc-4.8.2-r0/gcc-4.8.2/libstdc++-v3/libsupc++/eh_throw.cc:84

6 0xb6dae824 in std::throw_future_error (i=__i@entry=2) at functexcept.cc:109

7 0xb6ed4ef0 in _M_set_result (__ignore_failure=false, __res=..., this=0x96a78) at future:360

8 std::promise::set_value(bool&&) (this=this@entry=0xb6984218 ,

__r=__r@entry=<unknown type in /usr/lib/libMediaPlayer.so, CU 0x46162, DIE 0x89a5d>)
at /future:994

9 0xb6eccbe4 in alexaClientSDK::mediaPlayer::MediaPlayer::handlePlay (this=0xa9108, id=, promise=0xbe9a383c)

at /home/dhananjay/AVSDevelopement/git_repos/avs-device-sdk/MediaPlayer/src/MediaPlayer.cpp:1026

10 0xb6eccfdc in operator() (__closure=) at avs-device-sdk/MediaPlayer/src/MediaPlayer.cpp:228

11 std::_Function_handler<int(), alexaClientSDK::mediaPlayer::MediaPlayer::play(alexaClientSDK::avsCommon::utils::mediaPlayer::MediaPlayerInterface::SourceId)::lambda9>::_M_invoke(const std::_Any_data &) (functor=...) at /functional:2056

12 0xb69878dc in g_main_dispatch (context=0x26b000) at gmain.c:3154

13 g_main_context_dispatch (context=context@entry=0x26b000) at gmain.c:3769

14 0xb6987c44 in g_main_context_iterate (context=0x26b000, block=block@entry=1, dispatch=dispatch@entry=1, self=) at gmain.c:3840

15 0xb6987fa0 in g_main_loop_run (loop=0xad370) at gmain.c:4034

16 0xb6daf9a8 in std::(anonymous namespace)::execute_native_thread_routine (__p=)

at thread.cc:84

17 0xb6de4040 in start_thread (arg=0xb5373450) at pthread_create.c:314

18 0xb6c850e0 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/clone.S:92 from lib/libc.so.6

19 0xb6c850e0 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/clone.S:92 from lib/libc.so.6

Backtrace stopped: previous frame identical to this frame (corrupt stack?)

sanjayrd commented 6 years ago

Hi @dhananjayj29,

Would it be possible for you to upgrade to v1.3? We've made significant stability improvements in this release and we believe it should solve the crash you are seeing.

If not, could you give me some reproduction steps so that I can try to reproduce locally?

Thanks, Sanjay

dhananjayj29 commented 6 years ago

Hi Thanks for the reply, I have moved to 1.3 version and there are improvements seen for this issue. On previous version it crashed / aborted after every 2-3 times . and in latest v1.3 version it is aborting 1 out of 10 times.

Below are the logs

2017-12-08 23:27:08.369 [ 10] I InProcessAttachmentReader:readFailed:reason=SDS is closed 2017-12-08 23:27:09.002 [ 10] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0279dafffe599f4c-000043e3-0003c553-22557efc9270e84b-d17d1d20-41 2017-12-08 23:27:09.304 [ b] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechSynthesizer"\,name\:"Speak"\,messageId\:"1454533d-3b5b-42c3-a123-6c867f11a010"\,dialogRequestId\:"83492d12-029d} 2017-12-08 23:27:09.305 [ c] I DirectiveRouter:preHandleDirective:messageId=1454533d-3b5b-42c3-a123-6c867f11a010,action=calling 2017-12-08 23:27:09.305 [ c] 0 CapabilityAgent:addingMessageIdToMap:messageId=1454533d-3b5b-42c3-a123-6c867f11a010 2017-12-08 23:27:09.305 [ c] 9 SpeechSynthesizer:preHandleDirective:messageId=1454533d-3b5b-42c3-a123-6c867f11a010 2017-12-08 23:27:09.305 [ d] I DirectiveRouter:handleDirective:messageId=1454533d-3b5b-42c3-a123-6c867f11a010,action=calling 2017-12-08 23:27:09.305 [ 8] 0 SpeechSynthesizer:executePreHandle:messageId=1454533d-3b5b-42c3-a123-6c867f11a010 2017-12-08 23:27:09.305 [ d] 9 SpeechSynthesizer:handleDirective:messageId=1454533d-3b5b-42c3-a123-6c867f11a010 2017-12-08 23:27:09.310 [ 8] 0 SpeechSynthesizer:executeHandle:messageId=1454533d-3b5b-42c3-a123-6c867f11a010 2017-12-08 23:27:09.310 [ 8] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechSynthesizer.Speak 2017-12-08 23:27:09.311 [ 12] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE 2017-12-08 23:27:09.311 [ 12] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND 2017-12-08 23:27:09.311 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE 2017-12-08 23:27:09.312 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus 2017-12-08 23:27:09.312 [ 9] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE 2017-12-08 23:27:09.312 [ 12] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS 2017-12-08 23:27:09.312 [ 8] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING 2017-12-08 23:27:09.312 [ 8] 9 SpeechSynthesizer:startPlaying 2017-12-08 23:27:09.312 [ 8] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader 2017-12-08 23:27:09.312 [ 2] 0 MediaPlayer:handleSetSourceCalled 2017-12-08 23:27:09.312 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2017-12-08 23:27:09.313 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-08 23:27:09.315 [ 8] 9 MediaPlayer:playCalled 2017-12-08 23:27:09.316 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=7,currentId=7 terminate called after throwing an instance of 'std::future_error' what(): Promise already satisfied

Reproduction steps: Environment: linux embedded device , sdk v1.3

  1. Start Sample APP
  2. Press t on command line
  3. Ask query
  4. repeat steps 1 to 3 for sevaral times . (10 times) Sample app will abort from MediaPlayer handlePlayCalled() API.

Also can be reproduced by simply executing MediaPlayer test

sanjayrd commented 6 years ago

Hi @dhananjayj29,

Unfortunately, I was unable to reproduce this in my environment. However, it looks the error is coming from here. Could you maybe sprinkle in some log messages in there to see exactly when/where the promise is being set twice? From what I'm seeing in the code, anytime a promise is set, it immediately returns.

Thanks, Sanjay

anu-mathur commented 6 years ago

Hi @dhananjayj29 Can we talk more about your use case with the AVS Device SDK? Please fill out this Contact Form and I will get in touch with you! Thanks

dhananjayj29 commented 6 years ago

Thanks anu-mathur I filled the form. I will paste the logs

dhananjayj29 commented 6 years ago

I have added the logs in the suggested functions as below:

void MediaPlayer::handlePlay(SourceId id, std::promise* promise) { ACSDK_DEBUG(LX("handlePlayCalled").d("idPassed", id).d("currentId", (m_currentId))); if (!validateSourceAndId(id)) { ACSDK_ERROR(LX("handlePlayFailed")); promise->set_value(false); return; } ACSDK_DEBUG(LX("handlePlayCalled after validate source and ID \n"));

GstState curState;
auto stateChange = gst_element_get_state(m_pipeline.pipeline, &curState, NULL, TIMEOUT_ZERO_NANOSECONDS);
if (stateChange == GST_STATE_CHANGE_FAILURE) {
    ACSDK_ERROR(LX("handlePlayFailed").d("reason", "gstElementGetStateFailed"));
    promise->set_value(false);
    return;
}
ACSDK_DEBUG(LX("handlePlayCalled after gst_element_get_state\n"));

if (curState == GST_STATE_PLAYING) {
    ACSDK_DEBUG(LX("handlePlayFailed").d("reason", "alreadyPlaying"));
    promise->set_value(false);
    return;
}
ACSDK_DEBUG(LX("handlePlayCalled after GST_STATE_PLAYING\n"));
if (m_playPending) {
    ACSDK_DEBUG(LX("handlePlayFailed").d("reason", "playCurrentlyPending"));
    promise->set_value(false);
    return;
}

ACSDK_DEBUG(LX("handlePlayCalled before set state\n"));
m_playbackFinishedSent = false;
m_playbackStartedSent = false;
m_playPending = true;
m_pauseImmediately = false;
promise->set_value(true);

gboolean attemptBuffering;
g_object_get(m_pipeline.decoder, "use-buffering", &attemptBuffering, NULL);
ACSDK_DEBUG(LX("handlePlay").d("attemptBuffering", attemptBuffering));

GstState startingState = GST_STATE_PLAYING;
if (attemptBuffering) {
    /*
     * Set pipeline to PAUSED state to attempt buffering.
     * The pipeline will be set to PLAY in two ways:
     * i) If buffering is supported, then upon receiving buffer percent = 100.
     * ii) If buffering is not supported, then the pipeline will be set to PLAY immediately.
     */
    startingState = GST_STATE_PAUSED;
}

stateChange = gst_element_set_state(m_pipeline.pipeline, startingState);
ACSDK_DEBUG(LX("handlePlay")
                .d("startingState", gst_element_state_get_name(startingState))
                                                                                                                                                                                       1127,19       74%

Below are the details of crash out of 10 times system crashed 4 times with below logs:

########################################

2017-12-19 15:14:42.570 [ 3] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=CONNECTED,reason=ACL_CLIENT_REQUEST 2017-12-19 15:15:16.800 [ 9] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING 2017-12-19 15:15:16.802 [ 11] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING 2017-12-19 15:15:16.802 [ 6] 0 ContextManager:buildContextSuccessful:context={"context"\:[{"header"\:{"namespace"\:"Speaker"\,"name"\:"VolumeState"}\,"payload"\:{"volume"\:100\,"muted"\:false}}\,{"header} 2017-12-19 15:15:16.803 [ 9] 0 AudioInputProcessor:executeOnContextAvailable:jsonContext={"context"\:[{"header"\:{"namespace"\:"Speaker"\,"name"\:"VolumeState"}\,"payload"\:{"volume"\:100\,"muted"\:false} 2017-12-19 15:15:16.803 [ 9] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechRecognizer.Recognize ############################

Listening...

############################

2017-12-19 15:15:16.804 [ 12] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND 2017-12-19 15:15:16.803 [ 9] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=,newValue=2cbaf616-7d1f-4522-a9cf-6364d3399fc9 2017-12-19 15:15:16.804 [ 9] 0 DirectiveProcessor:scrubDialogRequestIdLocked:reason=emptyDialogRequestId 2017-12-19 15:15:16.805 [ 9] 0 EventBuilder:buildJsonEventString:messageId=02cab8a7-e20e-4f35-ae8d-7ae31a2c3333,namespace=SpeechRecognizer,name=Recognize 2017-12-19 15:15:16.805 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND 2017-12-19 15:15:16.805 [ 9] 9 HTTP2Transport:enqueueRequest:jsonContent={"context"\:[{"header"\:{"namespace"\:"Speaker"\,"name"\:"VolumeState"}\,"payload"\:{"volume"\:100\,"muted"\:false}}\,{"header"\:{} 2017-12-19 15:15:16.907 [ 10] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"context"\:[{"header"\:{"namespace"\:"Speaker"\,"name"\:"VolumeState"}\,"payload"\:{"volume"\:100\,"muted"\:false}}\,} 2017-12-19 15:15:16.907 [ 10] 0 HTTP2StreamPool:getStream:streamId=9,numAcquiredStreams=2 2017-12-19 15:15:16.908 [ 10] 9 HTTP2Transport:insertActiveStream:handle=0xb32b3ad8 2017-12-19 15:15:16.908 [ 10] I HTTP2Stream:libcurl:streamId=9,text=Found bundle for host avs-alexa-eu.amazon.com\: 0xb3201910 [can multiplex] 2017-12-19 15:15:16.908 [ 10] I HTTP2Stream:libcurl:streamId=9,text=Conn\: 0 (0xb32019b0) Receive pipe weight\: (-1/0)\, penalized\: (nil) 2017-12-19 15:15:16.908 [ 10] I HTTP2Stream:libcurl:streamId=9,text=Multiplexed connection found! 2017-12-19 15:15:16.908 [ 10] I HTTP2Stream:libcurl:streamId=9,text=Found connection 0\, with requests in the pipe (1) 2017-12-19 15:15:16.908 [ 10] I HTTP2Stream:libcurl:streamId=9,text=Re-using existing connection! (#0) with host avs-alexa-eu.amazon.com 2017-12-19 15:15:16.909 [ 10] I HTTP2Stream:libcurl:streamId=9,text=Using Stream ID\: 5 (easy handle 0xb32b3ad8) 2017-12-19 15:15:20.509 [ b] 0 MessageInterpreter:receive:messageId=79ccf874-38b2-4da2-b77a-c7affc317197:No dialogRequestId attached to message. 2017-12-19 15:15:20.509 [ b] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechRecognizer"\,name\:"StopCapture"\,messageId\:"79ccf874-38b2-4da2-b77a-c7affc317197"\,dialogRequestId\:""} 2017-12-19 15:15:20.509 [ c] I DirectiveRouter:preHandleDirective:messageId=79ccf874-38b2-4da2-b77a-c7affc317197,action=calling 2017-12-19 15:15:20.509 [ c] 0 CapabilityAgent:addingMessageIdToMap:messageId=79ccf874-38b2-4da2-b77a-c7affc317197 2017-12-19 15:15:20.510 [ d] I DirectiveRouter:handleDirective:messageId=79ccf874-38b2-4da2-b77a-c7affc317197,action=calling 2017-12-19 15:15:20.510 [ 9] 0 AudioInputProcessor:stopCapture:stopImmediately=true 2017-12-19 15:15:20.510 [ 9] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY 2017-12-19 15:15:20.510 [ 9] 0 DirectiveProcessor:onHandlingCompeted:messageId=79ccf874-38b2-4da2-b77a-c7affc317197,directiveBeingPreHandled=(nullptr) 2017-12-19 15:15:20.510 [ 9] 0 CapabilityAgent:removingMessageIdFromMap:messageId=79ccf874-38b2-4da2-b77a-c7affc317197 2017-12-19 15:15:20.510 [ 11] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING ###########################

Thinking...

###########################

2017-12-19 15:15:20.527 [ 10] I InProcessAttachmentReader:readFailed:reason=SDS is closed 2017-12-19 15:15:21.209 [ 10] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 066737fffe5f62a4-00007f15-0006a7b8-1ac754cedc881332-08e1603b-5 2017-12-19 15:15:21.517 [ b] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechSynthesizer"\,name\:"Speak"\,messageId\:"dbea3066-7e8e-481d-95dd-df4699a03886"\,dialogRequestId\:"2cbaf616-7d1f} 2017-12-19 15:15:21.517 [ c] I DirectiveRouter:preHandleDirective:messageId=dbea3066-7e8e-481d-95dd-df4699a03886,action=calling 2017-12-19 15:15:21.517 [ c] 0 CapabilityAgent:addingMessageIdToMap:messageId=dbea3066-7e8e-481d-95dd-df4699a03886 2017-12-19 15:15:21.518 [ c] 9 SpeechSynthesizer:preHandleDirective:messageId=dbea3066-7e8e-481d-95dd-df4699a03886 2017-12-19 15:15:21.518 [ 8] 0 SpeechSynthesizer:executePreHandle:messageId=dbea3066-7e8e-481d-95dd-df4699a03886 2017-12-19 15:15:21.518 [ d] I DirectiveRouter:handleDirective:messageId=dbea3066-7e8e-481d-95dd-df4699a03886,action=calling 2017-12-19 15:15:21.518 [ d] 9 SpeechSynthesizer:handleDirective:messageId=dbea3066-7e8e-481d-95dd-df4699a03886 2017-12-19 15:15:21.522 [ 8] 0 SpeechSynthesizer:executeHandle:messageId=dbea3066-7e8e-481d-95dd-df4699a03886 2017-12-19 15:15:21.523 [ 8] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechSynthesizer.Speak 2017-12-19 15:15:21.523 [ 12] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE 2017-12-19 15:15:21.523 [ 12] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND 2017-12-19 15:15:21.523 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE 2017-12-19 15:15:21.523 [ 12] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS 2017-12-19 15:15:21.523 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus 2017-12-19 15:15:21.524 [ 9] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE 2017-12-19 15:15:21.524 [ 8] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING 2017-12-19 15:15:21.524 [ 8] 9 SpeechSynthesizer:startPlaying 2017-12-19 15:15:21.524 [ 8] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader 2017-12-19 15:15:21.524 [ 2] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 15:15:21.524 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2017-12-19 15:15:21.525 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 15:15:21.547 [ 8] 9 MediaPlayer:playCalled 2017-12-19 15:15:21.547 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1 2017-12-19 15:15:21.547 [ 2] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 15:15:21.548 [ 2] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 15:15:21.548 [ 2] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 15:15:21.548 [ 2] 0 MediaPlayer:handlePlayCalled before set state

2 times it crashed with below logs:

:20:22.266 [ 9] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING 2017-12-19 15:20:22.267 [ 11] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING 2017-12-19 15:20:22.267 [ 6] 0 ContextManager:buildContextSuccessful:context={"context"\:[{"header"\:{"namespace"\:"Speaker"\,"name"\:"VolumeState"}\,"payload"\:{"volume"\:100\,"muted"\:false}}\,{"header} 2017-12-19 15:20:22.268 [ 9] 0 AudioInputProcessor:executeOnContextAvailable:jsonContext={"context"\:[{"header"\:{"namespace"\:"Speaker"\,"name"\:"VolumeState"}\,"payload"\:{"volume"\:100\,"muted"\:false} 2017-12-19 15:20:22.268 [ 9] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechRecognizer.Recognize 2017-12-19 15:20:22.268 [ 9] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=83e9feb8-3b84-4d6e-95c8-b0c8f615e77e,newValue=c8806c59-e64c-4b87-a0b7-1b5fd104f07b 2017-12-19 15:20:22.268 [ 9] 0 DirectiveProcessor:scrubDialogRequestIdLocked:dialogRequestId=83e9feb8-3b84-4d6e-95c8-b0c8f615e77e 2017-12-19 15:20:22.269 [ 9] 0 EventBuilder:buildJsonEventString:messageId=d8affa2c-7d50-4321-bba1-b79986226e78,namespace=SpeechRecognizer,name=Recognize 2017-12-19 15:20:22.269 [ 12] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND 2017-12-19 15:20:22.269 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND 2017-12-19 15:20:22.270 [ 9] 9 HTTP2Transport:enqueueRequest:jsonContent={"context"\:[{"header"\:{"namespace"\:"Speaker"\,"name"\:"VolumeState"}\,"payload"\:{"volume"\:100\,"muted"\:false}}\,{"header"\:{} ############################

Listening...

############################

2017-12-19 15:20:22.297 [ 10] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"context"\:[{"header"\:{"namespace"\:"Speaker"\,"name"\:"VolumeState"}\,"payload"\:{"volume"\:100\,"muted"\:false}}\,} 2017-12-19 15:20:22.638 [ 10] 0 HTTP2StreamPool:getStream:streamId=15,numAcquiredStreams=2 2017-12-19 15:20:22.638 [ 10] 9 HTTP2Transport:insertActiveStream:handle=0xb3ccba58 2017-12-19 15:20:22.639 [ 10] I HTTP2Stream:libcurl:streamId=15,text=Found bundle for host avs-alexa-eu.amazon.com\: 0xb3c19ae0 [can multiplex] 2017-12-19 15:20:22.639 [ 10] I HTTP2Stream:libcurl:streamId=15,text=Conn\: 0 (0xb3c19418) Receive pipe weight\: (-1/0)\, penalized\: (nil) 2017-12-19 15:20:22.639 [ 10] I HTTP2Stream:libcurl:streamId=15,text=Multiplexed connection found! 2017-12-19 15:20:22.639 [ 10] I HTTP2Stream:libcurl:streamId=15,text=Found connection 0\, with requests in the pipe (1) 2017-12-19 15:20:22.639 [ 10] I HTTP2Stream:libcurl:streamId=15,text=Re-using existing connection! (#0) with host avs-alexa-eu.amazon.com 2017-12-19 15:20:22.640 [ 10] I HTTP2Stream:libcurl:streamId=15,text=Using Stream ID\: b (easy handle 0xb3ccba58) 2017-12-19 15:20:26.700 [ b] 0 MessageInterpreter:receive:messageId=b132def7-81fb-4427-ae7b-207f112b9ce1:No dialogRequestId attached to message. 2017-12-19 15:20:26.700 [ b] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechRecognizer"\,name\:"StopCapture"\,messageId\:"b132def7-81fb-4427-ae7b-207f112b9ce1"\,dialogRequestId\:""} 2017-12-19 15:20:26.700 [ c] I DirectiveRouter:preHandleDirective:messageId=b132def7-81fb-4427-ae7b-207f112b9ce1,action=calling 2017-12-19 15:20:26.700 [ c] 0 CapabilityAgent:addingMessageIdToMap:messageId=b132def7-81fb-4427-ae7b-207f112b9ce1 2017-12-19 15:20:26.701 [ d] I DirectiveRouter:handleDirective:messageId=b132def7-81fb-4427-ae7b-207f112b9ce1,action=calling 2017-12-19 15:20:26.701 [ 9] 0 AudioInputProcessor:stopCapture:stopImmediately=true 2017-12-19 15:20:26.701 [ 9] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY 2017-12-19 15:20:26.701 [ 9] 0 DirectiveProcessor:onHandlingCompeted:messageId=b132def7-81fb-4427-ae7b-207f112b9ce1,directiveBeingPreHandled=(nullptr) 2017-12-19 15:20:26.701 [ 9] 0 CapabilityAgent:removingMessageIdFromMap:messageId=b132def7-81fb-4427-ae7b-207f112b9ce1 2017-12-19 15:20:26.701 [ 11] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING ###########################

Thinking...

###########################

2017-12-19 15:20:26.718 [ 10] I InProcessAttachmentReader:readFailed:reason=SDS is closed 2017-12-19 15:20:27.401 [ 10] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0248bbfffe45d0a6-0000486d-0006ad24-e108796344105224-c82fe2d2-11 2017-12-19 15:20:27.762 [ b] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechSynthesizer"\,name\:"Speak"\,messageId\:"72fcd302-0f99-4462-b2e2-09b57594d611"\,dialogRequestId\:"c8806c59-e64c} 2017-12-19 15:20:27.763 [ c] I DirectiveRouter:preHandleDirective:messageId=72fcd302-0f99-4462-b2e2-09b57594d611,action=calling 2017-12-19 15:20:27.763 [ c] 0 CapabilityAgent:addingMessageIdToMap:messageId=72fcd302-0f99-4462-b2e2-09b57594d611 2017-12-19 15:20:27.763 [ c] 9 SpeechSynthesizer:preHandleDirective:messageId=72fcd302-0f99-4462-b2e2-09b57594d611 2017-12-19 15:20:27.763 [ 7] 0 SpeechSynthesizer:executePreHandle:messageId=72fcd302-0f99-4462-b2e2-09b57594d611 2017-12-19 15:20:27.763 [ d] I DirectiveRouter:handleDirective:messageId=72fcd302-0f99-4462-b2e2-09b57594d611,action=calling 2017-12-19 15:20:27.763 [ d] 9 SpeechSynthesizer:handleDirective:messageId=72fcd302-0f99-4462-b2e2-09b57594d611 2017-12-19 15:20:27.766 [ 7] 0 SpeechSynthesizer:executeHandle:messageId=72fcd302-0f99-4462-b2e2-09b57594d611 2017-12-19 15:20:27.766 [ 7] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechSynthesizer.Speak 2017-12-19 15:20:27.766 [ 12] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE 2017-12-19 15:20:27.767 [ 12] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND 2017-12-19 15:20:27.767 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE 2017-12-19 15:20:27.767 [ 12] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS 2017-12-19 15:20:27.767 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus 2017-12-19 15:20:27.767 [ 9] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE 2017-12-19 15:20:27.767 [ 7] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING 2017-12-19 15:20:27.767 [ 7] 9 SpeechSynthesizer:startPlaying 2017-12-19 15:20:27.769 [ 7] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader 2017-12-19 15:20:27.770 [ 2] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 15:20:27.770 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2017-12-19 15:20:27.770 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 15:20:27.772 [ 7] 9 MediaPlayer:playCalled 2017-12-19 15:20:27.772 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=2,currentId=2 2017-12-19 15:20:27.772 [ 2] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 15:20:27.773 [ 2] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 15:20:27.773 [ 2] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 15:20:27.773 [ 2] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 15:20:27.773 [ 2] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 15:20:27.789 [ 2] 9 AttachmentReaderSource:handleSeekData:offset=0 2017-12-19 15:20:27.790 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 15:20:27.790 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.790 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.790 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.790 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.790 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.790 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.790 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:State Change:oldState=NULL,newState=READY,pendingState=PLAYING 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:20:27.791 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:27.792 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:20:28.132 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:20:27.792 [ 14] 9 BaseStreamSource:onNeedDataCalled:size=4096 2017-12-19 15:20:28.132 [ 2] 9 BaseStreamSource:handleNeedDataCalled 2017-12-19 15:20:28.133 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=19 2017-12-19 15:20:28.133 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.133 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.133 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.133 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.133 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.133 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.133 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.134 [ 2] 9 AttachmentReaderSource:read:size=3187,status=0 2017-12-19 15:20:28.151 [ 14] 9 MediaPlayer:onPadAddedCalled 2017-12-19 15:20:28.373 [ 10] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS 2017-12-19 15:20:28.374 [ 10] 0 HTTP2Transport:cleanupFinishedStream:streamId=15,result=200 2017-12-19 15:20:28.374 [ 10] 0 HTTP2StreamPool:releaseStream:streamId=15,numAcquiredStreams=1 2017-12-19 15:20:28.374 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.374 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.374 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.374 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.375 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.375 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.375 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.375 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:20:28.375 [ 2] 9 MediaPlayer:handlePadAddedSignalCalled 2017-12-19 15:20:28.404 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.404 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-start 2017-12-19 15:20:28.404 [ 2] 9 AttachmentReaderSource:read:size=3914,status=0 2017-12-19 15:20:28.404 [ 2] I InProcessAttachmentReader:readFailed:reason=SDS is closed 2017-12-19 15:20:28.404 [ 2] 9 AttachmentReaderSource:read:size=0,status=3 2017-12-19 15:20:28.404 [ 2] 9 AttachmentReaderSource:handleReadData:info=signalingEndOfData 2017-12-19 15:20:28.404 [ 2] 9 BaseStreamSource:signalEndOfDataCalled 2017-12-19 15:20:28.404 [ 2] 9 BaseStreamSource:gstAppSrcEndOfStreamSuccess 2017-12-19 15:20:28.406 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=19 2017-12-19 15:20:28.443 [ 2] 9 MediaPlayer:messageReceived:messageType=latency 2017-12-19 15:20:28.445 [ 2] 9 MediaPlayer:messageReceived:messageType=tag 2017-12-19 15:20:28.445 [ 2] 0 MediaPlayer:callingOnTags 2017-12-19 15:20:28.446 [ 2] 9 MediaPlayer:messageReceived:messageType=tag 2017-12-19 15:20:28.446 [ 2] 0 MediaPlayer:callingOnTags 2017-12-19 15:20:28.446 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.446 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.446 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.446 [ 2] 9 MediaPlayer:State Change:oldState=READY,newState=PAUSED,pendingState=PLAYING 2017-12-19 15:20:28.446 [ 2] 9 MediaPlayer:messageReceived:messageType=async-done 2017-12-19 15:20:28.446 [ 2] 9 MediaPlayer:messageReceived:messageType=new-clock 2017-12-19 15:20:28.447 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:20:28.449 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.449 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.449 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.449 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.449 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.449 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.449 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.450 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.450 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.450 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.450 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.450 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:20:28.450 [ 2] 9 MediaPlayer:State Change:oldState=PAUSED,newState=PLAYING,pendingState=VOID_PENDING 2017-12-19 15:20:28.450 [ 2] 0 MediaPlayer:callingOnPlaybackStarted:currentId=2 2017-12-19 15:20:28.450 [ 2] 9 SpeechSynthesizer:onPlaybackStarted:callbackSourceId=2 2017-12-19 15:20:28.450 [ 7] 0 SpeechSynthesizer:executePlaybackStarted 2017-12-19 15:20:28.450 [ 7] 9 SpeechSynthesizer:setCurrentStateLocked:state=PLAYING 2017-12-19 15:20:28.450 [ 7] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0 2017-12-19 15:20:28.451 [ 7] 9 MediaPlayer:getOffsetCalled 2017-12-19 15:20:28.451 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=2,currentId=2 2017-12-19 15:20:28.451 [ 7] 0 ContextManager:updateStateLocked:action=updatedState,state={"token"\:"amzn1.as-ct.v1.Domain\:Application\:Knowledge#ACRI#2af004b9-c075-4724-99e0-fc03f36e12f4#Alexa3P\:1.0/2e 2017-12-19 15:20:28.451 [ 12] 9 SpeechSynthesizer:onFocusChangedSuccess 2017-12-19 15:20:28.452 [ 7] 0 EventBuilder:buildJsonEventString:messageId=80830356-acee-4911-b873-a5d1f978a41f,namespace=SpeechSynthesizer,name=SpeechStarted 2017-12-19 15:20:28.792 [ 7] 9 HTTP2Transport:enqueueRequest:jsonContent={"event"\:{"header"\:{"namespace"\:"SpeechSynthesizer"\,"name"\:"SpeechStarted"\,"messageId"\:"80830356-acee-4911-b873-a5d1f978a41} 2017-12-19 15:20:28.452 [ 11] 0 DialogUXStateAggregator:setState:from=THINKING,to=SPEAKING 2017-12-19 15:20:28.454 [ 2] 9 MediaPlayer:messageReceived:messageType=tag ###########################

and single time it stuck with below logs:

17-12-19 15:23:05.767 [ c] 9 SpeechSynthesizer:preHandleDirective:messageId=10439ed8-cb51-42dc-852b-0983d033a224 2017-12-19 15:23:05.767 [ d] I DirectiveRouter:handleDirective:messageId=10439ed8-cb51-42dc-852b-0983d033a224,action=calling 2017-12-19 15:23:05.768 [ d] 9 SpeechSynthesizer:handleDirective:messageId=10439ed8-cb51-42dc-852b-0983d033a224 2017-12-19 15:23:05.768 [ 8] 0 SpeechSynthesizer:executePreHandle:messageId=10439ed8-cb51-42dc-852b-0983d033a224 2017-12-19 15:23:05.771 [ 8] 0 SpeechSynthesizer:executeHandle:messageId=10439ed8-cb51-42dc-852b-0983d033a224 2017-12-19 15:23:05.771 [ 8] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechSynthesizer.Speak 2017-12-19 15:23:05.772 [ 12] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE 2017-12-19 15:23:05.772 [ 12] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND 2017-12-19 15:23:05.772 [ 12] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS 2017-12-19 15:23:05.772 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE 2017-12-19 15:23:05.772 [ 9] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus 2017-12-19 15:23:05.772 [ 9] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE 2017-12-19 15:23:05.772 [ 8] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING 2017-12-19 15:23:05.772 [ 8] 9 SpeechSynthesizer:startPlaying 2017-12-19 15:23:05.772 [ 8] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader 2017-12-19 15:23:05.773 [ 2] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 15:23:05.773 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2017-12-19 15:23:05.773 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 15:23:05.775 [ 8] 9 MediaPlayer:playCalled 2017-12-19 15:23:05.776 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=2,currentId=2 2017-12-19 15:23:05.776 [ 2] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 15:23:05.776 [ 2] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 15:23:05.776 [ 2] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 15:23:05.776 [ 2] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 15:23:05.776 [ 2] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 15:23:05.796 [ 2] 9 AttachmentReaderSource:handleSeekData:offset=0 2017-12-19 15:23:05.796 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 15:23:05.796 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:State Change:oldState=NULL,newState=READY,pendingState=PLAYING 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.797 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.798 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:23:05.798 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.798 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.798 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:23:05.798 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:05.798 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:23:05.799 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:23:05.799 [ 14] 9 BaseStreamSource:onNeedDataCalled:size=4096 2017-12-19 15:23:06.139 [ 2] 9 BaseStreamSource:handleNeedDataCalled 2017-12-19 15:23:06.139 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=19 2017-12-19 15:23:06.139 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.140 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.140 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.140 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.140 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.140 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.140 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.140 [ 2] 9 AttachmentReaderSource:read:size=3187,status=0 2017-12-19 15:23:06.167 [ 14] 9 MediaPlayer:onPadAddedCalled 2017-12-19 15:23:06.408 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.409 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:06.409 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:06.409 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:06.409 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:06.409 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:06.409 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:06.409 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.409 [ 2] 9 MediaPlayer:handlePadAddedSignalCalled 2017-12-19 15:23:06.448 [ 2] 9 MediaPlayer:messageReceived:messageType=state-changed 2017-12-19 15:23:06.448 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-start 2017-12-19 15:23:06.448 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.448 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.630 [ f] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS 2017-12-19 15:23:06.630 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.630 [ 2] 9 MediaPlayer:messageReceived:messageType=latency 2017-12-19 15:23:06.630 [ 2] 9 MediaPlayer:messageReceived:messageType=tag 2017-12-19 15:23:06.631 [ 2] 0 MediaPlayer:callingOnTags 2017-12-19 15:23:06.631 [ 2] 9 MediaPlayer:messageReceived:messageType=tag 2017-12-19 15:23:06.631 [ 2] 0 MediaPlayer:callingOnTags 2017-12-19 15:23:06.632 [ 2] 9 MediaPlayer:messageReceived:messageType=stream-status 2017-12-19 15:23:06.632 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.633 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 2017-12-19 15:23:06.633 [ 2] 9 AttachmentReaderSource:read:size=1866,status=0 2017-12-19 15:23:06.633 [ 2] I InProcessAttachmentReader:readFailed:reason=SDS is closed 2017-12-19 15:23:06.633 [ 2] 9 AttachmentReaderSource:read:size=0,status=3 2017-12-19 15:23:06.633 [ 2] 9 AttachmentReaderSource:handleReadData:info=signalingEndOfData 2017-12-19 15:23:06.633 [ 2] 9 BaseStreamSource:signalEndOfDataCalled 2017-12-19 15:23:06.633 [ 2] 9 BaseStreamSource:gstAppSrcEndOfStreamSuccess 2017-12-19 15:23:06.634 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=19 2017-12-19 15:23:06.634 [ f] 0 HTTP2Transport:cleanupFinishedStream:streamId=15,result=200 2017-12-19 15:23:06.634 [ f] 0 HTTP2StreamPool:releaseStream:streamId=15,numAcquiredStreams=1 I have moved to v1.3.0 version and still lots of crashes are seen , pl suggest the solution.

dhananjayj29 commented 6 years ago

Hi Any updates on this issue ?

mradulan commented 6 years ago

@dhananjayj29 , looking into the issue, do you still see it when your run MediaPlayer tests? or only from the Sample App interaction.

dhananjayj29 commented 6 years ago

Hi mradulan , It crashed even with MediaPlayerTest below are the logs:

crash 1:

[==========] Running 35 tests from 1 test case. [----------] Global test environment set-up. [----------] 35 tests from MediaPlayerTest [ RUN ] MediaPlayerTest.testStartPlayWaitForEnd 2017-12-19 12:01:39.925 [ 1] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:01:39.926 [ 1] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:39.926 [ 1] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:39.944 [ 1] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1 2017-12-19 12:01:39.944 [ 1] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:40.022 [ 1] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:40.149 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:40.150 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:40.159 [ 1] 0 MediaPlayer:callingOnPlaybackStarted:currentId=1 2017-12-19 12:01:40.160 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:42.848 [ 1] 0 MediaPlayer:callingOnPlaybackFinished:currentId=1 2017-12-19 12:01:42.849 [ 1] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:01:42.860 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayWaitForEnd (5356 ms) [ RUN ] MediaPlayerTest.testStartPlayWaitForEndStartPlayAgain 2017-12-19 12:01:42.866 [ 3] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:01:42.867 [ 3] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:42.867 [ 3] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:42.870 [ 3] 0 MediaPlayer:handlePlayCalled:idPassed=2,currentId=2 2017-12-19 12:01:42.870 [ 3] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:42.885 [ 3] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:42.972 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:42.972 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:42.976 [ 3] 0 MediaPlayer:callingOnPlaybackStarted:currentId=2 2017-12-19 12:01:42.988 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:45.668 [ 3] 0 MediaPlayer:callingOnPlaybackFinished:currentId=2 2017-12-19 12:01:45.669 [ 3] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:01:45.690 [ 3] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:45.691 [ 3] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:45.693 [ 3] 0 MediaPlayer:handlePlayCalled:idPassed=3,currentId=3 2017-12-19 12:01:45.693 [ 3] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:45.708 [ 3] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:45.790 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:45.790 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:45.791 [ 3] 0 MediaPlayer:callingOnPlaybackStarted:currentId=3 2017-12-19 12:01:45.797 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:48.478 [ 3] 0 MediaPlayer:callingOnPlaybackFinished:currentId=3 2017-12-19 12:01:48.479 [ 3] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:01:48.499 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayWaitForEndStartPlayAgain (5638 ms) [ RUN ] MediaPlayerTest.testStopPlay 2017-12-19 12:01:48.506 [ 4] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:01:48.506 [ 4] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:48.507 [ 4] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:48.510 [ 4] 0 MediaPlayer:handlePlayCalled:idPassed=4,currentId=4 2017-12-19 12:01:48.510 [ 4] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:48.526 [ 4] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:48.611 [ 4] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:48.612 [ 4] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:48.616 [ 4] 0 MediaPlayer:callingOnPlaybackStarted:currentId=4 2017-12-19 12:01:48.626 [ 4] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:53.639 [ 4] 0 MediaPlayer:handleStopCalled:idPassed=4,currentId=4 2017-12-19 12:01:53.652 [ 4] 0 MediaPlayer:callingOnPlaybackStopped:currentId=4 2017-12-19 12:01:53.653 [ 4] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:53.656 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStopPlay (5157 ms) [ RUN ] MediaPlayerTest.testStartPlayCallAfterStopPlay 2017-12-19 12:01:53.663 [ 5] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:01:53.663 [ 5] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:53.663 [ 5] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:53.665 [ 5] 0 MediaPlayer:handlePlayCalled:idPassed=5,currentId=5 2017-12-19 12:01:53.665 [ 5] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:53.681 [ 5] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:53.762 [ 5] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:53.763 [ 5] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:53.765 [ 5] 0 MediaPlayer:callingOnPlaybackStarted:currentId=5 2017-12-19 12:01:53.769 [ 5] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:55.779 [ 5] 0 MediaPlayer:handleStopCalled:idPassed=5,currentId=5 2017-12-19 12:01:55.801 [ 5] 0 MediaPlayer:callingOnPlaybackStopped:currentId=5 2017-12-19 12:01:55.801 [ 5] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:55.802 [ 5] 0 MediaPlayer:handlePlayCalled:idPassed=5,currentId=0 2017-12-19 12:01:55.802 [ 5] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet 2017-12-19 12:01:55.803 [ 5] E MediaPlayer:handlePlayFailed 2017-12-19 12:01:55.805 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayCallAfterStopPlay (2149 ms) [ RUN ] MediaPlayerTest.testStartPlayCallAfterStopPlayDifferentSource 2017-12-19 12:01:55.812 [ 6] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:01:55.812 [ 6] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:55.812 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:55.814 [ 6] 0 MediaPlayer:handlePlayCalled:idPassed=6,currentId=6 2017-12-19 12:01:55.815 [ 6] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:55.832 [ 6] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:55.916 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:55.917 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:55.920 [ 6] 0 MediaPlayer:callingOnPlaybackStarted:currentId=6 2017-12-19 12:01:55.925 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:56.949 [ 6] 0 MediaPlayer:handleStopCalled:idPassed=6,currentId=6 2017-12-19 12:01:56.970 [ 6] 0 MediaPlayer:callingOnPlaybackStopped:currentId=6 2017-12-19 12:01:56.971 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:56.972 [ 6] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:56.972 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:56.974 [ 6] 0 MediaPlayer:handlePlayCalled:idPassed=7,currentId=7 2017-12-19 12:01:56.974 [ 6] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:56.991 [ 6] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:57.072 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:57.073 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:57.076 [ 6] 0 MediaPlayer:callingOnPlaybackStarted:currentId=7 2017-12-19 12:01:57.089 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:58.099 [ 6] 0 MediaPlayer:handleStopCalled:idPassed=7,currentId=7 2017-12-19 12:01:58.115 [ 6] 0 MediaPlayer:callingOnPlaybackStopped:currentId=7 2017-12-19 12:01:58.116 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:58.119 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayCallAfterStopPlayDifferentSource (2314 ms) [ RUN ] MediaPlayerTest.testPauseDuringPlay 2017-12-19 12:01:58.125 [ 7] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:01:58.126 [ 7] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:58.126 [ 7] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:58.129 [ 7] 0 MediaPlayer:handlePlayCalled:idPassed=8,currentId=8 2017-12-19 12:01:58.130 [ 7] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:58.144 [ 7] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:58.225 [ 7] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:58.226 [ 7] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:58.228 [ 7] 0 MediaPlayer:callingOnPlaybackStarted:currentId=8 2017-12-19 12:01:58.242 [ 7] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:59.249 [ 7] 0 MediaPlayer:handlePauseCalled:idPassed=8,currentId=8 2017-12-19 12:01:59.262 [ 7] 0 MediaPlayer:callingOnPlaybackPaused:currentId=8 2017-12-19 12:01:59.273 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testPauseDuringPlay (1154 ms) [ RUN ] MediaPlayerTest.testResumeAfterPauseThenStop 2017-12-19 12:01:59.282 [ 8] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:01:59.283 [ 8] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:01:59.283 [ 8] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:01:59.285 [ 8] 0 MediaPlayer:handlePlayCalled:idPassed=9,currentId=9 2017-12-19 12:01:59.285 [ 8] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:01:59.301 [ 8] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:01:59.382 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:59.382 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 12:01:59.384 [ 8] 0 MediaPlayer:callingOnPlaybackStarted:currentId=9 2017-12-19 12:01:59.384 [ 8] 0 MediaPlayer:handlePauseCalled:idPassed=9,currentId=9 2017-12-19 12:01:59.386 [ 8] 0 MediaPlayer:callingOnPlaybackPaused:currentId=9 2017-12-19 12:01:59.387 [ 8] 0 MediaPlayer:handleResumeCalled:idPassed=9,currentId=9 2017-12-19 12:01:59.390 [ 8] 0 MediaPlayer:callingOnPlaybackResumed:currentId=9 2017-12-19 12:01:59.400 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:02.055 [ 8] 0 MediaPlayer:callingOnPlaybackFinished:currentId=9 2017-12-19 12:02:02.055 [ 8] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:02:02.079 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testResumeAfterPauseThenStop (2806 ms) [ RUN ] MediaPlayerTest.testStopAfterPause 2017-12-19 12:02:02.087 [ 9] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:02.087 [ 9] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:02.087 [ 9] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:02.089 [ 9] 0 MediaPlayer:handlePlayCalled:idPassed=10,currentId=10 2017-12-19 12:02:02.089 [ 9] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:02.104 [ 9] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:02.190 [ 9] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:02.192 [ 9] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:02.193 [ 9] 0 MediaPlayer:callingOnPlaybackStarted:currentId=10 2017-12-19 12:02:02.198 [ 9] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:02.415 [ 9] 0 MediaPlayer:handlePauseCalled:idPassed=10,currentId=10 2017-12-19 12:02:02.422 [ 9] 0 MediaPlayer:callingOnPlaybackPaused:currentId=10 2017-12-19 12:02:02.422 [ 9] 0 MediaPlayer:handleStopCalled:idPassed=10,currentId=10 2017-12-19 12:02:02.430 [ 9] 0 MediaPlayer:callingOnPlaybackStopped:currentId=10 2017-12-19 12:02:02.430 [ 9] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:02.433 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStopAfterPause (354 ms) [ RUN ] MediaPlayerTest.testPauseAfterPause 2017-12-19 12:02:02.440 [ a] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:02.440 [ a] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:02.440 [ a] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:02.442 [ a] 0 MediaPlayer:handlePlayCalled:idPassed=11,currentId=11 2017-12-19 12:02:02.443 [ a] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:02.459 [ a] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:02.542 [ a] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:02.542 [ a] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:02.546 [ a] 0 MediaPlayer:callingOnPlaybackStarted:currentId=11 2017-12-19 12:02:02.546 [ a] 0 MediaPlayer:handlePauseCalled:idPassed=11,currentId=11 2017-12-19 12:02:02.548 [ a] 0 MediaPlayer:callingOnPlaybackPaused:currentId=11 2017-12-19 12:02:02.548 [ a] 0 MediaPlayer:handlePauseCalled:idPassed=11,currentId=11 2017-12-19 12:02:02.548 [ a] E MediaPlayer:handlePauseFailed:reason=noAudioPlaying 2017-12-19 12:02:02.548 [ a] 0 MediaPlayer:handleStopCalled:idPassed=11,currentId=11 terminate called after throwing an instance of 'std::future_error' what(): Promise already satisfied Aborted (core dumped)

crash 2: [ RUN ] MediaPlayerTest.testStartPlayWaitForEnd 2017-12-19 12:02:28.269 [ 1] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:28.270 [ 1] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:28.270 [ 1] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:28.284 [ 1] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1 2017-12-19 12:02:28.284 [ 1] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:28.363 [ 1] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:28.494 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:28.494 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:28.502 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:28.502 [ 1] 0 MediaPlayer:callingOnPlaybackStarted:currentId=1 2017-12-19 12:02:31.195 [ 1] 0 MediaPlayer:callingOnPlaybackFinished:currentId=1 2017-12-19 12:02:31.196 [ 1] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:02:31.217 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayWaitForEnd (3084 ms) [ RUN ] MediaPlayerTest.testStartPlayWaitForEndStartPlayAgain 2017-12-19 12:02:31.223 [ 3] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:31.224 [ 3] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:31.224 [ 3] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:31.227 [ 3] 0 MediaPlayer:handlePlayCalled:idPassed=2,currentId=2 2017-12-19 12:02:31.227 [ 3] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:31.242 [ 3] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:31.325 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:31.326 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:31.327 [ 3] 0 MediaPlayer:callingOnPlaybackStarted:currentId=2 2017-12-19 12:02:31.334 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:34.015 [ 3] 0 MediaPlayer:callingOnPlaybackFinished:currentId=2 2017-12-19 12:02:34.016 [ 3] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:02:34.032 [ 3] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:34.032 [ 3] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:34.034 [ 3] 0 MediaPlayer:handlePlayCalled:idPassed=3,currentId=3 2017-12-19 12:02:34.034 [ 3] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:34.050 [ 3] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:34.130 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:34.130 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:34.134 [ 3] 0 MediaPlayer:callingOnPlaybackStarted:currentId=3 2017-12-19 12:02:34.146 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:36.835 [ 3] 0 MediaPlayer:callingOnPlaybackFinished:currentId=3 2017-12-19 12:02:36.835 [ 3] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:02:36.857 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayWaitForEndStartPlayAgain (5640 ms) [ RUN ] MediaPlayerTest.testStopPlay 2017-12-19 12:02:36.863 [ 4] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:36.864 [ 4] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:36.864 [ 4] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:36.867 [ 4] 0 MediaPlayer:handlePlayCalled:idPassed=4,currentId=4 2017-12-19 12:02:36.867 [ 4] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:36.882 [ 4] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:36.966 [ 4] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:36.967 [ 4] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:36.969 [ 4] 0 MediaPlayer:callingOnPlaybackStarted:currentId=4 2017-12-19 12:02:36.984 [ 4] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:41.975 [ 4] 0 MediaPlayer:handleStopCalled:idPassed=4,currentId=4 2017-12-19 12:02:41.993 [ 4] 0 MediaPlayer:callingOnPlaybackStopped:currentId=4 2017-12-19 12:02:41.993 [ 4] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:41.997 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStopPlay (5140 ms) [ RUN ] MediaPlayerTest.testStartPlayCallAfterStopPlay 2017-12-19 12:02:42.003 [ 5] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:42.004 [ 5] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:42.005 [ 5] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:42.007 [ 5] 0 MediaPlayer:handlePlayCalled:idPassed=5,currentId=5 2017-12-19 12:02:42.007 [ 5] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:42.022 [ 5] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:42.102 [ 5] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:42.103 [ 5] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:42.104 [ 5] 0 MediaPlayer:callingOnPlaybackStarted:currentId=5 2017-12-19 12:02:42.113 [ 5] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:44.125 [ 5] 0 MediaPlayer:handleStopCalled:idPassed=5,currentId=5 2017-12-19 12:02:44.139 [ 5] 0 MediaPlayer:callingOnPlaybackStopped:currentId=5 2017-12-19 12:02:44.140 [ 5] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:44.141 [ 5] 0 MediaPlayer:handlePlayCalled:idPassed=5,currentId=0 2017-12-19 12:02:44.141 [ 5] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet 2017-12-19 12:02:44.141 [ 5] E MediaPlayer:handlePlayFailed 2017-12-19 12:02:44.143 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayCallAfterStopPlay (2146 ms) [ RUN ] MediaPlayerTest.testStartPlayCallAfterStopPlayDifferentSource 2017-12-19 12:02:44.150 [ 6] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:44.150 [ 6] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:44.151 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:44.153 [ 6] 0 MediaPlayer:handlePlayCalled:idPassed=6,currentId=6 2017-12-19 12:02:44.153 [ 6] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:44.170 [ 6] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:44.256 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:44.256 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:44.259 [ 6] 0 MediaPlayer:callingOnPlaybackStarted:currentId=6 2017-12-19 12:02:44.266 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:45.275 [ 6] 0 MediaPlayer:handleStopCalled:idPassed=6,currentId=6 2017-12-19 12:02:45.292 [ 6] 0 MediaPlayer:callingOnPlaybackStopped:currentId=6 2017-12-19 12:02:45.292 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:45.294 [ 6] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:45.294 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:45.297 [ 6] 0 MediaPlayer:handlePlayCalled:idPassed=7,currentId=7 2017-12-19 12:02:45.297 [ 6] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:45.311 [ 6] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:45.397 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:45.398 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:45.401 [ 6] 0 MediaPlayer:callingOnPlaybackStarted:currentId=7 2017-12-19 12:02:45.407 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:46.415 [ 6] 0 MediaPlayer:handleStopCalled:idPassed=7,currentId=7 2017-12-19 12:02:46.436 [ 6] 0 MediaPlayer:callingOnPlaybackStopped:currentId=7 2017-12-19 12:02:46.436 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:46.439 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayCallAfterStopPlayDifferentSource (2296 ms) [ RUN ] MediaPlayerTest.testPauseDuringPlay 2017-12-19 12:02:46.446 [ 7] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:46.446 [ 7] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:46.446 [ 7] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:46.448 [ 7] 0 MediaPlayer:handlePlayCalled:idPassed=8,currentId=8 2017-12-19 12:02:46.449 [ 7] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:46.464 [ 7] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:46.545 [ 7] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:46.546 [ 7] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:46.547 [ 7] 0 MediaPlayer:callingOnPlaybackStarted:currentId=8 2017-12-19 12:02:46.552 [ 7] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:47.565 [ 7] 0 MediaPlayer:handlePauseCalled:idPassed=8,currentId=8 2017-12-19 12:02:47.581 [ 7] 0 MediaPlayer:callingOnPlaybackPaused:currentId=8 2017-12-19 12:02:47.592 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testPauseDuringPlay (1153 ms) [ RUN ] MediaPlayerTest.testResumeAfterPauseThenStop 2017-12-19 12:02:47.599 [ 8] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:47.600 [ 8] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:47.600 [ 8] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:47.602 [ 8] 0 MediaPlayer:handlePlayCalled:idPassed=9,currentId=9 2017-12-19 12:02:47.602 [ 8] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:47.618 [ 8] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:47.702 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:47.702 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:47.704 [ 8] 0 MediaPlayer:callingOnPlaybackStarted:currentId=9 2017-12-19 12:02:47.706 [ 8] 0 MediaPlayer:handlePauseCalled:idPassed=9,currentId=9 2017-12-19 12:02:47.708 [ 8] 0 MediaPlayer:callingOnPlaybackPaused:currentId=9 2017-12-19 12:02:47.708 [ 8] 0 MediaPlayer:handleResumeCalled:idPassed=9,currentId=9 2017-12-19 12:02:47.711 [ 8] 0 MediaPlayer:callingOnPlaybackResumed:currentId=9 2017-12-19 12:02:47.717 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:50.395 [ 8] 0 MediaPlayer:callingOnPlaybackFinished:currentId=9 2017-12-19 12:02:50.396 [ 8] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:02:50.408 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testResumeAfterPauseThenStop (2816 ms) [ RUN ] MediaPlayerTest.testStopAfterPause 2017-12-19 12:02:50.416 [ 9] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:50.416 [ 9] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:50.417 [ 9] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:50.419 [ 9] 0 MediaPlayer:handlePlayCalled:idPassed=10,currentId=10 2017-12-19 12:02:50.419 [ 9] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:50.437 [ 9] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:50.517 [ 9] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:50.518 [ 9] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:50.520 [ 9] 0 MediaPlayer:callingOnPlaybackStarted:currentId=10 2017-12-19 12:02:50.536 [ 9] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:50.745 [ 9] 0 MediaPlayer:handlePauseCalled:idPassed=10,currentId=10 2017-12-19 12:02:50.753 [ 9] 0 MediaPlayer:callingOnPlaybackPaused:currentId=10 2017-12-19 12:02:50.753 [ 9] 0 MediaPlayer:handleStopCalled:idPassed=10,currentId=10 2017-12-19 12:02:50.761 [ 9] 0 MediaPlayer:callingOnPlaybackStopped:currentId=10 2017-12-19 12:02:50.762 [ 9] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:50.767 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStopAfterPause (359 ms) [ RUN ] MediaPlayerTest.testPauseAfterPause 2017-12-19 12:02:50.773 [ a] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:50.773 [ a] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:50.774 [ a] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:50.776 [ a] 0 MediaPlayer:handlePlayCalled:idPassed=11,currentId=11 2017-12-19 12:02:50.777 [ a] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:50.792 [ a] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:50.877 [ a] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:50.877 [ a] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:50.880 [ a] 0 MediaPlayer:callingOnPlaybackStarted:currentId=11 2017-12-19 12:02:50.880 [ a] 0 MediaPlayer:handlePauseCalled:idPassed=11,currentId=11 2017-12-19 12:02:50.882 [ a] 0 MediaPlayer:callingOnPlaybackPaused:currentId=11 2017-12-19 12:02:50.882 [ a] 0 MediaPlayer:handlePauseCalled:idPassed=11,currentId=11 2017-12-19 12:02:50.882 [ a] E MediaPlayer:handlePauseFailed:reason=noAudioPlaying 2017-12-19 12:02:50.883 [ a] 0 MediaPlayer:handleStopCalled:idPassed=11,currentId=11 2017-12-19 12:02:50.892 [ a] 0 MediaPlayer:callingOnPlaybackStopped:currentId=11 2017-12-19 12:02:50.892 [ a] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:50.895 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testPauseAfterPause (128 ms) [ RUN ] MediaPlayerTest.testResumeAfterPlay 2017-12-19 12:02:50.901 [ b] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:50.902 [ b] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:50.902 [ b] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:50.904 [ b] 0 MediaPlayer:handlePlayCalled:idPassed=12,currentId=12 2017-12-19 12:02:50.904 [ b] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:50.923 [ b] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:51.003 [ b] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:51.003 [ b] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:51.014 [ b] 0 MediaPlayer:callingOnPlaybackStarted:currentId=12 2017-12-19 12:02:51.015 [ b] 0 MediaPlayer:handleResumeCalled:idPassed=12,currentId=12 2017-12-19 12:02:51.015 [ b] E MediaPlayer:handleResumeFailed:reason=alreadyPlaying 2017-12-19 12:02:51.016 [ b] 0 MediaPlayer:handleStopCalled:idPassed=12,currentId=12 2017-12-19 12:02:51.026 [ b] 0 MediaPlayer:callingOnPlaybackStopped:currentId=12 2017-12-19 12:02:51.027 [ b] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:51.030 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testResumeAfterPlay (135 ms) [ RUN ] MediaPlayerTest.testGetOffsetInMilliseconds 2017-12-19 12:02:51.037 [ c] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:51.038 [ c] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:51.038 [ c] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:51.040 [ c] 0 MediaPlayer:handlePlayCalled:idPassed=13,currentId=13 2017-12-19 12:02:51.040 [ c] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:51.057 [ c] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:51.140 [ c] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:51.140 [ c] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:51.142 [ c] 0 MediaPlayer:callingOnPlaybackStarted:currentId=13 2017-12-19 12:02:51.148 [ c] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:52.155 [ c] 0 MediaPlayer:handleGetOffsetCalled:idPassed=13,currentId=13 2017-12-19 12:02:52.156 [ c] 0 MediaPlayer:handleStopCalled:idPassed=13,currentId=13 2017-12-19 12:02:52.180 [ c] 0 MediaPlayer:callingOnPlaybackStopped:currentId=13 2017-12-19 12:02:52.181 [ c] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:52.182 [ c] 0 MediaPlayer:handleGetOffsetCalled:idPassed=13,currentId=0 2017-12-19 12:02:52.182 [ c] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet 2017-12-19 12:02:52.184 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testGetOffsetInMilliseconds (1154 ms) [ RUN ] MediaPlayerTest.testGetOffsetInMillisecondsNullPipeline 2017-12-19 12:02:52.191 [ d] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:52.191 [ d] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:52.192 [ d] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:52.193 [ d] 0 MediaPlayer:handleGetOffsetCalled:idPassed=15,currentId=14 2017-12-19 12:02:52.194 [ d] E MediaPlayer:validateSourceAndIdFailed:reason=sourceIdMismatch 2017-12-19 12:02:52.197 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testGetOffsetInMillisecondsNullPipeline (13 ms) [ RUN ] MediaPlayerTest.testGetOffsetWhenStoppedFails 2017-12-19 12:02:52.203 [ e] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:52.203 [ e] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:52.203 [ e] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:52.205 [ e] 0 MediaPlayer:handlePlayCalled:idPassed=15,currentId=15 2017-12-19 12:02:52.206 [ e] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:52.221 [ e] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:52.303 [ e] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:52.303 [ e] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:52.307 [ e] 0 MediaPlayer:callingOnPlaybackStarted:currentId=15 2017-12-19 12:02:52.313 [ e] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:53.315 [ e] 0 MediaPlayer:handleStopCalled:idPassed=15,currentId=15 2017-12-19 12:02:53.330 [ e] 0 MediaPlayer:callingOnPlaybackStopped:currentId=15 2017-12-19 12:02:53.330 [ e] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:53.331 [ e] 0 MediaPlayer:handleGetOffsetCalled:idPassed=15,currentId=0 2017-12-19 12:02:53.331 [ e] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet 2017-12-19 12:02:53.333 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testGetOffsetWhenStoppedFails (1136 ms) [ RUN ] MediaPlayerTest.testGetOffsetWhenPaused 2017-12-19 12:02:53.340 [ f] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:53.340 [ f] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:53.341 [ f] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:53.343 [ f] 0 MediaPlayer:handlePlayCalled:idPassed=16,currentId=16 2017-12-19 12:02:53.343 [ f] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:53.359 [ f] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:53.442 [ f] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:53.442 [ f] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:53.444 [ f] 0 MediaPlayer:callingOnPlaybackStarted:currentId=16 2017-12-19 12:02:53.456 [ f] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:54.455 [ f] 0 MediaPlayer:handlePauseCalled:idPassed=16,currentId=16 2017-12-19 12:02:54.459 [ f] 0 MediaPlayer:callingOnPlaybackPaused:currentId=16 2017-12-19 12:02:54.459 [ f] 0 MediaPlayer:handleGetOffsetCalled:idPassed=16,currentId=16 2017-12-19 12:02:54.470 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testGetOffsetWhenPaused (1137 ms) [ RUN ] MediaPlayerTest.testPlayingTwoAttachments 2017-12-19 12:02:54.477 [ 10] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:54.477 [ 10] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:54.478 [ 10] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:54.480 [ 10] 0 MediaPlayer:handlePlayCalled:idPassed=17,currentId=17 2017-12-19 12:02:54.480 [ 10] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:54.497 [ 10] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:54.581 [ 10] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:54.581 [ 10] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:54.584 [ 10] 0 MediaPlayer:callingOnPlaybackStarted:currentId=17 2017-12-19 12:02:54.592 [ 10] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:55.595 [ 10] 0 MediaPlayer:handleGetOffsetCalled:idPassed=17,currentId=17 2017-12-19 12:02:57.275 [ 10] 0 MediaPlayer:callingOnPlaybackFinished:currentId=17 2017-12-19 12:02:57.275 [ 10] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:02:57.300 [ 10] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:57.301 [ 10] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:57.303 [ 10] 0 MediaPlayer:handlePlayCalled:idPassed=18,currentId=18 2017-12-19 12:02:57.303 [ 10] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:57.319 [ 10] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:02:57.403 [ 10] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:57.403 [ 10] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:57.415 [ 10] 0 MediaPlayer:callingOnPlaybackStarted:currentId=18 2017-12-19 12:02:57.417 [ 10] 0 MediaPlayer:callingOnTags 2017-12-19 12:02:58.425 [ 10] 0 MediaPlayer:handleGetOffsetCalled:idPassed=18,currentId=18 2017-12-19 12:02:58.426 [ 10] 0 MediaPlayer:handleStopCalled:idPassed=18,currentId=18 2017-12-19 12:02:58.443 [ 10] 0 MediaPlayer:callingOnPlaybackStopped:currentId=18 2017-12-19 12:02:58.443 [ 10] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:58.446 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testPlayingTwoAttachments (3976 ms) [ RUN ] MediaPlayerTest.testUnsteadyReads 2017-12-19 12:02:58.453 [ 11] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:02:58.453 [ 11] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:02:58.453 [ 11] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:02:58.456 [ 11] 0 MediaPlayer:handlePlayCalled:idPassed=19,currentId=19 2017-12-19 12:02:58.456 [ 11] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:02:58.471 [ 11] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:00.426 [ 11] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:00.427 [ 11] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:00.429 [ 11] 0 MediaPlayer:callingOnPlaybackStarted:currentId=19 2017-12-19 12:03:00.435 [ 11] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:08.501 [ 11] 0 MediaPlayer:callingOnPlaybackFinished:currentId=19 2017-12-19 12:03:08.502 [ 11] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=8064 2017-12-19 12:03:08.528 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testUnsteadyReads (10081 ms) [ RUN ] MediaPlayerTest.testRecoveryFromPausedReads 2017-12-19 12:03:08.535 [ 12] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:08.535 [ 12] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:08.536 [ 12] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:08.537 [ 12] 0 MediaPlayer:handlePlayCalled:idPassed=20,currentId=20 2017-12-19 12:03:08.538 [ 12] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:08.555 [ 12] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:10.613 [ 12] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:10.614 [ 12] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:10.616 [ 12] 0 MediaPlayer:callingOnPlaybackStarted:currentId=20 2017-12-19 12:03:10.624 [ 12] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:20.761 [ 12] 0 MediaPlayer:callingOnPlaybackFinished:currentId=20 2017-12-19 12:03:20.762 [ 12] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=8064 2017-12-19 12:03:20.788 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testRecoveryFromPausedReads (12259 ms) [ RUN ] MediaPlayerTest.testRepeatAttachment 2017-12-19 12:03:20.800 [ 13] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:20.802 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:20.802 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:20.804 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=21,currentId=21 2017-12-19 12:03:20.805 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:20.826 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:20.922 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:20.922 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:20.924 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=21 2017-12-19 12:03:20.929 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:23.611 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=21 2017-12-19 12:03:23.611 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:23.629 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:23.629 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:23.632 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=22,currentId=22 2017-12-19 12:03:23.633 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:23.648 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:23.729 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:23.730 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:23.734 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=22 2017-12-19 12:03:23.742 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:26.411 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=22 2017-12-19 12:03:26.412 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:26.438 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:26.438 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:26.440 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=23,currentId=23 2017-12-19 12:03:26.440 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:26.457 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:26.539 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:26.540 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:26.544 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=23 2017-12-19 12:03:26.548 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:29.221 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=23 2017-12-19 12:03:29.222 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:29.246 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:29.247 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:29.249 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=24,currentId=24 2017-12-19 12:03:29.249 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:29.268 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:29.350 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:29.350 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:29.353 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=24 2017-12-19 12:03:29.362 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:32.031 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=24 2017-12-19 12:03:32.031 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:32.053 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:32.053 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:32.055 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=25,currentId=25 2017-12-19 12:03:32.056 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:32.073 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:32.155 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:32.155 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:32.157 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=25 2017-12-19 12:03:32.163 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:34.841 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=25 2017-12-19 12:03:34.842 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:34.860 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:34.860 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:34.863 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=26,currentId=26 2017-12-19 12:03:34.863 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:34.880 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:34.962 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:34.962 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:34.965 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=26 2017-12-19 12:03:34.972 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:37.661 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=26 2017-12-19 12:03:37.661 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:37.686 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:37.686 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:37.688 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=27,currentId=27 2017-12-19 12:03:37.688 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:37.704 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:37.786 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:37.787 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:37.790 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=27 2017-12-19 12:03:37.794 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:40.471 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=27 2017-12-19 12:03:40.471 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:40.493 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:40.493 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:40.495 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=28,currentId=28 2017-12-19 12:03:40.496 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:40.510 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:40.602 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:40.603 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:40.611 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=28 2017-12-19 12:03:40.622 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:43.291 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=28 2017-12-19 12:03:43.292 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:43.316 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:43.316 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:43.318 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=29,currentId=29 2017-12-19 12:03:43.319 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:43.336 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:43.419 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:43.420 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:43.424 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=29 2017-12-19 12:03:43.431 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:46.101 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=29 2017-12-19 12:03:46.101 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:46.124 [ 13] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:46.124 [ 13] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:46.126 [ 13] 0 MediaPlayer:handlePlayCalled:idPassed=30,currentId=30 2017-12-19 12:03:46.126 [ 13] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:46.143 [ 13] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:46.225 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:46.225 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:46.228 [ 13] 0 MediaPlayer:callingOnPlaybackStarted:currentId=30 2017-12-19 12:03:46.242 [ 13] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:48.921 [ 13] 0 MediaPlayer:callingOnPlaybackFinished:currentId=30 2017-12-19 12:03:48.924 [ 13] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:48.935 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testRepeatAttachment (28147 ms) [ RUN ] MediaPlayerTest.testSetVolumePlays 2017-12-19 12:03:48.943 [ 14] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:48.943 [ 14] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:48.943 [ 14] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:48.945 [ 14] 0 MediaPlayer:handlePlayCalled:idPassed=31,currentId=31 2017-12-19 12:03:48.946 [ 14] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:48.963 [ 14] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:49.043 [ 14] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:49.043 [ 14] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:49.047 [ 14] 0 MediaPlayer:callingOnPlaybackStarted:currentId=31 2017-12-19 12:03:49.062 [ 14] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:50.051 [ 14] 0 MediaPlayer:handlePauseCalled:idPassed=31,currentId=31 2017-12-19 12:03:50.062 [ 14] 0 MediaPlayer:callingOnPlaybackPaused:currentId=31 2017-12-19 12:03:50.063 [ 14] 0 MediaPlayer:handleResumeCalled:idPassed=31,currentId=31 2017-12-19 12:03:50.065 [ 14] 0 MediaPlayer:callingOnPlaybackResumed:currentId=31 2017-12-19 12:03:51.441 [ 14] 0 MediaPlayer:callingOnPlaybackFinished:currentId=31 2017-12-19 12:03:51.441 [ 14] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:51.463 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testSetVolumePlays (2528 ms) [ RUN ] MediaPlayerTest.testAdjustVolumePlaysDuringPlay 2017-12-19 12:03:51.469 [ 15] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:51.470 [ 15] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:51.470 [ 15] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:51.472 [ 15] 0 MediaPlayer:handlePlayCalled:idPassed=32,currentId=32 2017-12-19 12:03:51.472 [ 15] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:51.488 [ 15] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:51.568 [ 15] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:51.568 [ 15] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:51.570 [ 15] 0 MediaPlayer:callingOnPlaybackStarted:currentId=32 2017-12-19 12:03:51.580 [ 15] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:54.261 [ 15] 0 MediaPlayer:callingOnPlaybackFinished:currentId=32 2017-12-19 12:03:54.261 [ 15] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:54.282 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testAdjustVolumePlaysDuringPlay (2820 ms) [ RUN ] MediaPlayerTest.testAdjustVolumePlays 2017-12-19 12:03:54.289 [ 16] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:54.289 [ 16] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:54.290 [ 16] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:54.292 [ 16] 0 MediaPlayer:handlePlayCalled:idPassed=33,currentId=33 2017-12-19 12:03:54.292 [ 16] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:54.308 [ 16] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:54.393 [ 16] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:54.393 [ 16] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:54.396 [ 16] 0 MediaPlayer:callingOnPlaybackStarted:currentId=33 2017-12-19 12:03:54.408 [ 16] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:55.401 [ 16] 0 MediaPlayer:handlePauseCalled:idPassed=33,currentId=33 2017-12-19 12:03:55.410 [ 16] 0 MediaPlayer:callingOnPlaybackPaused:currentId=33 2017-12-19 12:03:55.410 [ 16] 0 MediaPlayer:handleResumeCalled:idPassed=33,currentId=33 2017-12-19 12:03:55.413 [ 16] 0 MediaPlayer:callingOnPlaybackResumed:currentId=33 2017-12-19 12:03:56.791 [ 16] 0 MediaPlayer:callingOnPlaybackFinished:currentId=33 2017-12-19 12:03:56.791 [ 16] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:56.812 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testAdjustVolumePlays (2529 ms) [ RUN ] MediaPlayerTest.testAdjustVolumeOutOfBounds 2017-12-19 12:03:56.819 [ 17] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:56.820 [ 17] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:56.820 [ 17] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:56.824 [ 17] 0 MediaPlayer:handlePlayCalled:idPassed=34,currentId=34 2017-12-19 12:03:56.824 [ 17] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:56.839 [ 17] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:56.923 [ 17] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:56.923 [ 17] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:56.926 [ 17] 0 MediaPlayer:callingOnPlaybackStarted:currentId=34 2017-12-19 12:03:56.944 [ 17] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:57.941 [ 17] 0 MediaPlayer:handlePauseCalled:idPassed=34,currentId=34 2017-12-19 12:03:57.957 [ 17] 0 MediaPlayer:callingOnPlaybackPaused:currentId=34 2017-12-19 12:03:57.958 [ 17] 0 MediaPlayer:handleResumeCalled:idPassed=34,currentId=34 2017-12-19 12:03:57.964 [ 17] 0 MediaPlayer:callingOnPlaybackResumed:currentId=34 2017-12-19 12:03:58.281 [ 17] 0 MediaPlayer:callingOnPlaybackFinished:currentId=34 2017-12-19 12:03:58.282 [ 17] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:58.305 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testAdjustVolumeOutOfBounds (1492 ms) [ RUN ] MediaPlayerTest.testSetMutePlays 2017-12-19 12:03:58.314 [ 18] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:58.314 [ 18] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:58.315 [ 18] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:58.317 [ 18] 0 MediaPlayer:handlePlayCalled:idPassed=35,currentId=35 2017-12-19 12:03:58.318 [ 18] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:58.344 [ 18] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:58.429 [ 18] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:58.430 [ 18] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:58.434 [ 18] 0 MediaPlayer:callingOnPlaybackStarted:currentId=35 2017-12-19 12:03:58.442 [ 18] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:59.451 [ 18] 0 MediaPlayer:handlePauseCalled:idPassed=35,currentId=35 2017-12-19 12:03:59.458 [ 18] 0 MediaPlayer:callingOnPlaybackPaused:currentId=35 2017-12-19 12:03:59.459 [ 18] 0 MediaPlayer:handleResumeCalled:idPassed=35,currentId=35 2017-12-19 12:03:59.462 [ 18] 0 MediaPlayer:callingOnPlaybackResumed:currentId=35 2017-12-19 12:03:59.791 [ 18] 0 MediaPlayer:callingOnPlaybackFinished:currentId=35 2017-12-19 12:03:59.791 [ 18] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:03:59.820 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testSetMutePlays (1515 ms) [ RUN ] MediaPlayerTest.testGetSpeakerSettings 2017-12-19 12:03:59.827 [ 19] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:59.827 [ 19] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:59.827 [ 19] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:59.832 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testGetSpeakerSettings (12 ms) [ RUN ] MediaPlayerTest.testRoundingEdgeCase 2017-12-19 12:03:59.838 [ 1a] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:59.838 [ 1a] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:59.839 [ 1a] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:59.844 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testRoundingEdgeCase (11 ms) [ RUN ] MediaPlayerTest.testReadTags 2017-12-19 12:03:59.850 [ 1b] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:03:59.851 [ 1b] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:03:59.852 [ 1b] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:03:59.854 [ 1b] 0 MediaPlayer:handlePlayCalled:idPassed=38,currentId=38 2017-12-19 12:03:59.854 [ 1b] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:03:59.868 [ 1b] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:03:59.953 [ 1b] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:59.953 [ 1b] 0 MediaPlayer:callingOnTags 2017-12-19 12:03:59.956 [ 1b] 0 MediaPlayer:callingOnPlaybackStarted:currentId=38 2017-12-19 12:03:59.960 [ 1b] 0 MediaPlayer:callingOnTags 2017-12-19 12:04:02.636 [ 1b] 0 MediaPlayer:callingOnPlaybackFinished:currentId=38 2017-12-19 12:04:02.637 [ 1b] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 12:04:02.660 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testReadTags (2816 ms) [ RUN ] MediaPlayerTest.testConsecutiveSameApiCalls 2017-12-19 12:04:02.669 [ 1c] 0 MediaPlayer:handleSetObserverCalled 2017-12-19 12:04:02.669 [ 1c] 0 MediaPlayer:handleSetSourceCalled 2017-12-19 12:04:02.669 [ 1c] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 12:04:02.671 [ 1c] 0 MediaPlayer:handlePlayCalled:idPassed=39,currentId=39 2017-12-19 12:04:02.671 [ 1c] 0 MediaPlayer:handlePlay:attemptBuffering=0 2017-12-19 12:04:02.687 [ 1c] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC 2017-12-19 12:04:02.688 [ 1c] 0 MediaPlayer:handlePlayCalled:idPassed=39,currentId=39 2017-12-19 12:04:02.688 [ 1c] 0 MediaPlayer:handlePlayFailed:reason=playCurrentlyPending 2017-12-19 12:04:02.767 [ 1c] 0 MediaPlayer:callingOnTags 2017-12-19 12:04:02.767 [ 1c] 0 MediaPlayer:callingOnTags 2017-12-19 12:04:02.770 [ 1c] 0 MediaPlayer:callingOnPlaybackStarted:currentId=39 2017-12-19 12:04:02.770 [ 1c] 0 MediaPlayer:handlePauseCalled:idPassed=39,currentId=39 2017-12-19 12:04:02.771 [ 1c] 0 MediaPlayer:handlePauseCalled:idPassed=39,currentId=39 2017-12-19 12:04:02.771 [ 1c] 0 MediaPlayer:handlePauseFailed:reason=pauseCurrentlyPending 2017-12-19 12:04:02.773 [ 1c] 0 MediaPlayer:callingOnPlaybackPaused:currentId=39 2017-12-19 12:04:02.773 [ 1c] 0 MediaPlayer:handleResumeCalled:idPassed=39,currentId=39 2017-12-19 12:04:02.775 [ 1c] 0 MediaPlayer:callingOnPlaybackResumed:currentId=39 2017-12-19 12:04:02.776 [ 1c] 0 MediaPlayer:handleResumeCalled:idPassed=39,currentId=39 2017-12-19 12:04:02.777 [ 1c] E MediaPlayer:handleResumeFailed:reason=alreadyPlaying terminate called after throwing an instance of 'std::future_error' what(): Promise already satisfied Aborted (core dumped)

Pl provide some pointer , i want to fix this in some urgency

mradulan commented 6 years ago

what is the version of gstreamer?

dhananjayj29 commented 6 years ago

gstreamer along with all gst plugins 1.10.4

sanjayrd commented 6 years ago

Hi @dhananjayj29,

Looking through the code, I really don't see any code paths that could cause a promise to be set twice. For example, in play(), a local stack std::promise variable is created and passed into a separate function as a pointer. This is the same for each function (resume(), pause(), etc.). In those separate functions, any time a promise value is set, it appears to return immediately. I'm a little confused about how this could be happening unless GStreamer is invoking that same function twice.

Could you possibly provide some sort stack trace from the point at which the exception is thrown? If you could run the code in some sort of debugger and paste the stack trace when the exception occurs, that might be helpful.

Another possible helpful thing would be to log the address of each promise pointer that is passed into handlePlay() or handlePause(), etc. If we end up seeing the addresses being the same, it could be that there's some sort of issue cleaning up or initializing promises.

One more question - is this crash only happening on your embedded linux environment or other environments as well? Also, what version of GCC are you using?

Thanks, Sanjay

dhananjayj29 commented 6 years ago

Here are the answers of you questions:

  1. Stack Trace:

    0 __GI_raise (sig=sig@entry=6) at ../nptl/sysdeps/unix/sysv/linux/raise.c:57

    1 0xb6912950 in __GI_abort () at abort.c:89

    2 0xb6afa58c in __gnu_cxx::__verbose_terminate_handler () at /libsupc++/vterminate.cc:95

    3 0xb6af83d8 in cxxabiv1::terminate (handler=) at /libstdc++-v3/libsupc++/eh_terminate.cc:38

    4 0xb6af8400 in std::terminate () at gcc-4.8.2-r0/gcc-4.8.2/libstdc++-v3/libsupc++/eh_terminate.cc:48

    5 0xb6af873c in cxxabiv1::cxa_throw (obj=0xb3727e20, tinfo=, dest=)

    at gcc-4.8.2/libstdc++-v3/libsupc++/eh_throw.cc:84

    6 0xb6b4b824 in std::throw_future_error (i=__i@entry=2) at gcc-4.8.2-r0/gcc-4.8.2/libstdc++-v3/src/c++11/functexcept.cc:109

    7 0xb6f584dc in _M_set_result (__ignore_failure=false, __res=..., this=0xb3601c80) at /ysroots/c++/future:360

    8 std::promise::set_value(bool&&) (this=this@entry=0xb6432218 ,

    r=r@entry=<unknown type in /usr/local/i3l-target/sysroots/cortexa7hf-vfp-neon-kpit-linux-gnueabi/usr/lib/.debug/libMediaPlayer.so, CU 0x47a98, DIE 0x88a41>) at /u03/yoctobms/build/info3-low/tmp-eglibc/sysroots/info3-low/usr/include/c++/future:994

    9 0xb6f50eec in alexaClientSDK::mediaPlayer::MediaPlayer::handlePlay (this=0xa7af0, id=, promise=0xab92b874)

    at /usr/src/debug/avs-device-sdk/1.0-r0/git/MediaPlayer/src/MediaPlayer.cpp:1103

    10 0xb6f5133c in operator() (__closure=) at /usr/src/debug/avs-device-sdk/1.0-r0/git/MediaPlayer/src/MediaPlayer.cpp:218

    11 std::_Function_handler<int(), alexaClientSDK::mediaPlayer::MediaPlayer::play(alexaClientSDK::avsCommon::utils::mediaPlayer::MediaPlayerInterface::SourceId)::lambda10>::_M_invoke(const std::_Any_data &) (functor=...) at /c++/functional:2056

    12 0xb64358dc in g_main_dispatch (context=0xa6ce8) at /usr/src/debug/glib-2.0/1_2.46.2-r0/glib-2.46.2/glib/gmain.c:3154

    13 g_main_context_dispatch (context=context@entry=0xa6ce8) at /usr/src/debug/glib-2.0/1_2.46.2-r0/glib-2.46.2/glib/gmain.c:3769

    14 0xb6435c44 in g_main_context_iterate (context=0xa6ce8, block=block@entry=1, dispatch=dispatch@entry=1, self=) at /usr/src/debug/glib-2.0/1_2.46.2-r0/glib-2.46.2/glib/gmain.c:3840

    15 0xb6435fa0 in g_main_loop_run (loop=0x8b6f8) at /usr/src/debug/glib-2.0/1_2.46.2-r0/glib-2.46.2/glib/gmain.c:4034

    16 0xb6b4c9a8 in std::(anonymous namespace)::execute_native_thread_routine (__p=)

    at //gcc-4.8.2-r0/gcc-4.8.2/libstdc++-v3/src/c++11/thread.cc:84

    17 0xb6b8a040 in start_thread (arg=0xb31ff410) at pthread_create.c:314

    18 0xb69b10e0 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/clone.S:92 from /lib/libc.so.6

    19 0xb69b10e0 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/clone.S:92 from/lib/libc.so.6

    Backtrace stopped: previous frame identical to this frame (corrupt stack?)

stack trace from where the Play function is called:

(gdb) bt

0 0xb6b8ed08 in __pthread_cond_wait (cond=0xb3601ca0, mutex=0x0) at pthread_cond_wait.c:187

1 0xb6b49350 in gthread_cond_wait (mutex=, cond=cond@entry=0xb3601ca0)

at /bits/gthr-default.h:864

2 std::condition_variable::wait (this=this@entry=0xb3601ca0, __lock=...) at /u03/yoctobms/build/info3-low/tmp-eglibc/work-shared/gcc-4.8.2-r0/gcc-4.8.2/libstdc++-v3/src/c++11/condition_variable.cc:52

3 0x00038b18 in wait<std::__future_base::_State_base::wait()::lambda0> (p=..., __lock=..., this=0xb3601ca0)

at /usr/include/c++/condition_variable:93

4 wait (this=0xb3601c80) at /usr/local/i3l-target/avs/sysroots/cortexa7hf-vfp-neon-kpit-linux-gnueabi/usr/include/c++/future:327

5 _M_get_result (this=) at /c++/future:595

6 std::future::get (this=) atc++/future:674

7 0xb6f54e4c in alexaClientSDK::mediaPlayer::MediaPlayer::play (this=0xa7af0, id=) at /usr/src/debug/avs-device-sdk/1.0-r0/git/MediaPlayer/src/MediaPlayer.cpp:223

8 0xb67c41a4 in alexaClientSDK::capabilityAgents::speechSynthesizer::SpeechSynthesizer::startPlaying (this=this@entry=0x1afba8)

at /usr/src/debug/avs-device-sdk/1.0-r0/git/CapabilityAgents/SpeechSynthesizer/src/SpeechSynthesizer.cpp:714

9 0xb67c4ac4 in alexaClientSDK::capabilityAgents::speechSynthesizer::SpeechSynthesizer::executeStateChange (this=0x1afba8)

at /usr/src/debug/avs-device-sdk/1.0-r0/git/CapabilityAgents/SpeechSynthesizer/src/SpeechSynthesizer.cpp:529

10 0x00037d18 in operator() (this=0xb3601e7c) atfunctional:2464

11 operator() (this=0xb3601e78) at/c++/future:1227

12 std::_Function_handler<std::unique_ptr<std::__future_base::_Result_base, std::future_base::_Result_base::_Deleter> (), std::future_base::_Task_setter<std::unique_ptr<std::future_base::_Result, std::future_base::_Result_base::_Deleter>, void> >::_M_invoke(std::_Any_data const&) (__functor=...)

at usr/include/c++/functional:2057

13 0xb67d13f8 in operator() (this=) at //functional:2464

14 std::future_base::_State_base::_M_do_set(std::function<std::unique_ptr<std::__future_base::_Result_base, std::future_base::_Result_base::_Deleter> ()>&, bool&) (this=0xb36020c8, __f=...,

__set=@0xab92bd1f: false) at/c++/future:469

15 0xb6b902e4 in GI___pthread_once (once_control=0xb360211c, init_routine=0x23bb8 <once_proxy>) at ../ports/sysdeps/unix/sysv/linux/arm/nptl/pthread_once.c:76

16 0xb67cf8bc in __gthread_once (func=, once=0xb360211c) at/bits/gthr-default.h:699

17 call_once<void (std::future_base::_State_base::*)(std::function<std::unique_ptr<std::future_base::_Result_base, std::future_base::_Result_base::_Deleter>()>&, bool&), std::future_base::_State_base* const, std::reference_wrapper<std::function<std::unique_ptr<std::future_base::_Result_base, std::__future_base::_Result_base::_Deleter>()> >, std::reference_wrapper > (f=,

__once=...) at /usr/include/c++/mutex:786

18 _M_set_result (__ignore_failure=false, __res=..., this=0xb36020c8) at future:358

19 std::future_base::_Task_state<std::_Bind<alexaClientSDK::capabilityAgents::speechSynthesizer::SpeechSynthesizer::onFocusChanged(alexaClientSDK::avsCommon::avs::FocusState)::lambda16()>, std::allocator, void()>::_M_run(void) (this=0xb36020c8) at /u03/yoctobms/build/info3-low/tmp-eglibc/sysroots/info3-low/usr/include/c++/future:1276

20 0xb67bf8fc in operator() (this=) at /future:1407

21 operator() (__closure=0xb3602200) at /usr/src/debug/avs-device-sdk/1.0-r0/git/AVSCommon/Utils/include/AVSCommon/Utils/Threading/TaskQueue.h:185

22 std::_Function_handler<void(), alexaClientSDK::avsCommon::utils::threading::TaskQueue::pushTo(bool, Task, Args&& ...) [with Task = alexaClientSDK::capabilityAgents::speechSynthesizer::SpeechSynthesizer::onFocusChanged(alexaClientSDK::avsCommon::avs::FocusState)::lambda16; Args = {}; decltype (task(alexaClientSDK::avsCommon::utils::threading::TaskQueue::pushTo::args ...)) = void]::lambda6>::_M_invoke(const std::_Any_data &) (__functor=...) at functional:2071

23 0xb6e5753c in operator() (this=0xb36021e8) at :2464

24 alexaClientSDK::avsCommon::utils::threading::TaskThread::processTasksLoop (this=0x1b0310) at /usr/src/debug/avs-device-sdk/1.0-r0/git/AVSCommon/Utils/src/TaskThread.cpp:52

25 0xb6b4c9a8 in std::(anonymous namespace)::execute_native_thread_routine (__p=)

at /gcc-4.8.2/libstdc++-v3/src/c++11/thread.cc:84

26 0xb6b8a040 in start_thread (arg=0xab92c410) at pthread_create.c:314

27 0xb69b10e0 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/clone.S:92 from lib/libc.so.6

28 0xb69b10e0 in ?? () at ../ports/sysdeps/unix/sysv/linux/arm/clone.S:92 from /cortexa7hf-vfp-neon-lib/libc.so.6

Backtrace stopped: previous frame identical to this frame (corrupt stack?)

  1. GCC version 4.8.2

  2. I have tried this in ubuntu 14.04 , it crashed there also but less frequently. , in my embedded linux it almost crashed after every 2nd attempt now.

  3. Regarding the logs for all the local promise , I will paste shortly.

dhananjayj29 commented 6 years ago

Here are the logs for MediaPlayerTest:

[==========] Running 35 tests from 1 test case. [----------] Global test environment set-up. [----------] 35 tests from MediaPlayerTest [ RUN ] MediaPlayerTest.testStartPlayWaitForEnd setObserver &promise0xbef398d4 2017-12-19 11:49:40.318 [ 1] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource attachmentreader &promise0xbef39864 2017-12-19 11:49:40.320 [ 1] 0 MediaPlayer:handleSetSourceCalled handlesetAttachmentReaderSource promise0xbef39864 2017-12-19 11:49:40.321 [ 1] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef398a4 2017-12-19 11:49:40.343 [ 1] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1 handlePlay promise0xbef398a4 2017-12-19 11:49:40.343 [ 1] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:49:40.343 [ 1] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:49:40.343 [ 1] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:49:40.343 [ 1] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:49:40.351 [ 1] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:49:40.507 [ 1] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:49:40.823 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:40.825 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:40.846 [ 1] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:40.867 [ 1] 0 MediaPlayer:callingOnPlaybackStarted:currentId=1 2017-12-19 11:49:43.531 [ 1] 0 MediaPlayer:callingOnPlaybackFinished:currentId=1 2017-12-19 11:49:43.532 [ 1] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 11:49:43.562 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayWaitForEnd (3506 ms) [ RUN ] MediaPlayerTest.testStartPlayWaitForEndStartPlayAgain setObserver &promise0xbef398d4 2017-12-19 11:49:43.574 [ 3] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource istream &promise0xbef3985c 2017-12-19 11:49:43.575 [ 3] 0 MediaPlayer:handleSetSourceCalled handlesetsourceCalled promise0xbef3985c 2017-12-19 11:49:43.576 [ 3] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef39894 2017-12-19 11:49:43.578 [ 3] 0 MediaPlayer:handlePlayCalled:idPassed=2,currentId=2 handlePlay promise0xbef39894 2017-12-19 11:49:43.578 [ 3] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:49:43.579 [ 3] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:49:43.579 [ 3] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:49:43.579 [ 3] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:49:43.579 [ 3] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:49:43.599 [ 3] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:49:43.722 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:43.723 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:43.728 [ 3] 0 MediaPlayer:callingOnPlaybackStarted:currentId=2 2017-12-19 11:49:43.738 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:46.411 [ 3] 0 MediaPlayer:callingOnPlaybackFinished:currentId=2 2017-12-19 11:49:46.411 [ 3] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 setSource attachmentreader &promise0xbef39854 2017-12-19 11:49:46.437 [ 3] 0 MediaPlayer:handleSetSourceCalled handlesetAttachmentReaderSource promise0xbef39854 2017-12-19 11:49:46.437 [ 3] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef39894 2017-12-19 11:49:46.451 [ 3] 0 MediaPlayer:handlePlayCalled:idPassed=3,currentId=3 handlePlay promise0xbef39894 2017-12-19 11:49:46.451 [ 3] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:49:46.451 [ 3] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:49:46.451 [ 3] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:49:46.451 [ 3] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:49:46.451 [ 3] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:49:46.487 [ 3] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:49:46.612 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:46.613 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:46.618 [ 3] 0 MediaPlayer:callingOnPlaybackStarted:currentId=3 2017-12-19 11:49:46.635 [ 3] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:49.320 [ 3] 0 MediaPlayer:callingOnPlaybackFinished:currentId=3 2017-12-19 11:49:49.320 [ 3] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 11:49:49.338 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayWaitForEndStartPlayAgain (5775 ms) [ RUN ] MediaPlayerTest.testStopPlay setObserver &promise0xbef398d4 2017-12-19 11:49:49.349 [ 4] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource istream &promise0xbef39884 2017-12-19 11:49:49.351 [ 4] 0 MediaPlayer:handleSetSourceCalled handlesetsourceCalled promise0xbef39884 2017-12-19 11:49:49.351 [ 4] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef398bc 2017-12-19 11:49:49.354 [ 4] 0 MediaPlayer:handlePlayCalled:idPassed=4,currentId=4 handlePlay promise0xbef398bc 2017-12-19 11:49:49.354 [ 4] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:49:49.355 [ 4] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:49:49.355 [ 4] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:49:49.355 [ 4] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:49:49.355 [ 4] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:49:49.375 [ 4] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:49:49.491 [ 4] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:49.491 [ 4] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:49.503 [ 4] 0 MediaPlayer:callingOnPlaybackStarted:currentId=4 2017-12-19 11:49:49.505 [ 4] 0 MediaPlayer:callingOnTags Stop &promise0xbef398bc 2017-12-19 11:49:54.513 [ 4] 0 MediaPlayer:handleStopCalled:idPassed=4,currentId=4 handleStop promise0xbef398bc 2017-12-19 11:49:54.535 [ 4] 0 MediaPlayer:callingOnPlaybackStopped:currentId=4 2017-12-19 11:49:54.542 [ 4] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:49:54.546 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStopPlay (5209 ms) [ RUN ] MediaPlayerTest.testStartPlayCallAfterStopPlay setObserver &promise0xbef398d4 2017-12-19 11:49:54.558 [ 5] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource istream &promise0xbef39884 2017-12-19 11:49:54.559 [ 5] 0 MediaPlayer:handleSetSourceCalled handlesetsourceCalled promise0xbef39884 2017-12-19 11:49:54.559 [ 5] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef398bc 2017-12-19 11:49:54.564 [ 5] 0 MediaPlayer:handlePlayCalled:idPassed=5,currentId=5 handlePlay promise0xbef398bc 2017-12-19 11:49:54.565 [ 5] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:49:54.565 [ 5] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:49:54.565 [ 5] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:49:54.565 [ 5] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:49:54.565 [ 5] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:49:54.601 [ 5] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:49:54.753 [ 5] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:54.753 [ 5] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:54.759 [ 5] 0 MediaPlayer:callingOnPlaybackStarted:currentId=5 2017-12-19 11:49:54.771 [ 5] 0 MediaPlayer:callingOnTags Stop &promise0xbef398bc 2017-12-19 11:49:56.761 [ 5] 0 MediaPlayer:handleStopCalled:idPassed=5,currentId=5 handleStop promise0xbef398bc 2017-12-19 11:49:56.779 [ 5] 0 MediaPlayer:callingOnPlaybackStopped:currentId=5 Play &promise0xbef398bc 2017-12-19 11:49:56.779 [ 5] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:49:56.781 [ 5] 0 MediaPlayer:handlePlayCalled:idPassed=5,currentId=0 handlePlay promise0xbef398bc 2017-12-19 11:49:56.781 [ 5] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet 2017-12-19 11:49:56.781 [ 5] E MediaPlayer:handlePlayFailed 2017-12-19 11:49:56.784 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayCallAfterStopPlay (2237 ms) [ RUN ] MediaPlayerTest.testStartPlayCallAfterStopPlayDifferentSource setObserver &promise0xbef398d4 2017-12-19 11:49:56.795 [ 6] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource attachmentreader &promise0xbef39854 2017-12-19 11:49:56.800 [ 6] 0 MediaPlayer:handleSetSourceCalled handlesetAttachmentReaderSource promise0xbef39854 2017-12-19 11:49:56.800 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef39894 2017-12-19 11:49:56.803 [ 6] 0 MediaPlayer:handlePlayCalled:idPassed=6,currentId=6 handlePlay promise0xbef39894 2017-12-19 11:49:56.803 [ 6] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:49:56.803 [ 6] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:49:56.803 [ 6] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:49:56.803 [ 6] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:49:56.803 [ 6] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:49:56.823 [ 6] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:49:56.942 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:56.942 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:56.949 [ 6] 0 MediaPlayer:callingOnPlaybackStarted:currentId=6 2017-12-19 11:49:56.954 [ 6] 0 MediaPlayer:callingOnTags Stop &promise0xbef39894 2017-12-19 11:49:57.961 [ 6] 0 MediaPlayer:handleStopCalled:idPassed=6,currentId=6 handleStop promise0xbef39894 2017-12-19 11:49:57.975 [ 6] 0 MediaPlayer:callingOnPlaybackStopped:currentId=6 setSource attachmentreader &promise0xbef39854 2017-12-19 11:49:57.975 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:49:57.977 [ 6] 0 MediaPlayer:handleSetSourceCalled handlesetAttachmentReaderSource promise0xbef39854 2017-12-19 11:49:57.977 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef39894 2017-12-19 11:49:57.986 [ 6] 0 MediaPlayer:handlePlayCalled:idPassed=7,currentId=7 handlePlay promise0xbef39894 2017-12-19 11:49:57.986 [ 6] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:49:57.986 [ 6] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:49:57.986 [ 6] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:49:57.986 [ 6] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:49:57.987 [ 6] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:49:58.006 [ 6] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:49:58.127 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:58.127 [ 6] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:58.128 [ 6] 0 MediaPlayer:callingOnPlaybackStarted:currentId=7 2017-12-19 11:49:58.143 [ 6] 0 MediaPlayer:callingOnTags Stop &promise0xbef39894 2017-12-19 11:49:59.142 [ 6] 0 MediaPlayer:handleStopCalled:idPassed=7,currentId=7 handleStop promise0xbef39894 2017-12-19 11:49:59.161 [ 6] 0 MediaPlayer:callingOnPlaybackStopped:currentId=7 2017-12-19 11:49:59.162 [ 6] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:49:59.168 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStartPlayCallAfterStopPlayDifferentSource (2384 ms) [ RUN ] MediaPlayerTest.testPauseDuringPlay setObserver &promise0xbef398d4 2017-12-19 11:49:59.179 [ 7] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource istream &promise0xbef39884 2017-12-19 11:49:59.181 [ 7] 0 MediaPlayer:handleSetSourceCalled handlesetsourceCalled promise0xbef39884 2017-12-19 11:49:59.181 [ 7] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef398bc 2017-12-19 11:49:59.184 [ 7] 0 MediaPlayer:handlePlayCalled:idPassed=8,currentId=8 handlePlay promise0xbef398bc 2017-12-19 11:49:59.184 [ 7] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:49:59.184 [ 7] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:49:59.184 [ 7] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:49:59.184 [ 7] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:49:59.185 [ 7] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:49:59.207 [ 7] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:49:59.338 [ 7] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:59.338 [ 7] 0 MediaPlayer:callingOnTags 2017-12-19 11:49:59.345 [ 7] 0 MediaPlayer:callingOnPlaybackStarted:currentId=8 2017-12-19 11:49:59.356 [ 7] 0 MediaPlayer:callingOnTags pause &promise0xbef398bc 2017-12-19 11:50:00.346 [ 7] 0 MediaPlayer:handlePauseCalled:idPassed=8,currentId=8 handlePause promise0xbef398bc 2017-12-19 11:50:00.352 [ 7] 0 MediaPlayer:callingOnPlaybackPaused:currentId=8 2017-12-19 11:50:00.369 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testPauseDuringPlay (1200 ms) [ RUN ] MediaPlayerTest.testResumeAfterPauseThenStop setObserver &promise0xbef398d4 2017-12-19 11:50:00.381 [ 8] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource istream &promise0xbef39884 2017-12-19 11:50:00.381 [ 8] 0 MediaPlayer:handleSetSourceCalled handlesetsourceCalled promise0xbef39884 2017-12-19 11:50:00.382 [ 8] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef398bc 2017-12-19 11:50:00.384 [ 8] 0 MediaPlayer:handlePlayCalled:idPassed=9,currentId=9 handlePlay promise0xbef398bc 2017-12-19 11:50:00.384 [ 8] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:50:00.384 [ 8] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:50:00.385 [ 8] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:50:00.385 [ 8] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:50:00.385 [ 8] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:50:00.403 [ 8] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:50:00.534 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:00.535 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:00.538 [ 8] 0 MediaPlayer:callingOnPlaybackStarted:currentId=9 pause &promise0xbef398bc 2017-12-19 11:50:00.539 [ 8] 0 MediaPlayer:handlePauseCalled:idPassed=9,currentId=9 handlePause promise0xbef398bc 2017-12-19 11:50:00.540 [ 8] 0 MediaPlayer:callingOnPlaybackPaused:currentId=9 resume &promise0xbef398bc 2017-12-19 11:50:00.541 [ 8] 0 MediaPlayer:handleResumeCalled:idPassed=9,currentId=9 handleResume promise0xbef398bc 2017-12-19 11:50:00.543 [ 8] 0 MediaPlayer:callingOnPlaybackResumed:currentId=9 2017-12-19 11:50:00.546 [ 8] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:03.106 [ 8] 0 MediaPlayer:callingOnPlaybackFinished:currentId=9 2017-12-19 11:50:03.106 [ 8] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=2688 2017-12-19 11:50:03.133 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testResumeAfterPauseThenStop (2764 ms) [ RUN ] MediaPlayerTest.testStopAfterPause setObserver &promise0xbef398d4 2017-12-19 11:50:03.150 [ 9] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource istream &promise0xbef39884 2017-12-19 11:50:03.151 [ 9] 0 MediaPlayer:handleSetSourceCalled handlesetsourceCalled promise0xbef39884 2017-12-19 11:50:03.151 [ 9] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef398bc 2017-12-19 11:50:03.154 [ 9] 0 MediaPlayer:handlePlayCalled:idPassed=10,currentId=10 handlePlay promise0xbef398bc 2017-12-19 11:50:03.155 [ 9] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:50:03.155 [ 9] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:50:03.156 [ 9] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:50:03.156 [ 9] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:50:03.156 [ 9] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:50:03.191 [ 9] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:50:03.350 [ 9] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:03.351 [ 9] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:03.352 [ 9] 0 MediaPlayer:callingOnPlaybackStarted:currentId=10 2017-12-19 11:50:03.367 [ 9] 0 MediaPlayer:callingOnTags pause &promise0xbef398bc 2017-12-19 11:50:03.576 [ 9] 0 MediaPlayer:handlePauseCalled:idPassed=10,currentId=10 handlePause promise0xbef398bc 2017-12-19 11:50:03.584 [ 9] 0 MediaPlayer:callingOnPlaybackPaused:currentId=10 Stop &promise0xbef398bc 2017-12-19 11:50:03.585 [ 9] 0 MediaPlayer:handleStopCalled:idPassed=10,currentId=10 handleStop promise0xbef398bc 2017-12-19 11:50:03.598 [ 9] 0 MediaPlayer:callingOnPlaybackStopped:currentId=10 2017-12-19 11:50:03.603 [ 9] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:50:03.607 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testStopAfterPause (475 ms) [ RUN ] MediaPlayerTest.testPauseAfterPause setObserver &promise0xbef398d4 2017-12-19 11:50:03.616 [ a] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource istream &promise0xbef39884 2017-12-19 11:50:03.617 [ a] 0 MediaPlayer:handleSetSourceCalled handlesetsourceCalled promise0xbef39884 2017-12-19 11:50:03.617 [ a] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef398bc 2017-12-19 11:50:03.620 [ a] 0 MediaPlayer:handlePlayCalled:idPassed=11,currentId=11 handlePlay promise0xbef398bc 2017-12-19 11:50:03.620 [ a] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:50:03.620 [ a] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:50:03.620 [ a] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:50:03.620 [ a] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:50:03.620 [ a] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:50:03.650 [ a] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:50:03.788 [ a] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:03.789 [ a] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:03.796 [ a] 0 MediaPlayer:callingOnPlaybackStarted:currentId=11 pause &promise0xbef398bc 2017-12-19 11:50:03.796 [ a] 0 MediaPlayer:handlePauseCalled:idPassed=11,currentId=11 handlePause promise0xbef398bc 2017-12-19 11:50:03.798 [ a] 0 MediaPlayer:callingOnPlaybackPaused:currentId=11 pause &promise0xbef398bc 2017-12-19 11:50:03.806 [ a] 0 MediaPlayer:handlePauseCalled:idPassed=11,currentId=11 handlePause promise0xbef398bc 2017-12-19 11:50:03.806 [ a] E MediaPlayer:handlePauseFailed:reason=noAudioPlaying Stop &promise0xbef398bc 2017-12-19 11:50:03.807 [ a] 0 MediaPlayer:handleStopCalled:idPassed=11,currentId=11 handleStop promise0xbef398bc 2017-12-19 11:50:03.816 [ a] 0 MediaPlayer:callingOnPlaybackStopped:currentId=11 2017-12-19 11:50:03.817 [ a] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:50:03.820 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testPauseAfterPause (213 ms) [ RUN ] MediaPlayerTest.testResumeAfterPlay setObserver &promise0xbef398d4 2017-12-19 11:50:03.828 [ b] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource istream &promise0xbef39884 2017-12-19 11:50:03.829 [ b] 0 MediaPlayer:handleSetSourceCalled handlesetsourceCalled promise0xbef39884 2017-12-19 11:50:03.829 [ b] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef398bc 2017-12-19 11:50:03.832 [ b] 0 MediaPlayer:handlePlayCalled:idPassed=12,currentId=12 handlePlay promise0xbef398bc 2017-12-19 11:50:03.832 [ b] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:50:03.832 [ b] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:50:03.832 [ b] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:50:03.832 [ b] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:50:03.833 [ b] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:50:03.851 [ b] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:50:03.971 [ b] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:03.971 [ b] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:03.976 [ b] 0 MediaPlayer:callingOnPlaybackStarted:currentId=12 resume &promise0xbef398bc 2017-12-19 11:50:03.977 [ b] 0 MediaPlayer:handleResumeCalled:idPassed=12,currentId=12 handleResume promise0xbef398bc 2017-12-19 11:50:03.977 [ b] E MediaPlayer:handleResumeFailed:reason=alreadyPlaying Stop &promise0xbef398bc 2017-12-19 11:50:03.977 [ b] 0 MediaPlayer:handleStopCalled:idPassed=12,currentId=12 handleStop promise0xbef398bc 2017-12-19 11:50:03.994 [ b] 0 MediaPlayer:callingOnPlaybackStopped:currentId=12 2017-12-19 11:50:03.997 [ b] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:50:04.003 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testResumeAfterPlay (183 ms) [ RUN ] MediaPlayerTest.testGetOffsetInMilliseconds setObserver &promise0xbef398d4 2017-12-19 11:50:04.018 [ c] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource attachmentreader &promise0xbef39854 2017-12-19 11:50:04.018 [ c] 0 MediaPlayer:handleSetSourceCalled handlesetAttachmentReaderSource promise0xbef39854 2017-12-19 11:50:04.019 [ c] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef39894 2017-12-19 11:50:04.021 [ c] 0 MediaPlayer:handlePlayCalled:idPassed=13,currentId=13 handlePlay promise0xbef39894 2017-12-19 11:50:04.022 [ c] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:50:04.022 [ c] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:50:04.022 [ c] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:50:04.022 [ c] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:50:04.022 [ c] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:50:04.043 [ c] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:50:04.172 [ c] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:04.172 [ c] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:04.178 [ c] 0 MediaPlayer:callingOnPlaybackStarted:currentId=13 2017-12-19 11:50:04.190 [ c] 0 MediaPlayer:callingOnTags getOffset &promise0xbef39894 2017-12-19 11:50:05.186 [ c] 0 MediaPlayer:handleGetOffsetCalled:idPassed=13,currentId=13 handleGetOffset promise0xbef39894 Stop &promise0xbef39894 2017-12-19 11:50:05.187 [ c] 0 MediaPlayer:handleStopCalled:idPassed=13,currentId=13 handleStop promise0xbef39894 2017-12-19 11:50:05.209 [ c] 0 MediaPlayer:callingOnPlaybackStopped:currentId=13 getOffset &promise0xbef39894 2017-12-19 11:50:05.209 [ c] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:50:05.210 [ c] 0 MediaPlayer:handleGetOffsetCalled:idPassed=13,currentId=0 handleGetOffset promise0xbef39894 2017-12-19 11:50:05.211 [ c] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet 2017-12-19 11:50:05.218 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testGetOffsetInMilliseconds (1214 ms) [ RUN ] MediaPlayerTest.testGetOffsetInMillisecondsNullPipeline setObserver &promise0xbef398d4 2017-12-19 11:50:05.230 [ d] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource attachmentreader &promise0xbef39864 2017-12-19 11:50:05.231 [ d] 0 MediaPlayer:handleSetSourceCalled handlesetAttachmentReaderSource promise0xbef39864 2017-12-19 11:50:05.231 [ d] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed getOffset &promise0xbef398a4 2017-12-19 11:50:05.234 [ d] 0 MediaPlayer:handleGetOffsetCalled:idPassed=15,currentId=14 handleGetOffset promise0xbef398a4 2017-12-19 11:50:05.234 [ d] E MediaPlayer:validateSourceAndIdFailed:reason=sourceIdMismatch 2017-12-19 11:50:05.241 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testGetOffsetInMillisecondsNullPipeline (23 ms) [ RUN ] MediaPlayerTest.testGetOffsetWhenStoppedFails setObserver &promise0xbef398d4 2017-12-19 11:50:05.253 [ e] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource attachmentreader &promise0xbef3985c 2017-12-19 11:50:05.253 [ e] 0 MediaPlayer:handleSetSourceCalled handlesetAttachmentReaderSource promise0xbef3985c 2017-12-19 11:50:05.254 [ e] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Play &promise0xbef3989c 2017-12-19 11:50:05.258 [ e] 0 MediaPlayer:handlePlayCalled:idPassed=15,currentId=15 handlePlay promise0xbef3989c 2017-12-19 11:50:05.258 [ e] 0 MediaPlayer:handlePlayCalled after validate source and ID

2017-12-19 11:50:05.258 [ e] 0 MediaPlayer:handlePlayCalled after gst_element_get_state

2017-12-19 11:50:05.258 [ e] 0 MediaPlayer:handlePlayCalled after GST_STATE_PLAYING

2017-12-19 11:50:05.258 [ e] 0 MediaPlayer:handlePlayCalled before set state

2017-12-19 11:50:05.258 [ e] 0 MediaPlayer:handlePlay:attemptBuffering=0 Failed to create secure directory (/home/root/.config/pulse): Read-only file system 2017-12-19 11:50:05.279 [ e] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC OnPadAdded &promise0xb54f5b44 handlePadAdded promise0xb54f5b44 2017-12-19 11:50:05.425 [ e] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:05.426 [ e] 0 MediaPlayer:callingOnTags 2017-12-19 11:50:05.428 [ e] 0 MediaPlayer:callingOnPlaybackStarted:currentId=15 2017-12-19 11:50:05.437 [ e] 0 MediaPlayer:callingOnTags Stop &promise0xbef3989c 2017-12-19 11:50:06.436 [ e] 0 MediaPlayer:handleStopCalled:idPassed=15,currentId=15 handleStop promise0xbef3989c 2017-12-19 11:50:06.456 [ e] 0 MediaPlayer:callingOnPlaybackStopped:currentId=15 getOffset &promise0xbef3989c 2017-12-19 11:50:06.457 [ e] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2017-12-19 11:50:06.458 [ e] 0 MediaPlayer:handleGetOffsetCalled:idPassed=15,currentId=0 handleGetOffset promise0xbef3989c 2017-12-19 11:50:06.458 [ e] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet 2017-12-19 11:50:06.461 [ 2] E RequiresShutdown:~RequiresShutdownFailed:reason=notShutdown,name= [ OK ] MediaPlayerTest.testGetOffsetWhenStoppedFails (1220 ms) [ RUN ] MediaPlayerTest.testGetOffsetWhenPaused setObserver &promise0xbef398d4 2017-12-19 11:50:06.469 [ f] 0 MediaPlayer:handleSetObserverCalled handlesetObserver promise0xbef398d4 setSource attachmentreader &promise0xbef3985c 2017-12-19 11:50:06.469 [ f] 0 MediaPlayer:handleSetSourceCalled handlesetAttachmentReaderSource promise0xbef3985c 2017-12-19 11:50:06.469 [ f] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed terminate called after throwing an instance of 'std::future_error' what(): Promise already satisfied Aborted (core dumped) root@info3-low:~# root@info3-low:~#

I can see the same promise being used in multiple methods, though it is stack variable. You were correct , this is initialization or cleanup issue. Do you know how to cleanup std::promise after being set to true in the case of handlePlay. I am still struggling to understand this weird issue. is G++ is the culprit here.

dhananjayj29 commented 6 years ago

regarding the ubuntu 14.04 , I am having some issue with the setup today for v1.3 version and could not get the logs. so for ubuntu 14.04 m still not sure whether same issue occurs or not.

As previous testing for ubuntu 14.04 was done on v1.1.0 and there I found multiple issues with promise setting which were resolved in v1.3 version.

sanjayrd commented 6 years ago

Hi @dhananjayj29,

Thanks for confirming. It doesn't really seem to be a code or std::promise issue, but rather some sort of issue with your compiler possibly re-using memory twice when allocating promises, or not cleaning up the metadata associated with a promise properly - either way, very strange.

I've been searching around and couldn't find any known issues around GCC 4.8.2 about this sort of behavior unfortunately.

I wonder if it would be possible to allocate the std::promises differently, maybe as a heap variable instead to guarantee a different address be used.

Thanks, Sanjay

dhananjayj29 commented 6 years ago

used heap variables .. and fixed this issue

yerasiprathyusha commented 6 years ago

Hi @dhananjayj29,

I am also facing the same issue on embedded environment (arm7l with openwrt using AVS device sdkVersion: 1.6.0). Can you please share the fixes you did about using std::promises as heap variable. It will be really helpful for me.

Thank in advance

charlesexu commented 5 years ago

Hi @dhananjayj29, I have the similar issue porting avs device sdk (version 1.9.0) on an Amlogic board. Could you please share your fix about using std::promises as heap variable. Thanks.