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

SampleApp crashed when trying "Alexa skip" with IHeartRadio #153

Closed
shikha-bansal opened this issue Sep 12, 2017 · 7 comments
Closed

SampleApp crashed when trying "Alexa skip" with IHeartRadio #153

shikha-bansal opened this issue Sep 12, 2017 · 7 comments

Comments

@shikha-bansal
Copy link

SDK version : 1.0.2 .
Steps to reproduce : Alexa get program A piece of work from IHeartRadio
Alexa skip
Alexa skip

Log :
2017-09-12 21:28:36.556 [ c] W DirectiveRouter:preHandleDirectiveFailed:messageId=ffc1c60d-ccd8-4ed9-8214-ffced8c59af2,reason=noHandlerRegistered
2017-09-12 21:28:36.556 [ c] I DirectiveSequencer:sendingExceptionEncountered:messageId=ffc1c60d-ccd8-4ed9-8214-ffced8c59af2
2017-09-12 21:28:36.557 [ c] 0 EventBuilder:buildJsonEventString:messageId=9d75acd3-82a8-4187-8e55-0bae0f75ae00,namespace=System,name=ExceptionEncountered
2017-09-12 21:28:36.558 [ 6] I DirectiveSequencer:onDirective:directive={"namespace:"AudioPlayer",name:"Play",messageId:"854a24f8-f1bf-4fac-b533-076f12fd0ce4",dialogRequestId:"9a00f1bc-75ba-45dd-b96e-f57071461ae6"}
2017-09-12 21:28:36.558 [ c] I DirectiveRouter:preHandleDirective:messageId=854a24f8-f1bf-4fac-b533-076f12fd0ce4,action=calling
2017-09-12 21:28:36.558 [ c] 0 CapabilityAgent:addingMessageIdToMap:messageId=854a24f8-f1bf-4fac-b533-076f12fd0ce4
2017-09-12 21:28:36.559 [ d] I DirectiveRouter:handleDirective:messageId=854a24f8-f1bf-4fac-b533-076f12fd0ce4,action=calling
2017-09-12 21:28:36.559 [ d] E AudioPlayer:handlePlayDirective
2017-09-12 21:28:36.559 [ d] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=streamFormat
2017-09-12 21:28:36.559 [ d] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=progressReport
2017-09-12 21:28:36.559 [ d] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=expectedPreviousToken
2017-09-12 21:28:36.559 [ 8] E AudioPlayer:executePlay:playBehavior=REPLACE_ALL
2017-09-12 21:28:36.559 [ 8] E AudioPlayer:executestop:m_currentActivity=PAUSED
2017-09-12 21:28:36.559 [ 8] E MediaPlayer:stopCalled
2017-09-12 21:28:36.560 [ 2] 0 MediaPlayer:handleStopCalled
2017-09-12 21:28:36.565 [ 2] 0 MediaPlayer:callingOnPlaybackFinished
2017-09-12 21:28:36.565 [ 2] E AudioPlayer:onPlaybackFinished
onPlaybackFinished
2017-09-12 21:28:36.565 [ 2] E MediaPlayer:doStopSuccess
2017-09-12 21:28:36.566 [ 8] 0 AudioPlayer:changeActivity:from=PAUSED,to=STOPPED
2017-09-12 21:28:36.566 [ 8] 0 AudioPlayer:executeProvideState:sendToken=false,stateRequestToken=0
2017-09-12 21:28:36.566 [ 8] E MediaPlayer:getOffsetInMillisecondsCalled
2017-09-12 21:28:36.566 [ 2] 0 MediaPlayer:handleGetOffsetInMillisecondsCalled
2017-09-12 21:28:36.566 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#b82c5eff[18251.838662@3] aml_pdm_dai_trigger
[18251.840180@3] asoc-aml-card meson_sound: pdm capture enable
[18251.845787@3] aml_pdm_hw_free
[18251.848692@3] enter aml_pdm_close type: 1, irq:128
[18251.853416@3] toddrs[2] released by device ff642000.audiobus:pdm
[18251.859690@3] tdm playback enable
[18251.862611@3] asoc-aml-card meson_sound: tdm playback stop
[18251.869095@3] frddrs[1] released by device ff642000.audiobus:tdmb
-b5b9-412c-b585-29f6552be828:3","offsetInMilliseconds":0,"playerActivity":"STOPPED"},namespace=AudioPlayer,name=PlaybackState
2017-09-12 21:28:36.566 [ 8] E MediaPlayer:getOffsetInMillisecondsCalled
2017-09-12 21:28:36.566 [ 2] 0 MediaPlayer:handleGetOffsetInMillisecondsCalled
2017-09-12 21:28:36.566 [ 8] 0 EventBuilder:buildJsonEventString:messageId=b33f50e9-1345-43fc-88b8-f047e80f0293,namespace=AudioPlayer,name=PlaybackStopped
2017-09-12 21:28:36.567 [ 8] 0 DirectiveProcessor:onHandlingCompeted:messageId=854a24f8-f1bf-4fac-b533-076f12fd0ce4,directiveBeingPreHandled=(nullptr)
2017-09-12 21:28:36.567 [ e] E AudioPlayer:onFocusChanged:newFocus=NONE
onFocusChanged 2 newFocus
2017-09-12 21:28:36.567 [ 8] 0 CapabilityAgent:removingMessageIdFromMap:messageId=854a24f8-f1bf-4fac-b533-076f12fd0ce4
2017-09-12 21:28:36.567 [ 8] E AudioPlayer:executeOnPlaybackFinishedError:reason=notPlaying,m_currentActivity=STOPPED
2017-09-12 21:28:36.567 [ 8] E AudioPlayer:executeOnFocusChanged:from=BACKGROUND,to=NONE
2017-09-12 21:28:36.568 [ e] E AudioPlayer:onFocusChanged:newFocus=BACKGROUND
onFocusChanged 1 newFocus
2017-09-12 21:28:36.568 [ 8] E AudioPlayer:executeOnFocusChanged:from=NONE,to=BACKGROUND
2017-09-12 21:28:36.759 [ b] 0 DialogUXStateAggregator:transitionFromThinkingTimedOut
2017-09-12 21:28:36.759 [ b] 0 DialogUXStateAggregator:setState:from=THINKING,to=IDLE
2017-09-12 21:28:36.759 [ a] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
########################################

Alexa is currently idle!

########################################
2017-09-12 21:28:36.760 [ e] E AudioPlayer:onFocusChanged:newFocus=FOREGROUND
onFocusChanged 0 newFocus
2017-09-12 21:28:36.760 [ 8] E AudioPlayer:executeOnFocusChanged:from=BACKGROUND,to=FOREGROUND
2017-09-12 21:28:36.760 [ 8] E AudioPlayer:executeOnFocusChanged:action=playNextItem
2017-09-12 21:28:36.760 [ 8] E MediaPlayer:setSourceForUrlCalled
2017-09-12 21:28:36.761 [ a] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2017-09-12 21:28:36.760 [ 25] 0 MediaPlayer:handleSetSourceForUrlCalled
2017-09-12 21:28:36.761 [ 25] E MediaPlayer:tearDownPipeline
2017-09-12 21:28:36.761 [ 25] 0 MediaPlayer:doStopSuccess:reason=alreadyStopped
2017-09-12 21:28:36.761 [ a] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2017-09-12 21:28:36.761 [ 25] E MediaPlayer:doStopSuccess
2017-09-12 21:28:36.762 [ 25] E MediaPlayer:resetPipeline
2017-09-12 21:28:36.765 [ 25] E PlaylistParser:createCalled
2017-09-12 21:28:36.765 [ 25] 0 UrlSource:initCalledForUrlSource
2017-09-12 21:28:36.766 [ 25] E PlaylistParser:parsePlaylist:url=https://www.podtrac.com/pts/redirect.mp3/audio.wnyc.org/pieceofwork/pieceofwork073117_cms780705_pod.mp3
2017-09-12 21:28:36.766 [ 25] E PlaylistParser:createPlaylistInfo
2017-09-12 21:28:36.766 [ 26] E PlaylistParser:handleParsingLocked
2017-09-12 21:28:36.766 [ 8] E MediaPlayer:playCalled
2017-09-12 21:28:36.767 [ 2] E PlaylistParser:onParseComplete
2017-09-12 21:28:36.767 [ 2] E PlaylistParser:handleOnParseComplete
2017-09-12 21:28:36.767 [ 2] E PlaylistParser:playlistCouldNotBeHandled
2017-09-12 21:28:36.767 [ 2] 0 UrlSource:onPlaylistParsed:parseResult=PARSE_RESULT_UNHANDLED,numUrlsParsed=0
2017-09-12 21:28:36.767 [ 8] E PlaylistParser:destructorCalled
2017-09-12 21:28:36.767 [ 8] 0 UrlSource:onPlaylistParsed:parseResult=PARSE_RESULT_CANCELLED,numUrlsParsed=0
terminate called after throwing an instance of 'std::future_error'
what(): Promise already satisfied
Aborted

Thanks
Shikha
@sanjayrd
Copy link
Contributor

Hi @shikha-bansal,

Thank you for the useful logs. It appears that you are using the Totem Playlist Parser, a 3rd party library, which is throwing an error saying it can't handle the playlist. We plan on replacing this in our upcoming release with our own Playlist Parser. I've just tested the behavior you described with our own Playlist Parser and I haven't had any crashes. Given this, is this a blocker for you or can you wait until our next release for this issue to be solved?

Best,
Sanjay

@INRIX-joel-winarske
Copy link

It doesn't crash for me. Alexa returns "I can't skip to the next song on iHeart Radio live"...

@shikha-bansal
Copy link
Author

@sanjayrd
I highly appreciate your super quick responses.

I see the error from Totem Playlist parser , always , but it does not crash for every skip.
This testcase is a part of Qualification process , hence a blocker for us.

@sanjayrd
Copy link
Contributor

Hi @shikha-bansal,

Temporary idea for a solution to avoid the crashes:

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

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

Would that be an acceptable temporary solution to avoid the crashes? If not, I can potentially find a way to give you an early (not fully tested) drop of our Playlist Parser code.

Thanks,
Sanjay

@shikha-bansal
Copy link
Author

Thanks for the suggestion . Seems to be ok for now.

When can we expect the 1.1 release ?

@kjkh
Copy link

kjkh commented Sep 21, 2017

Hi,
The release can be expected to happen within 2-4 weeks. Thanks for your interest!

This was referenced Sep 25, 2017
Closed
Closed
frozenberg added a commit that referenced this issue Oct 2, 2017
@frozenberg
Version 1.1.0 alexa-client-sdk
81c81b4 
- Changes in this update:

	- Better GStreamer error reporting. MediaPlayer used to only report   `MEDIA_ERROR_UNKNOWN`, now reports more specific errors as defined in `ErrorType.h`.
	- Codebase has been formatted for easier reading.
	- `DirectiveRouter::removeDirectiveHandler()` signature changed and now returns a bool indicating if given handler should be successfully removed or not.
	- Cleanup of raw and shared pointers in the creation of `Transport` objects.
	- `HTTP2Stream`s now have IDs assigned as they are acquired as opposed to created, making associated logs easier to interpret.
	- `AlertsCapabilityAgent` has been refactored.
		- Alert management has been factored out into an `AlertScheduler` class.
	- Creation of Reminder (implements Alert) class.
	- Added new capability agent for `PlaybackController` with unit tests.
	- Added Settings interface with unit tests.
	- Return type of `getOffsetInMilliseconds()` changed from `int64_t` to `std::chronology::milliseconds`.
	- Added `AudioPlayer` unit tests.
	- Added teardown for all Integration tests except Alerts.
	- Implemented PlaylistParser.

- Bug fixes:

	- AIP getting stuck in `LISTENING` or `THINKING` and refusing user input on network outage.
	- SampleApp crashing if running for 5 minutes after network disconnect.
	- Issue where on repeated user barge-ins, `AudioPlayer` would not pause. Specifically, the third attempt to “Play iHeartRadio” would not result in currently-playing music pausing.
	- Utterances being ignored after particularly long TTS.
	- GStreamer errors cropping up on SampleApp exit as a result of accessing the pipeline before it’s been setup.
	- Crashing when playing one URL after another.
	- Buffer overrun in Alerts Renderer.
	- [SampleApp crashing when issuing "Alexa skip" command with iHeartRadio.](#153)
	- [`HTTP2Transport` network thread triggering a join on itself.](#127)
	- [`HTTP2Stream` request handling truncating exception messages.](#67)
	- [`AudioPlayer` was attempting an incorrect state transition from `STOPPED` to `PLAYING` through a `playbackResumed`.](#138)
@kclchan
Copy link
Contributor

kclchan commented Oct 2, 2017

v1.1.0 is released with the fix to this issue.

@kclchan kclchan closed this as completed Oct 2, 2017
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@sanjayrd @kjkh @INRIX-joel-winarske @shikha-bansal @kclchan