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

No audio feedback (sound) from Alexa Sample App #479

Closed
Pooperpotamus opened this issue Jan 26, 2018 · 28 comments
Closed

No audio feedback (sound) from Alexa Sample App #479

Pooperpotamus opened this issue Jan 26, 2018 · 28 comments

Comments

@Pooperpotamus
Copy link

Hello again!
So i installed Alexa SDK on my raspberry pi. and is trying to run sample app.
It seems to work, i say "hey Alexa" and the terminal respond, i say "Whats the weather" and i can see the status change to thinking, speaking, and then back to Idle. But there is no sound from the raspberry pi

This is the Full event:

2018-01-26 15:31:00.870 [ a] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-01-26 15:31:00.870 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"wakeword" : "alexa"},namespace=SpeechRecognizer,name=RecognizerState
2018-01-26 15:31:00.870 [ d] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
2018-01-26 15:31:00.871 [ 7] 0 NotificationsCapabilityAgent:provideState:stateRequestToken=2
############################

Listening...

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

2018-01-26 15:31:00.871 [ 4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=2
2018-01-26 15:31:00.872 [ 4] 0 ContextManager:updateStateLocked:action=updatedState,state={"isEnabled":false,"isVisualIndicatorPersisted":false},namespace=Notifications,name=IndicatorState
2018-01-26 15:31:00.874 [ 7] 0 ContextManager:buildContextSuccessful:context={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":
2018-01-26 15:31:00.870 [ a] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-01-26 15:31:00.870 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"wakeword" : "alexa"},namespace=SpeechRecognizer,name=RecognizerState
2018-01-26 15:31:00.870 [ d] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
2018-01-26 15:31:00.871 [ 7] 0 NotificationsCapabilityAgent:provideState:stateRequestToken=2
############################

Listening...

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

2018-01-26 15:31:00.871 [ 4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=2
2018-01-26 15:31:00.872 [ 4] 0 ContextManager:updateStateLocked:action=updatedState,state={"isEnabled":false,"isVisualIndicatorPersisted":false},namespace=Notifications,name=IndicatorState
2018-01-26 15:31:00.874 [ 7] 0 ContextManager:buildContextSuccessful:context={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}}]}
2018-01-26 15:31:00.874 [ a] 0 AudioInputProcessor:executeOnContextAvailable:jsonContext={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}}]}
2018-01-26 15:31:00.875 [ a] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechRecognizer.Recognize
2018-01-26 15:31:00.876 [ e] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND
2018-01-26 15:31:00.876 [ a] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=,newValue=f9c26d31-0030-48bf-b85e-c3d452de64de
2018-01-26 15:31:00.877 [ a] 0 DirectiveProcessor:scrubDialogRequestIdLocked:reason=emptyDialogRequestId
2018-01-26 15:31:00.878 [ a] 0 EventBuilder:buildJsonEventString:messageId=b94c7a56-2bb3-4524-85fe-b609626cfd04,namespace=SpeechRecognizer,name=Recognize
2018-01-26 15:31:00.879 [ a] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND
2018-01-26 15:31:00.879 [ a] 9 HTTP2Transport:enqueueRequest:jsonContent={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}}],"event":{"header":{"namespace":"SpeechRecognizer","name":"Recognize","messageId":"b94c7a56-2bb3-4524-85fe-b609626cfd04","dialogRequestId":"f9c26d31-0030-48bf-b85e-c3d452de64de"},"payload":{"profile":"NEAR_FIELD","format":"AUDIO_L16_RATE_16000_CHANNELS_1","initiator":{"type":"WAKEWORD","payload":{"wakeWordIndices":{"startIndexInSamples":8000,"endIndexInSamples":14480}}}}}}
2018-01-26 15:31:00.959 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}}],"event":{"header":{"namespace":"SpeechRecognizer","name":"Recognize","messageId":"b94c7a56-2bb3-4524-85fe-b609626cfd04","dialogRequestId":"f9c26d31-0030-48bf-b85e-c3d452de64de"},"payload":{"profile":"NEAR_FIELD","format":"AUDIO_L16_RATE_16000_CHANNELS_1","initiator":{"type":"WAKEWORD","payload":{"wakeWordIndices":{"startIndexInSamples":8000,"endIndexInSamples":14480}}}}}}
2018-01-26 15:31:00.959 [ b] 0 HTTP2StreamPool:getStream:streamId=5,numAcquiredStreams=2
2018-01-26 15:31:00.960 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x1f8cf90
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Found bundle for host avs-alexa-na.amazon.com: 0x1df8c88 [can multiplex]
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Conn: 0 (0x1ed2800) Receive pipe weight: (-1/0), penalized: (nil)
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Multiplexed connection found!
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Found connection 0, with requests in the pipe (1)
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-01-26 15:31:00.961 [ b] I HTTP2Stream:libcurl:streamId=5,text=Using Stream ID: 5 (easy handle 0x1f8cf90)
2018-01-26 15:31:03.619 [ f] 0 MessageInterpreter:receive:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b:No dialogRequestId attached to message.
2018-01-26 15:31:03.620 [ f] I DirectiveSequencer:onDirective:directive={"namespace:"SpeechRecognizer",name:"StopCapture",messageId:"06cf0bde-a58f-4e79-8988-ef1d3eec229b",dialogRequestId:""}
2018-01-26 15:31:03.621 [ 10] I DirectiveRouter:preHandleDirective:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b,action=calling
2018-01-26 15:31:03.622 [ 10] 0 CapabilityAgent:addingMessageIdToMap:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b
2018-01-26 15:31:03.623 [ 11] I DirectiveRouter:handleDirective:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b,action=calling
2018-01-26 15:31:03.624 [ a] 0 AudioInputProcessor:stopCapture:stopImmediately=true
2018-01-26 15:31:03.624 [ a] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY
2018-01-26 15:31:03.624 [ d] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING
2018-01-26 15:31:03.625 [ a] 0 DirectiveProcessor:onHandlingCompeted:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b,directiveBeingPreHandled=(nullptr)
2018-01-26 15:31:03.625 [ a] 0 CapabilityAgent:removingMessageIdFromMap:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b
###########################

Thinking...

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

2018-01-26 15:31:03.629 [ b] I InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-01-26 15:31:03.936 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 12c4fbfffed726a8-00002d6f-00019ec4-79394be76587e21a-78af384b-7
2018-01-26 15:31:03.942 [ f] I DirectiveSequencer:onDirective:directive={"namespace:"SpeechSynthesizer",name:"Speak",messageId:"948f340b-504f-4557-a301-aca68bf818bd",dialogRequestId:"f9c26d31-0030-48bf-b85e-c3d452de64de"}
2018-01-26 15:31:03.943 [ 10] I DirectiveRouter:preHandleDirective:messageId=948f340b-504f-4557-a301-aca68bf818bd,action=calling
2018-01-26 15:31:03.943 [ 10] 0 CapabilityAgent:addingMessageIdToMap:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.943 [ 10] 9 SpeechSynthesizer:preHandleDirective:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.944 [ 8] 0 SpeechSynthesizer:executePreHandle:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.944 [ 11] I DirectiveRouter:handleDirective:messageId=948f340b-504f-4557-a301-aca68bf818bd,action=calling
2018-01-26 15:31:03.944 [ 11] 9 SpeechSynthesizer:handleDirective:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.949 [ b] I HTTP2Stream:libcurl:streamId=5,text=Curl_http_done: called premature == 0
2018-01-26 15:31:03.949 [ b] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS
2018-01-26 15:31:03.950 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=5,result=200
2018-01-26 15:31:03.950 [ b] 0 HTTP2StreamPool:releaseStream:streamId=5,numAcquiredStreams=1
2018-01-26 15:31:03.951 [ 8] 0 SpeechSynthesizer:executeHandle:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.951 [ 8] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechSynthesizer.Speak
2018-01-26 15:31:03.952 [ e] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE
2018-01-26 15:31:03.952 [ e] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND
2018-01-26 15:31:03.952 [ e] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS
2018-01-26 15:31:03.952 [ a] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2018-01-26 15:31:03.953 [ 8] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING
2018-01-26 15:31:03.953 [ a] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2018-01-26 15:31:03.953 [ 8] 9 SpeechSynthesizer:startPlaying
2018-01-26 15:31:03.953 [ a] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2018-01-26 15:31:03.953 [ 8] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader
2018-01-26 15:31:03.954 [ 2] 0 MediaPlayer:handleSetSourceCalled
2018-01-26 15:31:03.954 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements
2018-01-26 15:31:03.954 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed
2018-01-26 15:31:04.035 [ 8] 9 MediaPlayer:playCalled
2018-01-26 15:31:04.036 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1
2018-01-26 15:31:04.036 [ 2] 0 MediaPlayer:handlePlay:attemptBuffering=0
2018-01-26 15:31:04.205 [ 2] 9 AttachmentReaderSource:handleSeekData:offset=0
2018-01-26 15:31:04.205 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC
2018-01-26 15:31:04.205 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-01-26 15:31:04.206 [ 12] 9 BaseStreamSource:onNeedDataCalled:size=4096
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:State Change:oldState=NULL,newState=READY,pendingState=PLAYING
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-01-26 15:31:04.206 [ 2] 9 BaseStreamSource:handleNeedDataCalled
2018-01-26 15:31:04.207 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=15
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:read:size=1213,status=0
2018-01-26 15:31:04.207 [ 2] I InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:read:size=0,status=3
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:handleReadData:info=signalingEndOfData
2018-01-26 15:31:04.207 [ 2] 9 BaseStreamSource:signalEndOfDataCalled
2018-01-26 15:31:04.207 [ 2] 9 BaseStreamSource:gstAppSrcEndOfStreamSuccess
2018-01-26 15:31:04.208 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=15
2018-01-26 15:31:04.242 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-01-26 15:31:04.242 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-01-26 15:31:04.258 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-01-26 15:31:04.258 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-01-26 15:31:05.609 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=avdec_mp3-0
2018-01-26 15:31:05.610 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=avdec_mp3-0
2018-01-26 15:31:05.664 [ 12] 9 MediaPlayer:onPadAddedCalled
2018-01-26 15:31:05.665 [ 2] 9 MediaPlayer:handlePadAddedSignalCalled
2018-01-26 15:31:05.668 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-01-26 15:31:05.669 [ 2] 9 MediaPlayer:messageReceived:type=stream-start,source=audio-pipeline
2018-01-26 15:31:05.690 [ 2] 9 MediaPlayer:messageReceived:type=latency,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.691 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.693 [ 2] 0 MediaPlayer:callingOnTags
2018-01-26 15:31:05.693 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.693 [ 2] 0 MediaPlayer:callingOnTags
2018-01-26 15:31:05.701 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:State Change:oldState=READY,newState=PAUSED,pendingState=PLAYING
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=async-done,source=audio-pipeline
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=new-clock,source=audio-pipeline
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.703 [ 2] 0 MediaPlayer:callingOnTags
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=avdec_mp3-0
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:State Change:oldState=PAUSED,newState=PLAYING,pendingState=VOID_PENDING
2018-01-26 15:31:05.704 [ 2] 0 MediaPlayer:callingOnPlaybackStarted:currentId=1
2018-01-26 15:31:05.704 [ 2] 9 SpeechSynthesizer:onPlaybackStarted:callbackSourceId=1
2018-01-26 15:31:05.705 [ 8] 0 SpeechSynthesizer:executePlaybackStarted
2018-01-26 15:31:05.705 [ 8] 9 SpeechSynthesizer:setCurrentStateLocked:state=PLAYING
2018-01-26 15:31:05.705 [ 8] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0
2018-01-26 15:31:05.705 [ 8] 9 MediaPlayer:getOffsetCalled
2018-01-26 15:31:05.706 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=audiosinkringbuffer0
2018-01-26 15:31:05.706 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=1,currentId=1
2018-01-26 15:31:05.708 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd","offsetInMilliseconds":384,"playerActivity":"PLAYING"},namespace=SpeechSynthesizer,name=SpeechState
2018-01-26 15:31:05.708 [ e] 9 SpeechSynthesizer:onFocusChangedSuccess
2018-01-26 15:31:05.709 [ 8] 0 EventBuilder:buildJsonEventString:messageId=6fcf8dee-ad9b-419d-8578-863625243cc2,namespace=SpeechSynthesizer,name=SpeechStarted
2018-01-26 15:31:05.710 [ 8] 9 HTTP2Transport:enqueueRequest:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechStarted","messageId":"6fcf8dee-ad9b-419d-8578-863625243cc2"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd"}}}
2018-01-26 15:31:05.711 [ d] 0 DialogUXStateAggregator:setState:from=THINKING,to=SPEAKING
###########################

Speaking...

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

2018-01-26 15:31:05.730 [ 12] 9 BaseStreamSource:onNeedDataCalled:size=4096
2018-01-26 15:31:05.731 [ 2] 9 BaseStreamSource:handleNeedDataCalled
2018-01-26 15:31:05.755 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechStarted","messageId":"6fcf8dee-ad9b-419d-8578-863625243cc2"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd"}}}
2018-01-26 15:31:05.755 [ b] 0 HTTP2StreamPool:getStream:streamId=7,numAcquiredStreams=2
2018-01-26 15:31:05.755 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x1f8cf90
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Found bundle for host avs-alexa-na.amazon.com: 0x1df8c88 [can multiplex]
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Conn: 0 (0x1ed2800) Receive pipe weight: (-1/0), penalized: (nil)
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Multiplexed connection found!
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Found connection 0, with requests in the pipe (1)
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-01-26 15:31:05.756 [ b] I HTTP2Stream:libcurl:streamId=7,text=Using Stream ID: 7 (easy handle 0x1f8cf90)
2018-01-26 15:31:05.958 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 12c4fbfffed726a8-00002d6f-0001b84f-0da51f420068c927-0b4bf0ce-7
2018-01-26 15:31:05.958 [ b] I HTTP2Stream:libcurl:streamId=7,text=Curl_http_done: called premature == 0
2018-01-26 15:31:05.958 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=7,result=204
2018-01-26 15:31:05.958 [ b] 0 HTTP2StreamPool:releaseStream:streamId=7,numAcquiredStreams=1
2018-01-26 15:31:05.958 [ b] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2018-01-26 15:31:06.347 [ 2] 9 MediaPlayer:messageReceived:type=eos,source=audio-pipeline
2018-01-26 15:31:06.647 [ 2] 9 BaseStreamSource:~BaseStreamSource
2018-01-26 15:31:06.648 [ 2] 0 MediaPlayer:callingOnPlaybackFinished:currentId=1
2018-01-26 15:31:06.648 [ 2] 9 SpeechSynthesizer:onPlaybackFinished:callbackSourceId=1
2018-01-26 15:31:06.649 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements
2018-01-26 15:31:06.649 [ 8] 0 SpeechSynthesizer:executePlaybackFinished
2018-01-26 15:31:06.649 [ 8] 9 SpeechSynthesizer:setCurrentStateLocked:state=FINISHED
2018-01-26 15:31:06.649 [ 8] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0
2018-01-26 15:31:06.649 [ 2] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=1560
2018-01-26 15:31:06.649 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd","offsetInMilliseconds":0,"playerActivity":"FINISHED"},namespace=SpeechSynthesizer,name=SpeechState
2018-01-26 15:31:06.651 [ 8] 0 EventBuilder:buildJsonEventString:messageId=10f9ac6d-a054-4427-814d-66f6e5d75ca5,namespace=SpeechSynthesizer,name=SpeechFinished
2018-01-26 15:31:06.651 [ 8] 9 HTTP2Transport:enqueueRequest:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechFinished","messageId":"10f9ac6d-a054-4427-814d-66f6e5d75ca5"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd"}}}
2018-01-26 15:31:06.652 [ 8] 9 SpeechSynthesizer:setHandlingCompleted
2018-01-26 15:31:06.652 [ 8] 0 DirectiveProcessor:onHandlingCompeted:messageId=948f340b-504f-4557-a301-aca68bf818bd,directiveBeingPreHandled=(nullptr)
2018-01-26 15:31:06.652 [ 8] 0 CapabilityAgent:removingMessageIdFromMap:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:06.661 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechFinished","messageId":"10f9ac6d-a054-4427-814d-66f6e5d75ca5"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd"}}}
2018-01-26 15:31:06.661 [ b] 0 HTTP2StreamPool:getStream:streamId=9,numAcquiredStreams=2
2018-01-26 15:31:06.661 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x1f8cf90
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Found bundle for host avs-alexa-na.amazon.com: 0x1df8c88 [can multiplex]
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Conn: 0 (0x1ed2800) Receive pipe weight: (-1/0), penalized: (nil)
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Multiplexed connection found!
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Found connection 0, with requests in the pipe (1)
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-01-26 15:31:06.663 [ b] I HTTP2Stream:libcurl:streamId=9,text=Using Stream ID: 9 (easy handle 0x1f8cf90)
2018-01-26 15:31:06.851 [ d] 0 DialogUXStateAggregator:setState:from=SPEAKING,to=IDLE
2018-01-26 15:31:06.851 [ 8] 1 FocusManager:releaseChannel:channelName=Dialog
########################################

Alexa is currently idle!

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

2018-01-26 15:31:06.852 [ e] 0 SpeechSynthesizer:onFocusChanged:newFocus=NONE
2018-01-26 15:31:06.902 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 12c4fbfffed726a8-00002d6f-0001b84f-0da51f420068c927-0b4bf0ce-9
2018-01-26 15:31:06.902 [ b] I HTTP2Stream:libcurl:streamId=9,text=Curl_http_done: called premature == 0
2018-01-26 15:31:06.902 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=9,result=204
2018-01-26 15:31:06.902 [ b] 0 HTTP2StreamPool:releaseStream:streamId=9,numAcquiredStreams=1
2018-01-26 15:31:06.902 [ b] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2018-01-26 15:31:30.758 [ 13] I AbstractKeywordDetector:readFromStreamFailed:reason=readerTimeOut
2018-01-26 15:31:00.870 [ a] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-01-26 15:31:00.870 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"wakeword" : "alexa"},namespace=SpeechRecognizer,name=RecognizerState
2018-01-26 15:31:00.870 [ d] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
2018-01-26 15:31:00.871 [ 7] 0 NotificationsCapabilityAgent:provideState:stateRequestToken=2
############################

Listening...

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

2018-01-26 15:31:00.871 [ 4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=2
2018-01-26 15:31:00.872 [ 4] 0 ContextManager:updateStateLocked:action=updatedState,state={"isEnabled":false,"isVisualIndicatorPersisted":false},namespace=Notifications,name=IndicatorState
2018-01-26 15:31:00.874 [ 7] 0 ContextManager:buildContextSuccessful:context={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":
2018-01-26 15:31:00.870 [ a] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-01-26 15:31:00.870 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"wakeword" : "alexa"},namespace=SpeechRecognizer,name=RecognizerState
2018-01-26 15:31:00.870 [ d] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
2018-01-26 15:31:00.871 [ 7] 0 NotificationsCapabilityAgent:provideState:stateRequestToken=2
############################

Listening...

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

2018-01-26 15:31:00.871 [ 4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=2
2018-01-26 15:31:00.872 [ 4] 0 ContextManager:updateStateLocked:action=updatedState,state={"isEnabled":false,"isVisualIndicatorPersisted":false},namespace=Notifications,name=IndicatorState
2018-01-26 15:31:00.874 [ 7] 0 ContextManager:buildContextSuccessful:context={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}}]}
2018-01-26 15:31:00.874 [ a] 0 AudioInputProcessor:executeOnContextAvailable:jsonContext={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}}]}
2018-01-26 15:31:00.875 [ a] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechRecognizer.Recognize
2018-01-26 15:31:00.876 [ e] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND
2018-01-26 15:31:00.876 [ a] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=,newValue=f9c26d31-0030-48bf-b85e-c3d452de64de
2018-01-26 15:31:00.877 [ a] 0 DirectiveProcessor:scrubDialogRequestIdLocked:reason=emptyDialogRequestId
2018-01-26 15:31:00.878 [ a] 0 EventBuilder:buildJsonEventString:messageId=b94c7a56-2bb3-4524-85fe-b609626cfd04,namespace=SpeechRecognizer,name=Recognize
2018-01-26 15:31:00.879 [ a] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND
2018-01-26 15:31:00.879 [ a] 9 HTTP2Transport:enqueueRequest:jsonContent={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}}],"event":{"header":{"namespace":"SpeechRecognizer","name":"Recognize","messageId":"b94c7a56-2bb3-4524-85fe-b609626cfd04","dialogRequestId":"f9c26d31-0030-48bf-b85e-c3d452de64de"},"payload":{"profile":"NEAR_FIELD","format":"AUDIO_L16_RATE_16000_CHANNELS_1","initiator":{"type":"WAKEWORD","payload":{"wakeWordIndices":{"startIndexInSamples":8000,"endIndexInSamples":14480}}}}}}
2018-01-26 15:31:00.959 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}}],"event":{"header":{"namespace":"SpeechRecognizer","name":"Recognize","messageId":"b94c7a56-2bb3-4524-85fe-b609626cfd04","dialogRequestId":"f9c26d31-0030-48bf-b85e-c3d452de64de"},"payload":{"profile":"NEAR_FIELD","format":"AUDIO_L16_RATE_16000_CHANNELS_1","initiator":{"type":"WAKEWORD","payload":{"wakeWordIndices":{"startIndexInSamples":8000,"endIndexInSamples":14480}}}}}}
2018-01-26 15:31:00.959 [ b] 0 HTTP2StreamPool:getStream:streamId=5,numAcquiredStreams=2
2018-01-26 15:31:00.960 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x1f8cf90
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Found bundle for host avs-alexa-na.amazon.com: 0x1df8c88 [can multiplex]
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Conn: 0 (0x1ed2800) Receive pipe weight: (-1/0), penalized: (nil)
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Multiplexed connection found!
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Found connection 0, with requests in the pipe (1)
2018-01-26 15:31:00.960 [ b] I HTTP2Stream:libcurl:streamId=5,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-01-26 15:31:00.961 [ b] I HTTP2Stream:libcurl:streamId=5,text=Using Stream ID: 5 (easy handle 0x1f8cf90)
2018-01-26 15:31:03.619 [ f] 0 MessageInterpreter:receive:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b:No dialogRequestId attached to message.
2018-01-26 15:31:03.620 [ f] I DirectiveSequencer:onDirective:directive={"namespace:"SpeechRecognizer",name:"StopCapture",messageId:"06cf0bde-a58f-4e79-8988-ef1d3eec229b",dialogRequestId:""}
2018-01-26 15:31:03.621 [ 10] I DirectiveRouter:preHandleDirective:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b,action=calling
2018-01-26 15:31:03.622 [ 10] 0 CapabilityAgent:addingMessageIdToMap:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b
2018-01-26 15:31:03.623 [ 11] I DirectiveRouter:handleDirective:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b,action=calling
2018-01-26 15:31:03.624 [ a] 0 AudioInputProcessor:stopCapture:stopImmediately=true
2018-01-26 15:31:03.624 [ a] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY
2018-01-26 15:31:03.624 [ d] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING
2018-01-26 15:31:03.625 [ a] 0 DirectiveProcessor:onHandlingCompeted:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b,directiveBeingPreHandled=(nullptr)
2018-01-26 15:31:03.625 [ a] 0 CapabilityAgent:removingMessageIdFromMap:messageId=06cf0bde-a58f-4e79-8988-ef1d3eec229b
###########################

Thinking...

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

2018-01-26 15:31:03.629 [ b] I InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-01-26 15:31:03.936 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 12c4fbfffed726a8-00002d6f-00019ec4-79394be76587e21a-78af384b-7
2018-01-26 15:31:03.942 [ f] I DirectiveSequencer:onDirective:directive={"namespace:"SpeechSynthesizer",name:"Speak",messageId:"948f340b-504f-4557-a301-aca68bf818bd",dialogRequestId:"f9c26d31-0030-48bf-b85e-c3d452de64de"}
2018-01-26 15:31:03.943 [ 10] I DirectiveRouter:preHandleDirective:messageId=948f340b-504f-4557-a301-aca68bf818bd,action=calling
2018-01-26 15:31:03.943 [ 10] 0 CapabilityAgent:addingMessageIdToMap:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.943 [ 10] 9 SpeechSynthesizer:preHandleDirective:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.944 [ 8] 0 SpeechSynthesizer:executePreHandle:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.944 [ 11] I DirectiveRouter:handleDirective:messageId=948f340b-504f-4557-a301-aca68bf818bd,action=calling
2018-01-26 15:31:03.944 [ 11] 9 SpeechSynthesizer:handleDirective:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.949 [ b] I HTTP2Stream:libcurl:streamId=5,text=Curl_http_done: called premature == 0
2018-01-26 15:31:03.949 [ b] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS
2018-01-26 15:31:03.950 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=5,result=200
2018-01-26 15:31:03.950 [ b] 0 HTTP2StreamPool:releaseStream:streamId=5,numAcquiredStreams=1
2018-01-26 15:31:03.951 [ 8] 0 SpeechSynthesizer:executeHandle:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:03.951 [ 8] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechSynthesizer.Speak
2018-01-26 15:31:03.952 [ e] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE
2018-01-26 15:31:03.952 [ e] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND
2018-01-26 15:31:03.952 [ e] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS
2018-01-26 15:31:03.952 [ a] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2018-01-26 15:31:03.953 [ 8] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING
2018-01-26 15:31:03.953 [ a] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2018-01-26 15:31:03.953 [ 8] 9 SpeechSynthesizer:startPlaying
2018-01-26 15:31:03.953 [ a] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2018-01-26 15:31:03.953 [ 8] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader
2018-01-26 15:31:03.954 [ 2] 0 MediaPlayer:handleSetSourceCalled
2018-01-26 15:31:03.954 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements
2018-01-26 15:31:03.954 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed
2018-01-26 15:31:04.035 [ 8] 9 MediaPlayer:playCalled
2018-01-26 15:31:04.036 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1
2018-01-26 15:31:04.036 [ 2] 0 MediaPlayer:handlePlay:attemptBuffering=0
2018-01-26 15:31:04.205 [ 2] 9 AttachmentReaderSource:handleSeekData:offset=0
2018-01-26 15:31:04.205 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC
2018-01-26 15:31:04.205 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-01-26 15:31:04.206 [ 12] 9 BaseStreamSource:onNeedDataCalled:size=4096
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:State Change:oldState=NULL,newState=READY,pendingState=PLAYING
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-01-26 15:31:04.206 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-01-26 15:31:04.206 [ 2] 9 BaseStreamSource:handleNeedDataCalled
2018-01-26 15:31:04.207 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=15
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:read:size=1213,status=0
2018-01-26 15:31:04.207 [ 2] I InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:read:size=0,status=3
2018-01-26 15:31:04.207 [ 2] 9 AttachmentReaderSource:handleReadData:info=signalingEndOfData
2018-01-26 15:31:04.207 [ 2] 9 BaseStreamSource:signalEndOfDataCalled
2018-01-26 15:31:04.207 [ 2] 9 BaseStreamSource:gstAppSrcEndOfStreamSuccess
2018-01-26 15:31:04.208 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=15
2018-01-26 15:31:04.242 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-01-26 15:31:04.242 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-01-26 15:31:04.258 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-01-26 15:31:04.258 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-01-26 15:31:05.609 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=avdec_mp3-0
2018-01-26 15:31:05.610 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=avdec_mp3-0
2018-01-26 15:31:05.664 [ 12] 9 MediaPlayer:onPadAddedCalled
2018-01-26 15:31:05.665 [ 2] 9 MediaPlayer:handlePadAddedSignalCalled
2018-01-26 15:31:05.668 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-01-26 15:31:05.669 [ 2] 9 MediaPlayer:messageReceived:type=stream-start,source=audio-pipeline
2018-01-26 15:31:05.690 [ 2] 9 MediaPlayer:messageReceived:type=latency,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.691 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.693 [ 2] 0 MediaPlayer:callingOnTags
2018-01-26 15:31:05.693 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.693 [ 2] 0 MediaPlayer:callingOnTags
2018-01-26 15:31:05.701 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:State Change:oldState=READY,newState=PAUSED,pendingState=PLAYING
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=async-done,source=audio-pipeline
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=new-clock,source=audio-pipeline
2018-01-26 15:31:05.702 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.703 [ 2] 0 MediaPlayer:callingOnTags
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink-actual-sink-omxhdmiaudio
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=avdec_mp3-0
2018-01-26 15:31:05.703 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-01-26 15:31:05.704 [ 2] 9 MediaPlayer:State Change:oldState=PAUSED,newState=PLAYING,pendingState=VOID_PENDING
2018-01-26 15:31:05.704 [ 2] 0 MediaPlayer:callingOnPlaybackStarted:currentId=1
2018-01-26 15:31:05.704 [ 2] 9 SpeechSynthesizer:onPlaybackStarted:callbackSourceId=1
2018-01-26 15:31:05.705 [ 8] 0 SpeechSynthesizer:executePlaybackStarted
2018-01-26 15:31:05.705 [ 8] 9 SpeechSynthesizer:setCurrentStateLocked:state=PLAYING
2018-01-26 15:31:05.705 [ 8] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0
2018-01-26 15:31:05.705 [ 8] 9 MediaPlayer:getOffsetCalled
2018-01-26 15:31:05.706 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=audiosinkringbuffer0
2018-01-26 15:31:05.706 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=1,currentId=1
2018-01-26 15:31:05.708 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd","offsetInMilliseconds":384,"playerActivity":"PLAYING"},namespace=SpeechSynthesizer,name=SpeechState
2018-01-26 15:31:05.708 [ e] 9 SpeechSynthesizer:onFocusChangedSuccess
2018-01-26 15:31:05.709 [ 8] 0 EventBuilder:buildJsonEventString:messageId=6fcf8dee-ad9b-419d-8578-863625243cc2,namespace=SpeechSynthesizer,name=SpeechStarted
2018-01-26 15:31:05.710 [ 8] 9 HTTP2Transport:enqueueRequest:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechStarted","messageId":"6fcf8dee-ad9b-419d-8578-863625243cc2"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd"}}}
2018-01-26 15:31:05.711 [ d] 0 DialogUXStateAggregator:setState:from=THINKING,to=SPEAKING
###########################

Speaking...

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

2018-01-26 15:31:05.730 [ 12] 9 BaseStreamSource:onNeedDataCalled:size=4096
2018-01-26 15:31:05.731 [ 2] 9 BaseStreamSource:handleNeedDataCalled
2018-01-26 15:31:05.755 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechStarted","messageId":"6fcf8dee-ad9b-419d-8578-863625243cc2"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd"}}}
2018-01-26 15:31:05.755 [ b] 0 HTTP2StreamPool:getStream:streamId=7,numAcquiredStreams=2
2018-01-26 15:31:05.755 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x1f8cf90
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Found bundle for host avs-alexa-na.amazon.com: 0x1df8c88 [can multiplex]
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Conn: 0 (0x1ed2800) Receive pipe weight: (-1/0), penalized: (nil)
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Multiplexed connection found!
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Found connection 0, with requests in the pipe (1)
2018-01-26 15:31:05.755 [ b] I HTTP2Stream:libcurl:streamId=7,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-01-26 15:31:05.756 [ b] I HTTP2Stream:libcurl:streamId=7,text=Using Stream ID: 7 (easy handle 0x1f8cf90)
2018-01-26 15:31:05.958 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 12c4fbfffed726a8-00002d6f-0001b84f-0da51f420068c927-0b4bf0ce-7
2018-01-26 15:31:05.958 [ b] I HTTP2Stream:libcurl:streamId=7,text=Curl_http_done: called premature == 0
2018-01-26 15:31:05.958 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=7,result=204
2018-01-26 15:31:05.958 [ b] 0 HTTP2StreamPool:releaseStream:streamId=7,numAcquiredStreams=1
2018-01-26 15:31:05.958 [ b] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2018-01-26 15:31:06.347 [ 2] 9 MediaPlayer:messageReceived:type=eos,source=audio-pipeline
2018-01-26 15:31:06.647 [ 2] 9 BaseStreamSource:~BaseStreamSource
2018-01-26 15:31:06.648 [ 2] 0 MediaPlayer:callingOnPlaybackFinished:currentId=1
2018-01-26 15:31:06.648 [ 2] 9 SpeechSynthesizer:onPlaybackFinished:callbackSourceId=1
2018-01-26 15:31:06.649 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements
2018-01-26 15:31:06.649 [ 8] 0 SpeechSynthesizer:executePlaybackFinished
2018-01-26 15:31:06.649 [ 8] 9 SpeechSynthesizer:setCurrentStateLocked:state=FINISHED
2018-01-26 15:31:06.649 [ 8] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0
2018-01-26 15:31:06.649 [ 2] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=1560
2018-01-26 15:31:06.649 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd","offsetInMilliseconds":0,"playerActivity":"FINISHED"},namespace=SpeechSynthesizer,name=SpeechState
2018-01-26 15:31:06.651 [ 8] 0 EventBuilder:buildJsonEventString:messageId=10f9ac6d-a054-4427-814d-66f6e5d75ca5,namespace=SpeechSynthesizer,name=SpeechFinished
2018-01-26 15:31:06.651 [ 8] 9 HTTP2Transport:enqueueRequest:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechFinished","messageId":"10f9ac6d-a054-4427-814d-66f6e5d75ca5"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd"}}}
2018-01-26 15:31:06.652 [ 8] 9 SpeechSynthesizer:setHandlingCompleted
2018-01-26 15:31:06.652 [ 8] 0 DirectiveProcessor:onHandlingCompeted:messageId=948f340b-504f-4557-a301-aca68bf818bd,directiveBeingPreHandled=(nullptr)
2018-01-26 15:31:06.652 [ 8] 0 CapabilityAgent:removingMessageIdFromMap:messageId=948f340b-504f-4557-a301-aca68bf818bd
2018-01-26 15:31:06.661 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechFinished","messageId":"10f9ac6d-a054-4427-814d-66f6e5d75ca5"},"payload":{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#ACRI#DeviceTTSRendererV4_8d7b6de8-11fd-4d2e-b693-7cbe791f97cd"}}}
2018-01-26 15:31:06.661 [ b] 0 HTTP2StreamPool:getStream:streamId=9,numAcquiredStreams=2
2018-01-26 15:31:06.661 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x1f8cf90
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Found bundle for host avs-alexa-na.amazon.com: 0x1df8c88 [can multiplex]
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Conn: 0 (0x1ed2800) Receive pipe weight: (-1/0), penalized: (nil)
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Multiplexed connection found!
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Found connection 0, with requests in the pipe (1)
2018-01-26 15:31:06.662 [ b] I HTTP2Stream:libcurl:streamId=9,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-01-26 15:31:06.663 [ b] I HTTP2Stream:libcurl:streamId=9,text=Using Stream ID: 9 (easy handle 0x1f8cf90)
2018-01-26 15:31:06.851 [ d] 0 DialogUXStateAggregator:setState:from=SPEAKING,to=IDLE
2018-01-26 15:31:06.851 [ 8] 1 FocusManager:releaseChannel:channelName=Dialog
########################################

Alexa is currently idle!

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

2018-01-26 15:31:06.852 [ e] 0 SpeechSynthesizer:onFocusChanged:newFocus=NONE
2018-01-26 15:31:06.902 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 12c4fbfffed726a8-00002d6f-0001b84f-0da51f420068c927-0b4bf0ce-9
2018-01-26 15:31:06.902 [ b] I HTTP2Stream:libcurl:streamId=9,text=Curl_http_done: called premature == 0
2018-01-26 15:31:06.902 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=9,result=204
2018-01-26 15:31:06.902 [ b] 0 HTTP2StreamPool:releaseStream:streamId=9,numAcquiredStreams=1
2018-01-26 15:31:06.902 [ b] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2018-01-26 15:31:30.758 [ 13] I AbstractKeywordDetector:readFromStreamFailed:reason=readerTimeOut

To me it seems to recognise (at least in parts) that i am saying something, and should (at least) respond with a "i dont understand"

There is sound coming from the pi (youtube works, and front_center test works) so i am not sure why i i hear nothing from alexa.

I cant find any settings for alexa specifically to change audio output.

Any guesses as to why alexa is being shy? :)

@Pooperpotamus
Copy link
Author

Pooperpotamus commented Jan 26, 2018

Hello again!

Just tried to plug it in to my TV with the HDMI cable. and there is sound, it just goes through the HDMI instead of the jack.

All other sound on the pi goes through the Jack (when chosen in the top right corners volume control) So why doenst the Alexa app?

Amy Clues? - is there a files to be altered?

I have tried sudo raspi config advanced option, audio and "force 3.5mm" but it doenst do anything :(

@sanjayrd
Copy link
Contributor

Hi @Pooperpotamus,

Not sure if this helps you out specifically, but someone else modified the boot/config.txt to comment out the following line: hdmi_force_hotplug=1 and then rebooted and got sound working. Can you give that a go and see if it helps?

Thanks,
Sanjay

@bandkenamazoncom
Copy link
Contributor

Thanks @sanjayrd!

@Pooperpotamus
Copy link
Author

Hi @sanjayrd Thanks for the answer man!

I tried with no success.

This is my Config file as is now:

For more options and information see

http://rpf.io/configtxt

Some settings may impact device functionality. See link above for details

uncomment if you get no picture on HDMI for a default "safe" mode

#hdmi_safe=1

uncomment this if your display has a black border of unused pixels visible

and your display can output without overscan

#disable_overscan=1

uncomment the following to adjust overscan. Use positive numbers if console

goes off screen, and negative if there is too much border

#overscan_left=16
#overscan_right=16
#overscan_top=16
#overscan_bottom=16

uncomment to force a console size. By default it will be display's size minus

overscan.

#framebuffer_width=1280
#framebuffer_height=720

uncomment if hdmi display is not detected and composite is being output

#hdmi_force_hotplug=1

uncomment to force a specific HDMI mode (this will force VGA)

#hdmi_group=1
#hdmi_mode=16

uncomment to force a HDMI mode rather than DVI. This can make audio work in

DMT (computer monitor) modes

#hdmi_drive=2

uncomment to increase signal to HDMI, if you have interference, blanking, or

no display

#config_hdmi_boost=4

uncomment for composite PAL

#sdtv_mode=2

#uncomment to overclock the arm. 700 MHz is the default.
#arm_freq=800

Uncomment some or all of these to enable the optional hardware interfaces

#dtparam=i2c_arm=on
#dtparam=i2s=on
#dtparam=spi=on

Uncomment this to enable the lirc-rpi module

#dtoverlay=lirc-rpi

Additional overlays and parameters are documented /boot/overlays/README

Enable audio (loads snd_bcm2835)

dtparam=audio=on

NOOBS Auto-generated Settings:

#hdmi_force_hotplug=1

As i said,i have sound from other sources (youtube for example) so is there a local setting for the sample app i perhaps can change?

@XcafebabeX
Copy link

@Pooperpotamus u should remove the "#" before hdmi_force_hotplug=1 to enable the config.

@XcafebabeX
Copy link

i have the same problem .have sound from other sources .and set the /boot/config.txt as advice,but not work, i use the sound card cm108.

@frozenberg
Copy link
Contributor

I see. Can you try running gst-launch-1.0 -m audiotestsrc ! autoaudiosink and tell me if you get a tone?

And as a follow-up, can you try changing line 577 in MediaPlayer.cpp from

m_pipeline.audioSink = gst_element_factory_make("autoaudiosink", "audio_sink");

to

m_pipeline.audioSink = gst_element_factory_make("alsasink", "audio_sink");

?

Thanks
Fede

@SpecificOcean
Copy link

SpecificOcean commented Feb 1, 2018

I'm having the same issue, and so far none of the above fixes, or those found in the threads of similar issues seems to fix it. I can get sound using speaker-test and using aplay on the fox_hound.mp3 file found in the app. However I get no audio out with the same set up that I tested using speaker-test.
edit: I forgot to mention that the above "gst-launch-1.0 -m audiotestsrc ! autoaudiosink" command does not play a tone, however basically everything else I have tried does. This leads me to believe that it may be an issue with gstreamer, does that sound like a possibility?

@frozenberg
Copy link
Contributor

Hi @SpecificOcean,

Does gst-launch-1.0 -m audiotestsrc ! alsasink play a tone?

Also, are you running on a headless setup? Some users found a solution by running headless here: #481

@SpecificOcean
Copy link

@frozenberg No tone with gst-launch-1.0 -m audiotestsrc ! alsasink, but aplay and speaker-test work fine. Yes I am running it headless.

@frozenberg
Copy link
Contributor

Could I see the output from running gst-launch-1.0 -m audiotestsrc ! autoaudiosink and gst-launch-1.0 -m audiotestsrc ! alsasink?

@SpecificOcean
Copy link

@frozenberg sorry, I misread your previous message, gst-launch-1.0 -m audiotestsrc ! alsasink DOES play a steady tone, while gst-launch-1.0 -m audiotestsrc ! autoaudiosink does not. Would you still like me to paste the output of gst-launch-1.0 -m audiotestsrc ! autoaudiosink anyways?

@frozenberg
Copy link
Contributor

Oh I see. So if you make the MediaPlayer.cpp change suggested above, what are the logs from trying to play music?

Make sure you pass the argument -DCMAKE_BUILD_TYPE=DEBUG when you cmake and the DEBUG9 flag when you make SampleApp.

@SpecificOcean
Copy link

@frozenberg Sorry, but im fairly new to all of this, at what point and for what reason would I run cmake? Do I have to do that after editing the mediaplayer.cpp file?

@frozenberg
Copy link
Contributor

frozenberg commented Feb 2, 2018

No worries!

The reason for running cmake is that it will let you compile a DEBUG build. I'm realizing now that if you set this up using our setup.sh script, you have already compiled a DEBUG build! Sorry for the confusion.

You can follow these steps:

  1. Edit the MediaPlayer.cpp file with the suggested change above.
  2. cd into your build directory (which is probably called build)
  3. Run this command: make SampleApp && TZ=UTC ./SampleApp "/home/pi/workplace/public_sdk/build/Integration/AlexaClientSDKConfig.json" "/home/pi/workplace/public_sdk/third-party/alexa-rpi/models" DEBUG9

Make sure those directories actually exist. If they don't, you will need to find the paths to AlexaClientSDKConfig.json and third-party/alexa-rpi/models yourself.

@SpecificOcean
Copy link

ok, I followed your steps, asked alexa to tell me a joke, and she was still silent. Here is the output from the app

2018-02-03 00:09:34.670 [ a] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-02-03 00:09:34.671 [ d] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
############################

Listening...

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

2018-02-03 00:09:34.672 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"wakeword" : "alexa"},namespace=SpeechRecognizer,name=RecognizerState
2018-02-03 00:09:34.673 [ 7] 0 NotificationsCapabilityAgent:provideState:stateRequestToken=2
2018-02-03 00:09:34.673 [ 4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=2
2018-02-03 00:09:34.674 [ 4] 0 ContextManager:updateStateLocked:action=updatedState,state={"isEnabled":false,"isVisualIndicatorPersisted":false},namespace=Notifications,name=IndicatorState
2018-02-03 00:09:34.676 [ 7] 0 ContextManager:buildContextSuccessful:context={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#b4f3b650-68c4-3ed4-a047-4ea02aa5e1c7","type":"ALARM","scheduledTime":"2018-02-05T11:00:10+0000"},{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#7bd0e03c-0fa0-3796-b59f-b4064a7c9981","type":"ALARM","scheduledTime":"2018-02-06T11:00:01+0000"},{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#49d8448a-c817-329c-b503-5bbeb125d98c","type":"ALARM","scheduledTime":"2018-02-08T11:00:03+0000"}],"activeAlerts":[]}}]}
2018-02-03 00:09:34.677 [ a] 0 AudioInputProcessor:executeOnContextAvailable:jsonContext={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#b4f3b650-68c4-3ed4-a047-4ea02aa5e1c7","type":"ALARM","scheduledTime":"2018-02-05T11:00:10+0000"},{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#7bd0e03c-0fa0-3796-b59f-b4064a7c9981","type":"ALARM","scheduledTime":"2018-02-06T11:00:01+0000"},{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#49d8448a-c817-329c-b503-5bbeb125d98c","type":"ALARM","scheduledTime":"2018-02-08T11:00:03+0000"}],"activeAlerts":[]}}]}
2018-02-03 00:09:34.678 [ a] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechRecognizer.Recognize
2018-02-03 00:09:34.680 [ a] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=,newValue=6b5cda39-e4c6-469c-a39d-41cd1fb0c96d
2018-02-03 00:09:34.680 [ a] 0 DirectiveProcessor:scrubDialogRequestIdLocked:reason=emptyDialogRequestId
2018-02-03 00:09:34.681 [ e] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND
2018-02-03 00:09:34.682 [ a] 0 EventBuilder:buildJsonEventString:messageId=071a29ce-7561-4dc3-89d8-cb54d026b13d,namespace=SpeechRecognizer,name=Recognize
2018-02-03 00:09:34.684 [ a] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND
2018-02-03 00:09:34.685 [ a] 9 HTTP2Transport:enqueueRequest:jsonContent={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#b4f3b650-68c4-3ed4-a047-4ea02aa5e1c7","type":"ALARM","scheduledTime":"2018-02-05T11:00:10+0000"},{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#7bd0e03c-0fa0-3796-b59f-b4064a7c9981","type":"ALARM","scheduledTime":"2018-02-06T11:00:01+0000"},{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#49d8448a-c817-329c-b503-5bbeb125d98c","type":"ALARM","scheduledTime":"2018-02-08T11:00:03+0000"}],"activeAlerts":[]}}],"event":{"header":{"namespace":"SpeechRecognizer","name":"Recognize","messageId":"071a29ce-7561-4dc3-89d8-cb54d026b13d","dialogRequestId":"6b5cda39-e4c6-469c-a39d-41cd1fb0c96d"},"payload":{"profile":"NEAR_FIELD","format":"AUDIO_L16_RATE_16000_CHANNELS_1","initiator":{"type":"WAKEWORD","payload":{"wakeWordIndices":{"startIndexInSamples":8000,"endIndexInSamples":14240}}}}}}
2018-02-03 00:09:34.739 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"Notifications","name":"IndicatorState"},"payload":{"isEnabled":false,"isVisualIndicatorPersisted":false}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":"alexa"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#b4f3b650-68c4-3ed4-a047-4ea02aa5e1c7","type":"ALARM","scheduledTime":"2018-02-05T11:00:10+0000"},{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#7bd0e03c-0fa0-3796-b59f-b4064a7c9981","type":"ALARM","scheduledTime":"2018-02-06T11:00:01+0000"},{"token":"amzn1.as-ct.v1.Domain:Application:NotificationsV4#DNID#49d8448a-c817-329c-b503-5bbeb125d98c","type":"ALARM","scheduledTime":"2018-02-08T11:00:03+0000"}],"activeAlerts":[]}}],"event":{"header":{"namespace":"SpeechRecognizer","name":"Recognize","messageId":"071a29ce-7561-4dc3-89d8-cb54d026b13d","dialogRequestId":"6b5cda39-e4c6-469c-a39d-41cd1fb0c96d"},"payload":{"profile":"NEAR_FIELD","format":"AUDIO_L16_RATE_16000_CHANNELS_1","initiator":{"type":"WAKEWORD","payload":{"wakeWordIndices":{"startIndexInSamples":8000,"endIndexInSamples":14240}}}}}}
2018-02-03 00:09:34.740 [ b] 0 HTTP2StreamPool:getStream:streamId=5,numAcquiredStreams=2
2018-02-03 00:09:34.741 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x64da06d0
2018-02-03 00:09:34.742 [ b] I HTTP2Stream:libcurl:streamId=5,text=Found bundle for host avs-alexa-na.amazon.com: 0x7111c210 [can multiplex]
2018-02-03 00:09:34.742 [ b] I HTTP2Stream:libcurl:streamId=5,text=Conn: 0 (0x711d0ac8) Receive pipe weight: (-1/0), penalized: (nil)
2018-02-03 00:09:34.743 [ b] I HTTP2Stream:libcurl:streamId=5,text=Multiplexed connection found!
2018-02-03 00:09:34.743 [ b] I HTTP2Stream:libcurl:streamId=5,text=Found connection 0, with requests in the pipe (1)
2018-02-03 00:09:34.743 [ b] I HTTP2Stream:libcurl:streamId=5,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-02-03 00:09:34.744 [ b] I HTTP2Stream:libcurl:streamId=5,text=Using Stream ID: 5 (easy handle 0x64da06d0)
2018-02-03 00:09:36.857 [ f] 0 MessageInterpreter:receive:messageId=2575f4ff-228e-4e60-a3b0-3ce6ce68d0bf:No dialogRequestId attached to message.
2018-02-03 00:09:36.859 [ f] I DirectiveSequencer:onDirective:directive={"namespace:"SpeechRecognizer",name:"StopCapture",messageId:"2575f4ff-228e-4e60-a3b0-3ce6ce68d0bf",dialogRequestId:""}
2018-02-03 00:09:36.864 [ 10] I DirectiveRouter:preHandleDirective:messageId=2575f4ff-228e-4e60-a3b0-3ce6ce68d0bf,action=calling
2018-02-03 00:09:36.864 [ 10] 0 CapabilityAgent:addingMessageIdToMap:messageId=2575f4ff-228e-4e60-a3b0-3ce6ce68d0bf
2018-02-03 00:09:36.867 [ 11] I DirectiveRouter:handleDirective:messageId=2575f4ff-228e-4e60-a3b0-3ce6ce68d0bf,action=calling
2018-02-03 00:09:36.868 [ a] 0 AudioInputProcessor:stopCapture:stopImmediately=true
2018-02-03 00:09:36.868 [ a] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY
2018-02-03 00:09:36.868 [ d] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING
2018-02-03 00:09:36.868 [ a] 0 DirectiveProcessor:onHandlingCompeted:messageId=2575f4ff-228e-4e60-a3b0-3ce6ce68d0bf,directiveBeingPreHandled=(nullptr)
2018-02-03 00:09:36.869 [ a] 0 CapabilityAgent:removingMessageIdFromMap:messageId=2575f4ff-228e-4e60-a3b0-3ce6ce68d0bf
###########################

Thinking...

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

2018-02-03 00:09:36.870 [ b] I InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-02-03 00:09:37.110 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 0a82c1fffe37b3f6-00004f0b-00026795-bfa4c7c6351ed01a-c9d4fe58-5
2018-02-03 00:09:37.160 [ f] I DirectiveSequencer:onDirective:directive={"namespace:"SpeechSynthesizer",name:"Speak",messageId:"9901de70-57f4-45ff-a8e7-072320d56b4c",dialogRequestId:"6b5cda39-e4c6-469c-a39d-41cd1fb0c96d"}
2018-02-03 00:09:37.161 [ 10] I DirectiveRouter:preHandleDirective:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c,action=calling
2018-02-03 00:09:37.161 [ 10] 0 CapabilityAgent:addingMessageIdToMap:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c
2018-02-03 00:09:37.162 [ 10] 9 SpeechSynthesizer:preHandleDirective:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c
2018-02-03 00:09:37.162 [ 8] 0 SpeechSynthesizer:executePreHandle:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c
2018-02-03 00:09:37.170 [ 11] I DirectiveRouter:handleDirective:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c,action=calling
2018-02-03 00:09:37.171 [ 11] 9 SpeechSynthesizer:handleDirective:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c
2018-02-03 00:09:37.171 [ 8] 0 SpeechSynthesizer:executeHandle:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c
2018-02-03 00:09:37.171 [ 8] 1 FocusManager:acquireChannel:channelName=Dialog,activityId=SpeechSynthesizer.Speak
2018-02-03 00:09:37.172 [ e] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE
2018-02-03 00:09:37.172 [ e] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND
2018-02-03 00:09:37.172 [ e] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS
2018-02-03 00:09:37.173 [ a] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2018-02-03 00:09:37.173 [ a] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2018-02-03 00:09:37.173 [ a] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2018-02-03 00:09:37.174 [ 8] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING
2018-02-03 00:09:37.174 [ 8] 9 SpeechSynthesizer:startPlaying
2018-02-03 00:09:37.174 [ 8] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader
2018-02-03 00:09:37.180 [ 2] 0 MediaPlayer:handleSetSourceCalled
2018-02-03 00:09:37.180 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements
2018-02-03 00:09:37.180 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed
2018-02-03 00:09:37.193 [ b] I HTTP2Stream:libcurl:streamId=5,text=Curl_http_done: called premature == 0
2018-02-03 00:09:37.193 [ b] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS
2018-02-03 00:09:37.193 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=5,result=200
2018-02-03 00:09:37.194 [ b] 0 HTTP2StreamPool:releaseStream:streamId=5,numAcquiredStreams=1
2018-02-03 00:09:37.207 [ 8] 9 MediaPlayer:playCalled
2018-02-03 00:09:37.207 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=1,currentId=1
2018-02-03 00:09:37.208 [ 2] 0 MediaPlayer:handlePlay:attemptBuffering=0
2018-02-03 00:09:37.211 [ 2] 9 AttachmentReaderSource:handleSeekData:offset=0
2018-02-03 00:09:37.212 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC
2018-02-03 00:09:37.212 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-02-03 00:09:37.212 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-02-03 00:09:37.212 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-02-03 00:09:37.213 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-02-03 00:09:37.213 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-02-03 00:09:37.213 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-02-03 00:09:37.213 [ 12] 9 BaseStreamSource:onNeedDataCalled:size=4096
2018-02-03 00:09:37.213 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:State Change:oldState=NULL,newState=READY,pendingState=PLAYING
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-02-03 00:09:37.216 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-02-03 00:09:37.217 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-02-03 00:09:37.217 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src
2018-02-03 00:09:37.217 [ 2] 9 BaseStreamSource:handleNeedDataCalled
2018-02-03 00:09:37.217 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=15
2018-02-03 00:09:37.217 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-02-03 00:09:37.218 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-02-03 00:09:37.218 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-02-03 00:09:37.218 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-02-03 00:09:37.219 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-02-03 00:09:37.219 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0
2018-02-03 00:09:37.219 [ 2] 9 AttachmentReaderSource:read:size=1533,status=0
2018-02-03 00:09:37.220 [ 2] I InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-02-03 00:09:37.220 [ 2] 9 AttachmentReaderSource:read:size=0,status=3
2018-02-03 00:09:37.220 [ 2] 9 AttachmentReaderSource:handleReadData:info=signalingEndOfData
2018-02-03 00:09:37.221 [ 2] 9 BaseStreamSource:signalEndOfDataCalled
2018-02-03 00:09:37.221 [ 2] 9 BaseStreamSource:gstAppSrcEndOfStreamSuccess
2018-02-03 00:09:37.222 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=15
2018-02-03 00:09:37.268 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-02-03 00:09:37.268 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-02-03 00:09:37.282 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-02-03 00:09:37.283 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-02-03 00:09:37.300 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mad0
2018-02-03 00:09:37.301 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mad0
2018-02-03 00:09:37.302 [ 12] 9 MediaPlayer:onPadAddedCalled
2018-02-03 00:09:37.303 [ 2] 9 MediaPlayer:handlePadAddedSignalCalled
2018-02-03 00:09:37.317 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-02-03 00:09:37.318 [ 2] 9 MediaPlayer:messageReceived:type=stream-start,source=audio-pipeline
2018-02-03 00:09:37.339 [ 2] 9 MediaPlayer:messageReceived:type=latency,source=audio_sink
2018-02-03 00:09:37.340 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=audiosinkringbuffer0
2018-02-03 00:09:37.341 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink
2018-02-03 00:09:37.342 [ 2] 0 MediaPlayer:callingOnTags
2018-02-03 00:09:37.342 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink
2018-02-03 00:09:37.343 [ 2] 0 MediaPlayer:callingOnTags
2018-02-03 00:09:37.343 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-02-03 00:09:37.343 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-02-03 00:09:37.344 [ 2] 9 MediaPlayer:State Change:oldState=READY,newState=PAUSED,pendingState=PLAYING
2018-02-03 00:09:37.344 [ 2] 9 MediaPlayer:messageReceived:type=async-done,source=audio-pipeline
2018-02-03 00:09:37.344 [ 2] 9 MediaPlayer:messageReceived:type=new-clock,source=audio-pipeline
2018-02-03 00:09:37.345 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink
2018-02-03 00:09:37.345 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=volume
2018-02-03 00:09:37.345 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter
2018-02-03 00:09:37.346 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodedQueue
2018-02-03 00:09:37.346 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mad0
2018-02-03 00:09:37.346 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse0
2018-02-03 00:09:37.347 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux0
2018-02-03 00:09:37.347 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind
2018-02-03 00:09:37.347 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder
2018-02-03 00:09:37.348 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src
2018-02-03 00:09:37.348 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline
2018-02-03 00:09:37.348 [ 2] 9 MediaPlayer:State Change:oldState=PAUSED,newState=PLAYING,pendingState=VOID_PENDING
2018-02-03 00:09:37.348 [ 2] 0 MediaPlayer:callingOnPlaybackStarted:currentId=1
2018-02-03 00:09:37.349 [ 2] 9 SpeechSynthesizer:onPlaybackStarted:callbackSourceId=1
2018-02-03 00:09:37.352 [ 8] 0 SpeechSynthesizer:executePlaybackStarted
2018-02-03 00:09:37.352 [ 8] 9 SpeechSynthesizer:setCurrentStateLocked:state=PLAYING
2018-02-03 00:09:37.352 [ 8] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0
2018-02-03 00:09:37.352 [ 8] 9 MediaPlayer:getOffsetCalled
2018-02-03 00:09:37.353 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=1,currentId=1
2018-02-03 00:09:37.354 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"amzn1.as-ct.v1.Domain:Phatic:AlexaOriginals#ACRI#AlexaOriginals|aa6d2a5c-73a6-473c-b44d-8629b55204c9|4|JOKE|ATVPDKIKX0DER|A223OUXYLG5TA1|en_US|Alexa3P:1.0/2018/02/03/00/ee1c464fa51a4759907b1fdbad7db077/09:35::TNIH_2V.3f092784-8e1a-48de-9a5e-526d9280484dZXV/1|54d83bc9-29e9-41d7-aa2e-38bb52650752|TellMeAJokeIntent","offsetInMilliseconds":0,"playerActivity":"PLAYING"},namespace=SpeechSynthesizer,name=SpeechState
2018-02-03 00:09:37.355 [ 8] 0 EventBuilder:buildJsonEventString:messageId=618f32e5-9449-47d0-9a3b-64cc2465db10,namespace=SpeechSynthesizer,name=SpeechStarted
2018-02-03 00:09:37.356 [ d] 0 DialogUXStateAggregator:setState:from=THINKING,to=SPEAKING
2018-02-03 00:09:37.356 [ 8] 9 HTTP2Transport:enqueueRequest:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechStarted","messageId":"618f32e5-9449-47d0-9a3b-64cc2465db10"},"payload":{"token":"amzn1.as-ct.v1.Domain:Phatic:AlexaOriginals#ACRI#AlexaOriginals|aa6d2a5c-73a6-473c-b44d-8629b55204c9|4|JOKE|ATVPDKIKX0DER|A223OUXYLG5TA1|en_US|Alexa3P:1.0/2018/02/03/00/ee1c464fa51a4759907b1fdbad7db077/09:35::TNIH_2V.3f092784-8e1a-48de-9a5e-526d9280484dZXV/1|54d83bc9-29e9-41d7-aa2e-38bb52650752|TellMeAJokeIntent"}}}
2018-02-03 00:09:37.356 [ e] 9 SpeechSynthesizer:onFocusChangedSuccess
2018-02-03 00:09:37.358 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink
2018-02-03 00:09:37.359 [ 2] 0 MediaPlayer:callingOnTags
###########################

Speaking...

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

2018-02-03 00:09:37.396 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechStarted","messageId":"618f32e5-9449-47d0-9a3b-64cc2465db10"},"payload":{"token":"amzn1.as-ct.v1.Domain:Phatic:AlexaOriginals#ACRI#AlexaOriginals|aa6d2a5c-73a6-473c-b44d-8629b55204c9|4|JOKE|ATVPDKIKX0DER|A223OUXYLG5TA1|en_US|Alexa3P:1.0/2018/02/03/00/ee1c464fa51a4759907b1fdbad7db077/09:35::TNIH_2V.3f092784-8e1a-48de-9a5e-526d9280484dZXV/1|54d83bc9-29e9-41d7-aa2e-38bb52650752|TellMeAJokeIntent"}}}
2018-02-03 00:09:37.397 [ b] 0 HTTP2StreamPool:getStream:streamId=7,numAcquiredStreams=2
2018-02-03 00:09:37.397 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x64da06d0
2018-02-03 00:09:37.397 [ b] I HTTP2Stream:libcurl:streamId=7,text=Found bundle for host avs-alexa-na.amazon.com: 0x7111c210 [can multiplex]
2018-02-03 00:09:37.397 [ b] I HTTP2Stream:libcurl:streamId=7,text=Conn: 0 (0x711d0ac8) Receive pipe weight: (-1/0), penalized: (nil)
2018-02-03 00:09:37.397 [ b] I HTTP2Stream:libcurl:streamId=7,text=Multiplexed connection found!
2018-02-03 00:09:37.398 [ b] I HTTP2Stream:libcurl:streamId=7,text=Found connection 0, with requests in the pipe (1)
2018-02-03 00:09:37.398 [ b] I HTTP2Stream:libcurl:streamId=7,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-02-03 00:09:37.398 [ b] I HTTP2Stream:libcurl:streamId=7,text=Using Stream ID: 7 (easy handle 0x64da06d0)
2018-02-03 00:09:37.536 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 0a82c1fffe37b3f6-00004f0b-0002678f-b5031f6ef51ec00d-b4009e9e-7
2018-02-03 00:09:37.536 [ b] I HTTP2Stream:libcurl:streamId=7,text=Curl_http_done: called premature == 0
2018-02-03 00:09:37.536 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=7,result=204
2018-02-03 00:09:37.536 [ b] 0 HTTP2StreamPool:releaseStream:streamId=7,numAcquiredStreams=1
2018-02-03 00:09:37.536 [ b] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2018-02-03 00:09:40.295 [ 12] 9 BaseStreamSource:onNeedDataCalled:size=4096
2018-02-03 00:09:40.295 [ 2] 9 BaseStreamSource:handleNeedDataCalled
2018-02-03 00:09:41.345 [ 2] 9 MediaPlayer:messageReceived:type=eos,source=audio-pipeline
2018-02-03 00:09:41.646 [ 2] 9 BaseStreamSource:~BaseStreamSource
2018-02-03 00:09:41.646 [ 2] 0 MediaPlayer:callingOnPlaybackFinished:currentId=1
2018-02-03 00:09:41.646 [ 2] 9 SpeechSynthesizer:onPlaybackFinished:callbackSourceId=1
2018-02-03 00:09:41.646 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements
2018-02-03 00:09:41.646 [ 2] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=4344
2018-02-03 00:09:41.647 [ 8] 0 SpeechSynthesizer:executePlaybackFinished
2018-02-03 00:09:41.647 [ 8] 9 SpeechSynthesizer:setCurrentStateLocked:state=FINISHED
2018-02-03 00:09:41.647 [ 8] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0
2018-02-03 00:09:41.647 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"amzn1.as-ct.v1.Domain:Phatic:AlexaOriginals#ACRI#AlexaOriginals|aa6d2a5c-73a6-473c-b44d-8629b55204c9|4|JOKE|ATVPDKIKX0DER|A223OUXYLG5TA1|en_US|Alexa3P:1.0/2018/02/03/00/ee1c464fa51a4759907b1fdbad7db077/09:35::TNIH_2V.3f092784-8e1a-48de-9a5e-526d9280484dZXV/1|54d83bc9-29e9-41d7-aa2e-38bb52650752|TellMeAJokeIntent","offsetInMilliseconds":0,"playerActivity":"FINISHED"},namespace=SpeechSynthesizer,name=SpeechState
2018-02-03 00:09:41.647 [ 8] 0 EventBuilder:buildJsonEventString:messageId=9458044d-02d6-45c6-9e79-0d2f15669183,namespace=SpeechSynthesizer,name=SpeechFinished
2018-02-03 00:09:41.648 [ 8] 9 HTTP2Transport:enqueueRequest:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechFinished","messageId":"9458044d-02d6-45c6-9e79-0d2f15669183"},"payload":{"token":"amzn1.as-ct.v1.Domain:Phatic:AlexaOriginals#ACRI#AlexaOriginals|aa6d2a5c-73a6-473c-b44d-8629b55204c9|4|JOKE|ATVPDKIKX0DER|A223OUXYLG5TA1|en_US|Alexa3P:1.0/2018/02/03/00/ee1c464fa51a4759907b1fdbad7db077/09:35::TNIH_2V.3f092784-8e1a-48de-9a5e-526d9280484dZXV/1|54d83bc9-29e9-41d7-aa2e-38bb52650752|TellMeAJokeIntent"}}}
2018-02-03 00:09:41.648 [ 8] 9 SpeechSynthesizer:setHandlingCompleted
2018-02-03 00:09:41.648 [ 8] 0 DirectiveProcessor:onHandlingCompeted:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c,directiveBeingPreHandled=(nullptr)
2018-02-03 00:09:41.648 [ 8] 0 CapabilityAgent:removingMessageIdFromMap:messageId=9901de70-57f4-45ff-a8e7-072320d56b4c
2018-02-03 00:09:41.746 [ b] 0 HTTP2Transport:processNextOutgoingMessage:jsonContent={"event":{"header":{"namespace":"SpeechSynthesizer","name":"SpeechFinished","messageId":"9458044d-02d6-45c6-9e79-0d2f15669183"},"payload":{"token":"amzn1.as-ct.v1.Domain:Phatic:AlexaOriginals#ACRI#AlexaOriginals|aa6d2a5c-73a6-473c-b44d-8629b55204c9|4|JOKE|ATVPDKIKX0DER|A223OUXYLG5TA1|en_US|Alexa3P:1.0/2018/02/03/00/ee1c464fa51a4759907b1fdbad7db077/09:35::TNIH_2V.3f092784-8e1a-48de-9a5e-526d9280484dZXV/1|54d83bc9-29e9-41d7-aa2e-38bb52650752|TellMeAJokeIntent"}}}
2018-02-03 00:09:41.746 [ b] 0 HTTP2StreamPool:getStream:streamId=9,numAcquiredStreams=2
2018-02-03 00:09:41.747 [ b] 9 HTTP2Transport:insertActiveStream:handle=0x64da06d0
2018-02-03 00:09:41.747 [ b] I HTTP2Stream:libcurl:streamId=9,text=Found bundle for host avs-alexa-na.amazon.com: 0x7111c210 [can multiplex]
2018-02-03 00:09:41.747 [ b] I HTTP2Stream:libcurl:streamId=9,text=Conn: 0 (0x711d0ac8) Receive pipe weight: (-1/0), penalized: (nil)
2018-02-03 00:09:41.747 [ b] I HTTP2Stream:libcurl:streamId=9,text=Multiplexed connection found!
2018-02-03 00:09:41.747 [ b] I HTTP2Stream:libcurl:streamId=9,text=Found connection 0, with requests in the pipe (1)
2018-02-03 00:09:41.747 [ b] I HTTP2Stream:libcurl:streamId=9,text=Re-using existing connection! (#0) with host avs-alexa-na.amazon.com
2018-02-03 00:09:41.748 [ b] I HTTP2Stream:libcurl:streamId=9,text=Using Stream ID: 9 (easy handle 0x64da06d0)
2018-02-03 00:09:41.849 [ d] 0 DialogUXStateAggregator:setState:from=SPEAKING,to=IDLE
2018-02-03 00:09:41.849 [ 8] 1 FocusManager:releaseChannel:channelName=Dialog
########################################

Alexa is currently idle!

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

2018-02-03 00:09:41.850 [ e] 0 SpeechSynthesizer:onFocusChanged:newFocus=NONE
2018-02-03 00:09:41.943 [ b] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 0a82c1fffe37b3f6-00004f0b-0002678f-b5031f6ef51ec00d-b4009e9e-9
2018-02-03 00:09:41.943 [ b] I HTTP2Stream:libcurl:streamId=9,text=Curl_http_done: called premature == 0
2018-02-03 00:09:41.944 [ b] 0 HTTP2Transport:cleanupFinishedStream:streamId=9,result=204
2018-02-03 00:09:41.944 [ b] 0 HTTP2StreamPool:releaseStream:streamId=9,numAcquiredStreams=1
2018-02-03 00:09:41.944 [ b] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT

@SpecificOcean
Copy link

ok! so it DOES work now, but not through my USB audio device. If i plug my speakers into the 3.5mm jack on the pi I can hear alexa.

@yash-6795
Copy link

@SpecificOcean Hi, I am having the same problem, can you please explain how'd you fixed it?

@SpecificOcean
Copy link

SpecificOcean commented Feb 4, 2018

@yash-6795 I followed the instructions above,
Edit the MediaPlayer.cpp file with the suggested change above.
cd into your build directory (which is probably called build)
Run this command: make SampleApp && TZ=UTC ./SampleApp "/home/pi/workplace/public_sdk/build/Integration/AlexaClientSDKConfig.json" "/home/pi/workplace/public_sdk/third-party/alexa-rpi/models" DEBUG9

and then rebooted, after the reboot sounds was working via my 3.5mm jack

@tgraf2
Copy link

tgraf2 commented Feb 4, 2018

I installed Alexa on a RaspberryPi3 using the install script (from Raspberry Pi Quick Start Guide with Script). I am running into the same problem as SpecificOcean: Alexa appears to be hearing my wakeword and operating, but there is no audio coming from the headphone jack. I do not have HDMI connected.

I edited MediaPlayer.cpp (located at /home/pi/avs-device-sdk/MediaPlayer/src/MediaPlayer.cpp). I changed line 569 to:
m_pipeline.audioSink = gst_element_factory_make("alsasink", "audio_sink");

My file locations are different from your make command:
AlexaClientSDKConfig.json is located at /home/pi/build/Integration/AlexaClientSDKConfig.json
but I cannot find 'alexa-rpi/models'. Can you tell me where I can find it?

Thanks.

@SpecificOcean
Copy link

@tgraf2 mine was located in /home/pi/alexa/third-party/alexa-rpi/models

@tgraf2
Copy link

tgraf2 commented Feb 4, 2018

I installed Alexa from
https://github.com/alexa/avs-device-sdk/wiki/Raspberry-Pi-Quick-Start-Guide-with-Script
and I do not have that directory structure. Mine looks like this:
/home/pi/avs-device-sdk/ThirdParty

and I do not have a alexa-rpi/models directory

Where did you install it from?

@SpecificOcean
Copy link

@tgraf2 I installed using the same page, you need to go up one folder, and you should see third-party it should be in the same folder as the startsample.sh file

@tgraf2
Copy link

tgraf2 commented Feb 4, 2018

You're right. My location is: /home/pi/third-party/alexa-rpi/models

So the make command would be:
make SampleApp && TZ=UTC ./SampleApp "/home/pi/build/Integration/AlexaClientSDKConfig.json" "/home/pi/third-party/alexa-rpi/models" DEBUG9

We'll give it a try.

@roykang75
Copy link

@tgraf2
I installed Alexa from
https://github.com/alexa/avs-device-sdk/wiki/Raspberry-Pi-Quick-Start-Guide-with-Script.
I tried your guide.
I edited MediaPlayer.cpp (/home/pi/avs-device-sdk/MediaPlayer/src)
and than "cd /home/pi/build",
run command:
make SampleApp && TZ=UTC ./SampleApp "/home/pi/build/Integration/AlexaClientSDKConfig.json" "/home/pi/third-party/alexa-rpi/models" DEBUG9

After build success, run command "cd ~".
sudo bash startsample.sh

Alexa work fine. thanks.

@yash-6795
Copy link

@SpecificOcean thanks it worked for me.

@gb160
Copy link

gb160 commented Feb 5, 2018

@SpecificOcean
This took me a while to get working via a usb sound card, but you have to create a '.asoundrc' file to direct the output audio to other devices.

Its working fine on my Pi2 now, using usb device for both input and output.

@frozenberg
Copy link
Contributor

@tgraf2

If you are still experiencing issues feel free to open a new issue.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

10 participants