SpeechSynthesizerIntegrationTest handleOneSpeech failed

[sangshengjie]

When I run the handleOneSpeech test, the speech played, but failed as follows:

`### [==========] Running 8 tests from 1 test case.
[----------] Global test environment set-up.
[----------] 8 tests from SpeechSynthesizerTest
[ RUN ] SpeechSynthesizerTest.handleOneSpeech
ConfigurationNode:initializeSuccess:
HttpPost:doPostSucceeded:code=200
AuthDelegate:handleLwaResponseSucceeded:refreshToken
AuthDelegate:onAuthStateChangeCalled:state=1,error=0
MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=PENDING

GET /v20160207/directives HTTP/2
Host: avs-alexa-na.amazon.com
Accept: /

< HTTP/2 200
< access-control-allow-origin: *
< x-amzn-requestid: 06ca64fffe863bc2-00004174-00004320-03668b53c70067f4-f0487a83-1
x-amzn-requestid: 06ca64fffe863bc2-00004174-00004320-03668b53c70067f4-f0487a83-1
< content-type: multipart/related; boundary=------abcde123; type=application/json
<
MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=CONNECTED
MediaPlayer:handleSetObserverCalled
DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x24f6a8,policy=BLOCKING
DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x1744c0,policy=BLOCKING
DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x1744c0,policy=BLOCKING
DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x1744c0,policy=BLOCKING
DirectiveProcessor:setDialogRequestId:dialogRequestId=DialogRequestID123

POST /v20160207/events HTTP/2
Host: avs-alexa-na.amazon.com
Accept: /
Content-Length: 999
Content-Type: multipart/form-data; boundary=------------------------dd5c8d465617f055

InProcessAttachmentReader:readFailed:reason=SDS is closed
< HTTP/2 200
< access-control-allow-origin: *
< x-amzn-requestid: 06ca64fffe863bc2-00004174-00004320-03668b53c70067f4-f0487a83-3
x-amzn-requestid: 06ca64fffe863bc2-00004174-00004320-03668b53c70067f4-f0487a83-3
< content-type: multipart/related;boundary=bd68974e-8df4-4cc6-8f9b-e9e925061a6e;start=metadata.1498118656523;type="application/json"
<
DirectiveSequencer:onDirective:directive={"namespace:"Speaker",name:"SetMute",messageId:"8e6e413f-4138-4317-953c-5088d9fe117e",dialogRequestId:"DialogRequestID123"}
DirectiveRouter:preHandleDirective:messageId=8e6e413f-4138-4317-953c-5088d9fe117e,action=calling
preHandleDirective---------------------------------------
DirectiveRouter:handleDirective:messageId=8e6e413f-4138-4317-953c-5088d9fe117e,action=calling
handleDirective---------------------------------------
DirectiveSequencer:onDirective:directive={"namespace:"SpeechSynthesizer",name:"Speak",messageId:"994fdc06-2833-4ca9-94ff-4a15758b2fca",dialogRequestId:"DialogRequestID123"}
DirectiveRouter:preHandleDirective:messageId=994fdc06-2833-4ca9-94ff-4a15758b2fca,action=calling
CapabilityAgent:addingMessageIdToMap:messageId=994fdc06-2833-4ca9-94ff-4a15758b2fca
DirectiveProcessor:onHandlingCompeted:messageId=8e6e413f-4138-4317-953c-5088d9fe117e,directiveBeingPreHandled=(nullptr)
DirectiveRouter:handleDirective:messageId=994fdc06-2833-4ca9-94ff-4a15758b2fca,action=calling
MediaPlayer:handleSetSourceCalled
MediaPlayer:doStopSuccess:reason=alreadyStopped
MediaPlayer:handlePlayCalled
MediaPlayer:doStopSuccess:reason=alreadyStopped
InProcessAttachmentReader:readFailed:reason=SDS is closed
[ 5185.341855@0] [aml-i2s-dai]i2s dma dfb00000,phy addr 1fd00000,mode 3,ch 1
[ 5185.343371@0] speaker_events--mute =1
[ 5185.668464@2] aiu i2s playback enable
[ 5185.668464@2]
SpeechSynthesizer:onFocusChangeFailed:reason=stateChangeTimeout,messageId=994fdc06-2833-4ca9-94ff-4a15758b2fca
DirectiveProcessor:onHandlingFailed:messageId=994fdc06-2833-4ca9-94ff-4a15758b2fca,directiveBeingPreHandled=(nullptr),description=stateChangeTimeout
CapabilityAgent:removingMessageIdFromMap:messageId=994fdc06-2833-4ca9-94ff-4a15758b2fca
/home/landon/alexa_c++/alexa-client-sdk/Integration/test/SpeechSynthesizerIntegrationTest.cpp:574: Failure
Expected: m_speechSynthesizerObserver->waitForNext(WAIT_FOR_TIMEOUT_DURATION)
Which is: 4-byte object <01-00 00-00>
To be equal to: SpeechSynthesizerState::PLAYING
Which is: 4-byte object <00-00 00-00>
MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=DISCONNECTED
DirectiveSequencer:shutdown
[ FAILED ] SpeechSynthesizerTest.handleOneSpeech (38176 ms)`

Then I find the function MediaPlayer::sendPlaybackStarted is not called.
The code below is in MediaPlayer.cpp:

### // Check that the state change is for the pipeline. if (GST_MESSAGE_SRC(message) == GST_OBJECT_CAST(m_audioPipeline.pipeline)) { GstState oldState; GstState newState; GstState pendingState; gst_message_parse_state_changed(message, &oldState, &newState, &pendingState); if (newState == GST_STATE_PLAYING) { sendPlaybackStarted(); } /* * If the previous state was PLAYING and the new state is PAUSED, ie, the audio has stopped playing, * indicate to the observer that playback has finished. */ if (newState == GST_STATE_PAUSED && oldState == GST_STATE_PLAYING) { sendPlaybackFinished(); } }

The condition (GST_MESSAGE_SRC(message) == GST_OBJECT_CAST(m_audioPipeline.pipeline)) is always false, and it never reaches "sendPlaybackStarted();"

[knikhila]

Hello @sangshengjie,

Thanks for the logs. Please remember to remove sensitive information such as refreshtoken before sharing the logs. I have removed the sensitive information from your post.

I will need additional information to help debug the issue.

Can you please try playing a sample mp3 file using the following command:
gst-launch-1.0 -vmt filesrc location=/path/to/samplemusic.mp3 ! decodebin ! audioconvert ! autoaudiosink

If you need the audio output at a specific frequency, you may try this:
gst-launch-1.0 -vmt filesrc location=/path/to/samplemusic.mp3 ! decodebin ! audioconvert ! audioresample ! audio/x-raw, rate=RequiredFrequency ! autoaudiosink

If gst-launch fails as well, please share the logs.

If you are able to play using gst-launch-1.0, can you please try setting the debug flag with
export GST_DEBUG=*:5 and share the logs?

Thanks,
Nikhila

[sangshengjie]

Hello @knikhila

I use the command to play normally in my arm board.
gst-launch-1.0 -vmt filesrc location=/path/to/samplemusic.mp3 ! decodebin ! audioconvert ! audioresample ! audio/x-raw, rate=RequiredFrequency , channels = 2 ! autoaudiosink

The attach file is the logs which I catch with exporting GST_DEBUG=*:5 (running command : ./MediaPlayerTest inputs/)
log.txt

And in my device GST_MESSAGE_SRC(message) equals 0xffffffff in the function handleBusMessage of MediaPlayer.cpp

The environment which I run the program is "Linux buildroot 3.10.33 #1 SMP PREEMPT Sat Jun 24 15:03:17 CST 2017 armv7l GNU/Linux". Did you run the code on raspberrypi or other similarly platforms normally?

Thanks,
sangshengjie

[knikhila]

Hello @sangshengjie,

Thanks for the logs.
We have been able to run the MediaPlayerTest and the SpeechSynthesizerIntegrationTest on the Raspberry Pi without encountering this issue.
We are still working on debugging the issue and will keep you updated.

Thanks
Nikhila

[knikhila]

Hi @sangshengjie ,

I have not been able to reproduce the issue.
Currently we set the timeout value to receive a playback started to 5000ms in MediaPlayerTest file.
The line of code that does this is:
bool waitForPlaybackStarted(const std::chrono::milliseconds duration = std::chrono::milliseconds(5000));
Can you please try increasing the timeout value from 5000ms to a higher value and check if issue still persists?

Thanks,
Nikhila

[sangshengjie]

Hi @knikhila

I increased the timeout value to a higher value, the issue still persists.
It seemed to be the gstreamer bug on my device.

Thanks,
sangshengjie

[sangshengjie]

Hi @knikhila

When I cross-compiled the sdk, I used the headers files of my local(/usr/local/include)。
When I found this, and recompiled with the target headers files, it worked.

Thanks,
sangshengjie