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

Failed to connect to AVS #306

Closed
yxzb opened this issue Nov 6, 2017 · 8 comments
Closed

Failed to connect to AVS #306

yxzb opened this issue Nov 6, 2017 · 8 comments

Comments

@yxzb
Copy link

yxzb commented Nov 6, 2017 •
edited
Loading

when i try to run the SampleApp,it reports that 'Failed to connect to AVS'

And the log is below:

`alexa@alexa-server:~/jqzhang/amazon/out/SampleApp/src$ TZ=UTC ./SampleApp /home/alexa/jqzhang/amazon/out/Integration/AlexaClientSDKConfig.json DEBUG9
Running app with log level: DEBUG9
2017-11-06 04:40:00.318 [ 1] I ConfigurationNode:initializeSuccess
2017-11-06 04:40:00.321 [ 1] 9 MediaPlayer:createCalled
2017-11-06 04:40:00.351 [ 1] 9 MediaPlayer:createCalled
2017-11-06 04:40:00.351 [ 1] 9 MediaPlayer:createCalled
2017-11-06 04:40:00.356 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-06 04:40:00.356 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-06 04:40:00.357 [ 1] 9 SpeechSynthesizer:addObserver:observer=0x14c0a40
2017-11-06 04:40:00.357 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-06 04:40:00.357 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-06 04:40:00.357 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-06 04:40:00.357 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-06 04:40:00.358 [ 1] 9 AlertScheduler:setTimerForNextAlertLocked
2017-11-06 04:40:00.358 [ 1] I AlertScheduler:executeScheduleNextAlertForRendering::no work to do.
2017-11-06 04:40:00.358 [ 3] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2017-11-06 04:40:00.359 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-06 04:40:00.360 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-06 04:40:00.360 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-06 04:40:00.360 [ 1] 0 SpeakerManager:mapCreated:numAvsSynced=2,numLocal=1
2017-11-06 04:40:00.360 [ 1] 1 AudioPlayer:addObserver
2017-11-06 04:40:00.360 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x14e5e30,policy=BLOCKING
2017-11-06 04:40:00.360 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x14e68e0,policy=NON_BLOCKING
2017-11-06 04:40:00.360 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x14e68e0,policy=NON_BLOCKING
2017-11-06 04:40:00.360 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x14e68e0,policy=NON_BLOCKING
2017-11-06 04:40:00.360 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x14e4dd0,policy=NON_BLOCKING
2017-11-06 04:40:00.360 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x14e4dd0,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x14e7990,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x14e7990,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetEndpoint,handler=0x1557bf0,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x14e49e8,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x1556730,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x1556730,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x1556730,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] 9 TemplateRuntime:getConfiguration
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x15570a0,policy=NON_BLOCKING
2017-11-06 04:40:00.361 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x15570a0,policy=NON_BLOCKING
2017-11-06 04:40:02.036 [ 4] 0 HttpPost:doPostSucceeded:code=200
2017-11-06 04:40:02.036 [ 4] 0 AuthDelegate:handleLwaResponseSucceeded:expiresInSeconds=3600
2017-11-06 04:40:02.036 [ 4] 0 AuthDelegate:onAuthStateChangeCalled:state=1,error=0
2017-11-06 04:40:02.036 [ 1] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=PENDING
2017-11-06 04:40:02.036 [ 1] W HTTP2Transport:OpenSSL minimum version requirement failed!:version=OpenSSL/1.0.1f,required=1.0.2
2017-11-06 04:40:02.037 [ 1] 0 HTTP2StreamPool:getStream:streamId=1,numAcquiredStreams=1
2017-11-06 04:40:02.037 [ 5] 9 PostConnectSynchronize:Entering postConnectLoop thread
#############################

Connecting...

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

2017-11-06 04:40:02.038 [ 6] 9 SpeakerManager:provideStateCalled
2017-11-06 04:40:02.038 [ 6] 0 AudioPlayer:provideState:stateRequestToken=1
2017-11-06 04:40:02.038 [ 3] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=PENDING,reason=ACL_CLIENT_REQUEST
2017-11-06 04:40:02.038 [ 6] 9 SpeechSynthesizer:provideState:token=1
2017-11-06 04:40:02.038 [ 7] 9 SpeakerManager:executeProvideStateCalled
2017-11-06 04:40:02.038 [ 7] 9 MediaPlayer:getSpeakerSettingsCalled
2017-11-06 04:40:02.038 [ 8] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2017-11-06 04:40:02.038 [ 2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2017-11-06 04:40:02.038 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"},namespace=AudioPlayer,name=PlaybackState
2017-11-06 04:40:02.038 [ 7] 9 MediaPlayer:getSpeakerSettingsCalled
2017-11-06 04:40:02.038 [ 2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2017-11-06 04:40:02.038 [ 9] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=1
2017-11-06 04:40:02.038 [ 7] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2017-11-06 04:40:02.039 [ 7] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2017-11-06 04:40:02.038 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"wakeword" : ""},namespace=SpeechRecognizer,name=RecognizerState
2017-11-06 04:40:02.039 [ 9] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"},namespace=SpeechSynthesizer,name=SpeechState
2017-11-06 04:40:02.039 [ 7] 0 ContextManager:updateStateLocked:action=updatedState,state={"volume":100,"muted":false},namespace=Speaker,name=VolumeState
2017-11-06 04:40:02.039 [ 6] 0 ContextManager:buildContextSuccessful:context={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":""}}]}
2017-11-06 04:40:02.040 [ 6] 0 EventBuilder:buildJsonEventString:messageId=66b794d1-a959-4685-a0da-435ed0a345e5,namespace=System,name=SynchronizeState
2017-11-06 04:40:02.040 [ 6] 0 PostConnectSynchronize:onContextAvailable : Send PostConnectMessage to transport
2017-11-06 04:40:02.040 [ 6] 9 HTTP2Transport:enqueueRequest
2017-11-06 04:40:05.509 [ b] 0 HTTP2StreamPool:releaseStream:streamId=1,numAcquiredStreams=0
2017-11-06 04:40:05.509 [ b] 0 HTTP2StreamPool:getStream:streamId=3,numAcquiredStreams=1
2017-11-06 04:40:05.510 [ b] E HTTP2Transport:networkLoopRetryingToConnect:reason=establishConnectionFailed,retryCount=0,retryBackoff=322
2017-11-06 04:40:07.230 [ b] 0 HTTP2StreamPool:releaseStream:streamId=3,numAcquiredStreams=0
2017-11-06 04:40:07.231 [ b] 0 HTTP2StreamPool:getStream:streamId=5,numAcquiredStreams=1
2017-11-06 04:40:07.231 [ b] E HTTP2Transport:networkLoopRetryingToConnect:reason=establishConnectionFailed,retryCount=1,retryBackoff=1307
2017-11-06 04:40:10.544 [ b] 0 HTTP2StreamPool:releaseStream:streamId=5,numAcquiredStreams=0
2017-11-06 04:40:10.544 [ b] 0 HTTP2StreamPool:getStream:streamId=7,numAcquiredStreams=1
2017-11-06 04:40:10.544 [ b] E HTTP2Transport:networkLoopRetryingToConnect:reason=establishConnectionFailed,retryCount=2,retryBackoff=4324
2017-11-06 04:40:16.242 [ b] 0 HTTP2StreamPool:releaseStream:streamId=7,numAcquiredStreams=0
2017-11-06 04:40:16.243 [ b] 0 HTTP2StreamPool:getStream:streamId=9,numAcquiredStreams=1
2017-11-06 04:40:16.243 [ b] E HTTP2Transport:networkLoopRetryingToConnect:reason=establishConnectionFailed,retryCount=3,retryBackoff=6955
Failed to connect to AVS!
2017-11-06 04:40:22.038 [ 1] I DirectiveSequencer:doShutdown
2017-11-06 04:40:22.038 [ 1] 9 TemplateRuntime:getConfiguration
2017-11-06 04:40:22.038 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x15570a0,policy=NON_BLOCKING
2017-11-06 04:40:22.038 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderTemplate,handler=0x15570a0,policy=NON_BLOCKING
2017-11-06 04:40:22.038 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetMute,handler=0x1556730,policy=NON_BLOCKING
2017-11-06 04:40:22.038 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=AdjustVolume,handler=0x1556730,policy=NON_BLOCKING
2017-11-06 04:40:22.038 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetVolume,handler=0x1556730,policy=NON_BLOCKING
2017-11-06 04:40:22.038 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=DeleteAlert,handler=0x14e7990,policy=NON_BLOCKING
2017-11-06 04:40:22.038 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=SetAlert,handler=0x14e7990,policy=NON_BLOCKING
2017-11-06 04:40:22.038 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=SetEndpoint,handler=0x1557bf0,policy=NON_BLOCKING
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechSynthesizer,name=Speak,handler=0x14e5e30,policy=BLOCKING
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=ClearQueue,handler=0x14e68e0,policy=NON_BLOCKING
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Stop,handler=0x14e68e0,policy=NON_BLOCKING
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Play,handler=0x14e68e0,policy=NON_BLOCKING
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x14e4dd0,policy=NON_BLOCKING
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=StopCapture,handler=0x14e4dd0,policy=NON_BLOCKING
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=ResetUserInactivity,handler=0x14e49e8,policy=NON_BLOCKING
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x15570a0
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1556730
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x14e7990
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1557bf0
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x14e5e30
2017-11-06 04:40:22.039 [ 1] 9 SpeechSynthesizer:onDeregistered
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x14e68e0
2017-11-06 04:40:22.039 [ 1] 0 AudioPlayer:onDeregistered
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x14e4dd0
2017-11-06 04:40:22.039 [ 8] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2017-11-06 04:40:22.039 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x14e49e8
2017-11-06 04:40:22.039 [ 1] 0 ContextManager:setStateProvider:action=removedStateProvider,namespace=Speaker,name=VolumeState
2017-11-06 04:40:22.040 [ 1] 1 AudioPlayer:removeObserver
2017-11-06 04:40:22.040 [ 1] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2017-11-06 04:40:22.040 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-06 04:40:22.040 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-06 04:40:22.040 [ 1] 0 ContextManager:setStateProvider:action=removedStateProvider,namespace=AudioPlayer,name=PlaybackState
2017-11-06 04:40:22.040 [ 1] 9 SpeechSynthesizer:doShutdown
2017-11-06 04:40:22.040 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-06 04:40:22.040 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-06 04:40:22.041 [ 1] 9 AlertsCapabilityAgent:releaseChannel
2017-11-06 04:40:22.041 [ 1] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=DISCONNECTED
2017-11-06 04:40:22.041 [ 1] 0 PostConnectSynchronize:PostConnectSynchronizer::doShutdown().
#####################################

Client not connected!

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

2017-11-06 04:40:22.041 [ 5] 9 PostConnectSynchronize:Exiting postConnectLoop thread
2017-11-06 04:40:22.041 [ b] 0 HTTP2StreamPool:releaseStream:streamId=9,numAcquiredStreams=0
2017-11-06 04:40:22.041 [ b] 0 HTTP2StreamPool:getStream:streamId=11,numAcquiredStreams=1
2017-11-06 04:40:22.041 [ b] 0 HTTP2StreamPool:releaseStream:streamId=11,numAcquiredStreams=0
2017-11-06 04:40:22.043 [ b] 0 PostConnectSynchronize:onSendCompleted:status=NOT_CONNECTED
2017-11-06 04:40:22.044 [ c] I CertifiedSender:CertifiedSender worker thread done. exiting mainloop.
2017-11-06 04:40:22.047 [ 1] 9 MediaPlayer:~MediaPlayerCalled
2017-11-06 04:40:22.047 [ 1] 9 MediaPlayer:resetPipeline
2017-11-06 04:40:22.048 [ 1] 9 MediaPlayer:~MediaPlayerCalled
2017-11-06 04:40:22.048 [ 1] 9 MediaPlayer:resetPipeline
Failed to initialize SampleApplication
Failed to create to SampleApplication!
`
Has anyone encountered the same problem and how to solve it?
@jjamazon
Copy link

jjamazon commented Nov 6, 2017

Hi yxzb,

What platform are you running this on Mac/Ubuntu/Pi ?
What version of the SDK are you using ?
Could you reply with your json config file. Make sure you block out any sensitive information in the config file like ClientSecret and deviceSerialNumber before posting.

@yxzb
Copy link
Author

yxzb commented Nov 8, 2017

Hi jjamazon,

The platform is ubuntu,and the SDK version is v1.2.0.

config file is below:

{ "alertsCapabilityAgent":{ "timerShortSoundFilePath":"/home/alexa/jqzhang/amazon/sound-file/med_system_alerts_melodic_02_short._TTH_.wav", "alarmSoundFilePath":"/home/alexa/jqzhang/amazon/sound-file/med_system_alerts_melodic_01._TTH_.mp3", "databaseFilePath":"/home/alexa/jqzhang/amazon/sound-file/alerts.db", "timerSoundFilePath":"/home/alexa/jqzhang/amazon/sound-file/med_system_alerts_melodic_02._TTH_.mp3", "alarmShortSoundFilePath":"/home/alexa/jqzhang/amazon/sound-file/med_system_alerts_melodic_01_short._TTH_.wav" }, "certifiedSender":{ "databaseFilePath":"/home/alexa/jqzhang/amazon/sound-file/certifiedSender.db" }, "settings":{ "databaseFilePath":"/home/alexa/jqzhang/amazon/sound-file/settings.db", "defaultAVSClientSettings":{ "locale":"en-US" } }, "authDelegate":{ "clientSecret":"xxxxxx", "deviceSerialNumber":"123456789", "refreshToken":"xxxxxx", "clientId":"xxxxxx", "productId":"hengbox" }
Thank you very much!

@jjamazon
Copy link

jjamazon commented Nov 8, 2017

Hi yxzb,

Looks like your Openssl does not meet minimum requirement

2017-11-06 04:40:02.036 [ 1] W HTTP2Transport:OpenSSL minimum version requirement failed!:version=OpenSSL/1.0.1f,required=1.0.2

Take a look at the minimum requirements link below.

https://github.com/alexa/avs-device-sdk/wiki/Linux-Quick-Start-Guide#minimum-requirements-and-dependencies

@yxzb
Copy link
Author

yxzb commented Nov 13, 2017

Hi jjamazon,

I hava installed the latest OpenSSL,and the log is below:

`alexa@alexa-server:~/jqzhang/amazon/out/SampleApp/src$ TZ=UTC ./SampleApp ../../Integration/AlexaClientSDKConfig.json DEBUG9
Running app with log level: DEBUG9
2017-11-13 03:01:09.771 [ 1] I ConfigurationNode:initializeSuccess
2017-11-13 03:01:09.773 [ 1] 9 MediaPlayer:createCalled
2017-11-13 03:01:09.803 [ 1] 9 MediaPlayer:createCalled
2017-11-13 03:01:09.803 [ 1] 9 MediaPlayer:createCalled
2017-11-13 03:01:09.809 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-13 03:01:09.809 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-13 03:01:09.809 [ 1] 9 SpeechSynthesizer:addObserver:observer=0x1169f40
2017-11-13 03:01:09.809 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-13 03:01:09.809 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-13 03:01:09.810 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-13 03:01:09.810 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-13 03:01:09.811 [ 1] 9 AlertScheduler:setTimerForNextAlertLocked
2017-11-13 03:01:09.811 [ 1] I AlertScheduler:executeScheduleNextAlertForRendering::no work to do.
2017-11-13 03:01:09.811 [ 3] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2017-11-13 03:01:09.812 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-13 03:01:09.812 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-13 03:01:09.812 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-13 03:01:09.812 [ 1] 0 SpeakerManager:mapCreated:numAvsSynced=2,numLocal=1
2017-11-13 03:01:09.813 [ 1] 1 AudioPlayer:addObserver
2017-11-13 03:01:09.813 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x118f340,policy=BLOCKING
2017-11-13 03:01:09.813 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x118fdb0,policy=NON_BLOCKING
2017-11-13 03:01:09.813 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x118fdb0,policy=NON_BLOCKING
2017-11-13 03:01:09.813 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x118fdb0,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x118e2e0,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x118e2e0,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x1190da0,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x1190da0,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetEndpoint,handler=0x1201100,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x118def8,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x11ffc40,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x11ffc40,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x11ffc40,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] 9 TemplateRuntime:getConfiguration
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x12005b0,policy=NON_BLOCKING
2017-11-13 03:01:09.814 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x12005b0,policy=NON_BLOCKING
2017-11-13 03:01:11.350 [ 4] 0 HttpPost:doPostSucceeded:code=200
2017-11-13 03:01:11.350 [ 4] 0 AuthDelegate:handleLwaResponseSucceeded:expiresInSeconds=3600
2017-11-13 03:01:11.350 [ 4] 0 AuthDelegate:onAuthStateChangeCalled:state=1,error=0
2017-11-13 03:01:11.351 [ 1] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=PENDING
2017-11-13 03:01:11.351 [ 1] W HTTP2Transport:OpenSSL minimum version requirement failed!:version=OpenSSL/1.0.1f,required=1.0.2
2017-11-13 03:01:11.351 [ 1] 0 HTTP2StreamPool:getStream:streamId=1,numAcquiredStreams=1
2017-11-13 03:01:11.352 [ 5] 9 PostConnectSynchronize:Entering postConnectLoop thread
2017-11-13 03:01:11.352 [ 3] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=PENDING,reason=ACL_CLIENT_REQUEST
#############################

Connecting...

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

2017-11-13 03:01:11.355 [ 6] 9 SpeakerManager:provideStateCalled
2017-11-13 03:01:11.355 [ 6] 0 AudioPlayer:provideState:stateRequestToken=1
2017-11-13 03:01:11.355 [ 7] 9 SpeakerManager:executeProvideStateCalled
2017-11-13 03:01:11.355 [ 7] 9 MediaPlayer:getSpeakerSettingsCalled
2017-11-13 03:01:11.356 [ 6] 9 SpeechSynthesizer:provideState:token=1
2017-11-13 03:01:11.356 [ 8] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2017-11-13 03:01:11.356 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"},namespace=AudioPlayer,name=PlaybackState
2017-11-13 03:01:11.356 [ 2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2017-11-13 03:01:11.356 [ 9] 0 ContextManager:updateStateLocked:action=updatedState,state={"wakeword" : ""},namespace=SpeechRecognizer,name=RecognizerState
2017-11-13 03:01:11.356 [ a] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=1
2017-11-13 03:01:11.356 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"},namespace=SpeechSynthesizer,name=SpeechState
2017-11-13 03:01:11.356 [ 7] 9 MediaPlayer:getSpeakerSettingsCalled
2017-11-13 03:01:11.356 [ 2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2017-11-13 03:01:11.356 [ 7] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2017-11-13 03:01:11.356 [ 7] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2017-11-13 03:01:11.357 [ 7] 0 ContextManager:updateStateLocked:action=updatedState,state={"volume":100,"muted":false},namespace=Speaker,name=VolumeState
2017-11-13 03:01:11.357 [ 6] 0 ContextManager:buildContextSuccessful:context={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":""}}]}
2017-11-13 03:01:11.358 [ 6] 0 EventBuilder:buildJsonEventString:messageId=93c98e55-7381-455d-a2c0-36fffef7e17b,namespace=System,name=SynchronizeState
2017-11-13 03:01:11.358 [ 6] 0 PostConnectSynchronize:onContextAvailable : Send PostConnectMessage to transport
2017-11-13 03:01:11.358 [ 6] 9 HTTP2Transport:enqueueRequest
Failed to connect to AVS!
2017-11-13 03:01:31.352 [ 1] I DirectiveSequencer:doShutdown
2017-11-13 03:01:31.352 [ 1] 9 TemplateRuntime:getConfiguration
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x12005b0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderTemplate,handler=0x12005b0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetMute,handler=0x11ffc40,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=AdjustVolume,handler=0x11ffc40,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetVolume,handler=0x11ffc40,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=DeleteAlert,handler=0x1190da0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=SetAlert,handler=0x1190da0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=SetEndpoint,handler=0x1201100,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechSynthesizer,name=Speak,handler=0x118f340,policy=BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=ClearQueue,handler=0x118fdb0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Stop,handler=0x118fdb0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Play,handler=0x118fdb0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x118e2e0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=StopCapture,handler=0x118e2e0,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=ResetUserInactivity,handler=0x118def8,policy=NON_BLOCKING
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x12005b0
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x11ffc40
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1190da0
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1201100
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x118f340
2017-11-13 03:01:31.353 [ 1] 9 SpeechSynthesizer:onDeregistered
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x118fdb0
2017-11-13 03:01:31.353 [ 1] 0 AudioPlayer:onDeregistered
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x118e2e0
2017-11-13 03:01:31.353 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x118def8
2017-11-13 03:01:31.353 [ 8] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2017-11-13 03:01:31.354 [ 1] 0 ContextManager:setStateProvider:action=removedStateProvider,namespace=Speaker,name=VolumeState
2017-11-13 03:01:31.354 [ 1] 1 AudioPlayer:removeObserver
2017-11-13 03:01:31.354 [ 1] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2017-11-13 03:01:31.354 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-13 03:01:31.354 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-13 03:01:31.355 [ 1] 0 ContextManager:setStateProvider:action=removedStateProvider,namespace=AudioPlayer,name=PlaybackState
2017-11-13 03:01:31.355 [ 1] 9 SpeechSynthesizer:doShutdown
2017-11-13 03:01:31.355 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-13 03:01:31.355 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-13 03:01:31.355 [ 1] 9 AlertsCapabilityAgent:releaseChannel
2017-11-13 03:01:31.355 [ 1] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=DISCONNECTED
2017-11-13 03:01:31.355 [ 1] 0 PostConnectSynchronize:PostConnectSynchronizer::doShutdown().
2017-11-13 03:01:31.355 [ 5] 9 PostConnectSynchronize:Exiting postConnectLoop thread
#####################################

Client not connected!

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

2017-11-13 03:01:31.360 [ b] 0 HTTP2StreamPool:releaseStream:streamId=1,numAcquiredStreams=0
2017-11-13 03:01:31.360 [ b] 0 HTTP2StreamPool:getStream:streamId=3,numAcquiredStreams=1
2017-11-13 03:01:31.360 [ b] 0 HTTP2StreamPool:releaseStream:streamId=3,numAcquiredStreams=0
2017-11-13 03:01:31.360 [ b] 0 PostConnectSynchronize:onSendCompleted:status=NOT_CONNECTED
2017-11-13 03:01:31.362 [ c] I CertifiedSender:CertifiedSender worker thread done. exiting mainloop.
2017-11-13 03:01:31.364 [ 1] 9 MediaPlayer:~MediaPlayerCalled
2017-11-13 03:01:31.365 [ 1] 9 MediaPlayer:resetPipeline
2017-11-13 03:01:31.365 [ 1] 9 MediaPlayer:MediaPlayerCalled
2017-11-13 03:01:31.365 [ 1] 9 MediaPlayer:resetPipeline
Failed to initialize SampleApplication
Failed to create to SampleApplication!
alexa@alexa-server:/jqzhang/amazon/out/SampleApp/src$
`

Thank you very much!

@scotthea-amazon
Copy link
Contributor

Hi yxzb,

Looking at that log, I can see that you have DEBUG9 logs enabled, but there is no obvious trigger for why the connection attempt failed.

The logs shows a very quick failure. I would have expect to see some logs from the connection attempt, and probably some logs from retrying to connect. This leads me to ask: Have you customized SampleApp or DefaultClient in some way?

It is a long shot, since I do not see any logs showing ACL attempting to connect, but you can get even more complete logs if you build with the cmake command line option

-DACSDK_EMIT_SENSITIVE_LOGS=ON

That will spit out the libcurl logs, which may show more detail about the attempt to connect to AVS. If you do try out this switch, be aware that the logs may include sensitive data, so you should be sure to redact anything you don't want to share before posting such logs.

Thank you,
-SWH

@yxzb
Copy link
Author

yxzb commented Nov 14, 2017

Hi scotthea-amazon，

I hava not customized SampleApp or DefaultClient.

I hava just built with the cmake command line option : -DACSDK_EMIT_SENSITIVE_LOGS=ON

and the log is below:

`alexa@alexa-server:~/jqzhang/amazon/out/SampleApp/src$ TZ=UTC ./SampleApp ../../Integration/AlexaClientSDKConfig.json DEBUG9
Running app with log level: DEBUG9
2017-11-14 02:30:25.670 [ 1] I ConfigurationNode:initializeSuccess:configuration={xxxxxx}
2017-11-14 02:30:25.690 [ 1] 9 MediaPlayer:createCalled
2017-11-14 02:30:25.932 [ 1] 9 MediaPlayer:createCalled
2017-11-14 02:30:25.932 [ 1] 9 MediaPlayer:createCalled
2017-11-14 02:30:25.956 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-14 02:30:25.956 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-14 02:30:25.956 [ 1] 9 SpeechSynthesizer:addObserver:observer=0x1bbdf00
2017-11-14 02:30:25.957 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-14 02:30:25.957 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-14 02:30:25.957 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-14 02:30:25.957 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-14 02:30:25.979 [ 1] 9 AlertScheduler:setTimerForNextAlertLocked
2017-11-14 02:30:25.979 [ 1] I AlertScheduler:executeScheduleNextAlertForRendering::no work to do.
2017-11-14 02:30:25.980 [ 3] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2017-11-14 02:30:25.981 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-14 02:30:25.981 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-14 02:30:25.981 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2017-11-14 02:30:25.981 [ 1] 0 SpeakerManager:mapCreated:numAvsSynced=2,numLocal=1
2017-11-14 02:30:25.982 [ 1] 1 AudioPlayer:addObserver
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x1be3180,policy=BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x1be3c30,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x1be3c30,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x1be3c30,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x1be2120,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x1be2120,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x1be4fb0,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x1be4fb0,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetEndpoint,handler=0x1c54f30,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x1be1d38,policy=NON_BLOCKING
2017-11-14 02:30:25.982 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x1c53a70,policy=NON_BLOCKING
2017-11-14 02:30:25.983 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x1c53a70,policy=NON_BLOCKING
2017-11-14 02:30:25.983 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x1c53a70,policy=NON_BLOCKING
2017-11-14 02:30:25.983 [ 1] 9 TemplateRuntime:getConfiguration
2017-11-14 02:30:25.983 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x1c543e0,policy=NON_BLOCKING
2017-11-14 02:30:25.983 [ 1] I DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x1c543e0,policy=NON_BLOCKING
2017-11-14 02:30:29.300 [ 4] 0 HttpPost:doPostSucceeded:code=200
2017-11-14 02:30:29.300 [ 4] 0 AuthDelegate:handleLwaResponseSucceeded:refreshToken=xxxxxx
2017-11-14 02:30:29.301 [ 4] 0 AuthDelegate:onAuthStateChangeCalled:state=1,error=0
2017-11-14 02:30:29.301 [ 1] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=PENDING
2017-11-14 02:30:29.301 [ 1] W HTTP2Transport:OpenSSL minimum version requirement failed!:version=OpenSSL/1.0.1f,required=1.0.2
2017-11-14 02:30:29.301 [ 1] 0 HTTP2StreamPool:getStream:streamId=1,numAcquiredStreams=1
2017-11-14 02:30:29.302 [ 5] 9 PostConnectSynchronize:Entering postConnectLoop thread
#############################

Connecting...

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

2017-11-14 02:30:29.302 [ 3] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=PENDING,reason=ACL_CLIENT_REQUEST
2017-11-14 02:30:29.303 [ 6] 9 SpeakerManager:provideStateCalled
2017-11-14 02:30:29.303 [ 6] 0 AudioPlayer:provideState:stateRequestToken=1
2017-11-14 02:30:29.303 [ 6] 9 SpeechSynthesizer:provideState:token=1
2017-11-14 02:30:29.303 [ 9] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=1
2017-11-14 02:30:29.303 [ 7] 9 SpeakerManager:executeProvideStateCalled
2017-11-14 02:30:29.304 [ 7] 9 MediaPlayer:getSpeakerSettingsCalled
2017-11-14 02:30:29.303 [ 8] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2017-11-14 02:30:29.303 [ a] 0 ContextManager:updateStateLocked:action=updatedState,state={"wakeword" : ""},namespace=SpeechRecognizer,name=RecognizerState
2017-11-14 02:30:29.304 [ 2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2017-11-14 02:30:29.304 [ 9] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"},namespace=SpeechSynthesizer,name=SpeechState
2017-11-14 02:30:29.305 [ 8] 0 ContextManager:updateStateLocked:action=updatedState,state={"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"},namespace=AudioPlayer,name=PlaybackState
2017-11-14 02:30:29.305 [ 7] 9 MediaPlayer:getSpeakerSettingsCalled
2017-11-14 02:30:29.305 [ 2] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2017-11-14 02:30:29.305 [ 7] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2017-11-14 02:30:29.305 [ 7] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2017-11-14 02:30:29.305 [ 7] 0 ContextManager:updateStateLocked:action=updatedState,state={"volume":100,"muted":false},namespace=Speaker,name=VolumeState
2017-11-14 02:30:29.306 [ 6] 0 ContextManager:buildContextSuccessful:context={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":""}}]}
2017-11-14 02:30:29.306 [ 6] 0 EventBuilder:buildJsonEventString:messageId=a79f0f99-7f0a-462c-a9ab-185695711e44,namespace=System,name=SynchronizeState
2017-11-14 02:30:29.307 [ 6] 0 PostConnectSynchronize:onContextAvailable : Send PostConnectMessage to transport
2017-11-14 02:30:29.307 [ 6] 9 HTTP2Transport:enqueueRequest:jsonContent={"context":[{"header":{"namespace":"Speaker","name":"VolumeState"},"payload":{"volume":100,"muted":false}},{"header":{"namespace":"AudioPlayer","name":"PlaybackState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"}},{"header":{"namespace":"Alerts","name":"AlertsState"},"payload":{"allAlerts":[],"activeAlerts":[]}},{"header":{"namespace":"SpeechSynthesizer","name":"SpeechState"},"payload":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"}},{"header":{"namespace":"SpeechRecognizer","name":"RecognizerState"},"payload":{"wakeword":""}}],"event":{"header":{"namespace":"System","name":"SynchronizeState","messageId":"a79f0f99-7f0a-462c-a9ab-185695711e44"},"payload":{}}}
2017-11-14 02:30:29.313 [ b] I HTTP2Stream:libcurl:streamId=1,text= Trying 54.239.23.243...
2017-11-14 02:30:29.313 [ b] I HTTP2Stream:libcurl:streamId=1,text=TCP_NODELAY set
2017-11-14 02:30:29.759 [ b] I HTTP2Stream:libcurl:streamId=1,text=Connected to avs-alexa-na.amazon.com (54.239.23.243) port 443 (#0)
2017-11-14 02:30:29.760 [ b] I HTTP2Stream:libcurl:streamId=1,text=Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@strength
2017-11-14 02:30:29.772 [ b] I HTTP2Stream:libcurl:streamId=1,text=successfully set certificate verify locations:
2017-11-14 02:30:29.772 [ b] I HTTP2Stream:libcurl:streamId=1,text= CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: none
2017-11-14 02:30:29.772 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (OUT), TLS handshake, Client hello (1):
2017-11-14 02:30:30.214 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (IN), TLS handshake, Server hello (2):
2017-11-14 02:30:30.214 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (IN), TLS handshake, Certificate (11):
2017-11-14 02:30:30.215 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (IN), TLS handshake, Server key exchange (12):
2017-11-14 02:30:30.215 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (IN), TLS handshake, Server finished (14):
2017-11-14 02:30:30.216 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
2017-11-14 02:30:30.216 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (OUT), TLS change cipher, Client hello (1):
2017-11-14 02:30:30.216 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (OUT), TLS handshake, Finished (20):
2017-11-14 02:30:30.650 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (IN), TLS change cipher, Client hello (1):
2017-11-14 02:30:30.650 [ b] I HTTP2Stream:libcurl:streamId=1,text=TLSv1.2 (IN), TLS handshake, Finished (20):
2017-11-14 02:30:30.650 [ b] I HTTP2Stream:libcurl:streamId=1,text=SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
2017-11-14 02:30:30.651 [ b] I HTTP2Stream:libcurl:streamId=1,text=Server certificate:
2017-11-14 02:30:30.651 [ b] I HTTP2Stream:libcurl:streamId=1,text= subject: C=US; ST=Washington; L=Seattle; O=Amazon.com, Inc.; CN=latinum.amazon.com
2017-11-14 02:30:30.651 [ b] I HTTP2Stream:libcurl:streamId=1,text= start date: Aug 23 00:00:00 2017 GMT
2017-11-14 02:30:30.651 [ b] I HTTP2Stream:libcurl:streamId=1,text= expire date: May 21 23:59:59 2018 GMT
2017-11-14 02:30:30.651 [ b] I HTTP2Stream:libcurl:streamId=1,text= subjectAltName: host "avs-alexa-na.amazon.com" matched cert's "avs-alexa-na.amazon.com"
2017-11-14 02:30:30.651 [ b] I HTTP2Stream:libcurl:streamId=1,text= issuer: C=US; O=Symantec Corporation; OU=Symantec Trust Network; CN=Symantec Class 3 Secure Server CA - G4
2017-11-14 02:30:30.651 [ b] I HTTP2Stream:libcurl:streamId=1,text= SSL certificate verify ok.
2017-11-14 02:30:34.172 [ b] I HTTP2Stream:libcurl:streamId=1,text=Connection #0 to host avs-alexa-na.amazon.com left intact
2017-11-14 02:30:34.172 [ b] 0 HTTP2StreamPool:releaseStream:streamId=1,numAcquiredStreams=0
2017-11-14 02:30:34.172 [ b] 0 HTTP2StreamPool:getStream:streamId=3,numAcquiredStreams=1
2017-11-14 02:30:34.172 [ b] E HTTP2Transport:networkLoopRetryingToConnect:reason=establishConnectionFailed,retryCount=0,retryBackoff=339
2017-11-14 02:30:34.511 [ b] I HTTP2Stream:libcurl:streamId=3,text=Connection 0 seems to be dead!
2017-11-14 02:30:34.511 [ b] I HTTP2Stream:libcurl:streamId=3,text=Closing connection 0
2017-11-14 02:30:34.512 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (OUT), TLS alert, Client hello (1):
2017-11-14 02:30:34.513 [ b] I HTTP2Stream:libcurl:streamId=3,text=Hostname avs-alexa-na.amazon.com was found in DNS cache
2017-11-14 02:30:34.513 [ b] I HTTP2Stream:libcurl:streamId=3,text= Trying 54.239.23.243...
2017-11-14 02:30:34.513 [ b] I HTTP2Stream:libcurl:streamId=3,text=TCP_NODELAY set
2017-11-14 02:30:37.967 [ b] I HTTP2Stream:libcurl:streamId=3,text=Connected to avs-alexa-na.amazon.com (54.239.23.243) port 443 (#1)
2017-11-14 02:30:37.967 [ b] I HTTP2Stream:libcurl:streamId=3,text=Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@strength
2017-11-14 02:30:37.978 [ b] I HTTP2Stream:libcurl:streamId=3,text=successfully set certificate verify locations:
2017-11-14 02:30:37.978 [ b] I HTTP2Stream:libcurl:streamId=3,text= CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: none
2017-11-14 02:30:37.978 [ b] I HTTP2Stream:libcurl:streamId=3,text=SSL re-using session ID
2017-11-14 02:30:37.978 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (OUT), TLS handshake, Client hello (1):
2017-11-14 02:30:39.309 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (IN), TLS handshake, Server hello (2):
2017-11-14 02:30:39.763 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (IN), TLS handshake, Certificate (11):
2017-11-14 02:30:39.763 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (IN), TLS handshake, Server key exchange (12):
2017-11-14 02:30:39.764 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (IN), TLS handshake, Server finished (14):
2017-11-14 02:30:39.764 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
2017-11-14 02:30:39.764 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (OUT), TLS change cipher, Client hello (1):
2017-11-14 02:30:39.764 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (OUT), TLS handshake, Finished (20):
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (IN), TLS change cipher, Client hello (1):
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text=TLSv1.2 (IN), TLS handshake, Finished (20):
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text=SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text=old SSL session ID is stale, removing
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text=Server certificate:
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text= subject: C=US; ST=Washington; L=Seattle; O=Amazon.com, Inc.; CN=latinum.amazon.com
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text= start date: Aug 23 00:00:00 2017 GMT
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text= expire date: May 21 23:59:59 2018 GMT
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text= subjectAltName: host "avs-alexa-na.amazon.com" matched cert's "avs-alexa-na.amazon.com"
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text= issuer: C=US; O=Symantec Corporation; OU=Symantec Trust Network; CN=Symantec Class 3 Secure Server CA - G4
2017-11-14 02:30:40.217 [ b] I HTTP2Stream:libcurl:streamId=3,text= SSL certificate verify ok.
2017-11-14 02:30:40.667 [ b] I HTTP2Stream:libcurl:streamId=3,text=Connection #1 to host avs-alexa-na.amazon.com left intact
2017-11-14 02:30:40.667 [ b] 0 HTTP2StreamPool:releaseStream:streamId=3,numAcquiredStreams=0
2017-11-14 02:30:40.667 [ b] 0 HTTP2StreamPool:getStream:streamId=5,numAcquiredStreams=1
2017-11-14 02:30:40.667 [ b] E HTTP2Transport:networkLoopRetryingToConnect:reason=establishConnectionFailed,retryCount=1,retryBackoff=1261
2017-11-14 02:30:41.928 [ b] I HTTP2Stream:libcurl:streamId=5,text=Connection 1 seems to be dead!
2017-11-14 02:30:41.928 [ b] I HTTP2Stream:libcurl:streamId=5,text=Closing connection 1
2017-11-14 02:30:41.928 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (OUT), TLS alert, Client hello (1):
2017-11-14 02:30:41.930 [ b] I HTTP2Stream:libcurl:streamId=5,text=Hostname avs-alexa-na.amazon.com was found in DNS cache
2017-11-14 02:30:41.930 [ b] I HTTP2Stream:libcurl:streamId=5,text= Trying 54.239.23.243...
2017-11-14 02:30:41.930 [ b] I HTTP2Stream:libcurl:streamId=5,text=TCP_NODELAY set
2017-11-14 02:30:42.383 [ b] I HTTP2Stream:libcurl:streamId=5,text=Connected to avs-alexa-na.amazon.com (54.239.23.243) port 443 (#2)
2017-11-14 02:30:42.383 [ b] I HTTP2Stream:libcurl:streamId=5,text=Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@strength
2017-11-14 02:30:42.394 [ b] I HTTP2Stream:libcurl:streamId=5,text=successfully set certificate verify locations:
2017-11-14 02:30:42.394 [ b] I HTTP2Stream:libcurl:streamId=5,text= CAfile: /etc/ssl/certs/ca-certificates.crt
CApath: none
2017-11-14 02:30:42.394 [ b] I HTTP2Stream:libcurl:streamId=5,text=SSL re-using session ID
2017-11-14 02:30:42.394 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (OUT), TLS handshake, Client hello (1):
2017-11-14 02:30:44.788 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (IN), TLS handshake, Server hello (2):
2017-11-14 02:30:44.788 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (IN), TLS handshake, Certificate (11):
2017-11-14 02:30:44.789 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (IN), TLS handshake, Server key exchange (12):
2017-11-14 02:30:44.789 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (IN), TLS handshake, Server finished (14):
2017-11-14 02:30:44.790 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
2017-11-14 02:30:44.790 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (OUT), TLS change cipher, Client hello (1):
2017-11-14 02:30:44.790 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (OUT), TLS handshake, Finished (20):
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (IN), TLS change cipher, Client hello (1):
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (IN), TLS handshake, Finished (20):
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text=SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text=old SSL session ID is stale, removing
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text=Server certificate:
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text= subject: C=US; ST=Washington; L=Seattle; O=Amazon.com, Inc.; CN=latinum.amazon.com
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text= start date: Aug 23 00:00:00 2017 GMT
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text= expire date: May 21 23:59:59 2018 GMT
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text= subjectAltName: host "avs-alexa-na.amazon.com" matched cert's "avs-alexa-na.amazon.com"
2017-11-14 02:30:45.237 [ b] I HTTP2Stream:libcurl:streamId=5,text= issuer: C=US; O=Symantec Corporation; OU=Symantec Trust Network; CN=Symantec Class 3 Secure Server CA - G4
2017-11-14 02:30:45.238 [ b] I HTTP2Stream:libcurl:streamId=5,text= SSL certificate verify ok.
Failed to connect to AVS!
2017-11-14 02:30:49.302 [ 1] I DirectiveSequencer:doShutdown
2017-11-14 02:30:49.302 [ 1] 9 TemplateRuntime:getConfiguration
2017-11-14 02:30:49.302 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x1c543e0,policy=NON_BLOCKING
2017-11-14 02:30:49.302 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderTemplate,handler=0x1c543e0,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetMute,handler=0x1c53a70,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=AdjustVolume,handler=0x1c53a70,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetVolume,handler=0x1c53a70,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=DeleteAlert,handler=0x1be4fb0,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=SetAlert,handler=0x1be4fb0,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=SetEndpoint,handler=0x1c54f30,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechSynthesizer,name=Speak,handler=0x1be3180,policy=BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=ClearQueue,handler=0x1be3c30,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Stop,handler=0x1be3c30,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Play,handler=0x1be3c30,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x1be2120,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=StopCapture,handler=0x1be2120,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=ResetUserInactivity,handler=0x1be1d38,policy=NON_BLOCKING
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1c543e0
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1c53a70
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1be4fb0
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1c54f30
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1be3180
2017-11-14 02:30:49.303 [ 1] 9 SpeechSynthesizer:onDeregistered
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1be3c30
2017-11-14 02:30:49.303 [ 1] 0 AudioPlayer:onDeregistered
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1be2120
2017-11-14 02:30:49.303 [ 1] I DirectiveRouter:onDeregisteredCalled:handler=0x1be1d38
2017-11-14 02:30:49.303 [ 8] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2017-11-14 02:30:49.304 [ 1] 0 ContextManager:setStateProvider:action=removedStateProvider,namespace=Speaker,name=VolumeState
2017-11-14 02:30:49.304 [ 1] 1 AudioPlayer:removeObserver
2017-11-14 02:30:49.304 [ 1] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2017-11-14 02:30:49.304 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-14 02:30:49.304 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-14 02:30:49.304 [ 1] 0 ContextManager:setStateProvider:action=removedStateProvider,namespace=AudioPlayer,name=PlaybackState
2017-11-14 02:30:49.304 [ 1] 9 SpeechSynthesizer:doShutdown
2017-11-14 02:30:49.304 [ 1] 9 MediaPlayer:setObserverCalled
2017-11-14 02:30:49.304 [ 2] 0 MediaPlayer:handleSetObserverCalled
2017-11-14 02:30:49.305 [ 1] 9 AlertsCapabilityAgent:releaseChannel
2017-11-14 02:30:49.305 [ 1] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=DISCONNECTED
2017-11-14 02:30:49.305 [ 1] 0 PostConnectSynchronize:PostConnectSynchronizer::doShutdown().
2017-11-14 02:30:49.305 [ 5] 9 PostConnectSynchronize:Exiting postConnectLoop thread
#####################################

Client not connected!

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

2017-11-14 02:30:49.397 [ b] I HTTP2Stream:libcurl:streamId=5,text=stopped the pause stream!
2017-11-14 02:30:49.397 [ b] I HTTP2Stream:libcurl:streamId=5,text=Closing connection 2
2017-11-14 02:30:49.397 [ b] I HTTP2Stream:libcurl:streamId=5,text=TLSv1.2 (OUT), TLS alert, Client hello (1):
2017-11-14 02:30:49.399 [ b] 0 HTTP2StreamPool:releaseStream:streamId=5,numAcquiredStreams=0
2017-11-14 02:30:49.399 [ b] 0 HTTP2StreamPool:getStream:streamId=7,numAcquiredStreams=1
2017-11-14 02:30:49.399 [ b] 0 HTTP2StreamPool:releaseStream:streamId=7,numAcquiredStreams=0
2017-11-14 02:30:49.399 [ b] 0 PostConnectSynchronize:onSendCompleted:status=NOT_CONNECTED
2017-11-14 02:30:49.400 [ c] I CertifiedSender:CertifiedSender worker thread done. exiting mainloop.
2017-11-14 02:30:49.403 [ 1] 9 MediaPlayer:MediaPlayerCalled
2017-11-14 02:30:49.403 [ 1] 9 MediaPlayer:resetPipeline
2017-11-14 02:30:49.403 [ 1] 9 MediaPlayer:MediaPlayerCalled
2017-11-14 02:30:49.404 [ 1] 9 MediaPlayer:resetPipeline
Failed to initialize SampleApplication
Failed to create to SampleApplication!
alexa@alexa-server:/jqzhang/amazon/out/SampleApp/src$
alexa@alexa-server:/jqzhang/amazon/out/SampleApp/src$
`

Thank you very much!

@scotthea-amazon
Copy link
Contributor

Hello yxzb,

Even in your latest log, after you upgraded OpenSSL, the log shows that the SDK has been linked with an incompatible version of OpenSSL:

2017-11-14 02:30:29.301 [ 1] W HTTP2Transport:OpenSSL minimum version requirement failed!:version=OpenSSL/1.0.1f,required=1.0.2

It looks like you need to update your configuration or entice CMake into to finding the newer version of OpenSSL on your system.

Regards,
-SWH

@peifeng000
Copy link

Hi @scotthea-amazon

I have met the same problem.

When I upgraded the version of openssl, the fail message "2018-02-26 06:05:21.795 [ 1] W HTTP2Transport:OpenSSL minimum version requirement failed!:version=OpenSSL/1.0.1f,required=1.0.2 " still showed up.

"It looks like you need to update your configuration or entice CMake into to finding the newer version of OpenSSL on your system."
->Could you please tell me the specific steps of how to do it?

Thanks!

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@sanjayrd @scotthea-amazon @yxzb @peifeng000 @jjamazon