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

updateStatesLoopFailed #911

Closed
6 tasks
xuqifu opened this issue Aug 16, 2018 · 6 comments
Closed
6 tasks

updateStatesLoopFailed #911

xuqifu opened this issue Aug 16, 2018 · 6 comments

Comments

@xuqifu
Copy link

xuqifu commented Aug 16, 2018

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

Briefly summarize your issue:

I have say "stop" is stop doing when avs is playing music, but next time say "alexa" is immediate from listening to idle. also have error log for updateStatesLoopFailed.

log following:
############################

Listening...
############################

2018-08-15 12:52:47.476 [ 12] 5 VisualActivityTracker:provideState
2018-08-15 12:52:47.477 [ 14] 5 VisualActivityTracker:executeProvideState
2018-08-15 12:52:47.478 [ 14] 9

ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2018-08-15 12:52:47.483 [ 13] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=12
2018-08-15 12:52:47.488 [ 13] 9

ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2018-08-15 12:52:47.490 [ 12] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=12
2018-08-15 12:52:47.492 [ 13] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=12
2018-08-15 12:52:47.494 [ 13] 9

ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2018-08-15 12:52:47.495 [ c] 5

NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=12
2018-08-15 12:52:47.497 [ c] 9

ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2018-08-15 12:52:47.500 [ 12] 5 AudioActivityTracker:provideState
2018-08-15 12:52:47.501 [ 15] 5 AudioActivityTracker:executeProvideState
2018-08-15 12:52:47.502 [ 15] 9

ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2018-08-15 12:52:47.502 [ 12] 0 AudioPlayer:provideState:stateRequestToken=12
2018-08-15 12:52:47.503 [ 18] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=12
2018-08-15 12:52:47.503 [ 18] 9 MediaPlayer:getOffsetCalled
2018-08-15 12:52:47.504 [ 5] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4
2018-08-15 12:52:47.513 [ 18] 9

ContextManager:updateStateLocked:action=updatedState,namespace=AudioPlayer,name=PlaybackState
2018-08-15 12:52:47.516 [ 12] 5 ContextManager:buildContextSuccessful
2018-08-15 12:52:47.548 [ 16] 0 AudioInputProcessor:executeOnContextAvailable
2018-08-15 12:52:47.548 [ 16] 1 FocusManager:acquireChannel:channelName=Dialog,interface=SpeechRecognizer
2018-08-15 12:52:47.549 [ 16] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=4bf72f93-fd11-41b7-8a9a-

951776a60351,newValue=cd8f6f92-b7aa-4ee9-8415-4f15ce9f4ebd
2018-08-15 12:52:47.550 [ 16] 0 DirectiveProcessor:scrubDialogRequestIdLocked:dialogRequestId=4bf72f93-fd11-41b7-

8a9a-951776a60351
2018-08-15 12:52:47.551 [ 19] 0 AudioPlayer:onFocusChanged:newFocus=BACKGROUND
2018-08-15 12:52:47.552 [ 18] 1

AudioPlayer:executeOnFocusChanged:from=FOREGROUND,to=BACKGROUND,m_currentActivity=PLAYING
2018-08-15 12:52:47.552 [ 18] 1 AudioPlayer:executeOnFocusChanged:action=pauseMediaPlayer
2018-08-15 12:52:47.552 [ 18] 9 MediaPlayer:pausedCalled
2018-08-15 12:52:47.553 [ 5] 0 MediaPlayer:handlePauseCalled:idPassed=4,currentId=4
2018-08-15 12:52:47.560 [ 16] 0 EventBuilder:buildJsonEventString:messageId=0341cd99-6e9b-45f9-99aa-

3e0e37271bc9,namespace=SpeechRecognizer,name=Recognize
2018-08-15 12:52:49.552 [ 19] E AudioPlayer:onFocusChangedTimedOut:newFocus=BACKGROUND,m_currentActivity=PLAYING
2018-08-15 12:52:49.553 [ 19] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND
2018-08-15 12:52:49.553 [ 16] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND
2018-08-15 12:52:49.554 [ 16] 9 HTTP2Transport:enqueueRequest
2018-08-15 12:52:49.555 [ 25] 0 HTTP2Transport:processNextOutgoingMessage
2018-08-15 12:52:49.555 [ 25] 0 HTTP2StreamPool:getStream:streamId=69,numAcquiredStreams=2
2018-08-15 12:52:49.556 [ 25] 9 HTTP2Transport:insertActiveStream:handle=0x1aa3c78
2018-08-15 12:52:49.560 [ 19] 5 AudioActivityTracker:notifyOfActivityUpdates
2018-08-15 12:52:49.561 [ 15] 5 AudioActivityTracker:executeNotifyOfActivityUpdates
2018-08-15 12:52:53.992 [ 1a] I DirectiveSequencer:onDirective:directive={"namespace:"SpeechRecognizer",name

:"StopCapture",messageId:"6c92f960-c4ab-4998-82ef-a125519e1c6a",dialogRequestId:"cd8f6f92-b7aa-4ee9-8415-

4f15ce9f4ebd"}
2018-08-15 12:52:53.993 [ 1b] I DirectiveRouter:preHandleDirective:messageId=6c92f960-c4ab-4998-82ef-

a125519e1c6a,action=calling
2018-08-15 12:52:53.993 [ 1b] 0 CapabilityAgent:addingMessageIdToMap:messageId=6c92f960-c4ab-4998-82ef-a125519e1c6a
2018-08-15 12:52:53.994 [ 1c] I DirectiveRouter:handleDirective:messageId=6c92f960-c4ab-4998-82ef-

a125519e1c6a,action=calling
2018-08-15 12:52:53.995 [ 16] 0 AudioInputProcessor:stopCapture:stopImmediately=true
2018-08-15 12:52:53.995 [ 16] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY
2018-08-15 12:52:53.995 [ 16] 0 DirectiveProcessor:onHandlingCompeted:messageId=6c92f960-c4ab-4998-82ef-

a125519e1c6a,directiveBeingPreHandled=(nullptr)
2018-08-15 12:52:53.996 [ 16] 0 CapabilityAgent:removingMessageIdFromMap:messageId=6c92f960-c4ab-4998-82ef-

a125519e1c6a
2018-08-15 12:52:53.996 [ d] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING
2018-08-15 12:52:53.997 [ d] 5 TemplateRuntime:onDialogUXStateChanged:state=THINKING
###########################

Thinking...
###########################

2018-08-15 12:52:54.247 [ d] 0 DialogUXStateAggregator:transitionFromThinkingTimedOut
2018-08-15 12:52:54.248 [ d] 0 DialogUXStateAggregator:setState:from=THINKING,to=IDLE
########################################

Alexa is currently idle!
########################################

2018-08-15 12:52:54.265 [ d] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2018-08-15 12:52:54.266 [ 16] 1 FocusManager:releaseChannel:channelName=Dialog
2018-08-15 12:52:54.267 [ 16] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2018-08-15 12:52:54.268 [ 19] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE
2018-08-15 12:52:54.270 [ 19] 0 AudioPlayer:onFocusChanged:newFocus=FOREGROUND
2018-08-15 12:52:54.271 [ 16] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2018-08-15 12:52:54.271 [ 16] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2018-08-15 12:52:54.273 [ 19] 5 AudioActivityTracker:notifyOfActivityUpdates
2018-08-15 12:52:54.274 [ 15] 5 AudioActivityTracker:executeNotifyOfActivityUpdates
2018-08-15 12:52:55.271 [ 25] 0 InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-08-15 12:52:56.299 [ 25] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid: 02363bfffef61422-0000308a-

000a2626-a56881f62523f91e-bc214f67-17
2018-08-15 12:52:56.305 [ 1a] I DirectiveSequencer:onDirective:directive={"namespace:"AudioPlayer",name

:"Stop",messageId:"ccc5db5e-d413-4f6d-8101-78da2ad298a2",dialogRequestId:"cd8f6f92-b7aa-4ee9-8415-

4f15ce9f4ebd"}
2018-08-15 12:52:56.306 [ 1b] I DirectiveRouter:preHandleDirective:messageId=ccc5db5e-d413-4f6d-8101-

78da2ad298a2,action=calling
2018-08-15 12:52:56.306 [ 1b] 0 CapabilityAgent:addingMessageIdToMap:messageId=ccc5db5e-d413-4f6d-8101-78da2ad298a2
2018-08-15 12:52:56.307 [ 1c] I DirectiveRouter:handleDirective:messageId=ccc5db5e-d413-4f6d-8101-

78da2ad298a2,action=calling
2018-08-15 12:52:56.307 [ 1c] 0 AudioPlayer:handleDirective:name=Stop,messageId=ccc5db5e-d413-4f6d-8101-

78da2ad298a2
2018-08-15 12:52:56.308 [ 1c] 1 AudioPlayer:handleStopDirective
2018-08-15 12:52:56.309 [ 1c] 0 DirectiveProcessor:onHandlingCompeted:messageId=ccc5db5e-d413-4f6d-8101-

78da2ad298a2,directiveBeingPreHandled=(nullptr)
2018-08-15 12:52:56.309 [ 1c] 0 CapabilityAgent:removingMessageIdFromMap:messageId=ccc5db5e-d413-4f6d-8101-

78da2ad298a2
2018-08-15 12:52:56.311 [ 25] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS
2018-08-15 12:52:56.311 [ 25] 0 HTTP2Transport:cleanupFinishedStream:streamId=69,result=200
2018-08-15 12:52:56.312 [ 25] 0 HTTP2StreamPool:releaseStream:streamId=69,numAcquiredStreams=1
2018-08-15 12:52:56.528 [ 1a] I DirectiveSequencer:onDirective:directive={"namespace:"SpeechRecognizer",name

:"StopCapture",messageId:"32fcf31e-1283-4718-8b64-50f5c6c54ab1",dialogRequestId:"4bf72f93-fd11-41b7-8a9a-

951776a60351"}
2018-08-15 12:52:56.541 [ 1b] I DirectiveProcessor:onDirective:messageId=32fcf31e-1283-4718-8b64-

50f5c6c54ab1,action=dropped,reason=dialogRequestIdDoesNotMatch,directivesDialogRequestId=4bf72f93-fd11-41b7-8a9a-

951776a60351,dialogRequestId=cd8f6f92-b7aa-4ee9-8415-4f15ce9f4ebd
2018-08-15 12:53:09.845 [ 16] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-08-15 12:53:09.846 [ d] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
############################

Listening...
############################

2018-08-15 12:53:09.861 [ d] 5 TemplateRuntime:onDialogUXStateChanged:state=LISTENING
2018-08-15 12:53:09.864 [ 12] 5 VisualActivityTracker:provideState
2018-08-15 12:53:09.865 [ 13] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=13
2018-08-15 12:53:09.866 [ 13] 9

ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2018-08-15 12:53:09.867 [ 14] 5 VisualActivityTracker:executeProvideState
2018-08-15 12:53:09.868 [ 14] 9

ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2018-08-15 12:53:09.869 [ 12] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=13
2018-08-15 12:53:09.870 [ c] 5

NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=13
2018-08-15 12:53:09.871 [ c] 9

ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2018-08-15 12:53:09.872 [ 13] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=13
2018-08-15 12:53:09.873 [ 13] 9

ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2018-08-15 12:53:09.873 [ 12] 5 AudioActivityTracker:provideState
2018-08-15 12:53:09.874 [ 15] 5 AudioActivityTracker:executeProvideState
2018-08-15 12:53:09.875 [ 15] 9

ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2018-08-15 12:53:09.876 [ 12] 0 AudioPlayer:provideState:stateRequestToken=13
2018-08-15 12:53:11.876 [ 12] E ContextManager:updateStatesLoopFailed:reason=stateProviderTimedOut
2018-08-15 12:53:11.878 [ 16] E AudioInputProcessor:executeOnContextFailure:error=STATE_PROVIDER_TIMEDOUT
2018-08-15 12:53:11.878 [ 16] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=IDLE
2018-08-15 12:53:12.085 [ d] 0 DialogUXStateAggregator:setState:from=LISTENING,to=IDLE
########################################

Alexa is currently idle!
########################################

2018-08-15 12:53:12.098 [ d] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2018-08-15 12:53:15.055 [ 3] 5 InternetConnectionMonitor:testConnection
2018-08-15 12:53:15.606 [ 3] 0 InProcessAttachmentReader:readFailed:reason=SDS is closed
2018-08-15 12:53:15.607 [ 3] 5 InternetConnectionMonitor:updateConnectionStatus:connected=true

2018-08-15 12:53:23.647 [ 16] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-08-15 12:53:23.648 [ d] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
############################

Listening...
############################

2018-08-15 12:53:23.664 [ d] 5 TemplateRuntime:onDialogUXStateChanged:state=LISTENING
2018-08-15 12:53:23.667 [ 12] 5 VisualActivityTracker:provideState
2018-08-15 12:53:23.668 [ 13] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=14
2018-08-15 12:53:23.669 [ 13] 9

ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2018-08-15 12:53:23.670 [ 14] 5 VisualActivityTracker:executeProvideState
2018-08-15 12:53:23.671 [ 14] 9

ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2018-08-15 12:53:23.672 [ 12] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=14
2018-08-15 12:53:23.673 [ c] 5

NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=14
2018-08-15 12:53:23.675 [ c] 9

ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2018-08-15 12:53:23.675 [ 13] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=14
2018-08-15 12:53:23.676 [ 13] 9

ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2018-08-15 12:53:23.677 [ 12] 5 AudioActivityTracker:provideState
2018-08-15 12:53:23.683 [ 15] 5 AudioActivityTracker:executeProvideState
2018-08-15 12:53:23.685 [ 15] 9

ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2018-08-15 12:53:23.686 [ 12] 0 AudioPlayer:provideState:stateRequestToken=14
2018-08-15 12:53:25.695 [ 12] E ContextManager:updateStatesLoopFailed:reason=stateProviderTimedOut
2018-08-15 12:53:25.695 [ 16] E AudioInputProcessor:executeOnContextFailure:error=STATE_PROVIDER_TIMEDOUT
2018-08-15 12:53:25.696 [ 16] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=IDLE
2018-08-15 12:53:25.898 [ d] 0 DialogUXStateAggregator:setState:from=LISTENING,to=IDLE
2018-08-15 12:53:25.899 [ d] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
########################################

Alexa is currently idle!
########################################

2018-08-15 12:53:31.058 [ 16] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-08-15 12:53:31.059 [ d] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
2018-08-15 12:53:31.059 [ d] 5 TemplateRuntime:onDialogUXStateChanged:state=LISTENING
############################

Listening...
############################

2018-08-15 12:53:31.074 [ 12] 5 VisualActivityTracker:provideState
2018-08-15 12:53:31.075 [ 14] 5 VisualActivityTracker:executeProvideState
2018-08-15 12:53:31.077 [ 13] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=15
2018-08-15 12:53:31.078 [ 13] 9

ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2018-08-15 12:53:31.081 [ 14] 9

ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2018-08-15 12:53:31.084 [ 12] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=15
2018-08-15 12:53:31.086 [ 13] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=15
2018-08-15 12:53:31.087 [ 13] 9

ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2018-08-15 12:53:31.088 [ c] 5

NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=15
2018-08-15 12:53:31.092 [ c] 9

ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2018-08-15 12:53:31.094 [ 12] 5 AudioActivityTracker:provideState
2018-08-15 12:53:31.097 [ 15] 5 AudioActivityTracker:executeProvideState
2018-08-15 12:53:31.098 [ 15] 9

ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2018-08-15 12:53:31.098 [ 12] 0 AudioPlayer:provideState:stateRequestToken=15
2018-08-15 12:53:33.099 [ 12] E ContextManager:updateStatesLoopFailed:reason=stateProviderTimedOut
2018-08-15 12:53:33.100 [ 16] E AudioInputProcessor:executeOnContextFailure:error=STATE_PROVIDER_TIMEDOUT
2018-08-15 12:53:33.100 [ 16] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=IDLE
2018-08-15 12:53:33.302 [ d] 0 DialogUXStateAggregator:setState:from=LISTENING,to=IDLE
2018-08-15 12:53:33.303 [ d] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
########################################

Alexa is currently idle!
########################################

log following :

What is the expected behavior?

What behavior are you observing?

Provide the steps to reproduce the issue, if applicable:

Tell us about your environment:

What version of the AVS Device SDK are you using?

  <1.8.1>

Tell us what hardware you're using:

  • Desktop / Laptop
  • Raspberry Pi
  • [y ] Other - tell us more:
    arm cortexA9

Tell us about your OS (Type & version):

  • [y ] Linux
  • MacOS
  • Raspbian Stretch
  • Raspbian Jessy
  • Other - tell us more:
@kjkh
Copy link

kjkh commented Aug 16, 2018

Hi @xuqifu,

We have seen similar behavior when a network disconnect occurs and the AudioPlayer is involved: #727. The symptoms look similar:

2018-08-15 12:52:47.551 [ 19] 0 AudioPlayer:onFocusChanged:newFocus=BACKGROUND
2018-08-15 12:52:47.552 [ 18] 1

AudioPlayer:executeOnFocusChanged:from=FOREGROUND,to=BACKGROUND,m_currentActivity=PLAYING
2018-08-15 12:52:47.552 [ 18] 1 AudioPlayer:executeOnFocusChanged:action=pauseMediaPlayer
2018-08-15 12:52:47.552 [ 18] 9 MediaPlayer:pausedCalled
2018-08-15 12:52:47.553 [ 5] 0 MediaPlayer:handlePauseCalled:idPassed=4,currentId=4
2018-08-15 12:52:47.560 [ 16] 0 EventBuilder:buildJsonEventString:messageId=0341cd99-6e9b-45f9-99aa-

3e0e37271bc9,namespace=SpeechRecognizer,name=Recognize
2018-08-15 12:52:49.552 [ 19] E AudioPlayer:onFocusChangedTimedOut:newFocus=BACKGROUND,m_currentActivity=PLAYING

AudioPlayer tries to pause the MediaPlayer, but never receives an onPlaybackPaused callback because MediaPlayer is blocked after the network disconnect.This causes subsequent issues later on with additional requests.

Also, looking through the server side logs, it looks like a SynchronizeState event was sent shortly beforehand. This usually indicates a network reconnect.

Can you verify if network issues occurred shortly before 2018-08-15 12:52:47.552? If so, then we are aware of the issue and will have a fix submitted in a future release.

@xuqifu
Copy link
Author

xuqifu commented Aug 22, 2018

hi @kjkh
the network is always connected , it's appear updateStatesLoopFailed when playing music and say "stop music" . so network is no problem.

@visayamv
Copy link
Contributor

Hi @xuqifu , this issue happens when the network got disconnected and reconnected. When the network is reconnected the music will still play, but when you say stop music, the issue will happen. So we're looking for a reconnection event before 2018-08-15 12:52:47.552

@visayamv visayamv mentioned this issue Aug 25, 2018
Closed
7 tasks
@subjectxbj
Copy link

I met this issue as well.

It seems "AudioPlayer" is required to provide the state:
2018-08-31 01:08:43.045 [ 7] 0 AudioPlayer:provideState:stateRequestToken=13
But I did not see the "AudioPlayer:executeProvideState" is called. Is it because "m_executor" failed to start the new thread to execute "AudioPlayer:executeProvideState"?

############################
#       Listening...       #
############################

2018-08-31 01:08:38.562 [  7] 5 AudioActivityTracker:provideState
2018-08-31 01:08:38.562 [  4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=12
2018-08-31 01:08:38.564 [  8] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2018-08-31 01:08:38.566 [  9] 5 AudioActivityTracker:executeProvideState
2018-08-31 01:08:38.569 [  7] 0 AudioPlayer:provideState:stateRequestToken=12
2018-08-31 01:08:38.569 [  8] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=12
ubus_call ret 0
2018-08-31 01:08:38.569 [  4] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2018-08-31 01:08:38.574 [  9] 0 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2018-08-31 01:08:38.576 [  8] 0 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2018-08-31 01:08:40.576 [  7] E ContextManager:updateStatesLoopFailed:reason=stateProviderTimedOut
2018-08-31 01:08:40.578 [  a] E AudioInputProcessor:executeOnContextFailure:error=STATE_PROVIDER_TIMEDOUT
2018-08-31 01:08:40.579 [  a] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=IDLE
2018-08-31 01:08:40.781 [  f] 0 DialogUXStateAggregator:setState:from=LISTENING,to=IDLE
########################################
#       Alexa is currently idle!       #
########################################

ubus_call ret 0
2018-08-31 01:08:43.031 [  a] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2018-08-31 01:08:43.033 [  f] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
2018-08-31 01:08:43.033 [  7] 0 NotificationsCapabilityAgent:provideState:stateRequestToken=13
2018-08-31 01:08:43.033 [  8] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=13
############################
#       Listening...       #
############################

2018-08-31 01:08:43.035 [  7] 5 AudioActivityTracker:provideState
2018-08-31 01:08:43.035 [  4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=13
2018-08-31 01:08:43.036 [  8] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2018-08-31 01:08:43.040 [  9] 5 AudioActivityTracker:executeProvideState
ubus_call ret 0
2018-08-31 01:08:43.045 [  7] 0 AudioPlayer:provideState:stateRequestToken=13
2018-08-31 01:08:43.045 [  8] 0 ExternalMediaPlayer:executeProvide

@bennyAv10
Copy link

Hi @subjectxbj, @xuqifu,

As #727 has been solved as part of v1.9, Could you try reproducing the issue on 1.9?

Thanks,
Benny

@visayamv
Copy link
Contributor

Hi @subjectxbj @xuqifu , I'm closing this issue, but feel free to reopen if you're still having problems. Thanks

@subjectxbj subjectxbj mentioned this issue May 20, 2019
Closed
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@bennyAv10 @subjectxbj @kjkh @xuqifu @visayamv