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

alexa-smart-screen-sdk error #8

Closed
shubhamsbhosale96 opened this issue Nov 30, 2019 · 8 comments
Closed

alexa-smart-screen-sdk error #8

shubhamsbhosale96 opened this issue Nov 30, 2019 · 8 comments

Comments

@shubhamsbhosale96
Copy link

shubhamsbhosale96 commented Nov 30, 2019 •
edited

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

Briefly summarize your issue:

while testing alexa smart screen sample app by pressing and holding "A" button, It doesn't take voice input. Terminal displays=
E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy

What is the expected behavior?

when press and hold the "A" button, alexa should take voice input and provide output with display template.

What behavior are you observing?

2019-11-30 11:26:33.391 [ 3] 3 GUILogBridge:GUILog:component=WSClient:message sent, type: holdToTalk
2019-11-30 11:26:33.391 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.392 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.393 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.393 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.393 [ 6] 9 GUIClient:onMessage:payload={"type":"holdToTalk"}
2019-11-30 11:26:33.394 [ 6] 9 GUIManager:handleHoldToTalk
2019-11-30 11:26:33.397 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.397 [ 19] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-11-30 11:26:33.398 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.398 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.398 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.399 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"message sent, type: holdToTalk"}
2019-11-30 11:26:33.399 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.399 [ 3] 3 GUILogBridge:GUILog:component=WSClient:message sent, type: holdToTalk
2019-11-30 11:26:33.400 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.400 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.400 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.400 [ 6] 9 GUIClient:onMessage:payload={"type":"holdToTalk"}
2019-11-30 11:26:33.401 [ 6] 9 GUIManager:handleHoldToTalk
2019-11-30 11:26:33.401 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.401 [ 19] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-11-30 11:26:33.402 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.403 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.403 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:26:33.403 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"message sent, type: holdToTalk"}

2019-11-30 11:39:44.117 [ 37] 9 HTTP2Transport:onActivity
2019-11-30 11:39:44.117 [ 37] 9 HTTP2MimeResponseDecoder:onResponseFinished:status=COMPLETE
2019-11-30 11:39:44.117 [ 37] 9 MimeResponseSink:onResponseFinished:status=COMPLETE
2019-11-30 11:39:44.117 [ 37] 7 MessageRequestHandler:onResponseFinished:status=COMPLETE,responseCode=204
2019-11-30 11:39:44.118 [ 37] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-11-30 11:39:44.118 [ 37] 7 MessageRequestHandler:reportMessageRequestFinished
2019-11-30 11:39:44.118 [ 37] 7 HTTP2Transport:onMessageRequestFinished:countOfUnfinishedMessageHandlers=0
2019-11-30 11:39:44.118 [ 37] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS_NO_CONTENT
2019-11-30 11:39:44.118 [ 37] 5 AudioInputProcessor:stopCapture:reason=streamClosed
2019-11-30 11:39:44.118 [ 37] 0 LibcurlHTTP2Connection:streamFinished:streamId=AVSEvent-31,result=No error,CURLcode=0
2019-11-30 11:39:44.118 [ 37] 9 LibcurlHTTP2Connection:releaseStream:streamId=AVSEvent-31
2019-11-30 11:39:44.118 [ 37] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-11-30 11:39:44.118 [ 37] 7 MessageRequestHandler:reportMessageRequestFinished
2019-11-30 11:39:48.323 [ c] 0 DialogUXStateAggregator:transitionFromThinkingTimedOut
2019-11-30 11:39:48.323 [ c] 0 DialogUXStateAggregator:setState:from=THINKING,to=IDLE
2019-11-30 11:39:48.323 [ c] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2019-11-30 11:39:48.323 [ 19] 1 FocusManager:releaseChannel:channelName=Dialog
2019-11-30 11:39:48.323 [ 5] 9 WebSocketServer:writeMessageBegin
2019-11-30 11:39:48.323 [ c] 5 AlexaPresentation:onDialogUXStateChanged:state=IDLE
2019-11-30 11:39:48.324 [ 5] 9 WebSocket:AccessLog
2019-11-30 11:39:48.324 [ 19] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2019-11-30 11:39:48.324 [ 5] 9 WebSocket:AccessLog
2019-11-30 11:39:48.324 [ 5] 9 WebSocketServer:writeMessageComplete
2019-11-30 11:39:48.324 [ 17] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE
2019-11-30 11:39:48.324 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:39:48.324 [ 6] 9 WebSocket:AccessLog
2019-11-30 11:39:48.324 [ 6] 9 WebSocket:AccessLog
#################################

ALEXA STATE: IDLE

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

Provide the steps to reproduce the issue, if applicable:

cd /home/pi/sdk_folder/ss-build
PA_ALSA_PLUGHW=1 ./modules/Alexa/SampleApp/src/SampleApp -C
/home/pi/sdk_folder/sdk-build/Integration/AlexaClientSDKConfig.json -C
/home/pi/sdk_folder/alexa-smart-screen-sdk/modules/GUI/config/SmartScreenSDKConfig.json -L DEBUG9

Tell us about your environment:

What version of the AVS Device SDK are you using?

  sdk version : 1.15.0
  SmartScreenSDKVersion: 2.0.1

Tell us what hardware you're using:

  • [X ] Raspberry Pi

Tell us about your OS (Type & version):

  • [ X] Raspbian Stretch
@bennyAv10
Copy link

Hi @shubhamsbhosale96,

Could you attach the log messages starting right when SampleApp has started?

Thanks,
Benny

@shubhamsbhosale96
Copy link
Author

shubhamsbhosale96 commented Dec 3, 2019 •
edited by powj

Hi @bennyAv10
for cmmand: cd /home/pi/sdk_folder/ss-build
PA_ALSA_PLUGHW=1 ./modules/Alexa/SampleApp/src/SampleApp -C
/home/pi/sdk_folder/sdk-build/Integration/AlexaClientSDKConfig.json -C
/home/pi/sdk_folder/alexa-smart-screen-sdk/modules/GUI/config/SmartScreenSDKConfig.json -L INFO

for INFO
log messages are as given below

pi@raspberrypi:~/sdk_folder/ss-build $ cd /home/pi/sdk_folder/ss-build
pi@raspberrypi:~/sdk_folder/ss-build $ PA_ALSA_PLUGHW=1 ./modules/Alexa/SampleApp/src/SampleApp -C \
> /home/pi/sdk_folder/sdk-build/Integration/AlexaClientSDKConfig.json -C \
> /home/pi/sdk_folder/alexa-smart-screen-sdk/modules/GUI/config/SmartScreenSDKConfig.json -L INFO
2019-12-03 05:49:55.855 [  1] I sdkVersion: 1.15.0
SmartScreenSDKVersion 2.0.1
configFile /home/pi/sdk_folder/sdk-build/Integration/AlexaClientSDKConfig.json
configFile /home/pi/sdk_folder/alexa-smart-screen-sdk/modules/GUI/config/SmartScreenSDKConfig.json
Running app with log level: INFO
2019-12-03 05:49:56.047 [  1] I LocaleAssetsManager:initialize:supportedWakeWords=NONE
2019-12-03 05:49:56.068 [  7] I WebSocketServer:Listening for websocket connections:interface=127.0.0.1,port=8933
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
2019-12-03 05:49:56.173 [  1] I Setting:handleSetValue:value=false
2019-12-03 05:49:56.180 [  1] I Setting:handleSetValue:value="NONE"
2019-12-03 05:49:56.184 [  1] I Setting:handleSetValue:value="NONE"
2019-12-03 05:49:56.189 [  1] I Setting:handleSetValue:value="America/Vancouver"
2019-12-03 05:49:56.196 [ 11] I LocaleAssetsManager:changeAssets:Locale=["en-US"],WakeWords=[]
#################################################
#       NOTIFICATION INDICATOR STATE: OFF       #
#################################################

2019-12-03 05:49:56.302 [  5] E WebSocketServer:server::send:errorCode=15,errorCategory=websocketpp
#######################################
#       ALEXA STATE: CONNECTING       #
#######################################

2019-12-03 05:49:56.308 [ 26] E ContextManager:buildStateFailed:reason=parseError,payload=
2019-12-03 05:49:56.308 [ 26] E ContextManager:buildContextFailed:reason=buildStateFailed
2019-12-03 05:49:56.309 [ 26] E PostConnectSynchronizer:onContextFailure:error=BUILD_CONTEXT_ERROR
2019-12-03 05:49:56.310 [ 26] E ContextManager:buildStateFailed:reason=parseError,payload=
2019-12-03 05:49:56.310 [ 26] E ContextManager:buildContextFailed:reason=buildStateFailed
2019-12-03 05:49:56.310 [ 26] E PostConnectSynchronizer:onContextFailure:error=BUILD_CONTEXT_ERROR
2019-12-03 05:49:56.311 [ 27] W PostConnectSynchronizer:waitingToRetryPostConnectOperation:timeoutMs=904
2019-12-03 05:49:57.217 [ 26] E ContextManager:buildStateFailed:reason=parseError,payload=
2019-12-03 05:49:57.217 [ 26] E ContextManager:buildContextFailed:reason=buildStateFailed
2019-12-03 05:49:57.217 [ 26] E PostConnectSynchronizer:onContextFailure:error=BUILD_CONTEXT_ERROR
2019-12-03 05:49:57.218 [ 27] W PostConnectSynchronizer:waitingToRetryPostConnectOperation:timeoutMs=2804
###########################
#       Authorized!       #
###########################

2019-12-03 05:49:58.223 [ 28] E WebSocketServer:server::send:errorCode=15,errorCategory=websocketpp
2019-12-03 05:50:00.024 [ 26] E ContextManager:buildStateFailed:reason=parseError,payload=
2019-12-03 05:50:00.024 [ 26] E ContextManager:buildContextFailed:reason=buildStateFailed
2019-12-03 05:50:00.024 [ 26] E PostConnectSynchronizer:onContextFailure:error=BUILD_CONTEXT_ERROR
2019-12-03 05:50:00.025 [ 27] W PostConnectSynchronizer:waitingToRetryPostConnectOperation:timeoutMs=4105
2019-12-03 05:50:02.167 [  7] I WebSocketServer:onConnectionOpen:remoteHost=127.0.0.1\:39008
#################################################
#       Message Server Connection Opened.       #
#################################################

#######################################
#       ALEXA STATE: CONNECTING       #
#######################################

2019-12-03 05:50:02.179 [  7] I GUIClient:processInitResponse:APL Max Version=1.2
2019-12-03 05:50:04.844 [  a] I DirectiveSequencer:onDirective:directive={"namespace\:"System"\,name\:"SetEndpoint"\,messageId\:"faa9a62b-8706-4bb4-82d2-33289ffb3cb5"\,dialogRequestId\:""}
2019-12-03 05:50:04.845 [ 29] I DirectiveRouter:preHandleDirective:messageId=faa9a62b-8706-4bb4-82d2-33289ffb3cb5,action=calling
2019-12-03 05:50:04.847 [ 2a] I DirectiveRouter:handleDirective:messageId=faa9a62b-8706-4bb4-82d2-33289ffb3cb5,action=calling
2019-12-03 05:50:04.854 [  c] E MessageRouter:sendFailed:reason=noActiveTransport
#################################
#       ALEXA STATE: IDLE       #
#################################

#########################################
#       ALEXA STATE: DISCONNECTED       #
#########################################

2019-12-03 05:50:04.946 [ 2b] I LibcurlHTTP2Connection:cancelStream:streamId=AVSDownChannel-1
#################################
#       ALEXA STATE: IDLE       #
#################################

2019-12-03 05:50:24.537 [  7] I WebSocketServer:onConnectionClose
#################################################
#       Message Server Connection Closed.       #
#################################################

2019-12-03 05:50:24.538 [  5] E WebSocketServer:server::send:errorCode=15,errorCategory=websocketpp
#################################
#       ALEXA STATE: IDLE       #
#################################

2019-12-03 05:50:25.631 [  7] I WebSocketServer:onConnectionOpen:remoteHost=127.0.0.1\:39020
#################################################
#       Message Server Connection Opened.       #
#################################################

#################################
#       ALEXA STATE: IDLE       #
#################################

2019-12-03 05:50:25.654 [  7] I GUIClient:processInitResponse:APL Max Version=1.2
2019-12-03 05:50:04.844 [  a] I DirectiveSequencer:onDirective:directive={"namespace\:"System"\,name\:"SetEndpoint"\,messageId\:"faa9a62b-8706-4bb4-82d2-33289ffb3cb5"\,dialogRequestId\:""}
2019-12-03 05:50:04.845 [ 29] I DirectiveRouter:preHandleDirective:messageId=faa9a62b-8706-4bb4-82d2-33289ffb3cb5,action=calling
2019-12-03 05:50:04.847 [ 2a] I DirectiveRouter:handleDirective:messageId=faa9a62b-8706-4bb4-82d2-33289ffb3cb5,action=calling
2019-12-03 05:50:04.854 [  c] E MessageRouter:sendFailed:reason=noActiveTransport
#################################
#       ALEXA STATE: IDLE       #
#################################

#########################################
#       ALEXA STATE: DISCONNECTED       #
#########################################

2019-12-03 05:50:04.946 [ 2b] I LibcurlHTTP2Connection:cancelStream:streamId=AVSDownChannel-1
#################################
#       ALEXA STATE: IDLE       #
#################################

2019-12-03 05:50:24.537 [  7] I WebSocketServer:onConnectionClose
#################################################
#       Message Server Connection Closed.       #
#################################################

2019-12-03 05:50:24.538 [  5] E WebSocketServer:server::send:errorCode=15,errorCategory=websocketpp
#################################
#       ALEXA STATE: IDLE       #
#################################

2019-12-03 05:50:25.631 [  7] I WebSocketServer:onConnectionOpen:remoteHost=127.0.0.1\:39020
#################################################
#       Message Server Connection Opened.       #
#################################################

#################################
#       ALEXA STATE: IDLE       #
#################################

2019-12-03 05:50:25.654 [  7] I GUIClient:processInitResponse:APL Max Version=1.2
2019-12-03 05:57:36.113 [  7] E WebSocket:ErrorLog
2019-12-03 05:57:36.113 [  7] I WebSocketServer:onConnectionClose
#################################################
#       Message Server Connection Closed.       #
#################################################

2019-12-03 05:57:36.114 [  5] E WebSocketServer:server::send:errorCode=15,errorCategory=websocketpp
#################################
#       ALEXA STATE: IDLE       #
#################################

2019-12-03 05:57:36.579 [  7] I WebSocketServer:onConnectionOpen:remoteHost=127.0.0.1\:39078
#################################################
#       Message Server Connection Opened.       #
#################################################

#################################
#       ALEXA STATE: IDLE       #
#################################

2019-12-03 05:57:36.625 [  7] I GUIClient:processInitResponse:APL Max Version=1.2
######################################
#       ALEXA STATE: LISTENING       #
######################################

2019-12-03 06:01:01.808 [ 14] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=,newValue=2633babd-db3f-4941-a6ff-2dffedefbaa0
2019-12-03 06:01:02.303 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
#####################################
#       ALEXA STATE: THINKING       #
#####################################

2019-12-03 06:01:02.331 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.333 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.400 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.407 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.411 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.416 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.495 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.499 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.503 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.507 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.510 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.513 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.567 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.570 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.698 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.701 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.705 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.709 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.712 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.715 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.718 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.720 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.721 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.727 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.728 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.729 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.792 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.793 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.865 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.869 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.873 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.875 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.880 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.883 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.925 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.946 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.958 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:02.969 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.031 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.040 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.047 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.064 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.087 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.095 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.102 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.115 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.134 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.139 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
2019-12-03 06:01:03.195 [ 14] E AudioInputProcessor:executeRecognizeFailed:reason=Barge-in is not permitted while busy
#################################
#       ALEXA STATE: IDLE       #
#################################

browser window when sample app started
html_page

@shubhamsbhosale96
Copy link
Author

shubhamsbhosale96 commented Dec 3, 2019 •
edited by powj

Hi @bennyAv10
for cmmand: cd /home/pi/sdk_folder/ss-build
PA_ALSA_PLUGHW=1 ./modules/Alexa/SampleApp/src/SampleApp -C
/home/pi/sdk_folder/sdk-build/Integration/AlexaClientSDKConfig.json -C
/home/pi/sdk_folder/alexa-smart-screen-sdk/modules/GUI/config/SmartScreenSDKConfig.json -L DEBUG9

for DEBUG9
log messages are as given below

2019-12-03 06:59:39.561 [ 1] 1 AlexaPresentation:setAPLMaxVersion:APLVersion=1.2
2019-12-03 06:59:39.564 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:39.565 [ c] 5 AlexaPresentation:onDialogUXStateChanged:state=IDLE
2019-12-03 06:59:39.568 [ 1] 5 ExternalMediaPlayer:setObserver
2019-12-03 06:59:39.569 [ 1] 1 AudioPlayer:setObserver
2019-12-03 06:59:39.571 [ 1] 5 AlexaPresentation:addObserver
2019-12-03 06:59:39.571 [ 1] 9 VisualCharacteristics:getVisualCharacteristicsCapabilityConfiguration
2019-12-03 06:59:39.572 [ 2b] 5 AlexaPresentation:addObserverInExecutor
2019-12-03 06:59:39.573 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:39.582 [ c] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2019-12-03 06:59:39.596 [ 1] 5 SmartScreenClient:bluetoothCapabilityAgentDisabled:reason=nullBluetoothDeviceManager
2019-12-03 06:59:39.598 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x12f7470,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-12-03 06:59:39.599 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x12f86f8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.599 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x12f86f8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.599 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x12f86f8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=AdjustSeekPosition,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=SetSeekPosition,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableShuffle,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableShuffle,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeat,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeatOne,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Favorite,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=FastForward,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Previous,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.600 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=StartOver,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Next,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableRepeat,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Rewind,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Stop,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Pause,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Play,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Logout,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Login,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Unfavorite,handler=0x1302318,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.601 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Play,handler=0x1302318,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.602 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetSpeechConfirmation,handler=0x12f6cb8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.602 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetWakeWords,handler=0x12f6cb8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.602 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x12f6cb8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.602 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x12f6cb8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2019-12-03 06:59:39.602 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetEndOfSpeechOffset,handler=0x12f6cb8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.602 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetWakeWordConfirmation,handler=0x12f6cb8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.603 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=AdjustVolume,handler=0x12f9e00,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.603 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x12f9e00,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.603 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlerts,handler=0x12f9e00,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.603 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x12f9e00,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.603 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetVolume,handler=0x12f9e00,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.604 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetEndpoint,handler=0x13087d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.604 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetLocales,handler=0x1307a30,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.605 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetTimeZone,handler=0x1305f70,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.606 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ReportState,handler=0x13092e0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.606 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x12f6754,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.606 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x12f9140,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.607 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x12f9140,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.607 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x12f9140,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2019-12-03 06:59:39.607 [ 1] 5 AlexaPresentation:getConfiguration
2019-12-03 06:59:39.608 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.Presentation.APL,name=ExecuteCommands,handler=0x13046d0,policy= Mediums:MEDIUMS_AUDIO_AND_VISUAL11 .isBlocking:True
2019-12-03 06:59:39.609 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.Presentation.APL,name=RenderDocument,handler=0x13046d0,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:True
2019-12-03 06:59:39.609 [ 1] 5 TemplateRuntime:getConfiguration
2019-12-03 06:59:39.609 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x1305218,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-12-03 06:59:39.609 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x1305218,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2019-12-03 06:59:39.610 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=ClearIndicator,handler=0x12fdeb4,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.610 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=SetIndicator,handler=0x12fdeb4,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.610 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=InteractionModel,name=NewDialogRequest,handler=0x1303728,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.610 [ 1] 5 EqualizerController:getConfiguration
2019-12-03 06:59:39.610 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=AdjustBands,handler=0x1307344,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.610 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=SetMode,handler=0x1307344,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.611 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=ResetBands,handler=0x1307344,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.611 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=EqualizerController,name=SetBands,handler=0x1307344,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.611 [ 1] 5 DoNotDisturbCapabilityAgent:getConfiguration
2019-12-03 06:59:39.611 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.DoNotDisturb,name=SetDoNotDisturb,handler=0x12f2c80,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:39.619 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled
2019-12-03 06:59:39.621 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x12afad8
2019-12-03 06:59:39.622 [ 1] 5 NotificationsCapabilityAgent:addObserver
2019-12-03 06:59:39.624 [ 1] 5 TemplateRuntime:addObserver
#################################################

NOTIFICATION INDICATOR STATE: OFF
#################################################

2019-12-03 06:59:39.625 [ 1] 5 AlexaPresentation:addObserver
2019-12-03 06:59:39.625 [ 2c] 5 TemplateRuntime:addObserverInExecutor
2019-12-03 06:59:39.625 [ 2b] 5 AlexaPresentation:addObserverInExecutor
2019-12-03 06:59:39.626 [ 1] 1 AudioPlayer:addObserver
2019-12-03 06:59:39.628 [ 1] 5 CBLAuthDelegate:addAuthObserver:observer=0x12ae508
2019-12-03 06:59:39.628 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x12ae50c
2019-12-03 06:59:39.628 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x12eaa88
2019-12-03 06:59:39.629 [ 1] 3 GUIClient:run
2019-12-03 06:59:39.642 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.642 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.642 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.643 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.643 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.643 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.643 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.643 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.643 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.643 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.643 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.644 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.644 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.644 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.644 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.645 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.645 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.645 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.645 [ 7] 0 CapabilitiesDelegate:getCapabilityConfigsStringFromJsonFailed::Interface configurations not available
2019-12-03 06:59:39.648 [ 7] 5 CapabilitiesDelegate:setCapabilitiesState:newCapabilitiesState=SUCCESS
2019-12-03 06:59:39.648 [ 7] 9 CapabilitiesDelegate:callingOnCapabilitiesStateChange:state=SUCCESS,error=SUCCESS
2019-12-03 06:59:39.649 [ 7] 5 AVSConnectionManager:enable
2019-12-03 06:59:39.649 [ 7] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=PENDING
2019-12-03 06:59:39.650 [ 7] 5 LibcurlHTTP2ConnectionFactory:createHTTP2Connection
2019-12-03 06:59:39.651 [ 31] 5 LibcurlHTTP2Connection:networkLoop
2019-12-03 06:59:39.651 [ 7] 5 HTTP2Transport:create:authDelegate=0x12b8930,avsEndpoint=https://alexa.na.gateway.devices.a2z.com,http2Connection=0x7000c490,messageConsumer=0x12eb298,attachmentManager=0x12eb1e0,transportObserver=0x12eb294,postConnectFactory=0x12af8c8
2019-12-03 06:59:39.652 [ 7] 7 HTTP2Transport:HTTP2Transport:authDelegate=0x12b8930,avsEndpoint=https://alexa.na.gateway.devices.a2z.com,http2Connection=0x7000c490,messageConsumer=0x12eb298,attachmentManager=0x12eb1e0,transportObserver=0x12eb294,postConnectFactory=0x12af8c8
2019-12-03 06:59:39.652 [ 7] 5 HTTP2Transport:connect
2019-12-03 06:59:39.652 [ 7] 5 HTTP2Transport:setStateLocked:newState=AUTHORIZING,changedReason=ACL_CLIENT_REQUEST
2019-12-03 06:59:39.653 [ 26] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=PENDING,reason=ACL_CLIENT_REQUEST
2019-12-03 06:59:39.654 [ 32] 7 HTTP2Transport:mainLoop
2019-12-03 06:59:39.654 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 06:59:39.654 [ 32] 0 PostConnectSynchronizer:doPostConnect
2019-12-03 06:59:39.655 [ 5] E WebSocketServer:server::send:errorCode=15,errorCategory=websocketpp
2019-12-03 06:59:39.655 [ 5] 9 WebSocketServer:writeMessageComplete
2019-12-03 06:59:39.655 [ 32] 5 PostConnectSynchronizer:setState:from=IDLE,to=RUNNING
#######################################

ALEXA STATE: CONNECTING
#######################################

2019-12-03 06:59:39.655 [ 32] 5 HTTP2Transport:handleAuthorizing
2019-12-03 06:59:39.655 [ 32] 5 CBLAuthDelegate:addAuthObserver:observer=0x7000c998
2019-12-03 06:59:39.655 [ 32] 5 HTTP2Transport:onAuthStateChange:newState=UNINITIALIZED,error=SUCCESS
2019-12-03 06:59:39.656 [ 33] 5 PostConnectSynchronizer:mainLoop
2019-12-03 06:59:39.656 [ 33] 5 PostConnectSynchronizer:setState:from=RUNNING,to=FETCHING
2019-12-03 06:59:39.657 [ 34] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Display.Window,name=WindowState
2019-12-03 06:59:39.657 [ 34] 5 AudioActivityTracker:provideState
2019-12-03 06:59:39.658 [ 34] 0 AudioPlayer:provideState:stateRequestToken=1
2019-12-03 06:59:39.658 [ 34] 9 SpeechSynthesizer:provideState:token=1
2019-12-03 06:59:39.658 [ 1d] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2019-12-03 06:59:39.659 [ 34] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=1
2019-12-03 06:59:39.659 [ 1d] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioPlayer,name=PlaybackState
2019-12-03 06:59:39.659 [ 27] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=1
2019-12-03 06:59:39.659 [ 1a] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=1
2019-12-03 06:59:39.661 [ 16] 5 AudioActivityTracker:executeProvideState
2019-12-03 06:59:39.659 [ 2b] 3 AlexaPresentation:executeProvideState:token=1
2019-12-03 06:59:39.662 [ 1a] 9 ContextManager:updateStateLocked:action=updatedState,namespace=SpeechSynthesizer,name=SpeechState
2019-12-03 06:59:39.664 [ 27] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-12-03 06:59:39.665 [ 34] 5 VisualActivityTracker:provideState
2019-12-03 06:59:39.666 [ 2b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 06:59:39.667 [ 16] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2019-12-03 06:59:39.668 [ 29] 5 VisualActivityTracker:executeProvideState
2019-12-03 06:59:39.669 [ 29] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2019-12-03 06:59:39.669 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2019-12-03 06:59:39.670 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-12-03 06:59:39.670 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2019-12-03 06:59:39.671 [ 28] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers
2019-12-03 06:59:39.671 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-12-03 06:59:39.671 [ 34] E ContextManager:buildStateFailed:reason=parseError,payload=
2019-12-03 06:59:39.672 [ 34] E ContextManager:buildContextFailed:reason=buildStateFailed
2019-12-03 06:59:39.672 [ 34] E PostConnectSynchronizer:onContextFailure:error=BUILD_CONTEXT_ERROR
2019-12-03 06:59:39.672 [ 34] 5 PostConnectSynchronizer:setState:from=FETCHING,to=RUNNING
2019-12-03 06:59:39.672 [ 33] 5 PostConnectSynchronizer:setState:from=RUNNING,to=FETCHING
2019-12-03 06:59:39.673 [ 34] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Display.Window,name=WindowState
2019-12-03 06:59:39.673 [ 34] 5 AudioActivityTracker:provideState
2019-12-03 06:59:39.673 [ 34] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=2
2019-12-03 06:59:39.674 [ 34] 5 VisualActivityTracker:provideState
2019-12-03 06:59:39.674 [ 2b] 3 AlexaPresentation:executeProvideState:token=2
2019-12-03 06:59:39.674 [ 2b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 06:59:39.673 [ 16] 5 AudioActivityTracker:executeProvideState
2019-12-03 06:59:39.675 [ 16] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2019-12-03 06:59:39.674 [ 27] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=2
2019-12-03 06:59:39.675 [ 27] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-12-03 06:59:39.676 [ 29] 5 VisualActivityTracker:executeProvideState
2019-12-03 06:59:39.676 [ 29] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2019-12-03 06:59:39.677 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=2
2019-12-03 06:59:39.677 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-12-03 06:59:39.677 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=2
2019-12-03 06:59:39.677 [ 28] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers
2019-12-03 06:59:39.677 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-12-03 06:59:39.677 [ 34] E ContextManager:buildStateFailed:reason=parseError,payload=
2019-12-03 06:59:39.677 [ 34] E ContextManager:buildContextFailed:reason=buildStateFailed
2019-12-03 06:59:39.678 [ 34] E PostConnectSynchronizer:onContextFailure:error=BUILD_CONTEXT_ERROR
2019-12-03 06:59:39.678 [ 34] 5 PostConnectSynchronizer:setState:from=FETCHING,to=RUNNING
2019-12-03 06:59:39.678 [ 33] W PostConnectSynchronizer:waitingToRetryPostConnectOperation:timeoutMs=1321
2019-12-03 06:59:39.679 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:39.720 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:39.796 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:39.897 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:39.997 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:40.098 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:40.198 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:40.299 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:40.335 [ a] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2019-12-03 06:59:40.335 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.338 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.338 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.339 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.339 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.339 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.339 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.339 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.347 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.347 [ a] 9 LibCurlHttpContentFetcher:headerCallback:type=content-length,length=419
2019-12-03 06:59:40.348 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.348 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.348 [ a] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2019-12-03 06:59:40.348 [ a] 9 LibCurlHttpContentFetcher:bodyCallback::End of header found.
2019-12-03 06:59:40.348 [ 9] 9 InternetConnectionMonitor:testConnection:contentLength=419
2019-12-03 06:59:40.349 [ a] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_HEADER,newState=HEADER_DONE:State transition
2019-12-03 06:59:40.349 [ 9] 9 LibCurlHttpContentFetcher:stateTransition:oldState=HEADER_DONE,newState=FETCHING_BODY:State transition
2019-12-03 06:59:40.449 [ a] 9 LibCurlHttpContentFetcher:bodyCallback:totalContentReceived=419,contentLength=419,currentContentReceived=419,remaining=0,totalBytesWritten=419
2019-12-03 06:59:40.450 [ a] 9 LibCurlHttpContentFetcher:transferThread::end
2019-12-03 06:59:40.450 [ a] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_BODY,newState=BODY_DONE:State transition
2019-12-03 06:59:40.550 [ 9] 9 InternetConnectionMonitor:testConnection::alreadyReadAllBytes
2019-12-03 06:59:40.550 [ 9] 9 InternetConnectionMonitor:testConnection::Finished reading
2019-12-03 06:59:40.551 [ 9] 5 InternetConnectionMonitor:updateConnectionStatus:connected=true
2019-12-03 06:59:40.551 [ 9] 5 InternetConnectionMonitor:notifyObserversLocked
2019-12-03 06:59:40.551 [ 9] 5 AVSConnectionManager:onConnectionStatusChanged:connected=true
2019-12-03 06:59:40.551 [ 9] 9 LibCurlHttpContentFetcher:~LibCurlHttpContentFetcher
2019-12-03 06:59:40.999 [ 33] 5 PostConnectSynchronizer:setState:from=RUNNING,to=FETCHING
2019-12-03 06:59:41.000 [ 34] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Display.Window,name=WindowState
2019-12-03 06:59:41.000 [ 34] 5 AudioActivityTracker:provideState
2019-12-03 06:59:41.000 [ 16] 5 AudioActivityTracker:executeProvideState
2019-12-03 06:59:41.000 [ 2b] 3 AlexaPresentation:executeProvideState:token=3
2019-12-03 06:59:41.001 [ 34] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=3
2019-12-03 06:59:41.001 [ 16] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2019-12-03 06:59:41.001 [ 2b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 06:59:41.001 [ 34] 5 VisualActivityTracker:provideState
2019-12-03 06:59:41.002 [ 29] 5 VisualActivityTracker:executeProvideState
2019-12-03 06:59:41.002 [ 27] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=3
2019-12-03 06:59:41.002 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=3
2019-12-03 06:59:41.002 [ 29] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2019-12-03 06:59:41.003 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-12-03 06:59:41.003 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=3
2019-12-03 06:59:41.003 [ 28] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers
2019-12-03 06:59:41.003 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-12-03 06:59:41.003 [ 27] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-12-03 06:59:41.003 [ 34] E ContextManager:buildStateFailed:reason=parseError,payload=
2019-12-03 06:59:41.003 [ 34] E ContextManager:buildContextFailed:reason=buildStateFailed
2019-12-03 06:59:41.003 [ 34] E PostConnectSynchronizer:onContextFailure:error=BUILD_CONTEXT_ERROR
2019-12-03 06:59:41.004 [ 34] 5 PostConnectSynchronizer:setState:from=FETCHING,to=RUNNING
2019-12-03 06:59:41.004 [ 33] W PostConnectSynchronizer:waitingToRetryPostConnectOperation:timeoutMs=3600
2019-12-03 06:59:41.630 [ 8] 5 HttpPost:doPostSucceeded:code=200
2019-12-03 06:59:41.631 [ 8] 5 CBLAuthDelegate:receiveTokenResponse:code=200
2019-12-03 06:59:41.631 [ 8] 5 CBLAuthDelegate:mapHTTPStatusToError:code=200,error=SUCCESS
2019-12-03 06:59:41.631 [ 8] 5 CBLAuthDelegate:setAuthError:authError=SUCCESS
2019-12-03 06:59:41.631 [ 8] 5 CBLAuthDelegate:setRefreshToken
2019-12-03 06:59:41.631 [ 8] 5 SQLiteCBLAuthDelegateStorage:setRefreshToken
2019-12-03 06:59:43.343 [ 8] 5 CBLAuthDelegate:setAuthState:newAuthState=REFRESHED
2019-12-03 06:59:43.344 [ 8] 9 CBLAuthDelegate:callingOnAuthStateChange:state=REFRESHED,error=SUCCESS
2019-12-03 06:59:43.344 [ 8] 5 HTTP2Transport:onAuthStateChange:newState=REFRESHED,error=SUCCESS
2019-12-03 06:59:43.344 [ 8] 5 HTTP2Transport:setStateLocked:newState=CONNECTING,changedReason=SUCCESS
2019-12-03 06:59:43.344 [ 8] 9 WebSocketServer:writeMessageBegin
###########################

Authorized!
###########################

2019-12-03 06:59:43.344 [ 8] E WebSocketServer:server::send:errorCode=15,errorCategory=websocketpp
2019-12-03 06:59:43.344 [ 8] 9 WebSocketServer:writeMessageComplete
2019-12-03 06:59:43.344 [ 32] 5 HTTP2Transport:handleConnecting
2019-12-03 06:59:43.345 [ 32] 9 DownchannelHandler:create:context=0x7000c99c
2019-12-03 06:59:43.345 [ 32] 5 ExchangeHandler:ExchangeHandler:context=0x7000c99c
2019-12-03 06:59:43.345 [ 32] 9 DownchannelHandler:DownchannelHandler:context=0x7000c99c
2019-12-03 06:59:43.346 [ 32] 9 MimeResponseSink:MimeResponseSink:handler=0x72802a58
2019-12-03 06:59:43.347 [ 32] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2019-12-03 06:59:43.347 [ 32] 7 HTTP2Transport:createAndSendRequest:type=GET
2019-12-03 06:59:43.347 [ 32] 9 DownchannelHandler:getRequestHeaderLines
2019-12-03 06:59:43.348 [ 31] 9 LibcurlHTTP2Connection:insertActiveStream:handle=0x72803c50,streamId=AVSDownChannel-1
2019-12-03 06:59:44.604 [ 33] 5 PostConnectSynchronizer:setState:from=RUNNING,to=FETCHING
2019-12-03 06:59:44.604 [ 34] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Display.Window,name=WindowState
2019-12-03 06:59:44.604 [ 34] 5 AudioActivityTracker:provideState
2019-12-03 06:59:44.605 [ 16] 5 AudioActivityTracker:executeProvideState
2019-12-03 06:59:44.605 [ 34] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=4
2019-12-03 06:59:44.605 [ 2b] 3 AlexaPresentation:executeProvideState:token=4
2019-12-03 06:59:44.605 [ 16] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2019-12-03 06:59:44.605 [ 27] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=4
2019-12-03 06:59:44.605 [ 2b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 06:59:44.606 [ 34] 5 VisualActivityTracker:provideState
2019-12-03 06:59:44.606 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=4
2019-12-03 06:59:44.606 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-12-03 06:59:44.606 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=4
2019-12-03 06:59:44.606 [ 28] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers
2019-12-03 06:59:44.606 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-12-03 06:59:44.606 [ 27] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-12-03 06:59:44.606 [ 29] 5 VisualActivityTracker:executeProvideState
2019-12-03 06:59:44.607 [ 29] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2019-12-03 06:59:44.607 [ 34] E ContextManager:buildStateFailed:reason=parseError,payload=
2019-12-03 06:59:44.607 [ 34] E ContextManager:buildContextFailed:reason=buildStateFailed
2019-12-03 06:59:44.607 [ 34] E PostConnectSynchronizer:onContextFailure:error=BUILD_CONTEXT_ERROR
2019-12-03 06:59:44.607 [ 34] 5 PostConnectSynchronizer:setState:from=FETCHING,to=RUNNING
2019-12-03 06:59:44.607 [ 33] W PostConnectSynchronizer:waitingToRetryPostConnectOperation:timeoutMs=3335
2019-12-03 06:59:45.105 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=13,userData=0x72803bf0
2019-12-03 06:59:45.105 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:45.105 [ 31] 9 MimeResponseSink:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:45.105 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:45.105 [ 31] 5 DownchannelHandler:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:45.106 [ 31] 7 HTTP2Transport:onDownchannelConnected
2019-12-03 06:59:45.106 [ 31] 5 HTTP2Transport:setStateLocked:newState=POST_CONNECTING,changedReason=SUCCESS
2019-12-03 06:59:45.106 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=HTTP/2 200

2019-12-03 06:59:45.106 [ 32] 5 HTTP2Transport:handlePostConnecting
2019-12-03 06:59:45.106 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=HTTP/2 200

2019-12-03 06:59:45.106 [ 32] 7 HTTP2Transport:sendMessagesAndPings:whileState=POST_CONNECTING
2019-12-03 06:59:45.106 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:45.107 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=64,userData=0x72803bf0
2019-12-03 06:59:45.107 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-headers: authorization,x-amz-access-token

2019-12-03 06:59:45.107 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-headers: authorization,x-amz-access-token

2019-12-03 06:59:45.107 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:45.107 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=32,userData=0x72803bf0
2019-12-03 06:59:45.107 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:45.107 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:45.108 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:45.108 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=81,userData=0x72803bf0
2019-12-03 06:59:45.108 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=content-type: multipart/related; boundary=------abcde123; type=application/json

2019-12-03 06:59:45.108 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=content-type: multipart/related; boundary=------abcde123; type=application/json

2019-12-03 06:59:45.108 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:45.108 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=20,userData=0x72803bf0
2019-12-03 06:59:45.108 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid:

2019-12-03 06:59:45.108 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid:

2019-12-03 06:59:45.108 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:45.109 [ 31] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid:
2019-12-03 06:59:45.109 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=2,userData=0x72803bf0
2019-12-03 06:59:45.109 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=

2019-12-03 06:59:45.109 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=

2019-12-03 06:59:45.109 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:45.109 [ 31] 9 LibcurlHTTP2Request:writeCallback:id=AVSDownChannel-1,size=1,nmemb=18,userData=0x72803bf0
2019-12-03 06:59:45.109 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveData:size=18
2019-12-03 06:59:47.733 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.734 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.734 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.735 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.735 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.737 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.738 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.738 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.738 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.739 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.740 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.740 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.740 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.740 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.741 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.742 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.742 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.745 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.745 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.746 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.746 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.748 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.748 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.752 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.753 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.753 [ 6] I WebSocketServer:onConnectionOpen:remoteHost=127.0.0.1:42198
2019-12-03 06:59:47.753 [ 6] 3 GUIClient:onConnectionOpened
2019-12-03 06:59:47.753 [ 35] 9 GUIClient:sendInitRequestAndWait::waiting for server to be ready
2019-12-03 06:59:47.754 [ 35] 9 WebSocketServer:writeMessageBegin
#################################################

Message Server Connection Opened.
#################################################

2019-12-03 06:59:47.754 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.754 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.754 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 06:59:47.754 [ 35] 9 WebSocket:AccessLog
2019-12-03 06:59:47.754 [ 5] 9 WebSocket:AccessLog
2019-12-03 06:59:47.754 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.755 [ 35] 9 WebSocket:AccessLog
2019-12-03 06:59:47.755 [ 5] 9 WebSocket:AccessLog
2019-12-03 06:59:47.756 [ 5] 9 WebSocketServer:writeMessageComplete
2019-12-03 06:59:47.756 [ 35] 9 WebSocketServer:writeMessageComplete
2019-12-03 06:59:47.756 [ 35] 3 GUIClient:start::waiting for InitResponse
2019-12-03 06:59:47.756 [ 35] 9 GUIClient:sendInitRequestAndWait:errorState=0,initMessage received=0
#######################################

ALEXA STATE: CONNECTING
#######################################

2019-12-03 06:59:47.757 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.757 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.758 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.758 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.758 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.759 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.764 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.764 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.766 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.766 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.767 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.767 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.768 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 06:59:47.768 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.769 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.769 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.769 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.769 [ 6] 9 GUIClient:onMessage:payload={"type":"initResponse","isSupported":true,"APLMaxVersion":"1.2"}
2019-12-03 06:59:47.770 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 06:59:47.770 [ 6] I GUIClient:processInitResponse:APL Max Version=1.2
2019-12-03 06:59:47.770 [ 35] 9 GUIClient:sendInitRequestAndWait:errorState=0,initMessage received=1
2019-12-03 06:59:47.770 [ 35] 3 GUIClient:start::InitResponse received
2019-12-03 06:59:47.770 [ 35] 5 AplCoreConnectionManager:onConnectionOpened
2019-12-03 06:59:47.771 [ 6] 9 GUIClient:sendGuiConfiguration
2019-12-03 06:59:47.773 [ 6] 9 WebSocketServer:writeMessageBegin
2019-12-03 06:59:47.774 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.774 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.775 [ 6] 9 WebSocketServer:writeMessageComplete
2019-12-03 06:59:47.775 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.775 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.775 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.775 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.776 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"message sent, type: initResponse"}
2019-12-03 06:59:47.776 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.776 [ 3] 3 GUILogBridge:GUILog:component=WSClient:message sent, type: initResponse
2019-12-03 06:59:47.776 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.776 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.776 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.777 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 06:59:47.777 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.777 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 06:59:47.777 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.778 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.778 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.778 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.778 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.780 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.781 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.781 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.781 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.781 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.781 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.781 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 06:59:47.781 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.781 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 06:59:47.783 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.783 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.783 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.784 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.784 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.784 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.784 [ 6] 9 GUIClient:onMessage:payload={"type":"deviceWindowState","payload":{"defaultWindowId":"tvFullscreen","instances":[{"id":"tvFullscreen","templateId":"tvFullscreen","token":null,"configuration":{"interactionMode":"tv","sizeConfigurationId":"fullscreen"}},{"id":"tvOverlayLandscape","templateId":"tvOverlayLandscape","token":null,"configuration":{"interactionMode":"tv_overlay","sizeConfigurationId":"landscapePanel"}}]}}
2019-12-03 06:59:47.785 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.785 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.785 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.786 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.786 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.786 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.786 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.786 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"message sent, type: deviceWindowState"}
2019-12-03 06:59:47.786 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:47.786 [ 3] 3 GUILogBridge:GUILog:component=WSClient:message sent, type: deviceWindowState
2019-12-03 06:59:47.942 [ 33] 5 PostConnectSynchronizer:setState:from=RUNNING,to=FETCHING
2019-12-03 06:59:47.943 [ 34] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Display.Window,name=WindowState
2019-12-03 06:59:47.943 [ 34] 5 AudioActivityTracker:provideState
2019-12-03 06:59:47.943 [ 16] 5 AudioActivityTracker:executeProvideState
2019-12-03 06:59:47.943 [ 34] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=5
2019-12-03 06:59:47.943 [ 16] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2019-12-03 06:59:47.943 [ 2b] 3 AlexaPresentation:executeProvideState:token=5
2019-12-03 06:59:47.943 [ 2b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 06:59:47.943 [ 27] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=5
2019-12-03 06:59:47.944 [ 34] 5 VisualActivityTracker:provideState
2019-12-03 06:59:47.943 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=5
2019-12-03 06:59:47.944 [ 29] 5 VisualActivityTracker:executeProvideState
2019-12-03 06:59:47.944 [ 29] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2019-12-03 06:59:47.944 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-12-03 06:59:47.944 [ 27] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-12-03 06:59:47.944 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=5
2019-12-03 06:59:47.945 [ 28] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers
2019-12-03 06:59:47.945 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-12-03 06:59:47.945 [ 34] 9 ContextManager:buildContextIgnored:namespace=AudioActivityTracker,name=ActivityState
2019-12-03 06:59:47.945 [ 34] 9 ContextManager:buildContextIgnored:namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 06:59:47.945 [ 34] 9 ContextManager:buildContextIgnored:namespace=VisualActivityTracker,name=ActivityState
2019-12-03 06:59:47.946 [ 34] 5 ContextManager:buildContextSuccessful
2019-12-03 06:59:47.946 [ 34] 5 PostConnectSynchronizer:onContextAvailable
2019-12-03 06:59:47.946 [ 34] 5 PostConnectSynchronizer:setState:from=FETCHING,to=SENDING
2019-12-03 06:59:47.947 [ 34] 0 EventBuilder:buildJsonEventString:messageId=09a3a224-45e1-49cf-8d03-e7d48612dd42,namespace=System,name=SynchronizeState
2019-12-03 06:59:47.949 [ 34] 7 HTTP2Transport:sendPostConnectMessage
2019-12-03 06:59:47.949 [ 34] 7 HTTP2Transport:enqueueRequest:beforeConnected=true
2019-12-03 06:59:47.949 [ 32] 7 MessageRequestHandler:create:context=0x7000c99c,messageRequest=0x6ecc5104
2019-12-03 06:59:47.949 [ 32] 5 ExchangeHandler:ExchangeHandler:context=0x7000c99c
2019-12-03 06:59:47.949 [ 32] 7 MessageRequestHandler:MessageRequestHandler:context=0x7000c99c,messageRequest=0x6ecc5104
2019-12-03 06:59:47.950 [ 32] 9 HTTP2MimeRequestEncoder:HTTP2MimeRequestEncoder:boundary=WhooHooZeerOoonie!,source=0x72803864
2019-12-03 06:59:47.950 [ 32] 9 MimeResponseSink:MimeResponseSink:handler=0x72803868
2019-12-03 06:59:47.950 [ 32] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2019-12-03 06:59:47.950 [ 32] 7 HTTP2Transport:onMessageRequestSent:countOfUnfinishedMessageHandlers=1
2019-12-03 06:59:47.950 [ 32] 7 HTTP2Transport:createAndSendRequest:type=POST
2019-12-03 06:59:47.950 [ 32] 9 HTTP2MimeRequestEncoder:getRequestHeaderLines
2019-12-03 06:59:47.950 [ 32] 9 MessageRequestHandler:getRequestHeaderLines
2019-12-03 06:59:47.950 [ 32] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.017 [ 31] 9 LibcurlHTTP2Connection:insertActiveStream:handle=0x72813148,streamId=AVSEvent-3
2019-12-03 06:59:48.018 [ 31] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-3,size=1,nmemb=16384,userData=0x7280d948
2019-12-03 06:59:48.018 [ 31] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=NEW
2019-12-03 06:59:48.018 [ 31] 9 HTTP2MimeRequestEncoder:setState:state=NEW,newState=GETTING_1ST_PART_HEADERS
2019-12-03 06:59:48.018 [ 31] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 06:59:48.018 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.019 [ 31] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_1ST_PART_HEADERS,newState=SENDING_1ST_BOUNDARY
2019-12-03 06:59:48.019 [ 31] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_1ST_BOUNDARY,newState=SENDING_PART_HEADERS
2019-12-03 06:59:48.019 [ 31] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_HEADERS,newState=SENDING_PART_DATA
2019-12-03 06:59:48.019 [ 31] 9 MessageRequestHandler:onSendMimePartData:size=16277
2019-12-03 06:59:48.019 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.019 [ 31] 9 MessageRequestHandler:onSendMimePartData:size=14529
2019-12-03 06:59:48.019 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.019 [ 31] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_DATA,newState=SENDING_END_BOUNDARY
2019-12-03 06:59:48.019 [ 31] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_END_BOUNDARY,newState=GETTING_NTH_PART_HEADERS
2019-12-03 06:59:48.019 [ 31] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 06:59:48.019 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.019 [ 31] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_NTH_PART_HEADERS,newState=SENDING_TERMINATING_DASHES
2019-12-03 06:59:48.019 [ 31] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_TERMINATING_DASHES,newState=DONE
2019-12-03 06:59:48.020 [ 31] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-3,size=1,nmemb=16384,userData=0x7280d948
2019-12-03 06:59:48.020 [ 31] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=DONE
2019-12-03 06:59:48.656 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-3,size=1,nmemb=13,userData=0x7280d948
2019-12-03 06:59:48.656 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:48.656 [ 31] 9 MimeResponseSink:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:48.656 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.656 [ 31] 7 MessageRequestHandler:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:48.656 [ 31] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:48.656 [ 31] 7 HTTP2Transport:onMessageRequestAcknowledged
2019-12-03 06:59:48.656 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=HTTP/2 200

2019-12-03 06:59:48.656 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=HTTP/2 200

2019-12-03 06:59:48.656 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.656 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-3,size=1,nmemb=56,userData=0x7280d948
2019-12-03 06:59:48.656 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid: 78179f52-33df-487d-909b-e403a5fe6b60

2019-12-03 06:59:48.656 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid: 78179f52-33df-487d-909b-e403a5fe6b60

2019-12-03 06:59:48.656 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.656 [ 31] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid: 78179f52-33df-487d-909b-e403a5fe6b60
2019-12-03 06:59:48.656 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-3,size=1,nmemb=113,userData=0x7280d948
2019-12-03 06:59:48.657 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=content-type: multipart/related; boundary=------abcde123; start=metadata.1574761315818; type="application/json"

2019-12-03 06:59:48.657 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=content-type: multipart/related; boundary=------abcde123; start=metadata.1574761315818; type="application/json"

2019-12-03 06:59:48.657 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.657 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-3,size=1,nmemb=82,userData=0x7280d948
2019-12-03 06:59:48.657 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid: 160057fffe97dad1-00003fb9-00946d79-f6284feff21a0419-98ba2734-3

2019-12-03 06:59:48.657 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid: 160057fffe97dad1-00003fb9-00946d79-f6284feff21a0419-98ba2734-3

2019-12-03 06:59:48.657 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.657 [ 31] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid: 160057fffe97dad1-00003fb9-00946d79-f6284feff21a0419-98ba2734-3
2019-12-03 06:59:48.657 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-3,size=1,nmemb=32,userData=0x7280d948
2019-12-03 06:59:48.657 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:48.657 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:48.657 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.657 [ 31] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-3,size=1,nmemb=2,userData=0x7280d948
2019-12-03 06:59:48.657 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=

2019-12-03 06:59:48.657 [ 31] 9 MimeResponseSink:onReceiveHeaderLine:line=

2019-12-03 06:59:48.657 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.658 [ 31] 9 LibcurlHTTP2Request:writeCallback:id=AVSEvent-3,size=1,nmemb=265,userData=0x7280d948
2019-12-03 06:59:48.658 [ 31] 9 HTTP2MimeResponseDecoder:onReceiveData:size=265
2019-12-03 06:59:48.658 [ 31] 9 MimeResponseSink:onBeginMimePart
2019-12-03 06:59:48.658 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.658 [ 31] 9 MimeResponseSink:JsonContentDetected
2019-12-03 06:59:48.658 [ 31] 9 MimeResponseSink:onReceiveMimeData:size=176
2019-12-03 06:59:48.658 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.658 [ 31] 9 MimeResponseSink:onEndMimePart
2019-12-03 06:59:48.658 [ 31] 9 HTTP2Transport:onActivity
2019-12-03 06:59:48.659 [ 31] 9 HTTP2MimeResponseDecoder:onResponseFinished:status=COMPLETE
2019-12-03 06:59:48.659 [ 31] 9 MimeResponseSink:onResponseFinished:status=COMPLETE
2019-12-03 06:59:48.659 [ 31] 7 MessageRequestHandler:onResponseFinished:status=COMPLETE,responseCode=200
2019-12-03 06:59:48.659 [ 31] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:48.659 [ 31] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 06:59:48.659 [ 31] 7 HTTP2Transport:onMessageRequestFinished:countOfUnfinishedMessageHandlers=0
2019-12-03 06:59:48.660 [ d] I DirectiveSequencer:onDirective:directive={"namespace:"System",name:"SetEndpoint",messageId:"fbc76f47-b2d8-44f5-ae88-65c014f72cb4",dialogRequestId:""}
2019-12-03 06:59:48.660 [ 31] 5 PostConnectSynchronizer:onSendCompleted:status=SUCCESS
2019-12-03 06:59:48.660 [ 31] 5 PostConnectSynchronizer:stop
2019-12-03 06:59:48.660 [ 31] 5 PostConnectSynchronizer:setState:from=SENDING,to=STOPPING
2019-12-03 06:59:48.660 [ 33] 5 PostConnectSynchronizer:mainLoopReturning
2019-12-03 06:59:48.660 [ 36] I DirectiveRouter:preHandleDirective:messageId=fbc76f47-b2d8-44f5-ae88-65c014f72cb4,action=calling
2019-12-03 06:59:48.661 [ 36] 0 CapabilityAgent:addingMessageIdToMap:messageId=fbc76f47-b2d8-44f5-ae88-65c014f72cb4
2019-12-03 06:59:48.662 [ 31] 5 PostConnectSynchronizer:setState:from=STOPPING,to=STOPPED
2019-12-03 06:59:48.662 [ 31] 5 HTTP2Transport:onPostConnected
2019-12-03 06:59:48.662 [ 31] 5 HTTP2Transport:setStateLocked:newState=CONNECTED,changedReason=SUCCESS
2019-12-03 06:59:48.662 [ f] 9 DirectiveProcessor:processCancelingQueueLocked:size=0
2019-12-03 06:59:48.663 [ 32] 5 HTTP2Transport:handleConnected
2019-12-03 06:59:48.663 [ f] 9 DirectiveProcessor:handleQueuedDirectivesLocked:queue size=1
2019-12-03 06:59:48.663 [ 31] 0 LibcurlHTTP2Connection:streamFinished:streamId=AVSEvent-3,result=No error,CURLcode=0
2019-12-03 06:59:48.663 [ 31] 9 LibcurlHTTP2Connection:releaseStream:streamId=AVSEvent-3
2019-12-03 06:59:48.663 [ f] 9 DirectiveProcessor:handleQueuedDirectivesLocked:proceeding with directive=fbc76f47-b2d8-44f5-ae88-65c014f72cb4,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2019-12-03 06:59:48.663 [ 32] 7 HTTP2Transport:notifyObserversOnConnected
2019-12-03 06:59:48.663 [ f] I DirectiveRouter:handleDirective:messageId=fbc76f47-b2d8-44f5-ae88-65c014f72cb4,action=calling
2019-12-03 06:59:48.663 [ 32] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=CONNECTED
2019-12-03 06:59:48.664 [ 31] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:48.664 [ 31] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 06:59:48.664 [ f] 0 MessageRouter:connectionStatusChanged:reason=SERVER_ENDPOINT_CHANGED,newStatus=DISCONNECTED
2019-12-03 06:59:48.664 [ 32] 7 HTTP2Transport:sendMessagesAndPings:whileState=CONNECTED
2019-12-03 06:59:48.664 [ 31] 0 PostConnectSynchronizer:~PostConnectSynchronizer
2019-12-03 06:59:48.664 [ 31] 5 PostConnectSynchronizer:stop
2019-12-03 06:59:48.664 [ f] 7 HTTP2Transport:doShutdown
2019-12-03 06:59:48.664 [ 31] 5 PostConnectSynchronizer:stopIgnored:reason=alreadyStopped
2019-12-03 06:59:48.664 [ f] 5 HTTP2Transport:setStateLocked:newState=SHUTDOWN,changedReason=ACL_CLIENT_REQUEST
2019-12-03 06:59:48.664 [ f] 5 HTTP2Transport:disconnect
2019-12-03 06:59:48.666 [ 32] 5 HTTP2Transport:handleShutdown
2019-12-03 06:59:48.667 [ 30] 5 ReportStateHandler:sendReportState:pendingReport=false
2019-12-03 06:59:48.667 [ 26] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=CONNECTED,reason=ACL_CLIENT_REQUEST
2019-12-03 06:59:48.667 [ 32] 5 LibcurlHTTP2Connection:disconnect
2019-12-03 06:59:48.669 [ 13] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer::speechConfirmation
2019-12-03 06:59:48.669 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 06:59:48.669 [ 5] 9 WebSocket:AccessLog
2019-12-03 06:59:48.669 [ 5] 9 WebSocket:AccessLog
2019-12-03 06:59:48.670 [ 5] 9 WebSocketServer:writeMessageComplete
#################################

ALEXA STATE: IDLE
#################################

2019-12-03 06:59:48.671 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.671 [ 13] 5 SQLiteDeviceSettingStorage:loadSetting
2019-12-03 06:59:48.671 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.671 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.671 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.671 [ 13] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=SpeechRecognizer::speechConfirmation,synchronized=true
2019-12-03 06:59:48.671 [ 13] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized
2019-12-03 06:59:48.672 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.673 [ 10] 0 EventBuilder:buildJsonEventString:messageId=4346e786-99e2-4453-9196-36d98eea46da,namespace=Alexa.DoNotDisturb,name=ReportDoNotDisturb
2019-12-03 06:59:48.673 [ 14] 5 SQLiteDeviceSettingStorage:loadSetting:key=System::timeZone
2019-12-03 06:59:48.675 [ 14] 5 SQLiteDeviceSettingStorage:loadSetting
2019-12-03 06:59:48.675 [ 12] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer::wakeWordConfirmation
2019-12-03 06:59:48.676 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.676 [ 10] E MessageRouter:sendFailed:reason=noActiveTransport
2019-12-03 06:59:48.677 [ 10] 9 DNDMessageRequest:sendCompleted:Completed with status=NOT_CONNECTED
2019-12-03 06:59:48.676 [ 14] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=System::timeZone,synchronized=true
2019-12-03 06:59:48.678 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.678 [ 14] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized
2019-12-03 06:59:48.678 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.678 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.678 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.678 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.678 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 06:59:48.679 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.679 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 06:59:48.679 [ 12] 5 SQLiteDeviceSettingStorage:loadSetting
2019-12-03 06:59:48.680 [ 12] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=SpeechRecognizer::wakeWordConfirmation,synchronized=true
2019-12-03 06:59:48.680 [ 12] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized
2019-12-03 06:59:48.680 [ 26] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=SERVER_ENDPOINT_CHANGED
2019-12-03 06:59:48.680 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 06:59:48.681 [ 5] 9 WebSocket:AccessLog
2019-12-03 06:59:48.681 [ 5] 9 WebSocket:AccessLog
2019-12-03 06:59:48.681 [ 5] 9 WebSocketServer:writeMessageComplete
2019-12-03 06:59:48.681 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.681 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.681 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.681 [ 6] 9 WebSocket:AccessLog
#########################################

ALEXA STATE: DISCONNECTED
#########################################

2019-12-03 06:59:48.682 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.702 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.702 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.702 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.702 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.703 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.703 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.703 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 06:59:48.703 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:48.703 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 06:59:48.765 [ 31] I LibcurlHTTP2Connection:cancelStream:streamId=AVSDownChannel-1
2019-12-03 06:59:48.766 [ 31] 9 HTTP2MimeResponseDecoder:onResponseFinished:status=CANCELLED
2019-12-03 06:59:48.766 [ 31] 9 MimeResponseSink:onResponseFinished:status=CANCELLED
2019-12-03 06:59:48.766 [ 31] 5 DownchannelHandler:onResponseFinished:status=CANCELLED,nonMimeBody=
2019-12-03 06:59:48.766 [ 31] 7 HTTP2Transport:onDownchannelFinished
2019-12-03 06:59:48.766 [ 31] 9 LibcurlHTTP2Connection:releaseStream:streamId=AVSDownChannel-1
2019-12-03 06:59:48.789 [ 31] 5 LibcurlHTTP2Connection:networkLoopExiting
2019-12-03 06:59:48.790 [ 32] 7 HTTP2Transport:notifyObserversOnDisconnect
2019-12-03 06:59:48.790 [ 32] 7 HTTP2Transport:mainLoopExiting
2019-12-03 06:59:48.790 [ f] 5 CBLAuthDelegate:removeAuthObserver:observer=0x7000c998
2019-12-03 06:59:48.791 [ f] 5 LibcurlHTTP2Connection:~LibcurlHTTP2Connection
2019-12-03 06:59:48.791 [ f] 5 LibcurlHTTP2Connection:disconnect
2019-12-03 06:59:48.792 [ f] 5 LibcurlHTTP2ConnectionFactory:createHTTP2Connection
2019-12-03 06:59:48.792 [ f] 5 HTTP2Transport:create:authDelegate=0x12b8930,avsEndpoint=https://avs-alexa-eu.amazon.com,http2Connection=0x1308228,messageConsumer=0x12eb298,attachmentManager=0x12eb1e0,transportObserver=0x12eb294,postConnectFactory=0x12af8c8
2019-12-03 06:59:48.793 [ f] 7 HTTP2Transport:HTTP2Transport:authDelegate=0x12b8930,avsEndpoint=https://avs-alexa-eu.amazon.com,http2Connection=0x1308228,messageConsumer=0x12eb298,attachmentManager=0x12eb1e0,transportObserver=0x12eb294,postConnectFactory=0x12af8c8
2019-12-03 06:59:48.793 [ f] 5 HTTP2Transport:connect
2019-12-03 06:59:48.793 [ f] 5 HTTP2Transport:setStateLocked:newState=AUTHORIZING,changedReason=ACL_CLIENT_REQUEST
2019-12-03 06:59:48.793 [ 37] 7 HTTP2Transport:mainLoop
2019-12-03 06:59:48.793 [ 37] 0 PostConnectSynchronizer:doPostConnect
2019-12-03 06:59:48.793 [ f] 0 DirectiveProcessor:onHandlingCompeted:messageId=fbc76f47-b2d8-44f5-ae88-65c014f72cb4,directiveBeingPreHandled=(nullptr)
2019-12-03 06:59:48.793 [ 37] 5 PostConnectSynchronizer:setState:from=IDLE,to=RUNNING
2019-12-03 06:59:48.794 [ f] 0 CapabilityAgent:removingMessageIdFromMap:messageId=fbc76f47-b2d8-44f5-ae88-65c014f72cb4
2019-12-03 06:59:48.794 [ 37] 5 HTTP2Transport:handleAuthorizing
2019-12-03 06:59:48.794 [ f] 9 DirectiveProcessor:processCancelingQueueLocked:size=0
2019-12-03 06:59:48.793 [ 38] 5 LibcurlHTTP2Connection:networkLoop
2019-12-03 06:59:48.794 [ 37] 5 CBLAuthDelegate:addAuthObserver:observer=0x13127b0
2019-12-03 06:59:48.795 [ 39] 5 PostConnectSynchronizer:mainLoop
2019-12-03 06:59:48.795 [ 37] 5 HTTP2Transport:onAuthStateChange:newState=REFRESHED,error=SUCCESS
2019-12-03 06:59:48.795 [ 37] 5 HTTP2Transport:setStateLocked:newState=CONNECTING,changedReason=SUCCESS
2019-12-03 06:59:48.795 [ 37] 5 HTTP2Transport:handleConnecting
2019-12-03 06:59:48.795 [ 37] 9 DownchannelHandler:create:context=0x13127b4
2019-12-03 06:59:48.795 [ 37] 5 ExchangeHandler:ExchangeHandler:context=0x13127b4
2019-12-03 06:59:48.795 [ 37] 9 DownchannelHandler:DownchannelHandler:context=0x13127b4
2019-12-03 06:59:48.795 [ 37] 9 MimeResponseSink:MimeResponseSink:handler=0x71ed2870
2019-12-03 06:59:48.795 [ 37] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2019-12-03 06:59:48.795 [ 37] 7 HTTP2Transport:createAndSendRequest:type=GET
2019-12-03 06:59:48.795 [ 39] 5 PostConnectSynchronizer:setState:from=RUNNING,to=FETCHING
2019-12-03 06:59:48.796 [ 34] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Display.Window,name=WindowState
2019-12-03 06:59:48.796 [ 34] 5 AudioActivityTracker:provideState
2019-12-03 06:59:48.796 [ 16] 5 AudioActivityTracker:executeProvideState
2019-12-03 06:59:48.796 [ 34] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=6
2019-12-03 06:59:48.796 [ 2b] 3 AlexaPresentation:executeProvideState:token=6
2019-12-03 06:59:48.796 [ 16] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2019-12-03 06:59:48.796 [ 2b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 06:59:48.796 [ 37] 9 DownchannelHandler:getRequestHeaderLines
2019-12-03 06:59:48.797 [ 34] 5 VisualActivityTracker:provideState
2019-12-03 06:59:48.797 [ 27] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=6
2019-12-03 06:59:48.797 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=6
2019-12-03 06:59:48.798 [ 29] 5 VisualActivityTracker:executeProvideState
2019-12-03 06:59:48.798 [ 38] 9 LibcurlHTTP2Connection:insertActiveStream:handle=0x71e021c8,streamId=AVSDownChannel-5
2019-12-03 06:59:48.798 [ 29] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2019-12-03 06:59:48.798 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-12-03 06:59:48.798 [ 27] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-12-03 06:59:48.798 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=6
2019-12-03 06:59:48.798 [ 28] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers
2019-12-03 06:59:48.799 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-12-03 06:59:48.799 [ 34] 9 ContextManager:buildContextIgnored:namespace=AudioActivityTracker,name=ActivityState
2019-12-03 06:59:48.799 [ 34] 9 ContextManager:buildContextIgnored:namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 06:59:48.800 [ 34] 9 ContextManager:buildContextIgnored:namespace=VisualActivityTracker,name=ActivityState
2019-12-03 06:59:48.800 [ 34] 5 ContextManager:buildContextSuccessful
2019-12-03 06:59:48.801 [ 34] 5 PostConnectSynchronizer:onContextAvailable
2019-12-03 06:59:48.801 [ 34] 5 PostConnectSynchronizer:setState:from=FETCHING,to=SENDING
2019-12-03 06:59:48.802 [ 34] 0 EventBuilder:buildJsonEventString:messageId=ebdbb4b0-e25a-4411-9100-6b5c8235582c,namespace=System,name=SynchronizeState
2019-12-03 06:59:48.803 [ 34] 7 HTTP2Transport:sendPostConnectMessage
2019-12-03 06:59:48.803 [ 34] 7 HTTP2Transport:enqueueRequest:beforeConnected=true
2019-12-03 06:59:50.257 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-5,size=1,nmemb=13,userData=0x71ed2770
2019-12-03 06:59:50.257 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:50.258 [ 38] 9 MimeResponseSink:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:50.258 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.258 [ 38] 5 DownchannelHandler:onReceiveResponseCode:responseCode=200
2019-12-03 06:59:50.258 [ 38] 7 HTTP2Transport:onDownchannelConnected
2019-12-03 06:59:50.258 [ 38] 5 HTTP2Transport:setStateLocked:newState=POST_CONNECTING,changedReason=SUCCESS
2019-12-03 06:59:50.258 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=HTTP/2 200

2019-12-03 06:59:50.258 [ 37] 5 HTTP2Transport:handlePostConnecting
2019-12-03 06:59:50.258 [ 37] 7 HTTP2Transport:sendMessagesAndPings:whileState=POST_CONNECTING
2019-12-03 06:59:50.258 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=HTTP/2 200

2019-12-03 06:59:50.259 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.258 [ 37] 7 MessageRequestHandler:create:context=0x13127b4,messageRequest=0x6ecc3e2c
2019-12-03 06:59:50.259 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-5,size=1,nmemb=64,userData=0x71ed2770
2019-12-03 06:59:50.259 [ 37] 5 ExchangeHandler:ExchangeHandler:context=0x13127b4
2019-12-03 06:59:50.259 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-headers: authorization,x-amz-access-token

2019-12-03 06:59:50.259 [ 37] 7 MessageRequestHandler:MessageRequestHandler:context=0x13127b4,messageRequest=0x6ecc3e2c
2019-12-03 06:59:50.259 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-headers: authorization,x-amz-access-token

2019-12-03 06:59:50.259 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.259 [ 37] 9 HTTP2MimeRequestEncoder:HTTP2MimeRequestEncoder:boundary=WhooHooZeerOoonie!,source=0x71ed342c
2019-12-03 06:59:50.259 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-5,size=1,nmemb=32,userData=0x71ed2770
2019-12-03 06:59:50.259 [ 37] 9 MimeResponseSink:MimeResponseSink:handler=0x71ed3430
2019-12-03 06:59:50.260 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:50.260 [ 37] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2019-12-03 06:59:50.260 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:50.260 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.260 [ 37] 7 HTTP2Transport:onMessageRequestSent:countOfUnfinishedMessageHandlers=1
2019-12-03 06:59:50.260 [ 37] 7 HTTP2Transport:createAndSendRequest:type=POST
2019-12-03 06:59:50.260 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-5,size=1,nmemb=81,userData=0x71ed2770
2019-12-03 06:59:50.260 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=content-type: multipart/related; boundary=------abcde123; type=application/json

2019-12-03 06:59:50.260 [ 37] 9 HTTP2MimeRequestEncoder:getRequestHeaderLines
2019-12-03 06:59:50.260 [ 37] 9 MessageRequestHandler:getRequestHeaderLines
2019-12-03 06:59:50.261 [ 37] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.260 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=content-type: multipart/related; boundary=------abcde123; type=application/json

2019-12-03 06:59:50.261 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.261 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-5,size=1,nmemb=20,userData=0x71ed2770
2019-12-03 06:59:50.261 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid:

2019-12-03 06:59:50.261 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid:

2019-12-03 06:59:50.261 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.261 [ 38] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid:
2019-12-03 06:59:50.261 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-5,size=1,nmemb=2,userData=0x71ed2770
2019-12-03 06:59:50.261 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=

2019-12-03 06:59:50.261 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=

2019-12-03 06:59:50.262 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.262 [ 38] 9 LibcurlHTTP2Request:writeCallback:id=AVSDownChannel-5,size=1,nmemb=18,userData=0x71ed2770
2019-12-03 06:59:50.262 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveData:size=18
2019-12-03 06:59:50.262 [ 38] 9 LibcurlHTTP2Connection:insertActiveStream:handle=0x71e8db18,streamId=AVSEvent-7
2019-12-03 06:59:50.263 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-7,size=1,nmemb=16384,userData=0x71ed2ee8
2019-12-03 06:59:50.263 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=NEW
2019-12-03 06:59:50.263 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=NEW,newState=GETTING_1ST_PART_HEADERS
2019-12-03 06:59:50.264 [ 38] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 06:59:50.264 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.264 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_1ST_PART_HEADERS,newState=SENDING_1ST_BOUNDARY
2019-12-03 06:59:50.264 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_1ST_BOUNDARY,newState=SENDING_PART_HEADERS
2019-12-03 06:59:50.264 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_HEADERS,newState=SENDING_PART_DATA
2019-12-03 06:59:50.264 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16277
2019-12-03 06:59:50.264 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.264 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=14529
2019-12-03 06:59:50.264 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.264 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_DATA,newState=SENDING_END_BOUNDARY
2019-12-03 06:59:50.264 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_END_BOUNDARY,newState=GETTING_NTH_PART_HEADERS
2019-12-03 06:59:50.264 [ 38] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 06:59:50.265 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:50.265 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_NTH_PART_HEADERS,newState=SENDING_TERMINATING_DASHES
2019-12-03 06:59:50.265 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_TERMINATING_DASHES,newState=DONE
2019-12-03 06:59:50.265 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-7,size=1,nmemb=16384,userData=0x71ed2ee8
2019-12-03 06:59:50.265 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=DONE
2019-12-03 06:59:51.214 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-7,size=1,nmemb=13,userData=0x71ed2ee8
2019-12-03 06:59:51.214 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveResponseCode:responseCode=204
2019-12-03 06:59:51.214 [ 38] 9 MimeResponseSink:onReceiveResponseCode:responseCode=204
2019-12-03 06:59:51.214 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.214 [ 38] 7 MessageRequestHandler:onReceiveResponseCode:responseCode=204
2019-12-03 06:59:51.214 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:51.214 [ 38] 7 HTTP2Transport:onMessageRequestAcknowledged
2019-12-03 06:59:51.214 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=HTTP/2 204

2019-12-03 06:59:51.215 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=HTTP/2 204

2019-12-03 06:59:51.215 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.215 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-7,size=1,nmemb=56,userData=0x71ed2ee8
2019-12-03 06:59:51.215 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid: 7ddde261-02c6-402e-8772-05a29c094d2a

2019-12-03 06:59:51.215 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid: 7ddde261-02c6-402e-8772-05a29c094d2a

2019-12-03 06:59:51.215 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.215 [ 38] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid: 7ddde261-02c6-402e-8772-05a29c094d2a
2019-12-03 06:59:51.215 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-7,size=1,nmemb=82,userData=0x71ed2ee8
2019-12-03 06:59:51.215 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-3

2019-12-03 06:59:51.215 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-3

2019-12-03 06:59:51.215 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.215 [ 38] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-3
2019-12-03 06:59:51.215 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-7,size=1,nmemb=32,userData=0x71ed2ee8
2019-12-03 06:59:51.215 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:51.215 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:51.215 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.215 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-7,size=1,nmemb=2,userData=0x71ed2ee8
2019-12-03 06:59:51.215 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=

2019-12-03 06:59:51.215 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=

2019-12-03 06:59:51.215 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.216 [ 38] 9 HTTP2MimeResponseDecoder:onResponseFinished:status=COMPLETE
2019-12-03 06:59:51.216 [ 38] 9 MimeResponseSink:onResponseFinished:status=COMPLETE
2019-12-03 06:59:51.216 [ 38] 7 MessageRequestHandler:onResponseFinished:status=COMPLETE,responseCode=204
2019-12-03 06:59:51.216 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:51.216 [ 38] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 06:59:51.216 [ 38] 7 HTTP2Transport:onMessageRequestFinished:countOfUnfinishedMessageHandlers=0
2019-12-03 06:59:51.216 [ 38] 5 PostConnectSynchronizer:onSendCompleted:status=SUCCESS_NO_CONTENT
2019-12-03 06:59:51.216 [ 38] 5 PostConnectSynchronizer:stop
2019-12-03 06:59:51.216 [ 38] 5 PostConnectSynchronizer:setState:from=SENDING,to=STOPPING
2019-12-03 06:59:51.216 [ 39] 5 PostConnectSynchronizer:mainLoopReturning
2019-12-03 06:59:51.216 [ 38] 5 PostConnectSynchronizer:setState:from=STOPPING,to=STOPPED
2019-12-03 06:59:51.216 [ 38] 5 HTTP2Transport:onPostConnected
2019-12-03 06:59:51.216 [ 38] 5 HTTP2Transport:setStateLocked:newState=CONNECTED,changedReason=SUCCESS
2019-12-03 06:59:51.216 [ 37] 5 HTTP2Transport:handleConnected
2019-12-03 06:59:51.217 [ 38] 0 LibcurlHTTP2Connection:streamFinished:streamId=AVSEvent-7,result=No error,CURLcode=0
2019-12-03 06:59:51.217 [ 37] 7 HTTP2Transport:notifyObserversOnConnected
2019-12-03 06:59:51.217 [ 38] 9 LibcurlHTTP2Connection:releaseStream:streamId=AVSEvent-7
2019-12-03 06:59:51.217 [ 37] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=CONNECTED
2019-12-03 06:59:51.217 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:51.217 [ 38] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 06:59:51.217 [ 38] 0 PostConnectSynchronizer:~PostConnectSynchronizer
2019-12-03 06:59:51.217 [ 38] 5 PostConnectSynchronizer:stop
2019-12-03 06:59:51.217 [ 37] 7 HTTP2Transport:sendMessagesAndPings:whileState=CONNECTED
2019-12-03 06:59:51.217 [ 38] 5 PostConnectSynchronizer:stopIgnored:reason=alreadyStopped
2019-12-03 06:59:51.218 [ 26] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=CONNECTED,reason=ACL_CLIENT_REQUEST
2019-12-03 06:59:51.219 [ 13] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer::speechConfirmation
2019-12-03 06:59:51.220 [ 13] 5 SQLiteDeviceSettingStorage:loadSetting
2019-12-03 06:59:51.220 [ 13] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=SpeechRecognizer::speechConfirmation,synchronized=true
2019-12-03 06:59:51.220 [ 13] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized
2019-12-03 06:59:51.220 [ 10] 0 EventBuilder:buildJsonEventString:messageId=0901e552-cd8e-49b1-9685-ac968bef33f8,namespace=Alexa.DoNotDisturb,name=ReportDoNotDisturb
2019-12-03 06:59:51.220 [ 12] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer::wakeWordConfirmation
2019-12-03 06:59:51.220 [ 10] 7 HTTP2Transport:send
2019-12-03 06:59:51.220 [ 10] 7 HTTP2Transport:enqueueRequest:beforeConnected=false
2019-12-03 06:59:51.221 [ 37] 7 MessageRequestHandler:create:context=0x13127b4,messageRequest=0x728c7c2c
2019-12-03 06:59:51.221 [ 37] 5 ExchangeHandler:ExchangeHandler:context=0x13127b4
2019-12-03 06:59:51.221 [ 37] 7 MessageRequestHandler:MessageRequestHandler:context=0x13127b4,messageRequest=0x728c7c2c
2019-12-03 06:59:51.221 [ 30] 5 ReportStateHandler:sendReportState:pendingReport=false
2019-12-03 06:59:51.221 [ 37] 9 HTTP2MimeRequestEncoder:HTTP2MimeRequestEncoder:boundary=WhooHooZeerOoonie!,source=0x71ed342c
2019-12-03 06:59:51.221 [ 37] 9 MimeResponseSink:MimeResponseSink:handler=0x71ed3430
2019-12-03 06:59:51.221 [ 37] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2019-12-03 06:59:51.221 [ 37] 7 HTTP2Transport:onMessageRequestSent:countOfUnfinishedMessageHandlers=1
2019-12-03 06:59:51.221 [ 37] 7 HTTP2Transport:createAndSendRequest:type=POST
2019-12-03 06:59:51.221 [ 37] 9 HTTP2MimeRequestEncoder:getRequestHeaderLines
2019-12-03 06:59:51.222 [ 37] 9 MessageRequestHandler:getRequestHeaderLines
2019-12-03 06:59:51.221 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 06:59:51.222 [ 37] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.222 [ 5] 9 WebSocket:AccessLog
2019-12-03 06:59:51.222 [ 5] 9 WebSocket:AccessLog
2019-12-03 06:59:51.222 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.223 [ 14] 5 SQLiteDeviceSettingStorage:loadSetting:key=System::timeZone
2019-12-03 06:59:51.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.224 [ 5] 9 WebSocketServer:writeMessageComplete
#################################

ALEXA STATE: IDLE
#################################

2019-12-03 06:59:51.222 [ 12] 5 SQLiteDeviceSettingStorage:loadSetting
2019-12-03 06:59:51.224 [ 12] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=SpeechRecognizer::wakeWordConfirmation,synchronized=true
2019-12-03 06:59:51.224 [ 12] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized
2019-12-03 06:59:51.225 [ 14] 5 SQLiteDeviceSettingStorage:loadSetting
2019-12-03 06:59:51.225 [ 14] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=System::timeZone,synchronized=true
2019-12-03 06:59:51.225 [ 14] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized
2019-12-03 06:59:51.234 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.234 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.234 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.234 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.234 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.234 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.234 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 06:59:51.235 [ 6] 9 WebSocket:AccessLog
2019-12-03 06:59:51.235 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 06:59:51.318 [ 38] 9 LibcurlHTTP2Connection:insertActiveStream:handle=0x71e8db18,streamId=AVSEvent-9
2019-12-03 06:59:51.319 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-9,size=1,nmemb=16384,userData=0x71ecca40
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=NEW
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=NEW,newState=GETTING_1ST_PART_HEADERS
2019-12-03 06:59:51.319 [ 38] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 06:59:51.319 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_1ST_PART_HEADERS,newState=SENDING_1ST_BOUNDARY
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_1ST_BOUNDARY,newState=SENDING_PART_HEADERS
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_HEADERS,newState=SENDING_PART_DATA
2019-12-03 06:59:51.319 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16277
2019-12-03 06:59:51.319 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.319 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16115
2019-12-03 06:59:51.319 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_DATA,newState=SENDING_END_BOUNDARY
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_END_BOUNDARY,newState=GETTING_NTH_PART_HEADERS
2019-12-03 06:59:51.319 [ 38] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 06:59:51.319 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_NTH_PART_HEADERS,newState=SENDING_TERMINATING_DASHES
2019-12-03 06:59:51.319 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_TERMINATING_DASHES,newState=DONE
2019-12-03 06:59:51.320 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-9,size=1,nmemb=16384,userData=0x71ecca40
2019-12-03 06:59:51.320 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=DONE
2019-12-03 06:59:51.854 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-9,size=1,nmemb=13,userData=0x71ecca40
2019-12-03 06:59:51.854 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveResponseCode:responseCode=204
2019-12-03 06:59:51.855 [ 38] 9 MimeResponseSink:onReceiveResponseCode:responseCode=204
2019-12-03 06:59:51.855 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.855 [ 38] 7 MessageRequestHandler:onReceiveResponseCode:responseCode=204
2019-12-03 06:59:51.855 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:51.855 [ 38] 7 HTTP2Transport:onMessageRequestAcknowledged
2019-12-03 06:59:51.855 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=HTTP/2 204

2019-12-03 06:59:51.855 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=HTTP/2 204

2019-12-03 06:59:51.855 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.855 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-9,size=1,nmemb=56,userData=0x71ecca40
2019-12-03 06:59:51.855 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid: 2ce0925f-9392-4492-894c-a3492e4a2f5d

2019-12-03 06:59:51.855 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid: 2ce0925f-9392-4492-894c-a3492e4a2f5d

2019-12-03 06:59:51.855 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.856 [ 38] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid: 2ce0925f-9392-4492-894c-a3492e4a2f5d
2019-12-03 06:59:51.856 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-9,size=1,nmemb=82,userData=0x71ecca40
2019-12-03 06:59:51.856 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-5

2019-12-03 06:59:51.856 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-5

2019-12-03 06:59:51.856 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.856 [ 38] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-5
2019-12-03 06:59:51.856 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-9,size=1,nmemb=32,userData=0x71ecca40
2019-12-03 06:59:51.856 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:51.856 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 06:59:51.856 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.856 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-9,size=1,nmemb=2,userData=0x71ecca40
2019-12-03 06:59:51.856 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=

2019-12-03 06:59:51.857 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=

2019-12-03 06:59:51.857 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 06:59:51.857 [ 38] 9 HTTP2MimeResponseDecoder:onResponseFinished:status=COMPLETE
2019-12-03 06:59:51.857 [ 38] 9 MimeResponseSink:onResponseFinished:status=COMPLETE
2019-12-03 06:59:51.857 [ 38] 7 MessageRequestHandler:onResponseFinished:status=COMPLETE,responseCode=204
2019-12-03 06:59:51.857 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:51.857 [ 38] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 06:59:51.857 [ 38] 7 HTTP2Transport:onMessageRequestFinished:countOfUnfinishedMessageHandlers=0
2019-12-03 06:59:51.857 [ 38] 9 DNDMessageRequest:sendCompleted:Completed with status=SUCCESS_NO_CONTENT
2019-12-03 06:59:51.857 [ 38] 0 LibcurlHTTP2Connection:streamFinished:streamId=AVSEvent-9,result=No error,CURLcode=0
2019-12-03 06:59:51.857 [ 38] 9 LibcurlHTTP2Connection:releaseStream:streamId=AVSEvent-9
2019-12-03 06:59:51.858 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 06:59:51.858 [ 38] 7 MessageRequestHandler:reportMessageRequestFinished

019-12-03 07:01:01.511 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:01:01.511 [ 38] 9 HTTP2MimeResponseDecoder:onResponseFinished:status=COMPLETE
2019-12-03 07:01:01.511 [ 38] 9 MimeResponseSink:onResponseFinished:status=COMPLETE
2019-12-03 07:01:01.511 [ 38] 7 MessageRequestHandler:onResponseFinished:status=COMPLETE,responseCode=204
2019-12-03 07:01:01.511 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 07:01:01.511 [ 38] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 07:01:01.511 [ 38] 7 HTTP2Transport:onMessageRequestFinished:countOfUnfinishedMessageHandlers=0
2019-12-03 07:01:01.512 [ 38] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS_NO_CONTENT
2019-12-03 07:01:01.512 [ 38] 5 AudioInputProcessor:stopCapture:reason=streamClosed
2019-12-03 07:01:01.512 [ 38] 0 LibcurlHTTP2Connection:streamFinished:streamId=AVSEvent-11,result=No error,CURLcode=0
2019-12-03 07:01:01.512 [ 38] 9 LibcurlHTTP2Connection:releaseStream:streamId=AVSEvent-11
2019-12-03 07:01:01.512 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 07:01:01.512 [ 38] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 07:01:06.155 [ c] 0 DialogUXStateAggregator:transitionFromThinkingTimedOut
2019-12-03 07:01:06.155 [ c] 0 DialogUXStateAggregator:setState:from=THINKING,to=IDLE
2019-12-03 07:01:06.155 [ c] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2019-12-03 07:01:06.156 [ c] 5 AlexaPresentation:onDialogUXStateChanged:state=IDLE
2019-12-03 07:01:06.156 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 07:01:06.156 [ 5] 9 WebSocket:AccessLog
2019-12-03 07:01:06.157 [ 5] 9 WebSocket:AccessLog
2019-12-03 07:01:06.157 [ 19] 1 FocusManager:releaseChannel:channelName=Dialog
2019-12-03 07:01:06.157 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.158 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.158 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.158 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.158 [ 19] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2019-12-03 07:01:06.159 [ 17] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE
2019-12-03 07:01:06.157 [ 5] 9 WebSocketServer:writeMessageComplete
#################################

ALEXA STATE: IDLE
#################################

2019-12-03 07:01:06.160 [ 17] 5 AudioActivityTracker:notifyOfActivityUpdates
2019-12-03 07:01:06.162 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.162 [ 16] 5 AudioActivityTracker:executeNotifyOfActivityUpdates
2019-12-03 07:01:06.160 [ 19] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2019-12-03 07:01:06.163 [ 19] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2019-12-03 07:01:06.163 [ 19] 0 AudioInputProcessor:executeResetState
2019-12-03 07:01:06.164 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.164 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.165 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.165 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.165 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.166 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.169 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 07:01:06.170 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:01:06.170 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 07:02:09.845 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.845 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.845 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.845 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.846 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.846 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.846 [ 6] 9 GUIClient:onMessage:payload={"type":"holdToTalk"}
2019-12-03 07:02:09.846 [ 6] 9 GUIManager:handleHoldToTalk
2019-12-03 07:02:09.847 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.848 [ 19] 0 AudioInputProcessor:notEncodingAudio
2019-12-03 07:02:09.848 [ 19] 5 UserInactivityMonitor:onUserActive
2019-12-03 07:02:09.850 [ 19] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING
2019-12-03 07:02:09.851 [ 34] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Display.Window,name=WindowState
2019-12-03 07:02:09.851 [ 34] 5 AudioActivityTracker:provideState
2019-12-03 07:02:09.852 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.852 [ 16] 5 AudioActivityTracker:executeProvideState
2019-12-03 07:02:09.852 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.852 [ 16] 9 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState
2019-12-03 07:02:09.852 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.852 [ 34] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=8
2019-12-03 07:02:09.852 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.853 [ 27] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=8
2019-12-03 07:02:09.854 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.854 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.854 [ 34] 5 VisualActivityTracker:provideState
2019-12-03 07:02:09.854 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"message sent, type: holdToTalk"}
2019-12-03 07:02:09.854 [ 27] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState
2019-12-03 07:02:09.855 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.855 [ 29] 5 VisualActivityTracker:executeProvideState
2019-12-03 07:02:09.856 [ 29] 9 ContextManager:updateStateLocked:action=updatedState,namespace=VisualActivityTracker,name=ActivityState
2019-12-03 07:02:09.855 [ c] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING
2019-12-03 07:02:09.855 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=8
2019-12-03 07:02:09.855 [ 2b] 3 AlexaPresentation:executeProvideState:token=8
2019-12-03 07:02:09.857 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState
2019-12-03 07:02:09.857 [ 2b] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 07:02:09.856 [ c] 5 TemplateRuntime:onDialogUXStateChanged:state=LISTENING
2019-12-03 07:02:09.858 [ c] 5 AlexaPresentation:onDialogUXStateChanged:state=LISTENING
2019-12-03 07:02:09.858 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 07:02:09.858 [ 5] 9 WebSocket:AccessLog
2019-12-03 07:02:09.857 [ 28] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=8
2019-12-03 07:02:09.859 [ 28] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers
2019-12-03 07:02:09.859 [ 28] 9 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState
2019-12-03 07:02:09.856 [ 3] 3 GUILogBridge:GUILog:component=WSClient:message sent, type: holdToTalk
2019-12-03 07:02:09.860 [ 34] 9 ContextManager:buildContextIgnored:namespace=AudioActivityTracker,name=ActivityState
2019-12-03 07:02:09.858 [ 5] 9 WebSocket:AccessLog
2019-12-03 07:02:09.860 [ 34] 9 ContextManager:buildContextIgnored:namespace=Alexa.Presentation.APL,name=RenderedDocumentState
2019-12-03 07:02:09.860 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.861 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.861 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.861 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.861 [ 34] 9 ContextManager:buildContextIgnored:namespace=VisualActivityTracker,name=ActivityState
2019-12-03 07:02:09.861 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.860 [ 5] 9 WebSocketServer:writeMessageComplete
######################################

ALEXA STATE: LISTENING
######################################

2019-12-03 07:02:09.862 [ 34] 5 ContextManager:buildContextSuccessful
2019-12-03 07:02:09.863 [ 19] 0 AudioInputProcessor:executeOnContextAvailable
2019-12-03 07:02:09.863 [ 19] 1 FocusManager:acquireChannel:channelName=Dialog,interface=SpeechRecognizer
2019-12-03 07:02:09.864 [ 17] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND
2019-12-03 07:02:09.865 [ 19] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=376ec233-f0ed-4e15-80ff-ae6dc17a542e,newValue=25e6a0ee-6890-4be0-8876-2d54fd513015
2019-12-03 07:02:09.865 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.865 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.865 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.865 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.865 [ 19] 0 DirectiveProcessor:scrubDialogRequestIdLocked:dialogRequestId=376ec233-f0ed-4e15-80ff-ae6dc17a542e
2019-12-03 07:02:09.866 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.866 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.866 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 07:02:09.866 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:09.867 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 07:02:09.867 [ 17] 5 AudioActivityTracker:notifyOfActivityUpdates
2019-12-03 07:02:09.868 [ 19] 0 EventBuilder:buildJsonEventString:messageId=6445c0dc-17a9-43a4-ab9c-9b0ea7826c22,namespace=SpeechRecognizer,name=Recognize
2019-12-03 07:02:09.869 [ 16] 5 AudioActivityTracker:executeNotifyOfActivityUpdates
2019-12-03 07:02:09.870 [ 19] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND
2019-12-03 07:02:09.870 [ 19] 0 AudioInputProcessor:sendRequestNow
2019-12-03 07:02:09.870 [ 19] 7 HTTP2Transport:send
2019-12-03 07:02:09.870 [ 19] 7 HTTP2Transport:enqueueRequest:beforeConnected=false
2019-12-03 07:02:09.870 [ 37] 7 MessageRequestHandler:create:context=0x13127b4,messageRequest=0x7000ae84
2019-12-03 07:02:09.871 [ 37] 5 ExchangeHandler:ExchangeHandler:context=0x13127b4
2019-12-03 07:02:09.871 [ 37] 7 MessageRequestHandler:MessageRequestHandler:context=0x13127b4,messageRequest=0x7000ae84
2019-12-03 07:02:09.871 [ 37] 9 HTTP2MimeRequestEncoder:HTTP2MimeRequestEncoder:boundary=WhooHooZeerOoonie!,source=0x71ed321c
2019-12-03 07:02:09.871 [ 37] 9 MimeResponseSink:MimeResponseSink:handler=0x71ed3220
2019-12-03 07:02:09.871 [ 37] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2019-12-03 07:02:09.871 [ 37] 7 HTTP2Transport:onMessageRequestSent:countOfUnfinishedMessageHandlers=1
2019-12-03 07:02:09.871 [ 37] 7 HTTP2Transport:createAndSendRequest:type=POST
2019-12-03 07:02:09.872 [ 37] 9 HTTP2MimeRequestEncoder:getRequestHeaderLines
2019-12-03 07:02:09.872 [ 37] 9 MessageRequestHandler:getRequestHeaderLines
2019-12-03 07:02:09.872 [ 37] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.897 [ 38] 9 LibcurlHTTP2Connection:insertActiveStream:handle=0x71e8db18,streamId=AVSEvent-13
2019-12-03 07:02:09.898 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.898 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=NEW
2019-12-03 07:02:09.898 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=NEW,newState=GETTING_1ST_PART_HEADERS
2019-12-03 07:02:09.899 [ 38] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 07:02:09.899 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.899 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_1ST_PART_HEADERS,newState=SENDING_1ST_BOUNDARY
2019-12-03 07:02:09.899 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_1ST_BOUNDARY,newState=SENDING_PART_HEADERS
2019-12-03 07:02:09.899 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_HEADERS,newState=SENDING_PART_DATA
2019-12-03 07:02:09.899 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16277
2019-12-03 07:02:09.899 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.899 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=14313
2019-12-03 07:02:09.900 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.900 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_DATA,newState=SENDING_END_BOUNDARY
2019-12-03 07:02:09.900 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_END_BOUNDARY,newState=GETTING_NTH_PART_HEADERS
2019-12-03 07:02:09.900 [ 38] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 07:02:09.900 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.901 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_NTH_PART_HEADERS,newState=SENDING_CRLF_AFTER_BOUNDARY
2019-12-03 07:02:09.901 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_CRLF_AFTER_BOUNDARY,newState=SENDING_PART_HEADERS
2019-12-03 07:02:09.901 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_HEADERS,newState=SENDING_PART_DATA
2019-12-03 07:02:09.901 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=14201
2019-12-03 07:02:09.901 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.901 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=1668
2019-12-03 07:02:09.901 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=12533
2019-12-03 07:02:09.901 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.901 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.902 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.903 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.903 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.903 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.903 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.913 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.914 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.914 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.914 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.914 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:09.914 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:09.914 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.914 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.915 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.915 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.915 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.915 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.915 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.926 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.926 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.927 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.927 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.927 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:09.927 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:09.927 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.928 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.929 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.929 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.930 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.930 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.930 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.941 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.941 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.941 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.941 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.942 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:09.942 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:09.942 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.942 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.943 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.943 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.943 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.943 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.943 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:09.943 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:09.943 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.943 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.944 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.944 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.944 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.944 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.944 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.955 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.955 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.955 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.955 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.955 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:09.955 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:09.955 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.955 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.956 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.956 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.956 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.956 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.956 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.969 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.969 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.969 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.969 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.970 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:09.970 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:09.970 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.970 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.970 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.970 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.970 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.970 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.970 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.981 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.981 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.981 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.981 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.981 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:09.981 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:09.981 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.981 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.982 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.982 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.982 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.982 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.982 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.993 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.994 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.994 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.995 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.995 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:09.995 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:09.995 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.996 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:09.996 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:09.996 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:09.996 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:09.996 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:09.996 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.007 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.007 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.007 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.007 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.008 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.008 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.008 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.008 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.008 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.009 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.009 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.009 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.009 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.021 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.021 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.021 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.022 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.022 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:10.022 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:10.022 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.022 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.022 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.026 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.026 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.027 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.029 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.040 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.040 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.041 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.041 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.041 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:10.041 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:10.041 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.041 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.042 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.042 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.042 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.042 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.042 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.053 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.053 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.054 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.054 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.054 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.054 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.054 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.054 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.055 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.055 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.055 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.055 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.055 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.066 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.066 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.066 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.066 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.066 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:10.066 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:10.066 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.066 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.066 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.066 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.066 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.066 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.066 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.077 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.077 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.077 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.077 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.078 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.078 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.078 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.078 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.078 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.078 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.078 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.078 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.078 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.089 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.091 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.091 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.091 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.092 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:10.092 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:10.092 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.092 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.092 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.092 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.092 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.093 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.093 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.103 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.103 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.103 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.103 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.103 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.103 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.103 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.103 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.104 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.104 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.104 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.104 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.104 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.115 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.115 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.116 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.116 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.116 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.116 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.116 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.116 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.118 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.118 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.118 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.118 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.118 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.118 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.118 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.118 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.119 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.119 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.119 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.119 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.119 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.133 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.134 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.134 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.134 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.134 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.134 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.134 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.134 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.135 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.135 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.135 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.136 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.136 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.146 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.146 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.147 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.147 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.147 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:10.147 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:10.147 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.147 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.148 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.148 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.148 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.148 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.148 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.159 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.159 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.159 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.159 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.160 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.160 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.160 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.160 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.160 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:10.160 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.160 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.161 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.161 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.162 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.162 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.162 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.173 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.173 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.173 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.173 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.173 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.173 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.173 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.173 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.174 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.174 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.174 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.174 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.174 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.185 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.185 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.185 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.185 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.185 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.185 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.185 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.185 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.187 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.187 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.187 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.187 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.187 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.188 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.188 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.188 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.189 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.189 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.189 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.189 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.189 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.200 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.200 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.200 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.200 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.201 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=278
2019-12-03 07:02:10.201 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16106
2019-12-03 07:02:10.201 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.201 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.201 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.201 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.201 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.202 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.202 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=1,bytesRead=0
2019-12-03 07:02:10.210 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.210 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.210 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.210 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.210 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.210 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.210 [ 6] 9 GUIClient:onMessage:payload={"type":"holdToTalk"}
2019-12-03 07:02:10.211 [ 6] 9 GUIManager:handleHoldToTalk
2019-12-03 07:02:10.211 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.211 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.212 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.212 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.212 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.212 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.212 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.212 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"message sent, type: holdToTalk"}
2019-12-03 07:02:10.213 [ 3] 3 GUILogBridge:GUILog:component=WSClient:message sent, type: holdToTalk
2019-12-03 07:02:10.214 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.214 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.214 [ 19] 0 AudioInputProcessor:stopCapture:stopImmediately=false
2019-12-03 07:02:10.214 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=SENDING_PART_DATA
2019-12-03 07:02:10.214 [ 19] 5 UserInactivityMonitor:onUserActive
2019-12-03 07:02:10.214 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=16384
2019-12-03 07:02:10.214 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.214 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=0,bytesRead=556
2019-12-03 07:02:10.214 [ 38] 9 MessageRequestHandler:onSendMimePartData:size=15828
2019-12-03 07:02:10.215 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.215 [ 38] 0 InProcessAttachmentReader:readFailed:reason=SDS is closed
2019-12-03 07:02:10.215 [ 38] 9 MessageRequestHandler:attachmentRead:readStatus=4,bytesRead=0
2019-12-03 07:02:10.215 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_DATA,newState=SENDING_END_BOUNDARY
2019-12-03 07:02:10.215 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_END_BOUNDARY,newState=GETTING_NTH_PART_HEADERS
2019-12-03 07:02:10.215 [ 38] 9 MessageRequestHandler:getMimePartHeaderLines
2019-12-03 07:02:10.215 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.215 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_NTH_PART_HEADERS,newState=SENDING_TERMINATING_DASHES
2019-12-03 07:02:10.215 [ 19] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY
2019-12-03 07:02:10.215 [ 38] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_TERMINATING_DASHES,newState=DONE
2019-12-03 07:02:10.215 [ c] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING
2019-12-03 07:02:10.216 [ c] 5 TemplateRuntime:onDialogUXStateChanged:state=THINKING
2019-12-03 07:02:10.216 [ c] 5 AlexaPresentation:onDialogUXStateChanged:state=THINKING
2019-12-03 07:02:10.216 [ 38] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-13,size=1,nmemb=16384,userData=0x71ecbf40
2019-12-03 07:02:10.216 [ 38] 9 HTTP2MimeRequestEncoder:onSendData:size=16384,state=DONE
2019-12-03 07:02:10.217 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 07:02:10.217 [ 5] 9 WebSocket:AccessLog
2019-12-03 07:02:10.218 [ 5] 9 WebSocket:AccessLog
2019-12-03 07:02:10.218 [ 5] 9 WebSocketServer:writeMessageComplete
#####################################

ALEXA STATE: THINKING
#####################################

2019-12-03 07:02:10.219 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.219 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.219 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.219 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.220 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.222 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.224 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 07:02:10.224 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message
2019-12-03 07:02:10.224 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:10.560 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-13,size=1,nmemb=13,userData=0x71ecbf40
2019-12-03 07:02:10.561 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveResponseCode:responseCode=204
2019-12-03 07:02:10.561 [ 38] 9 MimeResponseSink:onReceiveResponseCode:responseCode=204
2019-12-03 07:02:10.561 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.561 [ 38] 7 MessageRequestHandler:onReceiveResponseCode:responseCode=204
2019-12-03 07:02:10.561 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 07:02:10.561 [ 38] 7 HTTP2Transport:onMessageRequestAcknowledged
2019-12-03 07:02:10.561 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=HTTP/2 204

2019-12-03 07:02:10.561 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=HTTP/2 204

2019-12-03 07:02:10.561 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.561 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-13,size=1,nmemb=56,userData=0x71ecbf40
2019-12-03 07:02:10.561 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid: 9a173f88-044a-4224-806f-723cadab915a

2019-12-03 07:02:10.561 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid: 9a173f88-044a-4224-806f-723cadab915a

2019-12-03 07:02:10.561 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.561 [ 38] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid: 9a173f88-044a-4224-806f-723cadab915a
2019-12-03 07:02:10.561 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-13,size=1,nmemb=82,userData=0x71ecbf40
2019-12-03 07:02:10.561 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-9

2019-12-03 07:02:10.561 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-9

2019-12-03 07:02:10.561 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.561 [ 38] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid: 0a6c39fffecb1964-0001e9e6-011c8207-d5a17b7ed548bf5d-ea7d6acd-9
2019-12-03 07:02:10.561 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-13,size=1,nmemb=32,userData=0x71ecbf40
2019-12-03 07:02:10.562 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 07:02:10.562 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-origin: *

2019-12-03 07:02:10.562 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.562 [ 38] 9 LibcurlHTTP2Request:headerCallback:id=AVSEvent-13,size=1,nmemb=2,userData=0x71ecbf40
2019-12-03 07:02:10.562 [ 38] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=

2019-12-03 07:02:10.562 [ 38] 9 MimeResponseSink:onReceiveHeaderLine:line=

2019-12-03 07:02:10.562 [ 38] 9 HTTP2Transport:onActivity
2019-12-03 07:02:10.562 [ 38] 9 HTTP2MimeResponseDecoder:onResponseFinished:status=COMPLETE
2019-12-03 07:02:10.562 [ 38] 9 MimeResponseSink:onResponseFinished:status=COMPLETE
2019-12-03 07:02:10.562 [ 38] 7 MessageRequestHandler:onResponseFinished:status=COMPLETE,responseCode=204
2019-12-03 07:02:10.562 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 07:02:10.562 [ 38] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 07:02:10.562 [ 38] 7 HTTP2Transport:onMessageRequestFinished:countOfUnfinishedMessageHandlers=0
2019-12-03 07:02:10.562 [ 38] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS_NO_CONTENT
2019-12-03 07:02:10.562 [ 38] 5 AudioInputProcessor:stopCapture:reason=streamClosed
2019-12-03 07:02:10.563 [ 38] 0 LibcurlHTTP2Connection:streamFinished:streamId=AVSEvent-13,result=No error,CURLcode=0
2019-12-03 07:02:10.563 [ 38] 9 LibcurlHTTP2Connection:releaseStream:streamId=AVSEvent-13
2019-12-03 07:02:10.563 [ 38] 7 MessageRequestHandler:reportMessageRequestAcknowledged
2019-12-03 07:02:10.563 [ 38] 7 MessageRequestHandler:reportMessageRequestFinished
2019-12-03 07:02:15.218 [ c] 0 DialogUXStateAggregator:transitionFromThinkingTimedOut
2019-12-03 07:02:15.218 [ c] 0 DialogUXStateAggregator:setState:from=THINKING,to=IDLE
2019-12-03 07:02:15.218 [ c] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2019-12-03 07:02:15.219 [ c] 5 AlexaPresentation:onDialogUXStateChanged:state=IDLE
2019-12-03 07:02:15.219 [ 5] 9 WebSocketServer:writeMessageBegin
2019-12-03 07:02:15.219 [ 5] 9 WebSocket:AccessLog
2019-12-03 07:02:15.219 [ 5] 9 WebSocket:AccessLog
2019-12-03 07:02:15.219 [ 19] 1 FocusManager:releaseChannel:channelName=Dialog
2019-12-03 07:02:15.219 [ 5] 9 WebSocketServer:writeMessageComplete
2019-12-03 07:02:15.220 [ 6] 9 WebSocket:AccessLog
#################################

ALEXA STATE: IDLE
#################################

2019-12-03 07:02:15.220 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.220 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.220 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.221 [ 19] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE
2019-12-03 07:02:15.221 [ 17] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE
2019-12-03 07:02:15.221 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.222 [ 19] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE
2019-12-03 07:02:15.221 [ 17] 5 AudioActivityTracker:notifyOfActivityUpdates
2019-12-03 07:02:15.222 [ 19] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus
2019-12-03 07:02:15.222 [ 19] 0 AudioInputProcessor:executeResetState
2019-12-03 07:02:15.223 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.224 [ 16] 5 AudioActivityTracker:executeNotifyOfActivityUpdates
2019-12-03 07:02:15.224 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.224 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.225 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.225 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.225 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.226 [ 6] 9 GUIClient:onMessage:payload={"type":"logEvent","level":"info","component":"WSClient","message":"received message"}
2019-12-03 07:02:15.227 [ 6] 9 WebSocket:AccessLog
2019-12-03 07:02:15.227 [ 3] 3 GUILogBridge:GUILog:component=WSClient:received message

@powj
Copy link
Contributor

powj commented Dec 12, 2019

Hi @shubhamsbhosale96 ,

Can you try running with the AVS Device SDK SampleApp? You can check the instructions on how to run that SampleApp in the quick start guide

@shubhamsbhosale96
Copy link
Author

avs device SDK sample app working fine.
no error

@shubhamsbhosale96
Copy link
Author

I have re-installed AVS Smart screen sdk with fresh raspbian stretch os on RPi.
but it gives same error as above
audio input processor recognizefailed:barge-in is not permitted while busy

@eeduwj
Copy link

eeduwj commented Dec 14, 2019

Could the problem be related to the remote desktop software (VNC)you are using?

Can you try on the Raspberry Pi directly?
First with the "AVS Device SDK SampleApp" (audio only) and if that works then with the Smart Screen SDK sample app.

@shubhamsbhosale96
Copy link
Author

thanks
It's working

@shenhuaz shenhuaz mentioned this issue Apr 14, 2020
Closed
6 tasks
@yuan0258 yuan0258 mentioned this issue Jun 2, 2020
Closed
6 tasks
This was referenced Sep 29, 2020
Closed
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
4 participants
@bennyAv10 @powj @eeduwj @shubhamsbhosale96