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

Failed to create to SampleApplication! #1366

Closed
1 of 8 tasks
stevesherri opened this issue May 27, 2019 · 21 comments
Closed
1 of 8 tasks

Failed to create to SampleApplication! #1366

stevesherri opened this issue May 27, 2019 · 21 comments

Comments

@stevesherri
Copy link

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

Briefly summarize your issue:

Had Alexa working fine... Changed to new SD card, built Alexa fine but when I try to open SampleApp I get an error. I am able to record audio with a record and play with aplay so mic and speaker are working fine

What is the expected behavior?

Alexa should start

What behavior are you observing?

2019-05-27 11:08:11.005 [ 1] I sdkVersion: 1.13.0
configFile /home/pi/build/Integration/AlexaClientSDKConfig.json
Running app with log level: DEBUG9
2019-05-27 11:08:11.024 [ 1] 0 ConfigurationNode:initializeSuccess
2019-05-27 11:08:11.037 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating Equalizer configuration
2019-05-27 11:08:11.037 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating default Equalizer state
2019-05-27 11:08:11.038 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating Equalizer configuration
2019-05-27 11:08:11.038 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating default Equalizer state
2019-05-27 11:08:11.042 [ 1] 9 MediaPlayer:createCalled:name=SpeakMediaPlayer
2019-05-27 11:08:11.132 [ 1] 9 MediaPlayer:noOutputConversion:name=SpeakMediaPlayer
2019-05-27 11:08:11.135 [ 1] 9 MediaPlayer:createCalled:name=AudioMediaPlayer
2019-05-27 11:08:11.139 [ 1] 9 MediaPlayer:noOutputConversion:name=AudioMediaPlayer
2019-05-27 11:08:11.141 [ 1] 9 MediaPlayer:createCalled:name=NotificationsMediaPlayer
2019-05-27 11:08:11.142 [ 1] 9 MediaPlayer:noOutputConversion:name=NotificationsMediaPlayer
2019-05-27 11:08:11.144 [ 1] 9 MediaPlayer:createCalled:name=BluetoothMediaPlayer
2019-05-27 11:08:11.145 [ 1] 9 MediaPlayer:noOutputConversion:name=BluetoothMediaPlayer
2019-05-27 11:08:11.147 [ 1] 9 MediaPlayer:createCalled:name=RingtoneMediaPlayer
2019-05-27 11:08:11.148 [ 1] 9 MediaPlayer:noOutputConversion:name=RingtoneMediaPlayer
2019-05-27 11:08:11.150 [ 1] 9 MediaPlayer:createCalled:name=AlertsMediaPlayer
2019-05-27 11:08:11.152 [ 1] 9 MediaPlayer:noOutputConversion:name=AlertsMediaPlayer
2019-05-27 11:08:11.155 [ 1] 5 SQLiteDeviceSettingStorage:create
2019-05-27 11:08:11.156 [ 1] 5 SQLiteBluetoothStorage:create
2019-05-27 11:08:11.157 [ 1] 5 CBLAuthDelegate:create
2019-05-27 11:08:11.158 [ 1] 5 CBLAuthDelegate:CBLAuthDelegate
2019-05-27 11:08:11.159 [ 1] 5 CBLAuthDelegate:init
2019-05-27 11:08:11.159 [ 1] 5 CBLAuthDelegateConfiguration:create
2019-05-27 11:08:11.159 [ 1] 5 CBLAuthDelegateConfiguration:init
2019-05-27 11:08:11.159 [ 1] 5 CBLAuthDelegateConfiguration:initScopeData
2019-05-27 11:08:11.159 [ 1] 9 CBLAuthDelegateConfiguration:initScopeDataSucceeded
2019-05-27 11:08:11.160 [ 1] 5 SQLiteCBLAuthDelegateStorage:open
2019-05-27 11:08:11.163 [ 1] 5 CBLAuthDelegate:addAuthObserver:observer=0x2318f74
2019-05-27 11:08:11.163 [ 4] 5 CBLAuthDelegate:handleAuthorizationFlow
2019-05-27 11:08:11.164 [ 4] 5 CBLAuthDelegate:handleStarting
2019-05-27 11:08:11.164 [ 4] 5 SQLiteCBLAuthDelegateStorage:getRefreshToken
2019-05-27 11:08:11.164 [ 1] 5 CBLAuthDelegate:addAuthObserver:observer=0x230421c
2019-05-27 11:08:11.164 [ 4] 0 SQLiteCBLAuthDelegateStorage:getRefreshTokenFailed:reason=stepResultWasNotRow
2019-05-27 11:08:11.164 [ 4] 0 CBLAuthDelegate:getRefreshTokenFailed
2019-05-27 11:08:11.165 [ 4] 5 CBLAuthDelegate:handleRequestingCodePair
2019-05-27 11:08:11.166 [ 4] 5 CBLAuthDelegate:requestCodePair
2019-05-27 11:08:11.166 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x2304220
2019-05-27 11:08:11.167 [ 1] 5 InternetConnectionMonitor:startMonitoring
2019-05-27 11:08:11.172 [ 5] 5 InternetConnectionMonitor:testConnection
2019-05-27 11:08:11.172 [ 5] 9 HTTPContentFetcherFactory:create::Creating a new http content fetcher
2019-05-27 11:08:11.172 [ 1] 5 SQLiteDeviceSettingStorage:open
2019-05-27 11:08:11.173 [ 5] 9 LibCurlHttpContentFetcher:stateTransition:oldState=INITIALIZED,newState=FETCHING_HEADER:State transition
2019-05-27 11:08:11.174 [ 6] 9 LibCurlHttpContentFetcher:transferThread::start
2019-05-27 11:08:11.176 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.177 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.177 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.178 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.178 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.178 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.178 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.178 [ 1] 5 AVSConnectionManager:create::Subscribing to InternetConnectionMonitor Callbacks
2019-05-27 11:08:11.179 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.179 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.179 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.179 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.179 [ 1] 5 AVSConnectionManager:onConnectionStatusChanged:connected=false
2019-05-27 11:08:11.180 [ 1] 5 AVSConnectionManager:reconnect:isEnabled=false
2019-05-27 11:08:11.179 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.180 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.180 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.180 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.180 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.180 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.181 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.181 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.181 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.181 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.182 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.182 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.182 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.182 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.182 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.182 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.183 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.183 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.183 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.183 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.183 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.183 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.184 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.184 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.184 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.184 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.184 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.185 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.185 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.185 [ a] 9 DirectiveProcessor:processingLoop
2019-05-27 11:08:11.185 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.185 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.185 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.186 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.186 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.186 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.186 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.186 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.186 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.187 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.187 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.187 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.187 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.187 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.188 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.188 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.188 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.188 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.189 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.189 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.189 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.189 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.189 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.189 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.190 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.190 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.190 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.190 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.190 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.190 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.191 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.191 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.191 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.191 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.191 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.192 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.192 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.192 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.192 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.192 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.193 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.193 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.194 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.194 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.194 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.194 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.194 [ 1] 9 MediaPlayer:setObserverCalled:name=SpeakMediaPlayer
2019-05-27 11:08:11.194 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.195 [ f] 0 MediaPlayer:handleSetObserverCalled:name=SpeakMediaPlayer
2019-05-27 11:08:11.195 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.195 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.195 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.195 [ 1] 9 SpeechSynthesizer:addObserver:observer=0x23200c4
2019-05-27 11:08:11.196 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.196 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.196 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.197 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.197 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.197 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.197 [ 1] 9 PlaybackRouter:create::called
2019-05-27 11:08:11.197 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.197 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.198 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.198 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.198 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.198 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.198 [ 1] 9 MediaPlayer:setObserverCalled:name=AudioMediaPlayer
2019-05-27 11:08:11.198 [ 12] 0 MediaPlayer:handleSetObserverCalled:name=AudioMediaPlayer
2019-05-27 11:08:11.198 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.199 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.199 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.200 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.200 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.200 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=SpeakMediaPlayer
2019-05-27 11:08:11.200 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.200 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.200 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=AudioMediaPlayer
2019-05-27 11:08:11.200 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.201 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=AlertsMediaPlayer
2019-05-27 11:08:11.201 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=NotificationsMediaPlayer
2019-05-27 11:08:11.201 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=BluetoothMediaPlayer
2019-05-27 11:08:11.201 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=RingtoneMediaPlayer
2019-05-27 11:08:11.201 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.201 [ 1] 0 SpeakerManager:mapCreated:numSpeakerVolume=4,numAlertsVolume=2
2019-05-27 11:08:11.202 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=SpeakMediaPlayer
2019-05-27 11:08:11.202 [ f] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=SpeakMediaPlayer
2019-05-27 11:08:11.202 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AudioMediaPlayer
2019-05-27 11:08:11.202 [ 12] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AudioMediaPlayer
2019-05-27 11:08:11.203 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=BluetoothMediaPlayer
2019-05-27 11:08:11.203 [ 14] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=BluetoothMediaPlayer
2019-05-27 11:08:11.203 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=RingtoneMediaPlayer
2019-05-27 11:08:11.203 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.203 [ 15] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=RingtoneMediaPlayer
2019-05-27 11:08:11.203 [ 1] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2019-05-27 11:08:11.203 [ 1] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2019-05-27 11:08:11.204 [ 1] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SPEAKER_VOLUME
2019-05-27 11:08:11.204 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.205 [ 1] 5 Renderer:resetSourceId
2019-05-27 11:08:11.205 [ 1] 9 MediaPlayer:setObserverCalled:name=AlertsMediaPlayer
2019-05-27 11:08:11.205 [ 17] 0 MediaPlayer:handleSetObserverCalled:name=AlertsMediaPlayer
2019-05-27 11:08:11.208 [ 1] 9 AlertScheduler:setTimerForNextAlertLocked
2019-05-27 11:08:11.208 [ 1] 9 AlertScheduler:executeScheduleNextAlertForRendering::no work to do.
2019-05-27 11:08:11.209 [ 1] 9 SpeakerManager:getSpeakerSettingsCalled
2019-05-27 11:08:11.210 [ 13] 9 SpeakerManager:executeGetSpeakerSettingsCalled
2019-05-27 11:08:11.210 [ 13] 9 MediaPlayer:getSpeakerSettingsCalled:name=AlertsMediaPlayer
2019-05-27 11:08:11.210 [ 17] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AlertsMediaPlayer
2019-05-27 11:08:11.210 [ 13] 9 MediaPlayer:getSpeakerSettingsCalled:name=NotificationsMediaPlayer
2019-05-27 11:08:11.210 [ 1a] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=NotificationsMediaPlayer
2019-05-27 11:08:11.210 [ 13] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2019-05-27 11:08:11.210 [ 13] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2019-05-27 11:08:11.212 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled
2019-05-27 11:08:11.212 [ 19] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2019-05-27 11:08:11.213 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x2327f9c
2019-05-27 11:08:11.213 [ 1] 5 NotificationsRenderer:create
2019-05-27 11:08:11.214 [ 1] 9 MediaPlayer:setObserverCalled:name=NotificationsMediaPlayer
2019-05-27 11:08:11.214 [ 1a] 0 MediaPlayer:handleSetObserverCalled:name=NotificationsMediaPlayer
2019-05-27 11:08:11.215 [ 1] 5 NotificationsCapabilityAgent:init
2019-05-27 11:08:11.215 [ 1] 5 NotificationsRenderer:addObserver
2019-05-27 11:08:11.218 [ 1] 5 InteractionModel:InteractionModelCapabilityAgent
2019-05-27 11:08:11.219 [ 1b] 5 NotificationsCapabilityAgent:executeInit
2019-05-27 11:08:11.220 [ 1b] 5 NotificationsCapabilityAgent:notifyObservers:indicatorState=0
2019-05-27 11:08:11.220 [ 1b] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=false,stateRequestToken=0
2019-05-27 11:08:11.223 [ 1b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-05-27 11:08:11.226 [ 1] 0 ExternalMediaPlayer:createAdapters
2019-05-27 11:08:11.229 [ 1] 1 AudioPlayer:addObserver
2019-05-27 11:08:11.230 [ 7] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2019-05-27 11:08:11.231 [ 1] 5 DNDSettingProtocol:create:settingName=enabled
2019-05-27 11:08:11.232 [ 1] 5 DNDSettingProtocol:restoreValue:setting=Alexa.DoNotDisturb::enabled
2019-05-27 11:08:11.232 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=Alexa.DoNotDisturb::enabled
2019-05-27 11:08:11.233 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:value=false
2019-05-27 11:08:11.234 [ 1] I Setting:handleSetValue:value=false
2019-05-27 11:08:11.240 [ 1] 5 DefaultClient:bluetoothCapabilityAgentDisabled:reason=nullBluetoothDeviceManager
2019-05-27 11:08:11.243 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x2335f98,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-05-27 11:08:11.244 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x2326b00,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.244 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x2326b00,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x2326b00,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=AdjustSeekPosition,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=SetSeekPosition,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableShuffle,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableShuffle,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeat,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeatOne,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Favorite,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.245 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=FastForward,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Previous,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=StartOver,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Next,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableRepeat,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Rewind,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Stop,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Pause,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Play,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Logout,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Login,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Unfavorite,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.246 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Play,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.247 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetEndOfSpeechOffset,handler=0x2325360,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.247 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x2325360,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-05-27 11:08:11.247 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x2325360,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.247 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=AdjustVolume,handler=0x2327f30,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.247 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x2327f30,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.247 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlerts,handler=0x2327f30,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.247 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x2327f30,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.247 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetVolume,handler=0x2327f30,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.248 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetEndpoint,handler=0x2337f18,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.248 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x23250bc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.248 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.248 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x2327518,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.248 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x2327518,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.248 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x2327518,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.248 [ 1] 5 TemplateRuntime:getConfiguration
2019-05-27 11:08:11.249 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x2336728,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-05-27 11:08:11.249 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x2336728,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-05-27 11:08:11.249 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=ClearIndicator,handler=0x232bb04,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.249 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=SetIndicator,handler=0x232bb04,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.249 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=InteractionModel,name=NewDialogRequest,handler=0x2330ca0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.250 [ 1] 5 EqualizerController:getConfiguration
2019-05-27 11:08:11.250 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=AdjustBands,handler=0x23385dc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.250 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=SetMode,handler=0x23385dc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.250 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=ResetBands,handler=0x23385dc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.250 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=SetBands,handler=0x23385dc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.250 [ 1] 5 DoNotDisturbCapabilityAgent:getConfiguration
2019-05-27 11:08:11.250 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.DoNotDisturb,name=SetDoNotDisturb,handler=0x23372e0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.254 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled
2019-05-27 11:08:11.255 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x230422c
2019-05-27 11:08:11.255 [ 1] 5 NotificationsCapabilityAgent:addObserver
2019-05-27 11:08:11.255 [ 1] 5 DefaultClient:addBluetoothDeviceObserver::bluetooth is disabled, not adding observer
2019-05-27 11:08:11.256 [ 1] 5 TemplateRuntime:addObserver
#################################################

NOTIFICATION INDICATOR STATE: OFF

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

2019-05-27 11:08:11.258 [ 20] 5 TemplateRuntime:addObserverInExecutor
2019-05-27 11:08:11.302 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-27 11:08:11.303 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.303 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.304 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.304 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.304 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.304 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.304 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.304 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.304 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.305 [ 6] 9 LibCurlHttpContentFetcher:headerCallback:type=content-length,length=419
2019-05-27 11:08:11.305 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.305 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.305 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-27 11:08:11.305 [ 6] 9 LibCurlHttpContentFetcher:bodyCallback::End of header found.
2019-05-27 11:08:11.349 [ 6] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_HEADER,newState=HEADER_DONE:State transition
2019-05-27 11:08:11.349 [ 5] 9 InternetConnectionMonitor:testConnection:contentLength=419
2019-05-27 11:08:11.349 [ 5] 9 LibCurlHttpContentFetcher:stateTransition:oldState=HEADER_DONE,newState=FETCHING_BODY:State transition
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'paInvalidSampleRate' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2043
Expression 'PaAlsaStreamComponent_InitialConfigure( &self->capture, inParams, self->primeBuffers, hwParamsCapture, &realSr )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2714
Expression 'PaAlsaStream_Configure( stream, inputParameters, outputParameters, sampleRate, framesPerBuffer, &inputLatency, &outputLatency, &hostBufferSizeMode )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2838
2019-05-27 11:08:11.397 [ 1] C PortAudioMicrophoneWrapper:Failed to open PortAudio default stream:errorCode=-9997
2019-05-27 11:08:11.398 [ 1] C PortAudioMicrophoneWrapper:Failed to initialize PortAudioMicrophoneWrapper
2019-05-27 11:08:11.398 [ 1] C SampleApplication:Failed to create PortAudioMicrophoneWrapper!
2019-05-27 11:08:11.399 [ 1] 5 DefaultClient:DirectiveSequencerShutdown
2019-05-27 11:08:11.399 [ 1] 9 DirectiveSequencer:doShutdown
2019-05-27 11:08:11.399 [ 1] 9 DirectiveProcessor:queueAllDirectivesForCancellationLocked
2019-05-27 11:08:11.399 [ a] 9 DirectiveProcessor:processCancelingQueueLocked:size=0
2019-05-27 11:08:11.400 [ 1] 5 DoNotDisturbCapabilityAgent:getConfiguration
2019-05-27 11:08:11.400 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.DoNotDisturb,name=SetDoNotDisturb,handler=0x23372e0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.SeekController,name=AdjustSeekPosition,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.SeekController,name=SetSeekPosition,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=DisableShuffle,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=EnableShuffle,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=EnableRepeat,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=EnableRepeatOne,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.FavoritesController,name=Favorite,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=FastForward,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.401 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Previous,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=StartOver,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Next,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=DisableRepeat,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Rewind,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Stop,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Pause,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Play,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=ExternalMediaPlayer,name=Logout,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=ExternalMediaPlayer,name=Login,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.FavoritesController,name=Unfavorite,handler=0x2335880,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=ExternalMediaPlayer,name=Play,handler=0x2335880,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=ResetUserInactivity,handler=0x23250bc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.402 [ 1] 5 TemplateRuntime:getConfiguration
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x2336728,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderTemplate,handler=0x2336728,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 5 EqualizerController:getConfiguration
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=EqualizerController,name=AdjustBands,handler=0x23385dc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=EqualizerController,name=SetMode,handler=0x23385dc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=EqualizerController,name=ResetBands,handler=0x23385dc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=EqualizerController,name=SetBands,handler=0x23385dc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=AdjustVolume,handler=0x2327f30,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=SetAlert,handler=0x2327f30,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=DeleteAlerts,handler=0x2327f30,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=DeleteAlert,handler=0x2327f30,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=SetVolume,handler=0x2327f30,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=ClearQueue,handler=0x2326b00,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.403 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Stop,handler=0x2326b00,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Play,handler=0x2326b00,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechSynthesizer,name=Speak,handler=0x2335f98,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=SetEndOfSpeechOffset,handler=0x2325360,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x2325360,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=StopCapture,handler=0x2325360,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=AdjustVolume,handler=0x2327518,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetMute,handler=0x2327518,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetVolume,handler=0x2327518,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=SetEndpoint,handler=0x2337f18,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Notifications,name=ClearIndicator,handler=0x232bb04,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Notifications,name=SetIndicator,handler=0x232bb04,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.404 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=InteractionModel,name=NewDialogRequest,handler=0x2330ca0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x23372e0
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2335880
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x23250bc
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2336728
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x23385dc
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2327f30
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2326b00
2019-05-27 11:08:11.405 [ 1] 0 AudioPlayer:onDeregistered
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2335f98
2019-05-27 11:08:11.405 [ 1] 9 SpeechSynthesizer:onDeregistered
2019-05-27 11:08:11.405 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2325360
2019-05-27 11:08:11.405 [ 11] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2019-05-27 11:08:11.405 [ d] 0 AudioInputProcessor:executeResetState
2019-05-27 11:08:11.406 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2327518
2019-05-27 11:08:11.406 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2337f18
2019-05-27 11:08:11.406 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x232bb04
2019-05-27 11:08:11.406 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2330ca0
2019-05-27 11:08:11.406 [ 1] 5 DefaultClient:SpeakerManagerShutdown
2019-05-27 11:08:11.407 [ 1] 5 DefaultClient:TemplateRuntimeShutdown
2019-05-27 11:08:11.407 [ 1] 1 AudioPlayer:removeObserver
2019-05-27 11:08:11.407 [ 1] 5 DefaultClient:AIPShutdown
2019-05-27 11:08:11.407 [ 1] 0 AudioInputProcessor:executeResetState
2019-05-27 11:08:11.407 [ 1] 5 DefaultClient:AudioPlayerShutdown
2019-05-27 11:08:11.407 [ 1] 5 ProgressTimer:stop
2019-05-27 11:08:11.408 [ 1] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2019-05-27 11:08:11.408 [ 1] 9 MediaPlayer:setObserverCalled:name=AudioMediaPlayer
2019-05-27 11:08:11.408 [ 12] 0 MediaPlayer:handleSetObserverCalled:name=AudioMediaPlayer
2019-05-27 11:08:11.408 [ 1] 5 ContextManager:setStateProvider:action=removedStateProvider,namespace=AudioPlayer,name=PlaybackState
2019-05-27 11:08:11.408 [ 1] 5 DefaultClient:ExternalMediaPlayerShutdown
2019-05-27 11:08:11.408 [ 1] 5 ContextManager:setStateProvider:action=removedStateProvider,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-05-27 11:08:11.408 [ 1] 5 ContextManager:setStateProvider:action=removedStateProvider,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-05-27 11:08:11.408 [ 1] 5 DefaultClient:SpeechSynthesizerShutdown
2019-05-27 11:08:11.408 [ 1] 9 SpeechSynthesizer:doShutdown
2019-05-27 11:08:11.408 [ 1] 9 MediaPlayer:setObserverCalled:name=SpeakMediaPlayer
2019-05-27 11:08:11.409 [ f] 0 MediaPlayer:handleSetObserverCalled:name=SpeakMediaPlayer
2019-05-27 11:08:11.409 [ 1] 5 DefaultClient:AlertsShutdown
2019-05-27 11:08:11.409 [ 1] 9 AlertsCapabilityAgent:releaseChannel
2019-05-27 11:08:11.410 [ 1] 5 DefaultClient:PlaybackControllerShutdown
2019-05-27 11:08:11.410 [ 1] 5 DefaultClient:MessageRouterShutdown.
2019-05-27 11:08:11.410 [ 1] 5 DefaultClient:ConnectionManagerShutdown.
2019-05-27 11:08:11.410 [ 1] 5 AVSConnectionManager:disable
2019-05-27 11:08:11.411 [ 1] 5 DefaultClient:CertifiedSenderShutdown.
2019-05-27 11:08:11.411 [ 1] 5 DefaultClient:AudioActivityTrackerShutdown.
2019-05-27 11:08:11.411 [ 1] 5 DefaultClient:VisualActivityTrackerShutdown.
2019-05-27 11:08:11.411 [ 1] 5 DefaultClient:PlaybackRouterShutdown.
2019-05-27 11:08:11.411 [ 1] 5 DefaultClient:NotificationsShutdown.
2019-05-27 11:08:11.411 [ 1] 5 NotificationsCapabilityAgent:doShutdown
2019-05-27 11:08:11.411 [ 1b] 5 NotificationsCapabilityAgent:executeShutdown:currentState=IDLE
2019-05-27 11:08:11.411 [ 1b] 5 NotificationsCapabilityAgent:executeSetState:previousState=IDLE,newState=SHUTDOWN
2019-05-27 11:08:11.412 [ 1] 5 ContextManager:setStateProvider:action=removedStateProvider,namespace=Notifications,name=IndicatorState
2019-05-27 11:08:11.412 [ 1] 5 DefaultClient:NotificationsRendererShutdown.
2019-05-27 11:08:11.412 [ 1] 5 NotificationsRenderer:doShutdown
2019-05-27 11:08:11.412 [ 1] 9 MediaPlayer:setObserverCalled:name=NotificationsMediaPlayer
2019-05-27 11:08:11.412 [ 1a] 0 MediaPlayer:handleSetObserverCalled:name=NotificationsMediaPlayer
2019-05-27 11:08:11.412 [ 1] 5 DefaultClient:UserInactivityMonitorShutdown.
2019-05-27 11:08:11.412 [ 1] 5 DefaultClient:DNDCapabilityAgentShutdown
2019-05-27 11:08:11.413 [ 1] 5 DefaultClient:EqualizerCapabilityAgentShutdown
2019-05-27 11:08:11.413 [ 1] 5 DefaultClient:CloseSettingStorage
2019-05-27 11:08:11.413 [ 1] 5 SQLiteDeviceSettingStorage:close
2019-05-27 11:08:11.414 [ 1] 5 SQLiteDeviceSettingStorage:close
2019-05-27 11:08:11.417 [ 1] 5 InteractionModel:~InteractionModelCapabilityAgent
2019-05-27 11:08:11.417 [ 1] 5 ProgressTimer:stop
2019-05-27 11:08:11.418 [ 24] 9 CertifiedSender:CertifiedSender worker thread done. Exiting mainloop.
2019-05-27 11:08:11.420 [ 1] 9 DirectiveProcessor:queueAllDirectivesForCancellationLocked
2019-05-27 11:08:11.422 [ 1] 5 InternetConnectionMonitor:stopMonitoring
2019-05-27 11:08:11.449 [ 6] 9 LibCurlHttpContentFetcher:bodyCallback:totalContentReceived=419,contentLength=419,currentContentReceived=419,remaining=0,totalBytesWritten=419
2019-05-27 11:08:11.449 [ 5] 9 LibCurlHttpContentFetcher:~LibCurlHttpContentFetcher
2019-05-27 11:08:11.449 [ 5] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_BODY,newState=BODY_DONE:State transition
2019-05-27 11:08:11.450 [ 6] 9 LibCurlHttpContentFetcher:transferThread::end
2019-05-27 11:08:11.452 [ 1] C SampleApplication:Failed to initialize SampleApplication
2019-05-27 11:08:11.453 [ 1] 5 CBLAuthDelegate:removeAuthObserver:observer=0x2318f74
2019-05-27 11:08:11.453 [ 1] 9 MediaPlayer:doShutdown:name=SpeakMediaPlayer
2019-05-27 11:08:11.453 [ 1] 9 MediaPlayer:doShutdown:name=AudioMediaPlayer
2019-05-27 11:08:11.453 [ 1] 9 MediaPlayer:doShutdown:name=AlertsMediaPlayer
2019-05-27 11:08:11.453 [ 1] 9 MediaPlayer:doShutdown:name=NotificationsMediaPlayer
2019-05-27 11:08:11.453 [ 1] 9 MediaPlayer:doShutdown:name=BluetoothMediaPlayer
2019-05-27 11:08:11.453 [ 1] 9 MediaPlayer:doShutdown:name=RingtoneMediaPlayer
2019-05-27 11:08:11.454 [ 1] 9 MediaPlayer:~MediaPlayer:name=RingtoneMediaPlayer
2019-05-27 11:08:11.456 [ 1] 9 MediaPlayer:resetPipeline:name=RingtoneMediaPlayer
2019-05-27 11:08:11.457 [ 1] 5 CBLAuthDelegate:stop
2019-05-27 11:08:11.504 [ 4] 5 HttpPost:doPostSucceeded:code=200
2019-05-27 11:08:11.504 [ 4] 5 CBLAuthDelegate:receiveCodePairResponse:code=200
2019-05-27 11:08:11.504 [ 4] 5 CBLAuthDelegate:mapHTTPStatusToError:code=200,error=SUCCESS
2019-05-27 11:08:11.504 [ 4] 5 CBLAuthDelegate:setAuthError:authError=SUCCESS
##################################

NOT YET AUTHORIZED

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

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

To authorize, browse to: 'https://amazon.com/us/code' and enter the code: D2EYAA

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

2019-05-27 11:08:11.505 [ 1] E SettingManager:removeObserverFailed:reason=invalidSetting,settingIndex=0
2019-05-27 11:08:11.512 [ 1] 5 SQLiteCBLAuthDelegateStorage:~SQLiteCBLAuthDelegateStorage
2019-05-27 11:08:11.513 [ 1] 5 SQLiteCBLAuthDelegateStorage:close
2019-05-27 11:08:11.514 [ 1] 9 MediaPlayer:~MediaPlayer:name=BluetoothMediaPlayer
2019-05-27 11:08:11.514 [ 1] 9 MediaPlayer:resetPipeline:name=BluetoothMediaPlayer
2019-05-27 11:08:11.515 [ 1] 9 MediaPlayer:~MediaPlayer:name=NotificationsMediaPlayer
2019-05-27 11:08:11.515 [ 1] 9 MediaPlayer:resetPipeline:name=NotificationsMediaPlayer
2019-05-27 11:08:11.515 [ 1] 9 MediaPlayer:~MediaPlayer:name=AlertsMediaPlayer
2019-05-27 11:08:11.516 [ 1] 9 MediaPlayer:resetPipeline:name=AlertsMediaPlayer
2019-05-27 11:08:11.516 [ 1] 9 MediaPlayer:~MediaPlayer:name=AudioMediaPlayer
2019-05-27 11:08:11.517 [ 1] 9 MediaPlayer:resetPipeline:name=AudioMediaPlayer
2019-05-27 11:08:11.517 [ 1] 9 MediaPlayer:~MediaPlayer:name=SpeakMediaPlayer
2019-05-27 11:08:11.518 [ 1] 9 MediaPlayer:resetPipeline:name=SpeakMediaPlayer
Failed to create to SampleApplication!

Provide the steps to reproduce the issue, if applicable:

Tell us about your environment:

Raspberry pi/ Raspian Stretch with Desktop

What version of the AVS Device SDK are you using?

  <x.y.z>

Tell us what hardware you're using:

  • Desktop / Laptop
  • Raspberry Pi
  • Other - tell us more:

Tell us about your OS (Type & version):

  • Linux
  • MacOS
  • Raspbian Stretch
  • Raspbian Jessy
  • Other - tell us more:
@mvelegon-amzn
Copy link
Contributor

Hi @stevesherri thanks for reaching out. From the above log attached, I see that PortAudio has not been initialized correctly. Here are the logs indicating an issue:

Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923

Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923

Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923

Expression 'paInvalidSampleRate' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2043

Expression 'PaAlsaStreamComponent_InitialConfigure( &self->capture, inParams, self->primeBuffers, hwParamsCapture, &realSr )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2714

Expression 'PaAlsaStream_Configure( stream, inputParameters, outputParameters, sampleRate, framesPerBuffer, &inputLatency, &outputLatency, &hostBufferSizeMode )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2838

2019-05-27 11:08:11.397 [ 1] C PortAudioMicrophoneWrapper:Failed to open PortAudio default stream:errorCode=-9997

2019-05-27 11:08:11.398 [ 1] C PortAudioMicrophoneWrapper:Failed to initialize PortAudioMicrophoneWrapper

2019-05-27 11:08:11.398 [ 1] C SampleApplication:Failed to create PortAudioMicrophoneWrapper!

You mentioned you were able to record audio, could you let us know if you followed the "Test the microphone" section in this wiki: https://github.com/alexa/avs-device-sdk/wiki/Raspberry-Pi-Quick-Start-Guide ? I want to make sure that the .asoundrc file has been updated as mentioned on the wiki. Please let us know if this fixes your issue.

@gitbenjazz
Copy link

gitbenjazz commented May 28, 2019

Hello
I have the exact same issue and even with a successfull test of recording by testing the microphone (https://github.com/alexa/avs-device-sdk/wiki/Raspberry-Pi-Quick-Start-Guide) and with .asoundrc file updated

@mvelegon-amzn
Copy link
Contributor

@gitbenjazz could you send add your full DEBUG9 log here?

Also, please refer to the following issues and let me know if it fixes the issue: #439 &#943 . Additionally, error code -9997 refers to invalid sample rate and I think it should be fixed by changing the .asoundrc file. Please ensure you run the sample app after the file is modified and in the same shell.

@gitbenjazz
Copy link

Thanks to look at this, i can't figure it out

Please find my debug
019-05-29 03:47:01.858 [ 1] I sdkVersion: 1.13.0
configFile /home/build/Integration/AlexaClientSDKConfig.json
Running app with log level: DEBUG9
2019-05-29 03:47:01.879 [ 1] 0 ConfigurationNode:initializeSuccess
2019-05-29 03:47:01.896 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating Equalizer configuration
2019-05-29 03:47:01.896 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating default Equalizer state
2019-05-29 03:47:01.897 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating Equalizer configuration
2019-05-29 03:47:01.897 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating default Equalizer state
2019-05-29 03:47:01.902 [ 1] 9 MediaPlayer:createCalled:name=SpeakMediaPlayer
2019-05-29 03:47:02.019 [ 1] 9 MediaPlayer:noOutputConversion:name=SpeakMediaPlayer
2019-05-29 03:47:02.022 [ 1] 9 MediaPlayer:createCalled:name=AudioMediaPlayer
2019-05-29 03:47:02.025 [ 1] 9 MediaPlayer:noOutputConversion:name=AudioMediaPlayer
2019-05-29 03:47:02.028 [ 1] 9 MediaPlayer:createCalled:name=NotificationsMediaPlayer
2019-05-29 03:47:02.029 [ 1] 9 MediaPlayer:noOutputConversion:name=NotificationsMediaPlayer
2019-05-29 03:47:02.032 [ 1] 9 MediaPlayer:createCalled:name=BluetoothMediaPlayer
2019-05-29 03:47:02.033 [ 1] 9 MediaPlayer:noOutputConversion:name=BluetoothMediaPlayer
2019-05-29 03:47:02.038 [ 1] 9 MediaPlayer:createCalled:name=RingtoneMediaPlayer
2019-05-29 03:47:02.039 [ 1] 9 MediaPlayer:noOutputConversion:name=RingtoneMediaPlayer
2019-05-29 03:47:02.041 [ 1] 9 MediaPlayer:createCalled:name=AlertsMediaPlayer
2019-05-29 03:47:02.042 [ 1] 9 MediaPlayer:noOutputConversion:name=AlertsMediaPlayer
2019-05-29 03:47:02.046 [ 1] 5 SQLiteDeviceSettingStorage:create
2019-05-29 03:47:02.047 [ 1] 5 SQLiteBluetoothStorage:create
2019-05-29 03:47:02.048 [ 1] 5 CBLAuthDelegate:create
2019-05-29 03:47:02.050 [ 1] 5 CBLAuthDelegate:CBLAuthDelegate
2019-05-29 03:47:02.051 [ 1] 5 CBLAuthDelegate:init
2019-05-29 03:47:02.052 [ 1] 5 CBLAuthDelegateConfiguration:create
2019-05-29 03:47:02.052 [ 1] 5 CBLAuthDelegateConfiguration:init
2019-05-29 03:47:02.053 [ 1] 5 CBLAuthDelegateConfiguration:initScopeData
2019-05-29 03:47:02.053 [ 1] 9 CBLAuthDelegateConfiguration:initScopeDataSucceeded
2019-05-29 03:47:02.054 [ 1] 5 SQLiteCBLAuthDelegateStorage:open
2019-05-29 03:47:02.059 [ 1] 5 CBLAuthDelegate:addAuthObserver:observer=0x2263964
2019-05-29 03:47:02.059 [ 4] 5 CBLAuthDelegate:handleAuthorizationFlow
2019-05-29 03:47:02.061 [ 4] 5 CBLAuthDelegate:handleStarting
2019-05-29 03:47:02.061 [ 1] 5 CBLAuthDelegate:addAuthObserver:observer=0x224ec34
2019-05-29 03:47:02.061 [ 4] 5 SQLiteCBLAuthDelegateStorage:getRefreshToken
2019-05-29 03:47:02.062 [ 4] 0 SQLiteCBLAuthDelegateStorage:getRefreshTokenFailed:reason=stepResultWasNotRow
2019-05-29 03:47:02.062 [ 4] 0 CBLAuthDelegate:getRefreshTokenFailed
2019-05-29 03:47:02.063 [ 4] 5 CBLAuthDelegate:handleRequestingCodePair
2019-05-29 03:47:02.063 [ 4] 5 CBLAuthDelegate:requestCodePair
2019-05-29 03:47:02.063 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x224ec38
2019-05-29 03:47:02.064 [ 1] 5 InternetConnectionMonitor:startMonitoring
2019-05-29 03:47:02.072 [ 5] 5 InternetConnectionMonitor:testConnection
2019-05-29 03:47:02.072 [ 5] 9 HTTPContentFetcherFactory:create::Creating a new http content fetcher
2019-05-29 03:47:02.073 [ 1] 5 SQLiteDeviceSettingStorage:open
2019-05-29 03:47:02.074 [ 5] 9 LibCurlHttpContentFetcher:stateTransition:oldState=INITIALIZED,newState=FETCHING_HEADER:State transition
2019-05-29 03:47:02.076 [ 6] 9 LibCurlHttpContentFetcher:transferThread::start
2019-05-29 03:47:02.078 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.079 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.079 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.079 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.079 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.079 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.079 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.079 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.080 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.081 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.082 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.083 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.084 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.085 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.086 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.087 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.087 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.088 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.088 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.088 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.088 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.089 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 1] 5 AVSConnectionManager:create::Subscribing to InternetConnectionMonitor Callbacks
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.090 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 1] 5 AVSConnectionManager:onConnectionStatusChanged:connected=false
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.091 [ 1] 5 AVSConnectionManager:reconnect:isEnabled=false
2019-05-29 03:47:02.091 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.092 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.092 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.092 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.092 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.092 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.092 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.092 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.092 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.093 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.093 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.093 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.093 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.093 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.093 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.094 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.095 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.096 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.096 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.096 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.096 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.097 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.098 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.099 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.100 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ a] 9 DirectiveProcessor:processingLoop
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.101 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.102 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.111 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.111 [ 1] 9 MediaPlayer:setObserverCalled:name=SpeakMediaPlayer
2019-05-29 03:47:02.112 [ f] 0 MediaPlayer:handleSetObserverCalled:name=SpeakMediaPlayer
2019-05-29 03:47:02.113 [ 1] 9 SpeechSynthesizer:addObserver:observer=0x2269b2c
2019-05-29 03:47:02.114 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.115 [ 1] 9 PlaybackRouter:create::called
2019-05-29 03:47:02.116 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.116 [ 1] 9 MediaPlayer:setObserverCalled:name=AudioMediaPlayer
2019-05-29 03:47:02.117 [ 12] 0 MediaPlayer:handleSetObserverCalled:name=AudioMediaPlayer
2019-05-29 03:47:02.118 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=SpeakMediaPlayer
2019-05-29 03:47:02.118 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=AudioMediaPlayer
2019-05-29 03:47:02.118 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=AlertsMediaPlayer
2019-05-29 03:47:02.118 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=NotificationsMediaPlayer
2019-05-29 03:47:02.118 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=BluetoothMediaPlayer
2019-05-29 03:47:02.118 [ 1] 9 MediaPlayer:getSpeakerTypeCalled:name=RingtoneMediaPlayer
2019-05-29 03:47:02.119 [ 1] 0 SpeakerManager:mapCreated:numSpeakerVolume=4,numAlertsVolume=2
2019-05-29 03:47:02.120 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=SpeakMediaPlayer
2019-05-29 03:47:02.120 [ f] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=SpeakMediaPlayer
2019-05-29 03:47:02.120 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AudioMediaPlayer
2019-05-29 03:47:02.121 [ 12] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AudioMediaPlayer
2019-05-29 03:47:02.121 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=BluetoothMediaPlayer
2019-05-29 03:47:02.121 [ 14] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=BluetoothMediaPlayer
2019-05-29 03:47:02.121 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=RingtoneMediaPlayer
2019-05-29 03:47:02.121 [ 15] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=RingtoneMediaPlayer
2019-05-29 03:47:02.122 [ 1] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2019-05-29 03:47:02.122 [ 1] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2019-05-29 03:47:02.122 [ 1] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SPEAKER_VOLUME
2019-05-29 03:47:02.123 [ 1] 5 Renderer:resetSourceId
2019-05-29 03:47:02.123 [ 1] 9 MediaPlayer:setObserverCalled:name=AlertsMediaPlayer
2019-05-29 03:47:02.123 [ 17] 0 MediaPlayer:handleSetObserverCalled:name=AlertsMediaPlayer
2019-05-29 03:47:02.127 [ 1] 9 AlertScheduler:setTimerForNextAlertLocked
2019-05-29 03:47:02.128 [ 1] 9 AlertScheduler:executeScheduleNextAlertForRendering::no work to do.
2019-05-29 03:47:02.128 [ 1] 9 SpeakerManager:getSpeakerSettingsCalled
2019-05-29 03:47:02.129 [ 13] 9 SpeakerManager:executeGetSpeakerSettingsCalled
2019-05-29 03:47:02.129 [ 13] 9 MediaPlayer:getSpeakerSettingsCalled:name=AlertsMediaPlayer
2019-05-29 03:47:02.129 [ 17] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AlertsMediaPlayer
2019-05-29 03:47:02.130 [ 13] 9 MediaPlayer:getSpeakerSettingsCalled:name=NotificationsMediaPlayer
2019-05-29 03:47:02.130 [ 1a] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=NotificationsMediaPlayer
2019-05-29 03:47:02.130 [ 13] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2019-05-29 03:47:02.130 [ 13] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2019-05-29 03:47:02.132 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled
2019-05-29 03:47:02.133 [ 19] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2019-05-29 03:47:02.138 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x2271be4
2019-05-29 03:47:02.140 [ 1] 5 NotificationsRenderer:create
2019-05-29 03:47:02.141 [ 1] 9 MediaPlayer:setObserverCalled:name=NotificationsMediaPlayer
2019-05-29 03:47:02.141 [ 1a] 0 MediaPlayer:handleSetObserverCalled:name=NotificationsMediaPlayer
2019-05-29 03:47:02.144 [ 1] 5 NotificationsCapabilityAgent:init
2019-05-29 03:47:02.144 [ 1] 5 NotificationsRenderer:addObserver
2019-05-29 03:47:02.148 [ 1b] 5 NotificationsCapabilityAgent:executeInit
2019-05-29 03:47:02.148 [ 1] 5 InteractionModel:InteractionModelCapabilityAgent
2019-05-29 03:47:02.149 [ 1b] 5 NotificationsCapabilityAgent:notifyObservers:indicatorState=0
2019-05-29 03:47:02.149 [ 1b] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=false,stateRequestToken=0
2019-05-29 03:47:02.151 [ 1b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-05-29 03:47:02.155 [ 1] 0 ExternalMediaPlayer:createAdapters
2019-05-29 03:47:02.157 [ 1] 1 AudioPlayer:addObserver
2019-05-29 03:47:02.158 [ 7] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2019-05-29 03:47:02.159 [ 1] 5 DNDSettingProtocol:create:settingName=enabled
2019-05-29 03:47:02.160 [ 1] 5 DNDSettingProtocol:restoreValue:setting=Alexa.DoNotDisturb::enabled
2019-05-29 03:47:02.160 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=Alexa.DoNotDisturb::enabled
2019-05-29 03:47:02.161 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:value=false
2019-05-29 03:47:02.162 [ 1] I Setting:handleSetValue:value=false
2019-05-29 03:47:02.170 [ 1] 5 DefaultClient:bluetoothCapabilityAgentDisabled:reason=nullBluetoothDeviceManager
2019-05-29 03:47:02.173 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x226f7e8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-05-29 03:47:02.174 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x22709c8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.174 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x22709c8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.174 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x22709c8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=AdjustSeekPosition,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=SetSeekPosition,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableShuffle,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableShuffle,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeat,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeatOne,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Favorite,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=FastForward,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Previous,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=StartOver,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.175 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Next,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableRepeat,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Rewind,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Stop,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Pause,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Play,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Logout,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Login,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Unfavorite,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Play,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetEndOfSpeechOffset,handler=0x226ede8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.176 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x226ede8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-05-29 03:47:02.177 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x226ede8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.177 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=AdjustVolume,handler=0x2271b78,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.177 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x2271b78,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.177 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlerts,handler=0x2271b78,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.177 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x2271b78,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.177 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetVolume,handler=0x2271b78,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.177 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetEndpoint,handler=0x2280b08,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.177 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x226eb44,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.178 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x2271170,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.178 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x2271170,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.178 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x2271170,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.178 [ 1] 5 TemplateRuntime:getConfiguration
2019-05-29 03:47:02.178 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x2280170,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-05-29 03:47:02.178 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x2280170,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-05-29 03:47:02.179 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=ClearIndicator,handler=0x2275a1c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.179 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=SetIndicator,handler=0x2275a1c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.180 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=InteractionModel,name=NewDialogRequest,handler=0x227a958,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.180 [ 1] 5 EqualizerController:getConfiguration
2019-05-29 03:47:02.181 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=AdjustBands,handler=0x228264c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.181 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=SetMode,handler=0x228264c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.181 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=ResetBands,handler=0x228264c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.181 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=SetBands,handler=0x228264c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.181 [ 1] 5 DoNotDisturbCapabilityAgent:getConfiguration
2019-05-29 03:47:02.181 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.DoNotDisturb,name=SetDoNotDisturb,handler=0x2280e78,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.186 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled
2019-05-29 03:47:02.186 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x224ec44
2019-05-29 03:47:02.187 [ 1] 5 NotificationsCapabilityAgent:addObserver
2019-05-29 03:47:02.187 [ 1] 5 DefaultClient:addBluetoothDeviceObserver::bluetooth is disabled, not adding observer
2019-05-29 03:47:02.188 [ 1] 5 TemplateRuntime:addObserver
2019-05-29 03:47:02.188 [ 20] 5 TemplateRuntime:addObserverInExecutor
#################################################

NOTIFICATION INDICATOR STATE: OFF

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

2019-05-29 03:47:02.194 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'alsa_snd_pcm_hw_params_set_period_size_near( pcm, hwParams, &alsaPeriodFrames, &dir )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 923
Expression 'paInvalidSampleRate' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2043
Expression 'PaAlsaStreamComponent_InitialConfigure( &self->capture, inParams, self->primeBuffers, hwParamsCapture, &realSr )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2714
Expression 'PaAlsaStream_Configure( stream, inputParameters, outputParameters, sampleRate, framesPerBuffer, &inputLatency, &outputLatency, &hostBufferSizeMode )' failed in 'src/hostapi/alsa/pa_linux_alsa.c', line: 2838
2019-05-29 03:47:02.246 [ 1] C PortAudioMicrophoneWrapper:Failed to open PortAudio default stream:errorCode=-9997
2019-05-29 03:47:02.246 [ 1] C PortAudioMicrophoneWrapper:Failed to initialize PortAudioMicrophoneWrapper
2019-05-29 03:47:02.247 [ 1] C SampleApplication:Failed to create PortAudioMicrophoneWrapper!
2019-05-29 03:47:02.250 [ 1] 5 DefaultClient:DirectiveSequencerShutdown
2019-05-29 03:47:02.250 [ 1] 9 DirectiveSequencer:doShutdown
2019-05-29 03:47:02.251 [ 1] 9 DirectiveProcessor:queueAllDirectivesForCancellationLocked
2019-05-29 03:47:02.251 [ a] 9 DirectiveProcessor:processCancelingQueueLocked:size=0
2019-05-29 03:47:02.252 [ 1] 5 DoNotDisturbCapabilityAgent:getConfiguration
2019-05-29 03:47:02.253 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.DoNotDisturb,name=SetDoNotDisturb,handler=0x2280e78,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.SeekController,name=AdjustSeekPosition,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.SeekController,name=SetSeekPosition,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=DisableShuffle,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=EnableShuffle,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=EnableRepeat,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=EnableRepeatOne,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.FavoritesController,name=Favorite,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=FastForward,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Previous,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=StartOver,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Next,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.254 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaylistController,name=DisableRepeat,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Rewind,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Stop,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Pause,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.PlaybackController,name=Play,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=ExternalMediaPlayer,name=Logout,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=ExternalMediaPlayer,name=Login,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alexa.FavoritesController,name=Unfavorite,handler=0x227e1d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=ExternalMediaPlayer,name=Play,handler=0x227e1d0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.255 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=ResetUserInactivity,handler=0x226eb44,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 5 TemplateRuntime:getConfiguration
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x2280170,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=TemplateRuntime,name=RenderTemplate,handler=0x2280170,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 5 EqualizerController:getConfiguration
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=EqualizerController,name=AdjustBands,handler=0x228264c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=EqualizerController,name=SetMode,handler=0x228264c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=EqualizerController,name=ResetBands,handler=0x228264c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=EqualizerController,name=SetBands,handler=0x228264c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=AdjustVolume,handler=0x2271b78,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=SetAlert,handler=0x2271b78,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.256 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=DeleteAlerts,handler=0x2271b78,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=DeleteAlert,handler=0x2271b78,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Alerts,name=SetVolume,handler=0x2271b78,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=ClearQueue,handler=0x22709c8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Stop,handler=0x22709c8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=AudioPlayer,name=Play,handler=0x22709c8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechSynthesizer,name=Speak,handler=0x226f7e8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=SetEndOfSpeechOffset,handler=0x226ede8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x226ede8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=SpeechRecognizer,name=StopCapture,handler=0x226ede8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=AdjustVolume,handler=0x2271170,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.257 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetMute,handler=0x2271170,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.258 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Speaker,name=SetVolume,handler=0x2271170,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-05-29 03:47:02.258 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=System,name=SetEndpoint,handler=0x2280b08,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.258 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Notifications,name=ClearIndicator,handler=0x2275a1c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.258 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=Notifications,name=SetIndicator,handler=0x2275a1c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.258 [ 1] 9 DirectiveRouter:removeDirectiveHandlers:action=removed,namespace=InteractionModel,name=NewDialogRequest,handler=0x227a958,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-05-29 03:47:02.258 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2280e78
2019-05-29 03:47:02.258 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x227e1d0
2019-05-29 03:47:02.259 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x226eb44
2019-05-29 03:47:02.259 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2280170
2019-05-29 03:47:02.259 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x228264c
2019-05-29 03:47:02.259 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2271b78
2019-05-29 03:47:02.259 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x22709c8
2019-05-29 03:47:02.259 [ 1] 0 AudioPlayer:onDeregistered
2019-05-29 03:47:02.259 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x226f7e8
2019-05-29 03:47:02.259 [ 1] 9 SpeechSynthesizer:onDeregistered
2019-05-29 03:47:02.259 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x226ede8
2019-05-29 03:47:02.259 [ 11] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2019-05-29 03:47:02.259 [ d] 0 AudioInputProcessor:executeResetState
2019-05-29 03:47:02.260 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2271170
2019-05-29 03:47:02.260 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2280b08
2019-05-29 03:47:02.260 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x2275a1c
2019-05-29 03:47:02.260 [ 1] 9 DirectiveRouter:onDeregisteredCalled:handler=0x227a958
2019-05-29 03:47:02.260 [ 1] 5 DefaultClient:SpeakerManagerShutdown
2019-05-29 03:47:02.261 [ 1] 5 DefaultClient:TemplateRuntimeShutdown
2019-05-29 03:47:02.262 [ 1] 1 AudioPlayer:removeObserver
2019-05-29 03:47:02.262 [ 1] 5 DefaultClient:AIPShutdown
2019-05-29 03:47:02.262 [ 1] 0 AudioInputProcessor:executeResetState
2019-05-29 03:47:02.263 [ 1] 5 DefaultClient:AudioPlayerShutdown
2019-05-29 03:47:02.263 [ 1] 5 ProgressTimer:stop
2019-05-29 03:47:02.263 [ 1] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=IDLE
2019-05-29 03:47:02.263 [ 1] 9 MediaPlayer:setObserverCalled:name=AudioMediaPlayer
2019-05-29 03:47:02.263 [ 12] 0 MediaPlayer:handleSetObserverCalled:name=AudioMediaPlayer
2019-05-29 03:47:02.264 [ 1] 5 ContextManager:setStateProvider:action=removedStateProvider,namespace=AudioPlayer,name=PlaybackState
2019-05-29 03:47:02.264 [ 1] 5 DefaultClient:ExternalMediaPlayerShutdown
2019-05-29 03:47:02.264 [ 1] 5 ContextManager:setStateProvider:action=removedStateProvider,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-05-29 03:47:02.264 [ 1] 5 ContextManager:setStateProvider:action=removedStateProvider,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-05-29 03:47:02.264 [ 1] 5 DefaultClient:SpeechSynthesizerShutdown
2019-05-29 03:47:02.264 [ 1] 9 SpeechSynthesizer:doShutdown
2019-05-29 03:47:02.264 [ 1] 9 MediaPlayer:setObserverCalled:name=SpeakMediaPlayer
2019-05-29 03:47:02.264 [ f] 0 MediaPlayer:handleSetObserverCalled:name=SpeakMediaPlayer
2019-05-29 03:47:02.265 [ 1] 5 DefaultClient:AlertsShutdown
2019-05-29 03:47:02.265 [ 1] 9 AlertsCapabilityAgent:releaseChannel
2019-05-29 03:47:02.267 [ 1] 5 DefaultClient:PlaybackControllerShutdown
2019-05-29 03:47:02.268 [ 1] 5 DefaultClient:MessageRouterShutdown.
2019-05-29 03:47:02.268 [ 1] 5 DefaultClient:ConnectionManagerShutdown.
2019-05-29 03:47:02.268 [ 1] 5 AVSConnectionManager:disable
2019-05-29 03:47:02.269 [ 1] 5 DefaultClient:CertifiedSenderShutdown.
2019-05-29 03:47:02.269 [ 1] 5 DefaultClient:AudioActivityTrackerShutdown.
2019-05-29 03:47:02.269 [ 1] 5 DefaultClient:VisualActivityTrackerShutdown.
2019-05-29 03:47:02.269 [ 1] 5 DefaultClient:PlaybackRouterShutdown.
2019-05-29 03:47:02.269 [ 1] 5 DefaultClient:NotificationsShutdown.
2019-05-29 03:47:02.269 [ 1] 5 NotificationsCapabilityAgent:doShutdown
2019-05-29 03:47:02.270 [ 1b] 5 NotificationsCapabilityAgent:executeShutdown:currentState=IDLE
2019-05-29 03:47:02.270 [ 1b] 5 NotificationsCapabilityAgent:executeSetState:previousState=IDLE,newState=SHUTDOWN
2019-05-29 03:47:02.270 [ 1] 5 ContextManager:setStateProvider:action=removedStateProvider,namespace=Notifications,name=IndicatorState
2019-05-29 03:47:02.271 [ 1] 5 DefaultClient:NotificationsRendererShutdown.
2019-05-29 03:47:02.271 [ 1] 5 NotificationsRenderer:doShutdown
2019-05-29 03:47:02.271 [ 1] 9 MediaPlayer:setObserverCalled:name=NotificationsMediaPlayer
2019-05-29 03:47:02.271 [ 1a] 0 MediaPlayer:handleSetObserverCalled:name=NotificationsMediaPlayer
2019-05-29 03:47:02.272 [ 1] 5 DefaultClient:UserInactivityMonitorShutdown.
2019-05-29 03:47:02.272 [ 1] 5 DefaultClient:DNDCapabilityAgentShutdown
2019-05-29 03:47:02.272 [ 1] 5 DefaultClient:EqualizerCapabilityAgentShutdown
2019-05-29 03:47:02.273 [ 1] 5 DefaultClient:CloseSettingStorage
2019-05-29 03:47:02.273 [ 1] 5 SQLiteDeviceSettingStorage:close
2019-05-29 03:47:02.274 [ 1] 5 SQLiteDeviceSettingStorage:close
2019-05-29 03:47:02.288 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.289 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.289 [ 1] 5 InteractionModel:~InteractionModelCapabilityAgent
2019-05-29 03:47:02.289 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.289 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.289 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.289 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.290 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.290 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.290 [ 1] 5 ProgressTimer:stop
2019-05-29 03:47:02.290 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.290 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.291 [ 6] 9 LibCurlHttpContentFetcher:headerCallback:type=content-length,length=419
2019-05-29 03:47:02.291 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.291 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.291 [ 6] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-05-29 03:47:02.291 [ 6] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-05-29 03:47:02.291 [ 6] 9 LibCurlHttpContentFetcher:bodyCallback::End of header found.
2019-05-29 03:47:02.291 [ 24] 9 CertifiedSender:CertifiedSender worker thread done. Exiting mainloop.
2019-05-29 03:47:02.291 [ 6] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_HEADER,newState=HEADER_DONE:State transition
2019-05-29 03:47:02.292 [ 5] 9 InternetConnectionMonitor:testConnection:contentLength=419
2019-05-29 03:47:02.292 [ 5] 9 LibCurlHttpContentFetcher:stateTransition:oldState=HEADER_DONE,newState=FETCHING_BODY:State transition
2019-05-29 03:47:02.300 [ 1] 9 DirectiveProcessor:queueAllDirectivesForCancellationLocked
2019-05-29 03:47:02.302 [ 1] 5 InternetConnectionMonitor:stopMonitoring
2019-05-29 03:47:02.392 [ 6] 9 LibCurlHttpContentFetcher:bodyCallback:totalContentReceived=419,contentLength=419,currentContentReceived=419,remaining=0,totalBytesWritten=419
2019-05-29 03:47:02.392 [ 5] 9 LibCurlHttpContentFetcher:~LibCurlHttpContentFetcher
2019-05-29 03:47:02.392 [ 5] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_BODY,newState=BODY_DONE:State transition
2019-05-29 03:47:02.393 [ 6] 9 LibCurlHttpContentFetcher:transferThread::end
2019-05-29 03:47:02.396 [ 1] C SampleApplication:Failed to initialize SampleApplication
2019-05-29 03:47:02.396 [ 1] 5 CBLAuthDelegate:removeAuthObserver:observer=0x2263964
2019-05-29 03:47:02.396 [ 1] 9 MediaPlayer:doShutdown:name=SpeakMediaPlayer
2019-05-29 03:47:02.396 [ 1] 9 MediaPlayer:doShutdown:name=AudioMediaPlayer
2019-05-29 03:47:02.396 [ 1] 9 MediaPlayer:doShutdown:name=AlertsMediaPlayer
2019-05-29 03:47:02.396 [ 1] 9 MediaPlayer:doShutdown:name=NotificationsMediaPlayer
2019-05-29 03:47:02.396 [ 1] 9 MediaPlayer:doShutdown:name=BluetoothMediaPlayer
2019-05-29 03:47:02.396 [ 1] 9 MediaPlayer:doShutdown:name=RingtoneMediaPlayer
2019-05-29 03:47:02.398 [ 1] 9 MediaPlayer:~MediaPlayer:name=RingtoneMediaPlayer
2019-05-29 03:47:02.399 [ 1] 9 MediaPlayer:resetPipeline:name=RingtoneMediaPlayer
2019-05-29 03:47:02.400 [ 1] 5 CBLAuthDelegate:stop
2019-05-29 03:47:02.429 [ 4] E HttpPost:doPostFailed:reason=curl_easy_performFailed,result=35,error=SSL connect error
2019-05-29 03:47:02.436 [ 4] 5 CBLAuthDelegate:receiveCodePairResponse:code=0
2019-05-29 03:47:02.437 [ 4] 5 CBLAuthDelegate:mapHTTPStatusToError:code=0,error=UNKNOWN_ERROR
2019-05-29 03:47:02.437 [ 4] E CBLAuthDelegate:parseLWAResponseFailed:reason=parseJsonFailed,position=0,error=The document is empty.
2019-05-29 03:47:02.437 [ 4] 5 CBLAuthDelegate:setAuthError:authError=UNKNOWN_ERROR
2019-05-29 03:47:02.437 [ 4] 0 CBLAuthDelegate:receiveCodePairResponseFailed:result=UNKNOWN_ERROR
2019-05-29 03:47:02.438 [ 1] E SettingManager:removeObserverFailed:reason=invalidSetting,settingIndex=0
2019-05-29 03:47:02.440 [ 1] 5 SQLiteCBLAuthDelegateStorage:~SQLiteCBLAuthDelegateStorage
2019-05-29 03:47:02.441 [ 1] 5 SQLiteCBLAuthDelegateStorage:close
2019-05-29 03:47:02.442 [ 1] 9 MediaPlayer:~MediaPlayer:name=BluetoothMediaPlayer
2019-05-29 03:47:02.443 [ 1] 9 MediaPlayer:resetPipeline:name=BluetoothMediaPlayer
2019-05-29 03:47:02.443 [ 1] 9 MediaPlayer:~MediaPlayer:name=NotificationsMediaPlayer
2019-05-29 03:47:02.444 [ 1] 9 MediaPlayer:resetPipeline:name=NotificationsMediaPlayer
2019-05-29 03:47:02.444 [ 1] 9 MediaPlayer:~MediaPlayer:name=AlertsMediaPlayer
2019-05-29 03:47:02.445 [ 1] 9 MediaPlayer:resetPipeline:name=AlertsMediaPlayer
2019-05-29 03:47:02.445 [ 1] 9 MediaPlayer:~MediaPlayer:name=AudioMediaPlayer
2019-05-29 03:47:02.447 [ 1] 9 MediaPlayer:resetPipeline:name=AudioMediaPlayer
2019-05-29 03:47:02.447 [ 1] 9 MediaPlayer:~MediaPlayer:name=SpeakMediaPlayer
2019-05-29 03:47:02.448 [ 1] 9 MediaPlayer:resetPipeline:name=SpeakMediaPlayer
Failed to create to SampleApplication!

and my asoundrc file

pi@caramel:~ $ more .asoundrc
pcm.dsnooper {
type dsnoop
ipc_key 816357492
ipc_key_add_uid 0
ipc_perm 0666
slave {
pcm "hw:1,0"
channels 1
}
}
pcm.dmixer {
type dmix
ipc_key 1024
slave {
pcm "hw:1,0"
period_time 0
period_size 1024
buffer_size 8192
rate 44100
}

}

pcm.!default {
type asym
playback.pcm {
type plug
slave.pcm "dmixer"
}
capture.pcm {
type plug
slave.pcm "dsnooper"
}
}

@gitbenjazz
Copy link

Some links for this issue has reported a check if the USB microphone is plugged, well ..sometimes it's as silly as that . I followed this test and it's successfull : http://wiki.sunfounder.cc/index.php?title=To_use_USB_mini_microphone_on_Raspbian...any idea ?

@moryoav
Copy link

moryoav commented May 30, 2019

I'm having the exact same problem (on a Raspberry Pi 3B+), a system that worked in the past and then suddenly stopped working a few days ago. I think one of the sudo apt-get upgrade I may have done perhaps broke something here. I'm getting the exact same log with the same portaudio errors.

Edit1: Maybe this has something to do with the fact that arecord -l now shows the USB microphone as card 2, I thought it used to be card 1 in the past (I changed pi.sh and also the asoundrc file to "hw:2,0", it still doesn't work, so maybe this is not related. Also "arecord" and "aplay" both work fine.

Edit2: I removed HDMI audio in boot\config.txt, so now the microphone is again Card 1. Removed all the folders and files and rebuilt the whole thing from scratch according to the guides. Problem persists. Same log file.

@mvelegon-amzn
Copy link
Contributor

Hi @moryoav @gitbenjazz @stevesherri it is possible you are seeing the issue mentioned here: #879 . If you check the last few comments, it is possible that you are modifying the .asoundrc file logged-in as the user, but when running the sample app you are running it using the sudo bash startupsample.sh . You could try modifying the .asoundrc file logged in as root and see if it fixes the issue.

Please get back to us to let us know if that fixed the issue. Thanks.

@moryoav
Copy link

moryoav commented Jun 1, 2019

Hi @moryoav @gitbenjazz @stevesherri it is possible you are seeing the issue mentioned here: #879 . If you check the last few comments, it is possible that you are modifying the .asoundrc file logged-in as the user, but when running the sample app you are running it using the sudo bash startupsample.sh . You could try modifying the .asoundrc file logged in as root and see if it fixes the issue.

Please get back to us to let us know if that fixed the issue. Thanks.

This did not help. I can confirm this problem on 2 unrelated PIs. Both probably stopped working after a apt-get upgrade. This seems like the latest avs release is broken on latest PI software.

@mrGrab
Copy link

mrGrab commented Jun 1, 2019

Try:
export PA_ALSA_PLUGHW=1; sudo bash startupsample.sh
It should helps.

@gitbenjazz
Copy link

Try:
export PA_ALSA_PLUGHW=1; sudo bash startupsample.sh
It should helps.

You might want to say : export PA_ALSA_PLUGHW=1; sudo bash startsample.sh
Anyway i tried but no luck

@gitbenjazz
Copy link

Hi @moryoav @gitbenjazz @stevesherri it is possible you are seeing the issue mentioned here: #879 . If you check the last few comments, it is possible that you are modifying the .asoundrc file logged-in as the user, but when running the sample app you are running it using the sudo bash startupsample.sh . You could try modifying the .asoundrc file logged in as root and see if it fixes the issue.
Please get back to us to let us know if that fixed the issue. Thanks.

This did not help. I can confirm this problem on 2 unrelated PIs. Both probably stopped working after a apt-get upgrade. This seems like the latest avs release is broken on latest PI software.

Maybe but in this case we have no option than wait , or is it a way to report it ?

I'm doing a project with a Gopigo/raspberry and alexa for kids, do you see a workaround for me ?

@mvelegon-amzn
Copy link
Contributor

Hi @gitbenjazz , @moryoav We will try to reproduce this issue locally in order to find a solution for it.
Could you please let us know the version of raspbian you are using?

@moryoav
Copy link

moryoav commented Jun 2, 2019

export PA_ALSA_PLUGHW=1; sudo bash startsample.sh did not work as well.
Here's my information (1x RaspberryPi 3B and 1x RaspberryPI 3B+, same version on both, different USB microphones, both worked already and then stopped working one day).

pi@alexapi:~ $ uname -a

Linux alexapi 4.19.42-v7+ #1219 SMP Tue May 14 21:20:58 BST 2019 armv7l GNU/Linux

pi@alexapi:~ $ lsusb

Bus 001 Device 004: ID 0d8c:013c C-Media Electronics, Inc. CM108 Audio Controller
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter
Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

pi@alexapi:~ $ arecord -l

**** List of CAPTURE Hardware Devices ****
card 1: Device [USB PnP Sound Device], device 0: USB Audio [USB Audio]
Subdevices: 1/1
Subdevice #0: subdevice #0

pi@alexapi:~ $ aplay -l

**** List of PLAYBACK Hardware Devices ****
card 0: ALSA [bcm2835 ALSA], device 0: bcm2835 ALSA [bcm2835 ALSA]
Subdevices: 5/7
Subdevice #0: subdevice #0
Subdevice #1: subdevice #1
Subdevice #2: subdevice #2
Subdevice #3: subdevice #3
Subdevice #4: subdevice #4
Subdevice #5: subdevice #5
Subdevice #6: subdevice #6
card 0: ALSA [bcm2835 ALSA], device 1: bcm2835 IEC958/HDMI [bcm2835 IEC958/HDMI]
Subdevices: 1/1
Subdevice #0: subdevice #0

pi@alexapi:~ $ sudo cat /root/.asoundrc

pcm.!default {
type asym
playback.pcm {
type plug
slave.pcm "hw:0,0"
}
capture.pcm {
type plug
slave.pcm "hw:1,0"
}
}

@gitbenjazz
Copy link

Thanks for looking into this !

Please find mine:

pi@caramel:~ $ cat /etc/os-release
PRETTY_NAME="Raspbian GNU/Linux 9 (stretch)"
NAME="Raspbian GNU/Linux"
VERSION_ID="9"
VERSION="9 (stretch)"
ID=raspbian
ID_LIKE=debian

pi@caramel:~ $ uname -a
Linux caramel 4.19.42-v7+ #1219 SMP Tue May 14 21:20:58 BST 2019 armv7l GNU/Linux

pi@caramel:~ $ lsusb
Bus 001 Device 005: ID 8086:0808 Intel Corp.
Bus 001 Device 004: ID 0781:558a SanDisk Corp.
Bus 001 Device 003: ID 0424:ec00 Standard Microsystems Corp. SMSC9512/9514 Fast Ethernet Adapter
Bus 001 Device 002: ID 0424:9514 Standard Microsystems Corp. SMC9514 Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

pi@caramel:~ $ arecord -l
**** List of CAPTURE Hardware Devices ****
card 1: Device [USB PnP Sound Device], device 0: USB Audio [USB Audio]
Subdevices: 1/1
Subdevice #0: subdevice #0

pi@caramel:~ $ aplay -l
**** List of PLAYBACK Hardware Devices ****
card 0: ALSA [bcm2835 ALSA], device 0: bcm2835 ALSA [bcm2835 ALSA]
Subdevices: 7/7
Subdevice #0: subdevice #0
Subdevice #1: subdevice #1
Subdevice #2: subdevice #2
Subdevice #3: subdevice #3
Subdevice #4: subdevice #4
Subdevice #5: subdevice #5
Subdevice #6: subdevice #6
card 0: ALSA [bcm2835 ALSA], device 1: bcm2835 IEC958/HDMI [bcm2835 IEC958/HDMI]
Subdevices: 1/1
Subdevice #0: subdevice #0

pi@caramel:~ $ sudo cat /root/.asoundrc
pcm.!default {
type asym
playback.pcm {
type plug
slave.pcm "hw:0,0"
}
capture.pcm {
type plug
slave.pcm "hw:1,0"
}
}

pi@caramel:/ $ cat /home/pi/.asoundrc
pcm.dsnooper {
type dsnoop
ipc_key 816357492
ipc_key_add_uid 0
ipc_perm 0666
slave {
pcm "hw:1,0"
channels 1
}
}
pcm.dmixer {
type dmix
ipc_key 1024
slave {
pcm "hw:1,0"
period_time 0
period_size 1024
buffer_size 8192
rate 44100
}

}

pcm.!default {
type asym
playback.pcm {
type plug
slave.pcm "dmixer"
}
capture.pcm {
type plug
slave.pcm "dsnooper"
}
}

pcm.!default {
type hw
card 1
}

ctl.!default {
type hw
card 1
}

@celinval
Copy link
Contributor

celinval commented Jun 4, 2019

Hi @gitbenjazz, what parameters did you use while running arecord? Can you please make sure the following work:

arecord -f S16_LE -c1 -r16000 -d 3 > /tmp/test.wav
aplay /tmp/test.wav

This will try to record the audio using the same parameters as the sample application.

Thanks!

@moryoav
Copy link

moryoav commented Jun 4, 2019

$ arecord -f S16_LE -c1 -r16000 -d 3 > /tmp/test.wav
arecord: main:788: audio open error: No such file or directory
$ sudo arecord -f S16_LE -c1 -r16000 -d 3 > /tmp/test.wav
Recording WAVE 'stdin' : Signed 16 bit Little Endian, Rate 16000 Hz, Mono
$ aplay /tmp/test.wav
Playing WAVE '/tmp/test.wav' : Signed 16 bit Little Endian, Rate 16000 Hz, Mono

@celinval
Copy link
Contributor

celinval commented Jun 4, 2019

Since you are running the sample app with sudo, can you please configure /root/.asoundrc according to: https://github.com/alexa/avs-device-sdk/wiki/Troubleshooting-Guide (Section RaspberryPi)

@moryoav
Copy link

moryoav commented Jun 5, 2019

Since you are running the sample app with sudo, can you please configure /root/.asoundrc according to: https://github.com/alexa/avs-device-sdk/wiki/Troubleshooting-Guide (Section RaspberryPi)

I'm incredibly embarrassed to report that this actually worked and fixed the problem.
Pasting the following code:
https://github.com/shivasiddharth/Assistants-Pi/blob/master/audio-drivers/USB-DAC/scripts/asound.conf
into:
/home/pi/.asoundrc
/root/.asoundrc
/home/pi/third-party/alexa-rpi/config/asound.conf

Fixed the problem.
Now the interesting this is what caused this to begin with, since the 2 raspberry pis worked fine up until one day when they stopped working, and I sure never touched those .asoundrc files from their original configuration. Anyhow... good news, at least for me.

@moryoav
Copy link

moryoav commented Jun 5, 2019

I was a bit early to celebrate. While the sample code ran without crushing, there was no audio when Alexa needed to speak and some error messages about playback problems. Also "aplay" stopped working...
I changed lines 26-27 from here:
https://github.com/shivasiddharth/Assistants-Pi/blob/master/audio-drivers/USB-DAC/scripts/asound.conf
Into:

type hw
card 0

And updated /root/.asoundrc . That seemed to fix everything. Now everything works fine. Did I make the right change? Is there a better setting?

@celinval
Copy link
Contributor

celinval commented Jun 5, 2019

Hi @moryoav, thanks for sharing your solution. The .asoundrc configuration really depends on your hardware so there is no perfect solution.

I'm closing this issue since it is working for you. Please don't hesitate to contact us again if you have any issue.

Best,
Celina

@celinval celinval closed this as completed Jun 5, 2019
@Andergraw
Copy link

Andergraw commented Sep 8, 2019

Ey, just reaching out to thank everyone for this post. Exactly as @moryoav, this started happening recently after compiling several versions of Alexa SDK on a different Pi. I had never have to edit explicitly /root/.asoundrc and I didn't have to copy the linked code neither. I had a working version with my own .asoundrc.
Oh my God, I have been struggling with this for hours...
Thanks, guys, specially @moryoav for sharing the solution and the final touch (I couldn't hear Alexa back neither).

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

7 participants