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

PostConnectSynchronizer:stop #704

Closed
phantom-j opened this issue May 8, 2018 · 9 comments
Closed

PostConnectSynchronizer:stop #704

phantom-j opened this issue May 8, 2018 · 9 comments

Comments

@phantom-j
Copy link

Hi,
i have installed avs-sdk latest version on Raspbian strech in Raspberrypi 3 model B.It was installed properly,no error was shown.but its not listening.In debugging it is telling PostConnectSynchronizer:stop
my debugging result is

sudo bash startsample.sh
2018-05-08 18:18:12.477 [ 1] I sdkVersion: 1.7.1
configFile /home/pi/build/Integration/AlexaClientSDKConfig.json
Running app with log level: DEBUG9
2018-05-08 18:18:12.492 [ 1] 0 ConfigurationNode:initializeSuccess
2018-05-08 18:18:12.503 [ 1] 9 MediaPlayer:createCalled
2018-05-08 18:18:12.660 [ 1] 9 MediaPlayer:noOutputConversion
2018-05-08 18:18:12.664 [ 1] 9 MediaPlayer:createCalled
2018-05-08 18:18:12.666 [ 1] 9 MediaPlayer:noOutputConversion
2018-05-08 18:18:12.669 [ 1] 9 MediaPlayer:createCalled
2018-05-08 18:18:12.670 [ 1] 9 MediaPlayer:noOutputConversion
2018-05-08 18:18:12.673 [ 1] 9 MediaPlayer:createCalled
2018-05-08 18:18:12.674 [ 1] 9 MediaPlayer:noOutputConversion
2018-05-08 18:18:12.677 [ 1] 9 MediaPlayer:createCalled
2018-05-08 18:18:12.678 [ 1] 9 MediaPlayer:noOutputConversion
2018-05-08 18:18:12.681 [ 1] 9 MediaPlayer:createCalled
2018-05-08 18:18:12.682 [ 1] 9 MediaPlayer:noOutputConversion
2018-05-08 18:18:12.688 [ 1] 5 SQLiteBluetoothStorage:create
2018-05-08 18:18:12.691 [ 1] 5 CBLAuthDelegate:create
2018-05-08 18:18:12.693 [ 1] 5 CBLAuthDelegate:CBLAuthDelegate
2018-05-08 18:18:12.693 [ 1] 5 CBLAuthDelegate:init
2018-05-08 18:18:12.693 [ 1] 5 CBLAuthDelegateConfiguration:create
2018-05-08 18:18:12.693 [ 1] 5 CBLAuthDelegateConfiguration:init
2018-05-08 18:18:12.693 [ 1] 5 CBLAuthDelegateConfiguration:initScopeData
2018-05-08 18:18:12.694 [ 1] 9 CBLAuthDelegateConfiguration:initScopeDataSucceeded
2018-05-08 18:18:12.694 [ 1] 5 SQLiteCBLAuthDelegateStorage:open
2018-05-08 18:18:12.698 [ 2] 5 CBLAuthDelegate:handleAuthorizationFlow
2018-05-08 18:18:12.699 [ 2] 5 CBLAuthDelegate:handleStarting
2018-05-08 18:18:12.699 [ 2] 5 SQLiteCBLAuthDelegateStorage:getRefreshToken
2018-05-08 18:18:12.700 [ 2] 5 CBLAuthDelegate:handleRefreshingToken
2018-05-08 18:18:12.700 [ 2] 5 CBLAuthDelegate:requestRefresh
2018-05-08 18:18:12.702 [ 1] 5 CBLAuthDelegate:addAuthObserver:observer=0x1680394
2018-05-08 18:18:12.703 [ 1] 5 CBLAuthDelegate:addAuthObserver:observer=0x166b380
2018-05-08 18:18:12.704 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x166b384
2018-05-08 18:18:12.709 [ 1] 5 InternetConnectionMonitor:startMonitoring
2018-05-08 18:18:12.712 [ 3] 5 InternetConnectionMonitor:testConnection
2018-05-08 18:18:12.739 [ 1] 9 MediaPlayer:setObserverCalled
2018-05-08 18:18:12.739 [ 4] 0 MediaPlayer:handleSetObserverCalled
2018-05-08 18:18:12.740 [ 1] 9 SpeechSynthesizer:addObserver:observer=0x1685d34
2018-05-08 18:18:12.742 [ 1] 9 PlaybackRouter:create::called
2018-05-08 18:18:12.744 [ 1] 9 MediaPlayer:setObserverCalled
2018-05-08 18:18:12.745 [ 4] 0 MediaPlayer:handleSetObserverCalled
2018-05-08 18:18:12.746 [ 1] 9 MediaPlayer:setObserverCalled
2018-05-08 18:18:12.746 [ 4] 0 MediaPlayer:handleSetObserverCalled
2018-05-08 18:18:12.752 [ 1] 9 AlertScheduler:setTimerForNextAlertLocked
2018-05-08 18:18:12.752 [ 1] 9 AlertScheduler:executeScheduleNextAlertForRendering::no work to do.
2018-05-08 18:18:12.753 [ 5] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2018-05-08 18:18:12.754 [ 1] 5 NotificationsRenderer:create
2018-05-08 18:18:12.754 [ 1] 9 MediaPlayer:setObserverCalled
2018-05-08 18:18:12.754 [ 4] 0 MediaPlayer:handleSetObserverCalled
2018-05-08 18:18:12.756 [ 1] 5 NotificationsCapabilityAgent:init
2018-05-08 18:18:12.756 [ 1] 5 NotificationsRenderer:addObserver
2018-05-08 18:18:12.760 [ 6] 5 NotificationsCapabilityAgent:executeInit
2018-05-08 18:18:12.761 [ 6] 5 NotificationsCapabilityAgent:notifyObservers:indicatorState=0
2018-05-08 18:18:12.762 [ 6] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=false,stateRequestToken=0
2018-05-08 18:18:12.764 [ 6] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2018-05-08 18:18:12.768 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2018-05-08 18:18:12.768 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2018-05-08 18:18:12.768 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2018-05-08 18:18:12.768 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2018-05-08 18:18:12.769 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2018-05-08 18:18:12.769 [ 1] 9 MediaPlayer:getSpeakerTypeCalled
2018-05-08 18:18:12.769 [ 1] 0 SpeakerManager:mapCreated:numAvsSynced=5,numLocal=1
2018-05-08 18:18:12.769 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled
2018-05-08 18:18:12.770 [ 4] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-05-08 18:18:12.770 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled
2018-05-08 18:18:12.770 [ 4] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-05-08 18:18:12.770 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled
2018-05-08 18:18:12.771 [ 4] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-05-08 18:18:12.771 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled
2018-05-08 18:18:12.771 [ 4] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-05-08 18:18:12.771 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled
2018-05-08 18:18:12.771 [ 4] 9 MediaPlayer:handleGetSpeakerSettingsCalled
2018-05-08 18:18:12.771 [ 1] 9 SpeakerManager:validateSpeakerSettingsConsistencyResult:consistent=true
2018-05-08 18:18:12.771 [ 1] 9 SpeakerManager:validateSpeakerSettings:volume=100,mute=false
2018-05-08 18:18:12.771 [ 1] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SYNCED
2018-05-08 18:18:12.773 [ 1] 0 ExternalMediaPlayer:createAdapters
2018-05-08 18:18:12.777 [ 1] 1 AudioPlayer:addObserver
2018-05-08 18:18:12.779 [ 7] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2018-05-08 18:18:12.781 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x168cf48,policy=BLOCKING
2018-05-08 18:18:12.782 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x168e0f8,policy=NON_BLOCKING
2018-05-08 18:18:12.782 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x168e0f8,policy=NON_BLOCKING
2018-05-08 18:18:12.782 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x168e0f8,policy=NON_BLOCKING
2018-05-08 18:18:12.782 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Play,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.783 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Logout,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.783 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Login,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.783 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=SetSeekPosition,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.783 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Play,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.783 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Unfavorite,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.784 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableShuffle,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.784 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Pause,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.784 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Next,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.784 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Rewind,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.784 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeat,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.784 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Previous,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.784 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=StartOver,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.785 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=FastForward,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.785 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Favorite,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.785 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableShuffle,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.785 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeatOne,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.785 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableRepeat,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.785 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=AdjustSeekPosition,handler=0x169bad8,policy=NON_BLOCKING
2018-05-08 18:18:12.785 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x168c458,policy=NON_BLOCKING
2018-05-08 18:18:12.786 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x168c458,policy=NON_BLOCKING
2018-05-08 18:18:12.786 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x168ef90,policy=NON_BLOCKING
2018-05-08 18:18:12.786 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x168ef90,policy=NON_BLOCKING
2018-05-08 18:18:12.786 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetEndpoint,handler=0x169e250,policy=NON_BLOCKING
2018-05-08 18:18:12.786 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x168c26c,policy=NON_BLOCKING
2018-05-08 18:18:12.787 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x169b530,policy=NON_BLOCKING
2018-05-08 18:18:12.787 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x169b530,policy=NON_BLOCKING
2018-05-08 18:18:12.787 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x169b530,policy=NON_BLOCKING
2018-05-08 18:18:12.787 [ 1] 5 TemplateRuntime:getConfiguration
2018-05-08 18:18:12.787 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x169d500,policy=HANDLE_IMMEDIATELY
2018-05-08 18:18:12.787 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x169d500,policy=HANDLE_IMMEDIATELY
2018-05-08 18:18:12.788 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=ClearIndicator,handler=0x1693dac,policy=HANDLE_IMMEDIATELY
2018-05-08 18:18:12.788 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=SetIndicator,handler=0x1693dac,policy=HANDLE_IMMEDIATELY
2018-05-08 18:18:12.791 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled
2018-05-08 18:18:12.791 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x166b390
2018-05-08 18:18:12.792 [ 1] 5 NotificationsCapabilityAgent:addObserver
2018-05-08 18:18:12.792 [ 1] 5 TemplateRuntime:addObserver
2018-05-08 18:18:12.792 [ 8] 5 TemplateRuntime:addObserverInExecutor
#################################################

NOTIFICATION INDICATOR STATE: OFF

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

2018-05-08 18:18:12.897 [ 1] I SensoryKeywordDetector:License expires on 28 Aug 2018 00:00:00 GMT
2018-05-08 18:18:12.897 [ 1] I SensoryKeywordDetector:Sensory library license does not expire for at least 60 more days.
2018-05-08 18:18:12.917 [ 1] 5 CBLAuthDelegate:addAuthObserver:observer=0x16cb068
2018-05-08 18:18:12.917 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x16cb06c
2018-05-08 18:18:12.917 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x1685bc8
# # # ##### ##### ###### # #
# # # # # # # # # # # #
# # # # # # # # # #
# # # # ##### ##### # # ###
####### # # # # # # # #
# # # # # # # # # # # #
# # # ##### ##### ###### # #

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

   SDK Version 1.7.1

+----------------------------------------------------------------------------+
| Options: |
| Wake word: |
| Simply say Alexa and begin your query. |
| Tap to talk: |
| Press 't' and Enter followed by your query (no need for the 'Alexa').|
| Hold to talk: |
| Press 'h' followed by Enter to simulate holding a button. |
| Then say your query (no need for the 'Alexa'). |
| Press 'h' followed by Enter to simulate releasing a button. |
| Stop an interaction: |
| Press 's' and Enter to stop an ongoing interaction. |
| Privacy mode (microphone off): |
| Press 'm' and Enter to turn on and off the microphone. |
| Echo Spatial Perception (ESP): This is for testing purpose only! |
| Press 'e' followed by Enter at any time to adjust ESP settings. |
| Playback Controls: |
| Press '1' for a 'PLAY' button press. |
| Press '2' for a 'PAUSE' button press. |
| Press '3' for a 'NEXT' button press. |
| Press '4' for a 'PREVIOUS' button press. |
| Settings: |
| Press 'c' followed by Enter at any time to see the settings screen. |
| Speaker Control: |
| Press 'p' followed by Enter at any time to adjust speaker settings. |
| Firmware Version: |
| Press 'f' followed by Enter at any time to report a different |
| firmware version. |
| Info: |
| Press 'i' followed by Enter at any time to see the help screen. |
| Reset device: |
| Press 'k' followed by Enter at any time to reset your device. This |
| will erase any data stored in the device and you will have to |
| re-register your device. |
| This option will also exit the application. |
| Quit: |
| Press 'q' followed by Enter at any time to quit the application. |
+----------------------------------------------------------------------------+

2018-05-08 18:18:12.935 [ 9] 5 CapabilitiesDelegate:setCapabilitiesState:newCapabilitiesState=SUCCESS
2018-05-08 18:18:12.936 [ 9] 9 CapabilitiesDelegate:callingOnCapabilitiesStateChange:state=SUCCESS,error=SUCCESS
2018-05-08 18:18:12.937 [ 9] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=PENDING
2018-05-08 18:18:12.939 [ 9] 5 CBLAuthDelegate:addAuthObserver:observer=0x14de0b0
2018-05-08 18:18:12.942 [ 5] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=PENDING,reason=ACL_CLIENT_REQUEST
#############################

Connecting...

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

2018-05-08 18:18:12.943 [ a] 0 PostConnectSynchronizer:doPostConnect
2018-05-08 18:18:12.945 [ a] 5 PostConnectSynchronizer:setState:from=IDLE,to=RUNNING
2018-05-08 18:18:12.946 [ b] 5 PostConnectSynchronizer:mainLoop
2018-05-08 18:18:12.946 [ b] 5 PostConnectSynchronizer:setState:from=RUNNING,to=FETCHING
2018-05-08 18:18:12.948 [ c] 5 VisualActivityTracker:provideState
2018-05-08 18:18:12.948 [ d] 5 VisualActivityTracker:executeProvideState
2018-05-08 18:18:12.949 [ d] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2018-05-08 18:18:12.949 [ e] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2018-05-08 18:18:12.950 [ e] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2018-05-08 18:18:12.950 [ c] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=1
2018-05-08 18:18:12.950 [ c] 5 AudioActivityTracker:provideState
2018-05-08 18:18:12.951 [ 6] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=1
2018-05-08 18:18:12.951 [ c] 9 SpeechSynthesizer:provideState:token=1
2018-05-08 18:18:12.951 [ f] 5 AudioActivityTracker:executeProvideState
2018-05-08 18:18:12.951 [ f] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2018-05-08 18:18:12.951 [ 10] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=1
2018-05-08 18:18:12.952 [ 10] 9 ContextManager:updateStateLocked:action=updatedState,namespace=SpeechSynthesizer,name=SpeechState
2018-05-08 18:18:12.952 [ 11] 9 ContextManager:updateStateLocked:action=updatedState,namespace=SpeechRecognizer,name=RecognizerState
2018-05-08 18:18:12.952 [ 6] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2018-05-08 18:18:12.953 [ e] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2018-05-08 18:18:12.951 [ c] 0 AudioPlayer:provideState:stateRequestToken=1
2018-05-08 18:18:12.953 [ e] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2018-05-08 18:18:12.954 [ 12] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2018-05-08 18:18:12.954 [ 12] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioPlayer,name=PlaybackState
2018-05-08 18:18:12.954 [ c] 9 ContextManager:buildContextIgnored:namespace=VisualActivityTracker,name=ActivityState
2018-05-08 18:18:12.955 [ c] 9 ContextManager:buildContextIgnored:namespace=AudioActivityTracker,name=ActivityState
2018-05-08 18:18:12.957 [ c] 5 ContextManager:buildContextSuccessful
2018-05-08 18:18:12.957 [ c] 5 PostConnectSynchronizer:onContectAvailable
2018-05-08 18:18:12.957 [ c] 5 PostConnectSynchronizer:setState:from=FETCHING,to=SENDING
2018-05-08 18:18:12.959 [ c] 0 EventBuilder:buildJsonEventString:messageId=fe7630a3-cd3a-41cb-98ed-b0d52cb9f619,namespace=System,name=SynchronizeState
2018-05-08 18:18:12.963 [ c] 9 HTTP2Transport:enqueueRequest
2018-05-08 18:18:13.243 [ 3] 0 InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-05-08 18:18:13.244 [ 3] 5 InternetConnectionMonitor:updateConnectionStatus:connected=true
2018-05-08 18:18:13.245 [ 3] 5 InternetConnectionMonitor:notifyObserversLocked
2018-05-08 18:18:14.154 [ 2] 5 HttpPost:doPostSucceeded:code=200
2018-05-08 18:18:14.155 [ 2] 5 CBLAuthDelegate:receiveTokenResponse:code=200
2018-05-08 18:18:14.155 [ 2] 5 CBLAuthDelegate:mapHTTPStatusToError:code=200,error=SUCCESS
2018-05-08 18:18:14.156 [ 2] 5 CBLAuthDelegate:setAuthError:authError=SUCCESS
2018-05-08 18:18:14.156 [ 2] 5 CBLAuthDelegate:setRefreshToken
2018-05-08 18:18:14.156 [ 2] 5 SQLiteCBLAuthDelegateStorage:setRefreshToken
2018-05-08 18:18:14.179 [ 2] 5 CBLAuthDelegate:setAuthState:newAuthState=REFRESHED
2018-05-08 18:18:14.179 [ 2] 9 CBLAuthDelegate:callingOnAuthStateChange:state=REFRESHED,error=SUCCESS
###########################

Authorized!

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

2018-05-08 18:18:14.180 [ a] 3 HTTP2Transport:setupDownchannelStream:url=https://avs-alexa-na.amazon.com/v20160207/directives
2018-05-08 18:18:14.181 [ a] 0 HTTP2StreamPool:getStream:streamId=1,numAcquiredStreams=1
2018-05-08 18:18:15.688 [ a] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 0e4576fffeebecea-000063e2-000556bc-31c6d4c1483c6dda-9cc8a53d-1
2018-05-08 18:18:15.689 [ a] 0 HTTP2Transport:processNextOutgoingMessage
2018-05-08 18:18:15.690 [ a] 0 HTTP2StreamPool:getStream:streamId=3,numAcquiredStreams=2
2018-05-08 18:18:15.690 [ a] 9 HTTP2Transport:insertActiveStream:handle=0x713e0c58
2018-05-08 18:18:16.198 [ a] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 0e4576fffeebecea-000063e2-00053867-7b0d9a5e69650e52-43cf20d2-45
2018-05-08 18:18:16.200 [ 13] 0 MessageInterpreter:receive:messageId=9a5540d9-0f11-4424-9914-7599fd0319bc:No dialogRequestId attached to message.
2018-05-08 18:18:16.202 [ 13] I DirectiveSequencer:onDirective:directive={"namespace:"System",name:"SetEndpoint",messageId:"9a5540d9-0f11-4424-9914-7599fd0319bc",dialogRequestId:""}
2018-05-08 18:18:16.202 [ a] 5 PostConnectSynchronizer:onSendCompleted:status=SUCCESS
2018-05-08 18:18:16.203 [ a] 5 PostConnectSynchronizer:stop
2018-05-08 18:18:16.203 [ 14] I DirectiveRouter:preHandleDirective:messageId=9a5540d9-0f11-4424-9914-7599fd0319bc,action=calling
2018-05-08 18:18:16.204 [ a] 5 PostConnectSynchronizer:setState:from=SENDING,to=STOPPING
2018-05-08 18:18:16.204 [ b] 5 PostConnectSynchronizer:mainLoopReturning
2018-05-08 18:18:16.204 [ 14] 0 CapabilityAgent:addingMessageIdToMap:messageId=9a5540d9-0f11-4424-9914-7599fd0319bc
2018-05-08 18:18:16.205 [ a] 5 PostConnectSynchronizer:setState:from=STOPPING,to=STOPPED
2018-05-08 18:18:16.205 [ a] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=CONNECTED
2018-05-08 18:18:16.206 [ 5] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=CONNECTED,reason=ACL_CLIENT_REQUEST
########################################

Alexa is currently idle!

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

2018-05-08 18:18:16.207 [ 15] I DirectiveRouter:handleDirective:messageId=9a5540d9-0f11-4424-9914-7599fd0319bc,action=calling
2018-05-08 18:18:16.207 [ a] 0 HTTP2Transport:cleanupFinishedStream:streamId=3,result=200
2018-05-08 18:18:16.208 [ 15] 0 MessageRouter:connectionStatusChanged:reason=SERVER_ENDPOINT_CHANGED,newStatus=DISCONNECTED
2018-05-08 18:18:16.208 [ 15] 5 CBLAuthDelegate:removeAuthObserver:observer=0x14de0b0
2018-05-08 18:18:16.208 [ 5] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=SERVER_ENDPOINT_CHANGED
#####################################

Client not connected!

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

2018-05-08 18:18:16.209 [ a] 0 HTTP2StreamPool:releaseStream:streamId=3,numAcquiredStreams=1
2018-05-08 18:18:16.210 [ a] 0 PostConnectSynchronizer:~PostConnectSynchronizer
2018-05-08 18:18:16.210 [ a] 5 PostConnectSynchronizer:stop
2018-05-08 18:18:16.210 [ a] 5 PostConnectSynchronizer:stopIgnored:reason=alreadyStopped
2018-05-08 18:18:16.223 [ a] 0 HTTP2StreamPool:releaseStream:streamId=1,numAcquiredStreams=0
2018-05-08 18:18:16.230 [ 15] 5 CBLAuthDelegate:addAuthObserver:observer=0x713ab1f8
2018-05-08 18:18:16.230 [ 16] 0 PostConnectSynchronizer:doPostConnect
2018-05-08 18:18:16.231 [ 16] 5 PostConnectSynchronizer:setState:from=IDLE,to=RUNNING
2018-05-08 18:18:16.231 [ 15] 0 DirectiveProcessor:onHandlingCompeted:messageId=9a5540d9-0f11-4424-9914-7599fd0319bc,directiveBeingPreHandled=(nullptr)
2018-05-08 18:18:16.231 [ 16] 3 HTTP2Transport:setupDownchannelStream:url=https://avs-alexa-eu.amazon.com/v20160207/directives
2018-05-08 18:18:16.231 [ 15] 0 CapabilityAgent:removingMessageIdFromMap:messageId=9a5540d9-0f11-4424-9914-7599fd0319bc
2018-05-08 18:18:16.231 [ 16] 0 HTTP2StreamPool:getStream:streamId=5,numAcquiredStreams=1
2018-05-08 18:18:16.232 [ 17] 5 PostConnectSynchronizer:mainLoop
2018-05-08 18:18:16.233 [ 17] 5 PostConnectSynchronizer:setState:from=RUNNING,to=FETCHING
2018-05-08 18:18:16.233 [ c] 5 VisualActivityTracker:provideState
2018-05-08 18:18:16.233 [ d] 5 VisualActivityTracker:executeProvideState
2018-05-08 18:18:16.233 [ c] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=2
2018-05-08 18:18:16.233 [ e] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=2
2018-05-08 18:18:16.233 [ d] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2018-05-08 18:18:16.233 [ 6] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=2
2018-05-08 18:18:16.234 [ e] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2018-05-08 18:18:16.234 [ 6] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2018-05-08 18:18:16.235 [ e] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=2
2018-05-08 18:18:16.235 [ c] 5 AudioActivityTracker:provideState
2018-05-08 18:18:16.235 [ f] 5 AudioActivityTracker:executeProvideState
2018-05-08 18:18:16.235 [ e] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2018-05-08 18:18:16.236 [ f] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2018-05-08 18:18:16.236 [ c] 9 ContextManager:buildContextIgnored:namespace=VisualActivityTracker,name=ActivityState
2018-05-08 18:18:16.236 [ c] 9 ContextManager:buildContextIgnored:namespace=AudioActivityTracker,name=ActivityState
2018-05-08 18:18:16.238 [ c] 5 ContextManager:buildContextSuccessful
2018-05-08 18:18:16.238 [ c] 5 PostConnectSynchronizer:onContectAvailable
2018-05-08 18:18:16.238 [ c] 5 PostConnectSynchronizer:setState:from=FETCHING,to=SENDING
2018-05-08 18:18:16.239 [ c] 0 EventBuilder:buildJsonEventString:messageId=8a79b082-2718-4d64-9c76-775d27011492,namespace=System,name=SynchronizeState
2018-05-08 18:18:16.240 [ c] 9 HTTP2Transport:enqueueRequest
2018-05-08 18:18:17.390 [ 16] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 06a71efffece23c4-0000337a-0003b4e3-04e9e16dabaa1510-f61ea396-1
2018-05-08 18:18:17.390 [ 16] 0 HTTP2Transport:processNextOutgoingMessage
2018-05-08 18:18:17.390 [ 16] 0 HTTP2StreamPool:getStream:streamId=7,numAcquiredStreams=2
2018-05-08 18:18:17.391 [ 16] 9 HTTP2Transport:insertActiveStream:handle=0x726e0978
2018-05-08 18:18:18.364 [ 16] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 06a71efffece23c4-0000337a-00039951-68a5e6e7784f07a3-430b16fd-25
2018-05-08 18:18:18.364 [ 16] 5 PostConnectSynchronizer:onSendCompleted:status=SUCCESS_NO_CONTENT
2018-05-08 18:18:18.364 [ 16] 5 PostConnectSynchronizer:stop
2018-05-08 18:18:18.364 [ 16] 5 PostConnectSynchronizer:setState:from=SENDING,to=STOPPING
2018-05-08 18:18:18.364 [ 17] 5 PostConnectSynchronizer:mainLoopReturning
2018-05-08 18:18:18.365 [ 16] 5 PostConnectSynchronizer:setState:from=STOPPING,to=STOPPED
2018-05-08 18:18:18.365 [ 16] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=CONNECTED
2018-05-08 18:18:18.365 [ 16] 0 HTTP2Transport:cleanupFinishedStream:streamId=7,result=204
2018-05-08 18:18:18.366 [ 16] 0 HTTP2StreamPool:releaseStream:streamId=7,numAcquiredStreams=1
2018-05-08 18:18:18.366 [ 16] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT
2018-05-08 18:18:18.366 [ 16] 0 PostConnectSynchronizer:~PostConnectSynchronizer
2018-05-08 18:18:18.366 [ 16] 5 PostConnectSynchronizer:stop
2018-05-08 18:18:18.366 [ 16] 5 PostConnectSynchronizer:stopIgnored:reason=alreadyStopped
2018-05-08 18:18:18.366 [ 5] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=CONNECTED,reason=ACL_CLIENT_REQUEST
########################################

Alexa is currently idle!

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

2018-05-08 18:23:13.247 [ 3] 5 InternetConnectionMonitor:testConnection
2018-05-08 18:23:13.768 [ 3] 0 InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-05-08 18:23:13.768 [ 3] 5 InternetConnectionMonitor:updateConnectionStatus:connected=true
2018-05-08 18:23:18.369 [ 16] 0 HTTP2Transport:sendPing:pingStream=0
2018-05-08 18:23:18.369 [ 16] 0 HTTP2StreamPool:getStream:streamId=9,numAcquiredStreams=2
2018-05-08 18:23:18.554 [ 16] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 06a71efffece23c4-0000337a-0003b4e3-04e9e16dabaa1510-f61ea396-5
2018-05-08 18:23:18.555 [ 16] 0 HTTP2Transport:handlePingResponse
2018-05-08 18:23:18.555 [ 16] 0 HTTP2StreamPool:releaseStream:streamId=9,numAcquiredStreams=1
2018-05-08 18:23:18.555 [ 16] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT

Any ideas why it is giving that?
@priyagsenthil
Copy link
Contributor

Hi jay7583,

From the log it looks like PostConnectSynchronizer is doing what is expected. These were new states added to the PostConnectSynchronizer in 1.7 and they seem to be working right. The job of the PostConnectSynchronizer is to fetch the initial context of the SDK components and send to AVS after which it stops running. So its doing what is expected? The default state of Alexa is "IDLE". Did you try "tap to talk" or did you try with wakeword and it did not move to listening mode? From the log everything looks right. Please check your microphone settings and try "Tap to Talk" or try with wakeword enabled. Let us know if it still does not work.

Thanks
Priya

@phantom-j
Copy link
Author

phantom-j commented May 9, 2018 •
edited
Loading

Hi @priyagsenthil ,
Wakeupword is not working and tap to talk also not working.My mic and speaker normally working .
Is there anything to modify in AVS-SDK to select microphone?
All other applications accessing microphone except AVS-SDK.

@priyagsenthil
Copy link
Contributor

Hi jay7583,

Can you follow the instructions in the guide to check if your microphone is working.
https://github.com/alexa/avs-device-sdk/wiki/Raspberry-Pi-Quick-Start-Guide

Can you paste the contents of your soundrc file.

Thanks
Priya

@phantom-j
Copy link
Author

phantom-j commented May 9, 2018 •
edited
Loading

Hi Priya,
this is my asoundrc file
pcm.sc {
type hw
card 2
}
pcm.!default
{
type asym
playback.pcm {
type hw
card 0
device 0
}
capture.pcm {
type hw
card 2
device 0
}
}

@priyagsenthil
Copy link
Contributor

#669 -> could you follow the guidelines here to test the microphone and provide your inputs.

@phantom-j
Copy link
Author

I have used rec command to check mic it's working properly.and i am not using usb mic.

@priyagsenthil
Copy link
Contributor

Can you also paste the output of arecord -l.

@phantom-j
Copy link
Author

pi@raspberrypi:~ $ arecord -l
**** List of CAPTURE Hardware Devices ****
card 1: Dummy [Dummy], device 0: Dummy PCM [Dummy PCM]
Subdevices: 8/8
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
Subdevice #7: subdevice #7
card 2: SOUND [MATRIXIO SOUND], device 0: matrixio.mic.0 snd-soc-dummy-dai-0 []
Subdevices: 1/1
Subdevice #0: subdevice #0

@mavamazon
Copy link
Contributor

Hi!
Sorry for asking for more input, but could you please provide logs of the actual attempt to ask Alexa something? The logs you provided is for initialization stage only.

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

No branches or pull requests
3 participants
@phantom-j @priyagsenthil @mavamazon