alexa / avs-device-sdk

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

When playing an audio book, asking weather get no response #587

Closed subjectxbj closed 6 years ago

subjectxbj commented 6 years ago

IMPORTANT: Before you create an issue, please take a look at our Issue Reporting Guide.

Briefly summarize your issue:

SDK: 1.4 OS: Alpine-linux Platform: ARM7 Reproduce steps:

  1. Ask alexa to read an audio book
  2. When alexa is playing the audio book, ask "alexa, what is the weather"
  3. alexa stop playing the audio book, keep silent for a few seconds. But I can't hear the response for the weather request
  4. alexa resume playing the audio book.

I checked the Alexa APP, the history shows that it send the response to alexa. I also change to play flashbriefing in the 1st step, it has the same problem.

What is the expected behavior?

What behavior are you observing?

Provide the steps to reproduce the issue, if applicable:

Tell us about your environment:

What version of the AVS Device SDK are you using?

  <1.4.0>

Tell us what hardware you're using:

Tell us about your OS (Type & version):

subjectxbj commented 6 years ago

This problem can be reproduce 100% on my device.

priyagsenthil commented 6 years ago

Could you try upgrading to v1.6 of the SDK. We made some fixes for audible and when I tried on the latest version do not see the issue reported.

subjectxbj commented 6 years ago

I upgrade to 1.6, but the issue still exist.

subjectxbj commented 6 years ago

no reponse for weather when playing audio book.txt I attached the log.

ENT8R commented 6 years ago

Maybe this is a duplicate of #575?

subjectxbj commented 6 years ago

I'm testing with a USB audio card. Currently my audio setting is as below:

[avs_new] / # cat /etc/asound.conf
pcm.!default {
  type asym
   playback.pcm {
     type plug
     slave.pcm "hw:1,0"
   }
   capture.pcm {
     type plug
     slave.pcm "hw:1,0"
   }
}
[avs_new] / #

I changed the configuration as per #575 . Now the device even can't playback any sound, and it report error as below:

[avs_new] / # aplay test.wav
ALSA lib pcm_direct.c:1137:(snd1_pcm_direct_initialize_poll_fd) unable to open timer 'hw:CLASS=3,SCLASS=0,CARD=1,DEV=0,SUBDEV=0'
ALSA lib pcm_dmix.c:1099:(snd_pcm_dmix_open) unable to initialize poll_fd
aplay: main:722: audio open error: No such device
[avs_new] / #

So #575 does not fix my problem.

ENT8R commented 6 years ago

Did you just modified the file at /etc/asound.conf or also the file at /home/pi/.asoundrc ?

subjectxbj commented 6 years ago

I'm not running on Respberry Pi. I'm running on a openwrt system in root mode. So it will take the system configuration.

kclchan commented 6 years ago

Hi @subjectxbj, from the logs you attached, it seems that the "weather" is being played in the fake-audio-sink! That would explain why no sound is being heard.

018-03-30 08:28:06.329 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=fake-audio-sink

Did you make any modification to the SampleApp? If not, could you try modifying the MediaPlayer.cpp to use "alsasink" instead of "autoaudiosink", recompile and test again. This would ensure that it's not the "autoaudiosink" that's selecting a "fake-audio-sink".

subjectxbj commented 6 years ago

@kclchan OK. I will take a try.

subjectxbj commented 6 years ago

Hi @kclchan ,

I changed "autoaudiosink" to "alsasink" and build again. This time it report following error: ###########################

Thinking...

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

2018-04-03 05:24:37.169 [ d] I InProcessAttachmentReader:readFailed:reason=SDS is closed 2018-04-03 05:24:37.184 [ 1d] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. 2018-04-03 05:24:37.284 [ 1d] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. 2018-04-03 05:24:37.385 [ 1d] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. 2018-04-03 05:24:37.485 [ 1d] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. 2018-04-03 05:24:37.561 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0e0fcbfffeaed6e8-00000ecb-00174ca6-773f5a9e1e8e1628-a0dfda1a-5 2018-04-03 05:24:37.564 [ 10] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechSynthesizer"\,name\:"Speak"\,messageId\:"bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36"\,dialogRequestId\:"199c920e-5761-47aa-a5d0-d162582aa6e3"} 2018-04-03 05:24:37.565 [ 11] I DirectiveRouter:preHandleDirective:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36,action=calling 2018-04-03 05:24:37.565 [ 11] 0 CapabilityAgent:addingMessageIdToMap:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36 2018-04-03 05:24:37.565 [ 11] 9 SpeechSynthesizer:preHandleDirective:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36 2018-04-03 05:24:37.566 [ b] 0 SpeechSynthesizer:executePreHandle:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36 2018-04-03 05:24:37.566 [ 12] I DirectiveRouter:handleDirective:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36,action=calling 2018-04-03 05:24:37.566 [ 12] 9 SpeechSynthesizer:handleDirective:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36 2018-04-03 05:24:37.566 [ b] 0 SpeechSynthesizer:executeHandle:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36 2018-04-03 05:24:37.566 [ b] 1 FocusManager:acquireChannel:channelName=Dialog,interface=SpeechSynthesizer 2018-04-03 05:24:37.567 [ f] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE 2018-04-03 05:24:37.567 [ f] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND 2018-04-03 05:24:37.567 [ f] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS 2018-04-03 05:24:37.567 [ b] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING 2018-04-03 05:24:37.567 [ a] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE 2018-04-03 05:24:37.567 [ b] 9 SpeechSynthesizer:startPlaying 2018-04-03 05:24:37.567 [ a] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus 2018-04-03 05:24:37.567 [ b] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader 2018-04-03 05:24:37.567 [ a] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE 2018-04-03 05:24:37.567 [ 2] 0 MediaPlayer:handleSetSourceCalled 2018-04-03 05:24:37.567 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2018-04-03 05:24:37.568 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2018-04-03 05:24:37.568 [ 2] 9 BaseStreamSource:initNoAudioFormat 2018-04-03 05:24:37.569 [ b] 9 MediaPlayer:playCalled 2018-04-03 05:24:37.569 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=7,currentId=7 2018-04-03 05:24:37.570 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=FAILURE 2018-04-03 05:24:37.570 [ 2] E MediaPlayer:handlePlayFailed::reason=gstElementSetStateFailure 2018-04-03 05:24:37.570 [ 2] 0 MediaPlayer:callingOnPlaybackError:type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=reason\=gstElementSetStateFailure,currentId=7 2018-04-03 05:24:37.570 [ 2] 9 SpeechSynthesizer:onPlaybackError:callbackSourceId=7 2018-04-03 05:24:37.570 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2018-04-03 05:24:37.570 [ b] 0 SpeechSynthesizer:executePlaybackError:type=MEDIA_ERROR_INTERNAL_DEVICE_ERROR,error=reason\=gstElementSetStateFailure 2018-04-03 05:24:37.570 [ b] 9 SpeechSynthesizer:setCurrentStateLocked:state=FINISHED 2018-04-03 05:24:37.570 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed 2018-04-03 05:24:37.570 [ b] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0 2018-04-03 05:24:37.571 [ 2] 9 BaseStreamSource:~BaseStreamSource 2018-04-03 05:24:37.571 [ b] 0 ContextManager:updateStateLocked:action=updatedState,namespace=SpeechSynthesizer,name=SpeechState 2018-04-03 05:24:37.571 [ b] 9 SpeechSynthesizer:releaseForegroundFocus 2018-04-03 05:24:37.571 [ b] 1 FocusManager:releaseChannel:channelName=Dialog 2018-04-03 05:24:37.571 [ b] 0 CapabilityAgent:removingMessageIdFromMap:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36 2018-04-03 05:24:37.571 [ 2] 9 MediaPlayer:messageReceived:type=error,source=audio_sink 2018-04-03 05:24:37.572 [ 2] E MediaPlayer:handleBusMessageError:source=audio_sink,error=Could not open audio device for playback. Device is being used by another application.,debug=gstalsasink.c(860)\: gst_alsasink_open ()\: /GstPipeline\:audio-pipeline/GstAlsaSink\:audio_sink\: Device 'default' is busy 2018-04-03 05:24:37.572 [ b] 0 EventBuilder:buildJsonEventString:messageId=778e92ed-0f78-4e5e-a8d4-4bac3cb44247,namespace=System,name=ExceptionEncountered 2018-04-03 05:24:37.573 [ b] 9 HTTP2Transport:enqueueRequest 2018-04-03 05:24:37.573 [ b] 0 DirectiveProcessor:onHandlingFailed:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36,directiveBeingPreHandled=(nullptr),description=reason\=gstElementSetStateFailure 2018-04-03 05:24:37.573 [ b] 0 DirectiveProcessor:scrubDialogRequestIdLocked:dialogRequestId=199c920e-5761-47aa-a5d0-d162582aa6e3 2018-04-03 05:24:37.573 [ b] 0 CapabilityAgent:removingMessageIdFromMap:messageId=bbb7fb8e-3a30-4c7a-a14c-d2fda53a6a36 2018-04-03 05:24:37.585 [ 1d] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. 2018-04-03 05:24:37.667 [ d] 0 HTTP2Transport:processNextOutgoingMessage 2018-04-03 05:24:37.667 [ d] 0 HTTP2StreamPool:getStream:streamId=117,numAcquiredStreams=3 2018-04-03 05:24:37.667 [ d] 9 HTTP2Transport:insertActiveStream:handle=0x568f9aa0 2018-04-03 05:24:37.686 [ 1d] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. 2018-04-03 05:24:37.772 [ e] 0 DialogUXStateAggregator:setState:from=THINKING,to=IDLE ########################################

Alexa is currently idle!

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

My audio configure is still as below:

[avs_new] / # cat /etc/asound.conf
pcm.!default {
  type asym
   playback.pcm {
     type plug
     slave.pcm "hw:1,0"
   }
   capture.pcm {
     type plug
     slave.pcm "hw:1,0"
   }
}
[avs_new] / #
subjectxbj commented 6 years ago

I see when alexa receive the second command, the pipeline for "audio book" is set to "pause", but it still takes the resource of the audio sink. So the second pipeline for "weather report" failed to get the audio sink. Why not release the audio sink when the 1st pipeline is paused, so that the 2nd pipeline can use it to play back?

kclchan commented 6 years ago

Hi @subjectxbj, I think you will need to add a dmix plugin to your asound.conf file. Please find more information at https://alsa.opensrc.org/Dmix

Maybe take a look at #575 again.

subjectxbj commented 6 years ago

Thanks @kclchan .

I found my device does not support dmix plugin, that's why it report error when I use dmix plugin as the playback.

I fixed this problem by change the file. Now I can hear weather report when reading audio book. package/kernel/linux/modules/sound.mk

KCONFIG:= \ CONFIG_SOUND \ CONFIG_SND \ CONFIG_SND_HWDEP \ CONFIG_SND_RAWMIDI \ CONFIG_SND_TIMER \ CONFIG_SND_PCM \