search

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 602 forks source link

SampleApp crashed when using iheart-radio #78

Closed charleschen84 closed 6 years ago

charleschen84 commented 6 years ago

Hi, i say "Alexa, play Justin Bieber on iheart-radio" . some time all is well, and some time the SampleApp crashed with these log:

306 [  e] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=expectedPreviousToken
2017-08-15 08:26:36.329 [  a] 9 AudioPlayer:executePlay:playBehavior=REPLACE_ALL
2017-08-15 08:26:36.338 [  a] 9 AudioPlayer:executestop:m_currentActivity=IDLE
2017-08-15 08:26:36.344 [  f] 9 AudioPlayer:onFocusChanged:newFocus=FOREGROUND
2017-08-15 08:26:36.359 [  a] 0 DirectiveProcessor:onHandlingCompeted:messageId=fdb9d426-f57d-4d07-bcca-cfb93776e75b,directiveBeingPreHandled=(nullptr)
2017-08-15 08:26:36.375 [  a] 0 CapabilityAgent:removingMessageIdFromMap:messageId=fdb9d426-f57d-4d07-bcca-cfb93776e75b
2017-08-15 08:26:36.393 [  a] 9 AudioPlayer:executeOnFocusChanged:from=NONE,to=FOREGROUND
2017-08-15 08:26:36.398 [  a] 9 AudioPlayer:executeOnFocusChanged:action=playNextItem
2017-08-15 08:26:36.423 [  a] 9 MediaPlayer:setSourceForUrlCalled
2017-08-15 08:26:36.435 [ 11] 0 MediaPlayer:handleSetSourceForUrlCalled
2017-08-15 08:26:36.439 [ 11] 9 MediaPlayer:tearDownPipeline
2017-08-15 08:26:36.451 [ 11] 9 DummyPlaylistParser:createCalled
2017-08-15 08:26:36.454 [ 11] 0 UrlSource:initCalledForUrlSource
2017-08-15 08:26:36.460 [ 11] 9 DummyPlaylistParser:parsePlaylist:url=http\://custom-hls.iheart.com/ihr-ingestion-pipeline-production-sbmg/encodes/Aug17/080417/incoming/prod/DDEX/A10301A0003751822E_20170805001725870/resources/A10301A0003751822E_T-1012210532048_SoundRecording_001-005.m4a?nga\=20170815082730&track\=49810008&player\=UklBWVd3Q2FtYXBuMGZNQVQ3SzJvQT09&env\=live&sig\=sMT5EQk5BG9EP8MCM126OaCAakjbc14qrea9Bu4G4qA&as\=SIMPLE&rnga\=20170815082730&host\=amazon.appliance.us
2017-08-15 08:26:36.522 [ 11] 0 UrlSource:onPlaylistParsed:parseResult=PARSE_RESULT_UNHANDLED,numUrlsParsed=0
2017-08-15 08:26:36.533 [  a] 9 MediaPlayer:playCalled
2017-08-15 08:26:36.537 [  2] 0 MediaPlayer:handlePlayCalled
2017-08-15 08:26:36.542 [  2] 0 MediaPlayer:doStopSuccess:reason=alreadyStopped
2017-08-15 08:26:36.551 [  2] 9 MediaPlayer:doStopSuccess
2017-08-15 08:26:36.702 [  7] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0e46c9fffe91384e-0000719e-00003f0b-b143d5de6ffbaaf1-fc59e522-13
2017-08-15 08:26:36.712 [  7] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2017-08-15 08:26:37.498 [  2] 0 MediaPlayer:handlePlay:stateReturn=ASYNC
2017-08-15 08:26:38.003 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=1
2017-08-15 08:26:38.023 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=2
2017-08-15 08:26:38.035 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=1
2017-08-15 08:26:38.039 [ 12] 9 MediaPlayer:onPadAddedCalled
2017-08-15 08:26:38.048 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=2
2017-08-15 08:26:38.056 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=3
2017-08-15 08:26:38.065 [  2] 9 MediaPlayer:handlePadAddedSignalCalled
2017-08-15 08:26:38.087 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=4
2017-08-15 08:26:38.093 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=5
2017-08-15 08:26:38.109 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=93
2017-08-15 08:26:38.117 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=99
2017-08-15 08:26:38.125 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=100
2017-08-15 08:26:38.137 [  2] 0 MediaPlayer:callingOnPlaybackStarted
2017-08-15 08:26:38.141 [  2] 9 AudioPlayer:onPlaybackStarted
2017-08-15 08:26:38.147 [  a] 0 AudioPlayer:changeActivity:from=IDLE,to=PLAYING
2017-08-15 08:26:38.153 [  a] 0 AudioPlayer:executeProvideState:sendToken=false,stateRequestToken=0
2017-08-15 08:26:38.162 [  a] 9 MediaPlayer:getOffsetInMillisecondsCalled
2017-08-15 08:26:38.169 [  2] 0 MediaPlayer:handleGetOffsetInMillisecondsCalled
2017-08-15 08:26:38.176 [  a] 0 ContextManager:updateStateLocked:action=updatedState,state={"token"\:"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#1aa0b0dd-4d97-4faf-8742-28d85e574e21\:1"\,"offsetInMilliseconds"\:23\,"playerActivity"\:"PLAYING"},namespace=AudioPlayer,name=PlaybackState
2017-08-15 08:26:38.201 [  a] 9 MediaPlayer:getOffsetInMillisecondsCalled
2017-08-15 08:26:38.207 [  2] 0 MediaPlayer:handleGetOffsetInMillisecondsCalled
2017-08-15 08:26:38.215 [  a] 0 EventBuilder:buildJsonEventString:messageId=1fe3b4ab-211d-48c0-a44e-15a1ce783eb5,namespace=AudioPlayer,name=PlaybackStarted
2017-08-15 08:26:38.228 [  a] 9 MediaPlayer:getOffsetInMillisecondsCalled
2017-08-15 08:26:38.234 [  2] 0 MediaPlayer:handleGetOffsetInMillisecondsCalled
2017-08-15 08:26:38.243 [  a] 0 EventBuilder:buildJsonEventString:messageId=63bd5415-fcd9-4f11-abc6-ac611dda9615,namespace=AudioPlayer,name=PlaybackNearlyFinished
2017-08-15 08:26:38.939 [  7] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0e46c9fffe91384e-0000719e-00003f0b-b143d5de6ffbaaf1-fc59e522-15
2017-08-15 08:26:38.950 [  7] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2017-08-15 08:26:40.235 [  7] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0e46c9fffe91384e-0000719e-00003f0b-b143d5de6ffbaaf1-fc59e522-17
2017-08-15 08:26:40.272 [  6] 0 MessageInterpreter:receive:messageId=3b3b73f2-1d51-45ba-9e3b-a0fc86650efc:No dialogRequestId attached to message.
2017-08-15 08:26:40.282 [  6] I DirectiveSequencer:onDirective:directive={"namespace\:"AudioPlayer"\,name\:"Play"\,messageId\:"3b3b73f2-1d51-45ba-9e3b-a0fc86650efc"\,dialogRequestId\:""}
2017-08-15 08:26:40.298 [  d] I DirectiveRouter:preHandleDirective:messageId=3b3b73f2-1d51-45ba-9e3b-a0fc86650efc,action=calling
2017-08-15 08:26:40.311 [  d] 0 CapabilityAgent:addingMessageIdToMap:messageId=3b3b73f2-1d51-45ba-9e3b-a0fc86650efc
2017-08-15 08:26:40.320 [  e] I DirectiveRouter:handleDirective:messageId=3b3b73f2-1d51-45ba-9e3b-a0fc86650efc,action=calling
2017-08-15 08:26:40.330 [  e] 9 AudioPlayer:handlePlayDirective
2017-08-15 08:26:40.336 [  e] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=streamFormat
2017-08-15 08:26:40.351 [  e] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=expectedPreviousToken
2017-08-15 08:26:40.359 [  a] 9 AudioPlayer:executePlay:playBehavior=ENQUEUE
2017-08-15 08:26:40.366 [  a] 0 DirectiveProcessor:onHandlingCompeted:messageId=3b3b73f2-1d51-45ba-9e3b-a0fc86650efc,directiveBeingPreHandled=(nullptr)
2017-08-15 08:26:40.379 [  a] 0 CapabilityAgent:removingMessageIdFromMap:messageId=3b3b73f2-1d51-45ba-9e3b-a0fc86650efc
2017-08-15 08:26:42.696 [  2] 9 MediaPlayer:handleBusMessage:message=GST_MESSAGE_BUFFERING,percent=0
Assertion 'pthread_mutex_unlock(&m->mutex) == 0' failed at pulsecore/mutex-posix.c:108, function pa_mutex_unlock(). Aborting.
[ 6922.634851] dwc_otg_hc_halt: hcchar.b.chen 1, ep_type 1
Aborted
dhpp commented 6 years ago

Hi Charles,

This looks really interesting. I've looked over our MediaPlayer code, and the failing assert appears lower level than our SDK. I did some research online, and found a very similar looking issue that was recently fixed within glibc on the Ubuntu platform:

https://bugs.launchpad.net/ubuntu/+source/gst-plugins-good1.0/+bug/1436162

The line trace (function, filename, line-number) is almost identical. Does this relate to your development platform, and are your underlying libraries up to date?

If the problem persists, could you please provide a stack trace, so we can get more visibility into what's behind the failing assert?

Thanks.

charleschen84 commented 6 years ago

Hi dhpp,

Thanks you for your reply, and I will check my libraries.