alexa / avs-device-sdk

An SDK for commercial device makers to integrate Alexa directly into connected products.
https://developer.amazon.com/alexa/alexa-voice-service
Apache License 2.0
1.26k stars 602 forks source link

Delay in streaming music use case #805

Closed vaddep closed 6 years ago

vaddep commented 6 years ago

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

Briefly summarize your issue:

When we say "Alexa, Play some music" we observer following delays:

What is the expected behavior?

These should be faster and should not take more time.

What behavior are you observing?

Delay in sending StopCapture and also delay in parsing playlist URL.

Provide the steps to reproduce the issue, if applicable:

Just ask "Alexa, Play some music"

Tell us about your environment:

Linux - Arm

What version of the AVS Device SDK are you using?

AVS SDK V1.6

Tell us what hardware you're using:

Linux - ARM

Tell us about your OS (Type & version):

LOGS: #################################################################### Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: QTISoundTrigger::onKeyWordDetected - KEYWORD DETECTED = 3 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: QTISoundTrigger::onKeyWordDetected WITH INDICES START = 8000 END = 20799 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: QTISoundTrigger::onKeyWordDetected() - m_client->notifyOfWakeWord() Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: QSTHWClient::getDOADirection() - [Session:1] in get parameters 0 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: [Session:1] param to get st_direction_of_arrival Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: process_get_param_data: target angle boundaries [10, 50] Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: QSTHWClient::getChannelIndex() - [Session:1] in get parameters 0 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: [Session:1] param to get st_channel_index Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: process_get_param_data: procsesing channel index params Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: process_get_param_data: target channel index - [0] Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: ####################################___WITH INDICES START = 8000 END = 20799 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.223 [ b] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.225 [ e] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: ############################ Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: # Listening... # Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: ############################ Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: UIManager::onDialogUXStateChanged state = LISTENING Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: InteractionManager::onDialogUXStateChanged to LISTENING Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: QTISoundTrigger::getDOADirection() - DOA - m_dOAIndex = 0 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: LISTENING - DOA Index = 0 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: setAllON Called Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.226 [ 8] 0 NotificationsCapabilityAgent:provideState:stateRequestToken=4 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.226 [ 7] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=4 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.226 [ 8] 5 AudioActivityTracker:provideState Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.226 [ 4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=4 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.226 [ 9] 5 AudioActivityTracker:executeProvideState Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.226 [ 7] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.227 [ 7] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=4 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.227 [ 9] 0 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.227 [ 4] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: QTISoundTrigger::onKeyWordDetected - startRecognition = 1 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: lab capture file : /data/SVA/lab_capture_file_1 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: Starting LAB capture Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.227 [ 7] 0 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.228 [ 8] 0 ContextManager:buildContextSuccessful Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.229 [ b] 0 AudioInputProcessor:executeOnContextAvailable Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.229 [ b] 1 FocusManager:acquireChannel:channelName=Dialog,interface=SpeechRecognizer Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.229 [ b] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=512f8324-9e8b-4e15-bb0c-b1d3d92b634f,newValue=85e51c62-d37f-4ba6-acf4-307c8c23d0a9 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.229 [ f] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.230 [ f] 5 AudioActivityTracker:notifyOfActivityUpdates Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.229 [ b] 0 DirectiveProcessor:scrubDialogRequestIdLocked:dialogRequestId=512f8324-9e8b-4e15-bb0c-b1d3d92b634f Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.230 [ b] 0 EventBuilder:buildJsonEventString:messageId=941edd9f-fb9f-4f5c-a3e1-91ecff0a78d6,namespace=SpeechRecognizer,name=Recognize Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.231 [ b] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.231 [ b] 9 HTTP2Transport:enqueueRequest Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.231 [ 9] 5 AudioActivityTracker:executeNotifyOfActivityUpdates Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.310 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.310 [ d] 0 HTTP2StreamPool:getStream:streamId=65,numAcquiredStreams=2 Jun 25 09:46:45 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:45.310 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.088 [ 10] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechRecognizer"\,name\:"StopCapture"\,messageId\:"11c10ad4-94ec-4bd5-b948-7cad799c25e2"\,dialogRequestId\:"85e51c62-d37f-4ba6-acf4-307c8c23d0a9"} Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.089 [ 11] I DirectiveRouter:preHandleDirective:messageId=11c10ad4-94ec-4bd5-b948-7cad799c25e2,action=calling Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.089 [ 11] 0 CapabilityAgent:addingMessageIdToMap:messageId=11c10ad4-94ec-4bd5-b948-7cad799c25e2 Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.089 [ 12] I DirectiveRouter:handleDirective:messageId=11c10ad4-94ec-4bd5-b948-7cad799c25e2,action=calling Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.089 [ b] 0 AudioInputProcessor:stopCapture:stopImmediately=true Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.089 [ b] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.089 [ b] 0 DirectiveProcessor:onHandlingCompeted:messageId=11c10ad4-94ec-4bd5-b948-7cad799c25e2,directiveBeingPreHandled=(nullptr) Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.089 [ e] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.089 [ b] 0 CapabilityAgent:removingMessageIdFromMap:messageId=11c10ad4-94ec-4bd5-b948-7cad799c25e2 Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: ########################### Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: # Thinking... # Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: ########################### Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: UIManager::onDialogUXStateChanged state = THINKING Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: InteractionManager::onDialogUXStateChanged to THINKING Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: ######## QTISoundTrigger::stopRecording() 0 Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: QAHWManager::StopRecorder() 0 Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: setAllOff Called Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:48.098 [ d] I InProcessAttachmentReader:readFailed:reason=SDS is closed Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: exited lab processing Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: counter of buffer lastWakeWordAndUserUtteranceEndIndex = 192320bytes to read 182400 - old style, ignore, bytes read 131840 Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: event_handler_thread - exited capture_lab_data based on a call to doneLookahead() Jun 25 09:46:48 apq8009 AlexaClientApp[1588]: event_handler_thread - qsthw_start_recognition Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: QTISoundTrigger::recognitionStateChanged - m_isRecognizing = 0 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: [1] callback event processed, detection counter 3 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: proceed with utterance or command Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: event_handler_thread: Success to release qti lock Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.300 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-002502d2-e7d21c079e8a1efc-f81f79fa-5 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.519 [ 10] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechSynthesizer"\,name\:"Speak"\,messageId\:"f63252ac-37cf-4974-82ae-23a4e859cdcf"\,dialogRequestId\:"85e51c62-d37f-4ba6-acf4-307c8c23d0a9"} Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.519 [ 10] I DirectiveSequencer:onDirective:directive={"namespace\:"AudioPlayer"\,name\:"ClearQueue"\,messageId\:"ee246f2c-065b-40f4-9b08-0ecda5ca4e44"\,dialogRequestId\:"85e51c62-d37f-4ba6-acf4-307c8c23d0a9"} Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.519 [ 10] I DirectiveSequencer:onDirective:directive={"namespace\:"AudioPlayer"\,name\:"Play"\,messageId\:"a6e990ef-8e0d-47b5-b142-f8d8a171c570"\,dialogRequestId\:"85e51c62-d37f-4ba6-acf4-307c8c23d0a9"} Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.520 [ 11] I DirectiveRouter:preHandleDirective:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf,action=calling Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.520 [ 11] 0 CapabilityAgent:addingMessageIdToMap:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.520 [ 11] 9 SpeechSynthesizer:preHandleDirective:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.520 [ 11] I DirectiveRouter:preHandleDirective:messageId=ee246f2c-065b-40f4-9b08-0ecda5ca4e44,action=calling Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.520 [ 11] 0 CapabilityAgent:addingMessageIdToMap:messageId=ee246f2c-065b-40f4-9b08-0ecda5ca4e44 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.520 [ 11] I DirectiveRouter:preHandleDirective:messageId=a6e990ef-8e0d-47b5-b142-f8d8a171c570,action=calling Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.520 [ 11] 0 CapabilityAgent:addingMessageIdToMap:messageId=a6e990ef-8e0d-47b5-b142-f8d8a171c570 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.521 [ a] 0 SpeechSynthesizer:executePreHandle:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.521 [ 12] I DirectiveRouter:handleDirective:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf,action=calling Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.521 [ 12] 9 SpeechSynthesizer:handleDirective:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.525 [ a] 0 SpeechSynthesizer:executeHandle:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.526 [ a] 1 FocusManager:acquireChannel:channelName=Dialog,interface=SpeechSynthesizer Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.526 [ f] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.526 [ f] 0 SpeechSynthesizer:onFocusChanged:newFocus=FOREGROUND Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.526 [ b] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.526 [ b] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.527 [ b] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.526 [ f] 9 SpeechSynthesizer:setCurrentStateLocked:state=GAINING_FOCUS Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.527 [ a] 0 SpeechSynthesizer:executeStateChange:newState=PLAYING Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.528 [ a] 9 SpeechSynthesizer:startPlaying Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.528 [ a] 9 MediaPlayer:setSourceCalled:sourceType=AttachmentReader Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.528 [ 2] 0 MediaPlayer:handleSetSourceCalled Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.528 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.529 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.536 [ 2] 9 BaseStreamSource:Creating decodebin for URL Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.538 [ a] 9 MediaPlayer:playCalled Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.538 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=3,currentId=3 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.539 [ 2] 9 AttachmentReaderSource:handleSeekData:offset=0 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 1b] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.540 [ 2] 9 MediaPlayer:State Change:oldState=NULL,newState=READY,pendingState=PLAYING Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.541 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.541 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.541 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.541 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.541 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.541 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.541 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=49 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.541 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.542 [ 2] 9 AttachmentReaderSource:read:size=2299,status=0 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.567 [ 1b] 9 MediaPlayer:onPadAddedCalled Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.823 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.823 [ d] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.823 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.823 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=65,result=200 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.823 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.823 [ d] 0 HTTP2StreamPool:releaseStream:streamId=65,numAcquiredStreams=1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.823 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.824 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.824 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=avdec_mp3-1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.824 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.824 [ 2] 9 MediaPlayer:handlePadAddedSignalCalled Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.827 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.828 [ 2] 9 MediaPlayer:messageReceived:type=stream-start,source=audio-pipeline Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.828 [ 2] 9 AttachmentReaderSource:read:size=3618,status=0 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.828 [ 2] I InProcessAttachmentReader:readFailed:reason=SDS is closed Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.829 [ 2] 9 AttachmentReaderSource:read:size=0,status=3 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.829 [ 2] 9 AttachmentReaderSource:handleReadData:info=signalingEndOfData Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.829 [ 2] 9 BaseStreamSource:signalEndOfDataCalled Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.829 [ 2] 9 BaseStreamSource:gstAppSrcEndOfStreamSuccess Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.831 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=49 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.845 [ 2] 9 MediaPlayer:messageReceived:type=latency,source=audio_sink Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.845 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.845 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.845 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.845 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.845 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.846 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.846 [ 2] 9 MediaPlayer:State Change:oldState=READY,newState=PAUSED,pendingState=PLAYING Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.846 [ 2] 9 MediaPlayer:messageReceived:type=async-done,source=audio-pipeline Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.846 [ 2] 9 MediaPlayer:messageReceived:type=new-clock,source=audio-pipeline Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.847 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.859 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=converter Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.859 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=avdec_mp3-1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=mpegaudioparse1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=id3demux1 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decoder Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=src Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio-pipeline Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 9 MediaPlayer:State Change:oldState=PAUSED,newState=PLAYING,pendingState=VOID_PENDING Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 0 MediaPlayer:callingOnPlaybackStarted:currentId=3 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.860 [ 2] 9 SpeechSynthesizer:onPlaybackStarted:callbackSourceId=3 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.861 [ a] 0 SpeechSynthesizer:executePlaybackStarted Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.861 [ a] 9 SpeechSynthesizer:setCurrentStateLocked:state=PLAYING Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.861 [ a] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.861 [ a] 9 MediaPlayer:getOffsetCalled Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.861 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=3,currentId=3 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.862 [ a] 0 ContextManager:updateStateLocked:action=updatedState,namespace=SpeechSynthesizer,name=SpeechState Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.863 [ f] 9 SpeechSynthesizer:onFocusChangedSuccess Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.863 [ f] 5 AudioActivityTracker:notifyOfActivityUpdates Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.864 [ 9] 5 AudioActivityTracker:executeNotifyOfActivityUpdates Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.863 [ a] 0 EventBuilder:buildJsonEventString:messageId=80bfa423-ad3a-4bd8-b0cf-a72f859186c9,namespace=SpeechSynthesizer,name=SpeechStarted Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.864 [ a] 9 HTTP2Transport:enqueueRequest Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.864 [ e] 0 DialogUXStateAggregator:setState:from=THINKING,to=SPEAKING Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: ########################### Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: # Speaking... # Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: ########################### Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: UIManager::onDialogUXStateChanged state = SPEAKING Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: InteractionManager::onDialogUXStateChanged to SPEAKING Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: setAllON Called Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.924 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.924 [ d] 0 HTTP2StreamPool:getStream:streamId=67,numAcquiredStreams=2 Jun 25 09:46:49 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:49.924 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:46:50 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:50.056 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:46:50 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:50.056 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:46:50 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:50.342 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-67 Jun 25 09:46:50 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:50.343 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=67,result=204 Jun 25 09:46:50 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:50.343 [ d] 0 HTTP2StreamPool:releaseStream:streamId=67,numAcquiredStreams=1 Jun 25 09:46:50 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:50.343 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.221 [ 1b] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.221 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.221 [ 2] 9 MediaPlayer:messageReceived:type=eos,source=audio-pipeline Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.521 [ 2] 9 BaseStreamSource:~BaseStreamSource Jun 25 09:46:54 apq8009 AlexaClientApp[1588]:  Trying to dispose element src, but it is in PLAYING instead of the NULL state. You need to explicitly set elements to the NULL state before dropping the final reference, to allow them to clean up. This problem may also be caused by a refcounting bug in the application or some element. Jun 25 09:46:54 apq8009 AlexaClientApp[1588]:  Trying to dispose element typefind, but it is in PLAYING instead of the NULL state. You need to explicitly set elements to the NULL state before dropping the final reference, to allow them to clean up. This problem may also be caused by a refcounting bug in the application or some element. Jun 25 09:46:54 apq8009 AlexaClientApp[1588]:  Trying to dispose element decoder, but it is in PLAYING instead of the NULL state. You need to explicitly set elements to the NULL state before dropping the final reference, to allow them to clean up. This problem may also be caused by a refcounting bug in the application or some element. Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.526 [ 2] 0 MediaPlayer:callingOnPlaybackFinished:currentId=3 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.526 [ 2] 9 SpeechSynthesizer:onPlaybackFinished:callbackSourceId=3 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.527 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: gst_element_query_position = 4392000000 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: startStreamingPoint = 0 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.528 [ 2] 0 MediaPlayer:saveOffsetBeforeTeardown:offset=4392 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: m_offsetBeforeTeardown = 4392 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.528 [ a] 0 SpeechSynthesizer:executePlaybackFinished Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.529 [ a] 9 SpeechSynthesizer:setCurrentStateLocked:state=FINISHED Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.529 [ a] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=0 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.529 [ a] 0 ContextManager:updateStateLocked:action=updatedState,namespace=SpeechSynthesizer,name=SpeechState Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.530 [ a] 0 EventBuilder:buildJsonEventString:messageId=4f0eecfd-ce1f-4e60-b81f-0283be3508ae,namespace=SpeechSynthesizer,name=SpeechFinished Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.530 [ a] 9 HTTP2Transport:enqueueRequest Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.531 [ a] 9 SpeechSynthesizer:setHandlingCompleted Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.531 [ a] 0 DirectiveProcessor:onHandlingCompeted:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf,directiveBeingPreHandled=(nullptr) Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.531 [ a] 0 CapabilityAgent:removingMessageIdFromMap:messageId=f63252ac-37cf-4974-82ae-23a4e859cdcf Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.531 [ 12] I DirectiveRouter:handleDirective:messageId=ee246f2c-065b-40f4-9b08-0ecda5ca4e44,action=calling Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.533 [ 12] 0 AudioPlayer:handleDirective:name=ClearQueue,messageId=ee246f2c-065b-40f4-9b08-0ecda5ca4e44 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.534 [ 12] 1 AudioPlayer:handleClearQueue Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.534 [ 12] 0 DirectiveProcessor:onHandlingCompeted:messageId=ee246f2c-065b-40f4-9b08-0ecda5ca4e44,directiveBeingPreHandled=(nullptr) Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.534 [ 12] 0 CapabilityAgent:removingMessageIdFromMap:messageId=ee246f2c-065b-40f4-9b08-0ecda5ca4e44 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.534 [ 12] I DirectiveRouter:handleDirective:messageId=a6e990ef-8e0d-47b5-b142-f8d8a171c570,action=calling Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.534 [ c] 0 AudioPlayer:executeClearQueue:clearBehavior=CLEAR_ENQUEUED Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.537 [ c] 0 EventBuilder:buildJsonEventString:messageId=02c6e7e2-a096-406b-9571-a488f4c96fa7,namespace=AudioPlayer,name=PlaybackQueueCleared Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.537 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.537 [ 12] 0 AudioPlayer:handleDirective:name=Play,messageId=a6e990ef-8e0d-47b5-b142-f8d8a171c570 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.537 [ 12] 1 AudioPlayer:handlePlayDirective Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.538 [ 12] 9 AudioPlayer:PLAY:payload={"audioItem"\:{"audioItemId"\:"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#88756784-07e9-4ca7-9317-97a966d63d34\:1"\,"stream"\:{"offsetInMilliseconds"\:0\,"expiryTime"\:"2018-06-25T09\:47\:49+0000"\,"progressReport"\:{"progressReportDelayInMilliseconds"\:1000}\,"url"\:"https\://d29r7idq0wxsiz.cloudfront.net/DigitalMusicDeliveryService/HPS.m3u8?m\=m&dmid\=203884823&c\=cf&f\=ts&t\=10&bl\=256k&s\=true&e1\=1529921700000&e2\=1529921700000&v\=V2&n\=7LTOYQCR53EA2&h\=b6f9e7bf95812a005ba6f8197f43c42f009f924b2d8652c0de90b5ac0707a4b0"\,"token"\:"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#88756784-07e9-4ca7-9317-97a966d63d34\:1"}}\,"playBehavior"\:"REPLACE_ALL"} Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.538 [ 12] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=streamFormat Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.538 [ 12] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=progressReportIntervalInMilliseconds Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.538 [ 12] E JsonUtils:findNodeFailed:reason=missingDirectChild,child=expectedPreviousToken Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.538 [ 12] 0 DirectiveProcessor:onHandlingCompeted:messageId=a6e990ef-8e0d-47b5-b142-f8d8a171c570,directiveBeingPreHandled=(nullptr) Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.538 [ 12] 0 CapabilityAgent:removingMessageIdFromMap:messageId=a6e990ef-8e0d-47b5-b142-f8d8a171c570 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.538 [ c] 1 AudioPlayer:executePlay:playBehavior=REPLACE_ALL Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.539 [ c] 1 AudioPlayer:executeStop:playNextItem=true,m_currentActivity=STOPPED Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.539 [ c] 1 FocusManager:acquireChannel:channelName=Content,interface=AudioPlayer Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.539 [ f] 0 AudioPlayer:onFocusChanged:newFocus=BACKGROUND Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.539 [ f] 5 AudioActivityTracker:notifyOfActivityUpdates Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.539 [ c] 1 AudioPlayer:executeOnFocusChanged:from=NONE,to=BACKGROUND,m_currentActivity=STOPPED Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.539 [ 9] 5 AudioActivityTracker:executeNotifyOfActivityUpdates Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.539 [ c] 1 AudioPlayer:executeOnFocusChanged:action=pauseMediaPlayer Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.540 [ c] 9 MediaPlayer:pausedCalled Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.563 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.563 [ d] 0 HTTP2StreamPool:getStream:streamId=69,numAcquiredStreams=2 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.564 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.620 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 1 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.620 [ 2] 9 MediaPlayer:resetPipeline Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.620 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.621 [ 2] 0 MediaPlayer:handlePauseCalled:idPassed=2,currentId=0 Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.621 [ 2] E MediaPlayer:validateSourceAndIdFailed:reason=sourceNotSet Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.621 [ 2] E MediaPlayer:handlePauseFailed Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.048 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-002527dc-5af35fad1aae81a7-923bda28-7 Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.048 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=69,result=204 Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.048 [ d] 0 HTTP2StreamPool:releaseStream:streamId=69,numAcquiredStreams=1 Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.048 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.048 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.048 [ d] 0 HTTP2StreamPool:getStream:streamId=71,numAcquiredStreams=2 Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.049 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.461 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-71 Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.462 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=71,result=204 Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.462 [ d] 0 HTTP2StreamPool:releaseStream:streamId=71,numAcquiredStreams=1 Jun 25 09:46:55 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:55.462 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.534 [ e] 0 DialogUXStateAggregator:setState:from=SPEAKING,to=IDLE Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.534 [ a] 1 FocusManager:releaseChannel:channelName=Dialog Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: ######################################## Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: # Alexa is currently idle! # Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: ######################################## Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: UIManager::onDialogUXStateChanged state = IDLE Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: InteractionManager::onDialogUXStateChanged to IDLE Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: ######## QTISoundTrigger::stopRecording() 1 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: QAHWManager::StopRecorder() 0 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: setAllOff Called Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.537 [ f] 0 SpeechSynthesizer:onFocusChanged:newFocus=NONE Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.537 [ f] 0 AudioPlayer:onFocusChanged:newFocus=FOREGROUND Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.537 [ f] 5 AudioActivityTracker:notifyOfActivityUpdates Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.537 [ 9] 5 AudioActivityTracker:executeNotifyOfActivityUpdates Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.537 [ c] 1 AudioPlayer:executeOnFocusChanged:from=BACKGROUND,to=FOREGROUND,m_currentActivity=STOPPED Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.537 [ c] 1 AudioPlayer:executeOnFocusChanged:action=playNextItem Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.538 [ c] 1 AudioPlayer:playNextItem:m_audioItems.size=1 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.538 [ c] 0 AudioPlayer:cancelTimers Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.538 [ c] 9 AudioPlayer:settingUrlSource:offset=0 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.538 [ c] 9 MediaPlayer:setSourceForUrlCalled Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: URL https://d29r7idq0wxsiz.cloudfront.net/DigitalMusicDeliveryService/HPS.m3u8?m=m&dmid=203884823&c=cf&f=ts&t=10&bl=256k&s=true&e1=1529921700000&e2=1529921700000&v=V2&n=7LTOYQCR53EA2&h=b6f9e7bf95812a005ba6f8197f43c42f009f924b2d8652c0de90b5ac0707a4b0 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.538 [ 2] 0 MediaPlayer:handleSetSourceForUrlCalled Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.538 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.538 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.545 [ 2] 0 MediaPlayer:handleSetSourceCalled Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.545 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.545 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.545 [ 2] 9 BaseStreamSource:Creating Playbin for URL Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.548 [ c] 9 MediaPlayer:playCalled Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.549 [ 2] 0 MediaPlayer:handlePlayCalled:idPassed=4,currentId=4 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.561 [ 2] 9 BaseStreamSource:onSourceFound Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.561 [ 2] 9 BaseStreamSource:handleSourceFoundCalled Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.561 [ 2] 9 BaseStreamSource:handleSourceFoundCalled 1 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.562 [ 2] 9 BaseStreamSource:handleSourceFoundCalled 2 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.562 [ 2] 9 BaseStreamSource:handleSourceFoundCalled 3 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.564 [ 2] 9 AttachmentReaderSource:handleSeekData:offset=0 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.564 [ 2] 0 MediaPlayer:handlePlay:startingState=PLAYING,stateReturn=ASYNC Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.564 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=streamsynchronizer1 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.564 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=playsink Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.564 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=playbin1 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.564 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.564 [ 2] 9 MediaPlayer:State Change:oldState=NULL,newState=READY,pendingState=PLAYING Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.565 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=streamsynchronizer1 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.565 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.565 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=uridecodebin1 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.566 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.566 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodebin1 Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.566 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.566 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=source Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.566 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.566 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=source Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.567 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.567 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:46:56 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:56.567 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=58 Jun 25 09:46:57 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:57.419 [ 1d] 9 LibCurlHttpContentFetcher:getContent:responseCode=200 Jun 25 09:46:57 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:57.419 [ 1d] 9 LibCurlHttpContentFetcher:getContent:contentType=application/vnd.apple.mpegurl Jun 25 09:46:57 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:57.419 [ 1e] 9 PlaylistParser:PlaylistParser:contentType=application/vnd.apple.mpegurl,length=-1 Jun 25 09:46:57 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:57.553 [ c] 1 AudioPlayer:sendEventWithTokenAndOffset:eventName=ProgressReportDelayElapsed Jun 25 09:46:57 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:57.554 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:46:58 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:58.117 [ 1e] I InProcessAttachmentReader:readFailed:reason=SDS is closed Jun 25 09:46:58 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:58.131 [ 1e] 9 PlaylistParser:isM3U8Playlist Jun 25 09:46:58 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:58.134 [ 1e] 9 PlaylistParser:foundChildrenURLsInPlaylist:num=1 Jun 25 09:46:58 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:58.134 [ 1e] 9 PlaylistParser:encounteredMasterPlaylist Jun 25 09:46:59 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:59.065 [ 1f] 9 LibCurlHttpContentFetcher:getContent:responseCode=200 Jun 25 09:46:59 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:59.066 [ 1f] 9 LibCurlHttpContentFetcher:getContent:contentType=application/vnd.apple.mpegurl Jun 25 09:46:59 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:59.066 [ 1e] 9 PlaylistParser:PlaylistParser:contentType=application/vnd.apple.mpegurl,length=-1 Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.090 [ 1e] I InProcessAttachmentReader:readFailed:reason=SDS is closed Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.108 [ 1e] 9 PlaylistParser:isM3U8Playlist Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.109 [ 1e] 9 PlaylistParser:foundChildrenURLsInPlaylist:num=29 Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.110 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.110 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.111 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.111 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.111 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.111 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.111 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStream:info=beginning Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.112 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.117 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.117 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.117 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.117 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.117 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.117 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.118 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.119 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=STILL_ONGOING Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 9 PlaylistParser:foundNonPlaylistURL Jun 25 09:47:00 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:00.120 [ 1e] 3 UrlContentToAttachmentConverter:onPlaylistEntryParsed:status=SUCCESS Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.691 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStreamSuccess Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.691 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.693 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.693 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.694 [ 2] I MediaPlayer:handleGetOffset:reason=getElementGetStateUnsuccessful,stateChangeReturn=ASYNC Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.694 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.697 [ 2] 9 AttachmentReaderSource:read:size=629,status=0 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.698 [ c] 0 EventBuilder:buildJsonEventString:messageId=3e5d97d8-5c55-4fca-a163-5e5914bcaf50,namespace=AudioPlayer,name=ProgressReportDelayElapsed Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.698 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.704 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.704 [ d] 0 HTTP2StreamPool:getStream:streamId=73,numAcquiredStreams=2 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.704 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.753 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.879 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.879 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=tsdemux1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.879 [ 2] 9 MediaPlayer:messageReceived:type=element,source=tsdemux1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.879 [ 2] 9 MediaPlayer:messageReceived:type=stream-collection,source=tsdemux1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.880 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.880 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.880 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src_0 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.880 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aacparse1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.880 [ 2] 9 MediaPlayer:messageReceived:type=element,source=tsdemux1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.880 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audiotee Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodebin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=uridecodebin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=resample Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=conv Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=identity Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aconv Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aqueue Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=abin Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=resample Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.881 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=conv Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.882 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=identity Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.882 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aconv Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.882 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aqueue Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ 2] 9 MediaPlayer:messageReceived:type=stream-status,source=src Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ 2] 9 MediaPlayer:messageReceived:type=stream-start,source=playbin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ 2] 9 MediaPlayer:messageReceived:type=latency,source=audio_sink Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.884 [ c] 0 EventBuilder:buildJsonEventString:messageId=da24cc19-bbde-4032-a8e8-3b01309123ad,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.884 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.883 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.890 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.892 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.892 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.892 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.893 [ c] 0 EventBuilder:buildJsonEventString:messageId=8005b46c-d960-400c-a1fc-6fe43586f7c2,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.893 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=abin Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.893 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.896 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=playsink Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=playbin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:State Change:oldState=READY,newState=PAUSED,pendingState=PLAYING Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=async-done,source=playbin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=new-clock,source=playbin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=resample Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=conv Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=identity Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aconv Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aqueue Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.897 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=abin Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=streamsynchronizer1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audiotee Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=playsink Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=inputselector1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aacparse1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=multiqueue1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=tsdemux1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodebin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=source Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.898 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=uridecodebin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=playbin1 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ 2] 9 MediaPlayer:State Change:oldState=PAUSED,newState=PLAYING,pendingState=VOID_PENDING Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ 2] 0 MediaPlayer:callingOnPlaybackStarted:currentId=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ 2] 0 AudioPlayer:onPlaybackStarted:id=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ c] 1 AudioPlayer:executeOnPlaybackStarted:id=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ c] 9 PlaybackRouter:switchToDefaultHandler Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ c] 9 PlaybackRouter:setHandler:handler=0x83767b2c Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ c] 0 AudioPlayer:changeActivity:from=STOPPED,to=PLAYING Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ c] 0 AudioPlayer:executeProvideState:sendToken=false,stateRequestToken=0 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.899 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.900 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.900 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:01 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.900 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.900 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.900 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.902 [ c] 0 ContextManager:updateStateLocked:action=updatedState,namespace=AudioPlayer,name=PlaybackState Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.902 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.902 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.902 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.903 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.903 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.903 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.903 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.903 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.903 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.904 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.904 [ 2] 9 AttachmentReaderSource:read:size=2048,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.906 [ c] 1 AudioPlayer:notifyObserver:playerActivity=PLAYING Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.908 [ c] 1 AudioPlayer:sendEventWithTokenAndOffset:eventName=PlaybackStarted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.909 [ c] 0 EventBuilder:buildJsonEventString:messageId=20b15dc1-124c-46ec-915a-1e31e4387f6a,namespace=AudioPlayer,name=PlaybackStarted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.909 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.909 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.910 [ c] 0 EventBuilder:buildJsonEventString:messageId=ac7f8a70-6af6-42ce-9d11-09a952d1d534,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.910 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:01.917 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.079 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.079 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.079 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.079 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.079 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ c] 0 EventBuilder:buildJsonEventString:messageId=b73be696-47d7-4156-a5c7-5048b9838abc,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.080 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ c] 0 EventBuilder:buildJsonEventString:messageId=3d9742ae-674b-4a55-8efd-032124d56f96,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.081 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ c] 0 EventBuilder:buildJsonEventString:messageId=bc75ed8b-33a5-4551-974e-98853956ab46,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.082 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ c] 0 EventBuilder:buildJsonEventString:messageId=8f94390e-2dee-428b-b796-b1d3e54aeae4,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.083 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 0 EventBuilder:buildJsonEventString:messageId=7b0badc1-379b-47cb-9d8f-79a88e4005b5,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 0 EventBuilder:buildJsonEventString:messageId=a66fac86-87a7-4c98-b1d0-20e9c527ad27,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 0 EventBuilder:buildJsonEventString:messageId=85d649e0-61a2-435c-a517-feac3f198ea8,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.084 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.086 [ c] 0 EventBuilder:buildJsonEventString:messageId=3e94159c-c89b-41d3-a278-242d5471b9a1,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.086 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.087 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.087 [ c] 0 EventBuilder:buildJsonEventString:messageId=8f97204e-4962-4226-a328-4a89cbb2db8e,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.087 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.088 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.088 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.089 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.092 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.092 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.093 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.098 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.098 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.099 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.099 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.099 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.179 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-73 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.179 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=73,result=204 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.179 [ d] 0 HTTP2StreamPool:releaseStream:streamId=73,numAcquiredStreams=1 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.180 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.180 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.180 [ d] 0 HTTP2StreamPool:getStream:streamId=75,numAcquiredStreams=2 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.180 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.295 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.296 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.296 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.296 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.296 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.296 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.300 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.300 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.300 [ c] 0 EventBuilder:buildJsonEventString:messageId=b25e1c94-7ad4-4ac3-81b7-f17fdaab9d58,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.300 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.300 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.300 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.301 [ 2] 9 AttachmentReaderSource:read:size=2440,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.301 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.301 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.314 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.318 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.318 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.318 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.318 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.318 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.319 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.319 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.319 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.319 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.319 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.320 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.320 [ 2] 9 AttachmentReaderSource:read:size=632,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.321 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.502 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.502 [ 2] 9 AttachmentReaderSource:read:size=3144,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.502 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.506 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.515 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.519 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.519 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.519 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.519 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.520 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.521 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.521 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.521 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.521 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.521 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.521 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.524 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.525 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.525 [ 2] 9 AttachmentReaderSource:read:size=952,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.540 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.541 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.541 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.679 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.695 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fb8-edc3827bd3b731ac-6bdd007e-3 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.695 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=75,result=204 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.695 [ d] 0 HTTP2StreamPool:releaseStream:streamId=75,numAcquiredStreams=1 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.697 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.698 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.698 [ d] 0 HTTP2StreamPool:getStream:streamId=77,numAcquiredStreams=2 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.698 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.708 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.709 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.709 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.709 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.710 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.710 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.710 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.710 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.710 [ c] 0 EventBuilder:buildJsonEventString:messageId=451624f8-b725-445f-b0eb-e6bdccb47024,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.710 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.710 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.710 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.711 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.711 [ c] 0 EventBuilder:buildJsonEventString:messageId=ef89d0f0-6d46-4d2c-9269-1c21b09ecc04,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.711 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.712 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.712 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.712 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.712 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.713 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.713 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.713 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.713 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.713 [ c] 0 EventBuilder:buildJsonEventString:messageId=ed1d764e-a6ab-4e93-a890-52b8c4a11137,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.713 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.713 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.713 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.714 [ c] 0 EventBuilder:buildJsonEventString:messageId=009d9afd-a1d1-4ed6-a364-2fbddf20654f,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.714 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.714 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.716 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.717 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.717 [ 2] 9 AttachmentReaderSource:read:size=2048,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.726 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.727 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.727 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.729 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.759 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.760 [ 2] 9 AttachmentReaderSource:read:size=2048,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.920 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.920 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.920 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.921 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.921 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.921 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.921 [ c] 0 EventBuilder:buildJsonEventString:messageId=4ac3b20c-f6cd-4aa2-8722-85beb7f83dfe,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.921 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.921 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.928 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.929 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.931 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.933 [ 2] 9 AttachmentReaderSource:read:size=2995,status=0 Jun 25 09:47:02 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:02.961 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStream:info=beginning Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.131 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.219 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-77 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.219 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=77,result=204 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.219 [ d] 0 HTTP2StreamPool:releaseStream:streamId=77,numAcquiredStreams=1 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.219 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.219 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.219 [ d] 0 HTTP2StreamPool:getStream:streamId=79,numAcquiredStreams=2 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.220 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.922 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fb0-436748b5d3b73a84-bb268c84-3 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.923 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=79,result=204 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.923 [ d] 0 HTTP2StreamPool:releaseStream:streamId=79,numAcquiredStreams=1 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.923 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.923 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.923 [ d] 0 HTTP2StreamPool:getStream:streamId=81,numAcquiredStreams=2 Jun 25 09:47:03 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:03.923 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.420 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-81 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.420 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=81,result=204 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.420 [ d] 0 HTTP2StreamPool:releaseStream:streamId=81,numAcquiredStreams=1 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.421 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.421 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.421 [ d] 0 HTTP2StreamPool:getStream:streamId=83,numAcquiredStreams=2 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.421 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.798 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStreamSuccess Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.799 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.799 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.799 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.801 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.802 [ 2] 9 AttachmentReaderSource:read:size=629,status=0 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.802 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.802 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.941 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fbf-0f4dda4a23b729ce-49039cd2-3 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.941 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=83,result=204 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.941 [ d] 0 HTTP2StreamPool:releaseStream:streamId=83,numAcquiredStreams=1 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.941 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.941 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.941 [ d] 0 HTTP2StreamPool:getStream:streamId=85,numAcquiredStreams=2 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.942 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.942 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.942 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.942 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.943 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.943 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:04 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:04.944 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.161 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.162 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.162 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.162 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.162 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.163 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.163 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.163 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.175 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.181 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.181 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.181 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.181 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.181 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.181 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.182 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.182 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.356 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.357 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.357 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.357 [ 2] 9 AttachmentReaderSource:read:size=1944,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.357 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.358 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.367 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.367 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.368 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.367 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.370 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.370 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.383 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.384 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.384 [ 2] 9 AttachmentReaderSource:read:size=104,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.384 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.384 [ 1c] 9 BaseStreamSource:m_needDataCallbackId already set Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.458 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-85 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.458 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=85,result=204 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.458 [ d] 0 HTTP2StreamPool:releaseStream:streamId=85,numAcquiredStreams=1 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.458 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.458 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.459 [ d] 0 HTTP2StreamPool:getStream:streamId=87,numAcquiredStreams=2 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.459 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.572 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.574 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.574 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.574 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.581 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.599 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.601 [ 2] 9 AttachmentReaderSource:read:size=3928,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.602 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.602 [ 2] 9 AttachmentReaderSource:read:size=3240,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.782 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.782 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.783 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.783 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.784 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.784 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.787 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.791 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.794 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.813 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.816 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.816 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.818 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.980 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.981 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.981 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.983 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.983 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-87 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.983 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=87,result=204 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.984 [ d] 0 HTTP2StreamPool:releaseStream:streamId=87,numAcquiredStreams=1 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.984 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.984 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.984 [ d] 0 HTTP2StreamPool:getStream:streamId=89,numAcquiredStreams=2 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.984 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:05 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.988 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:05.999 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.021 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.021 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.022 [ 2] 9 AttachmentReaderSource:read:size=2048,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.023 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.023 [ 2] 9 AttachmentReaderSource:read:size=1024,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.202 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.203 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.211 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.212 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.212 [ 2] 9 AttachmentReaderSource:read:size=2048,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.214 [ 2] 9 BaseStreamSource:onEnoughDataCalled Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.240 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.241 [ 2] 9 BaseStreamSource:onEnoughDataCalled Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.241 [ 2] 9 BaseStreamSource:m_enoughDataCallbackId already set Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.241 [ 2] 9 BaseStreamSource:handleEnoughDataCalled Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.241 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=58 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.294 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStream:info=beginning Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.483 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-89 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.483 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=89,result=204 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.483 [ d] 0 HTTP2StreamPool:releaseStream:streamId=89,numAcquiredStreams=1 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.483 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.483 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.483 [ d] 0 HTTP2StreamPool:getStream:streamId=91,numAcquiredStreams=2 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.484 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.944 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.947 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.947 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.947 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.947 [ c] 0 EventBuilder:buildJsonEventString:messageId=27eca84c-d991-4112-ab0b-662844508a46,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:06 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:06.949 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.056 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-91 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.056 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=91,result=204 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.056 [ d] 0 HTTP2StreamPool:releaseStream:streamId=91,numAcquiredStreams=1 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.056 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.056 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.056 [ d] 0 HTTP2StreamPool:getStream:streamId=93,numAcquiredStreams=2 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.056 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.099 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStreamSuccess Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.570 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-93 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.570 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=93,result=204 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.570 [ d] 0 HTTP2StreamPool:releaseStream:streamId=93,numAcquiredStreams=1 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.570 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.570 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.570 [ d] 0 HTTP2StreamPool:getStream:streamId=95,numAcquiredStreams=2 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.573 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:07 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:07.960 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStream:info=beginning Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.119 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-95 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.120 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=95,result=204 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.120 [ d] 0 HTTP2StreamPool:releaseStream:streamId=95,numAcquiredStreams=1 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.120 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.120 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.120 [ d] 0 HTTP2StreamPool:getStream:streamId=97,numAcquiredStreams=2 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.120 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.727 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fc0-19305f0a23b729e9-ecd4c3bb-7 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.727 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=97,result=204 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.727 [ d] 0 HTTP2StreamPool:releaseStream:streamId=97,numAcquiredStreams=1 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.727 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.727 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.728 [ d] 0 HTTP2StreamPool:getStream:streamId=99,numAcquiredStreams=2 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.730 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.936 [ 2] 9 MediaPlayer:messageReceived:type=tag,source=audio_sink Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.939 [ 2] 0 MediaPlayer:callingOnTags Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.939 [ 2] 0 AudioPlayer:onTags:id=4 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.939 [ c] 1 AudioPlayer:executeOnTags:id=4 Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.939 [ c] 0 EventBuilder:buildJsonEventString:messageId=7593fda6-7739-4beb-8adb-a70efd213390,namespace=AudioPlayer,name=StreamMetadataExtracted Jun 25 09:47:08 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:08.940 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.356 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fca-f68fa2c323b72134-2828ce7c-5 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.356 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=99,result=204 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.357 [ d] 0 HTTP2StreamPool:releaseStream:streamId=99,numAcquiredStreams=1 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.357 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.357 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.357 [ d] 0 HTTP2StreamPool:getStream:streamId=101,numAcquiredStreams=2 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.357 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.511 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStreamSuccess Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.853 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-101 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.853 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=101,result=204 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.853 [ d] 0 HTTP2StreamPool:releaseStream:streamId=101,numAcquiredStreams=1 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.853 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.854 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.854 [ d] 0 HTTP2StreamPool:getStream:streamId=103,numAcquiredStreams=2 Jun 25 09:47:09 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:09.854 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.360 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fcb-8d8b5bc4a3b72346-5e431dff-5 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.362 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=103,result=204 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.362 [ d] 0 HTTP2StreamPool:releaseStream:streamId=103,numAcquiredStreams=1 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.362 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.362 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.362 [ d] 0 HTTP2StreamPool:getStream:streamId=105,numAcquiredStreams=2 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.362 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.875 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fd6-7bdeb685a3b6dbd5-ebcbeea7-9 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.875 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=105,result=204 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.877 [ d] 0 HTTP2StreamPool:releaseStream:streamId=105,numAcquiredStreams=1 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.877 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.877 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.877 [ d] 0 HTTP2StreamPool:getStream:streamId=107,numAcquiredStreams=2 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.878 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:10 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:10.959 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStream:info=beginning Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.422 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-107 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.422 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=107,result=204 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.422 [ d] 0 HTTP2StreamPool:releaseStream:streamId=107,numAcquiredStreams=1 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.422 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.423 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.423 [ d] 0 HTTP2StreamPool:getStream:streamId=109,numAcquiredStreams=2 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.423 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.968 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-0024f260-17e21c83ae3a9d4a-7c0d0b69-95 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.970 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=109,result=204 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.970 [ d] 0 HTTP2StreamPool:releaseStream:streamId=109,numAcquiredStreams=1 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.970 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.971 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.971 [ d] 0 HTTP2StreamPool:getStream:streamId=111,numAcquiredStreams=2 Jun 25 09:47:11 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:11.971 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.184 [ 1c] 9 BaseStreamSource:onNeedDataCalled:size=4096 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.184 [ 2] 9 BaseStreamSource:handleNeedDataCalled Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.186 [ 2] 9 BaseStreamSource:installOnReadDataHandler:action=newSourceId,sourceId=86 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.187 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.189 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.190 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.191 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.193 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.194 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.196 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.197 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.199 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.200 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.200 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.201 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.202 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.203 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.204 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.204 [ 2] 9 BaseStreamSource:onEnoughDataCalled Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.204 [ 2] 9 AttachmentReaderSource:read:size=4096,status=0 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.204 [ 2] 9 BaseStreamSource:onEnoughDataCalled Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.204 [ 2] 9 BaseStreamSource:m_enoughDataCallbackId already set Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.204 [ 2] 9 BaseStreamSource:handleEnoughDataCalled Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.204 [ 2] 9 BaseStreamSource:clearOnReadDataHandlerCalled:sourceId=86 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.488 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fe9-501ab11863b6d7c4-2cd107a0-5 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.488 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=111,result=204 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.490 [ d] 0 HTTP2StreamPool:releaseStream:streamId=111,numAcquiredStreams=1 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.490 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.491 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.491 [ d] 0 HTTP2StreamPool:getStream:streamId=113,numAcquiredStreams=2 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.491 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.835 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStreamSuccess Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.981 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-113 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.981 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=113,result=204 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.981 [ d] 0 HTTP2StreamPool:releaseStream:streamId=113,numAcquiredStreams=1 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.981 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.981 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.982 [ d] 0 HTTP2StreamPool:getStream:streamId=115,numAcquiredStreams=2 Jun 25 09:47:12 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:12.982 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:13 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:13.478 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252e82-8adee5ff9fb4619c-4eccd647-115 Jun 25 09:47:13 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:13.480 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=115,result=204 Jun 25 09:47:13 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:13.480 [ d] 0 HTTP2StreamPool:releaseStream:streamId=115,numAcquiredStreams=1 Jun 25 09:47:13 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:13.480 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.322 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStream:info=beginning Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: [1] Callback event received: 0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: [1] Event detection timestamp 0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: [1] failed to get esp levels Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: event_handler_thread: Success to acquire qti lock Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: [1] session params 0x83869f00, 5700 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: offset 1096, size 40 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: detection event status 0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: detection event timestamp 26388 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: version 1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: [0]: key 0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: key version 1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: key size 4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: conf levels 3 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: [0] kw_id level 77 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: [1] kw_id level 0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: [2] kw_id level 0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: [1]: key 1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: key version 1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: key size 8 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: class level keyword start index 8000, last utterance index 192320 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: keyword start index 8000 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: class level keyword stop index 21759, last utterance index 192320 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_detection_event: keyword stop index 21759 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: capture LAB data Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: ######################################### REINITIALIZED SHARED STREAM ######################################################## Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: Inside capture_lab_data Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: sample rate 16000, channels 1, samp sz 2, duration 5700 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: , total_bytes_to_read 182400 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: indices [start,end] [8000,21759] Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: calling keywordRecognizedWithIndices() 8000 21759 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: ######################QTISoundTrigger::keywordRecognizedWithIndices()########################## ALEXA, 8000, 21759 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: [1B blob data] Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: QTISoundTrigger::onKeyWordDetected - KEYWORD DETECTED = 4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: QTISoundTrigger::onKeyWordDetected WITH INDICES START = 8000 END = 21759 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: QTISoundTrigger::onKeyWordDetected() - m_client->notifyOfWakeWord() Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: QSTHWClient::getDOADirection() - [Session:1] in get parameters 0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: [Session:1] param to get st_direction_of_arrival Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_get_param_data: target angle boundaries [290, 330] Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: QSTHWClient::getChannelIndex() - [Session:1] in get parameters 0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: [Session:1] param to get st_channel_index Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_get_param_data: procsesing channel index params Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: process_get_param_data: target channel index - [7] Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: ####################################___WITH INDICES START = 8000 END = 21759 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.734 [ b] 0 AudioInputProcessor:setState:from=IDLE,to=RECOGNIZING Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.736 [ e] 0 DialogUXStateAggregator:setState:from=IDLE,to=LISTENING Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: ############################ Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: # Listening... # Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: ############################ Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: UIManager::onDialogUXStateChanged state = LISTENING Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: InteractionManager::onDialogUXStateChanged to LISTENING Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: QTISoundTrigger::getDOADirection() - DOA - m_dOAIndex = 7 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: LISTENING - DOA Index = 7 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: setAllON Called Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.737 [ 8] 0 NotificationsCapabilityAgent:provideState:stateRequestToken=5 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.737 [ 7] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=5 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.737 [ 4] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=5 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.737 [ 7] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Alexa.PlaybackStateReporter,name=playbackState Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.737 [ 7] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=5 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.737 [ 7] 0 ContextManager:updateStateLocked:action=updatedState,namespace=ExternalMediaPlayer,name=ExternalMediaPlayerState Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: QTISoundTrigger::onKeyWordDetected - startRecognition = 1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: lab capture file : /data/SVA/lab_capture_file_1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: Starting LAB capture Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.738 [ 4] 0 ContextManager:updateStateLocked:action=updatedState,namespace=Notifications,name=IndicatorState Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.737 [ 8] 5 AudioActivityTracker:provideState Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.738 [ 8] 0 AudioPlayer:provideState:stateRequestToken=5 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.738 [ c] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=5 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.738 [ 9] 5 AudioActivityTracker:executeProvideState Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.738 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.739 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.740 [ c] 0 ContextManager:updateStateLocked:action=updatedState,namespace=AudioPlayer,name=PlaybackState Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.742 [ 9] 0 ContextManager:updateStateLocked:action=updatedState,namespace=AudioActivityTracker,name=ActivityState Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.743 [ 8] 0 ContextManager:buildContextSuccessful Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.743 [ b] 0 AudioInputProcessor:executeOnContextAvailable Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.743 [ b] 1 FocusManager:acquireChannel:channelName=Dialog,interface=SpeechRecognizer Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.744 [ b] I DirectiveProcessor:setDialogRequestIdLocked:oldValue=85e51c62-d37f-4ba6-acf4-307c8c23d0a9,newValue=0c199420-5b5a-46ad-a743-b98410f69279 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.744 [ b] 0 DirectiveProcessor:scrubDialogRequestIdLocked:dialogRequestId=85e51c62-d37f-4ba6-acf4-307c8c23d0a9 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.744 [ f] 0 AudioPlayer:onFocusChanged:newFocus=BACKGROUND Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.744 [ b] 0 EventBuilder:buildJsonEventString:messageId=dfaa2ddf-cefb-44e9-b8ce-78f4b0373b74,namespace=SpeechRecognizer,name=Recognize Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.744 [ c] 1 AudioPlayer:executeOnFocusChanged:from=FOREGROUND,to=BACKGROUND,m_currentActivity=PLAYING Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.744 [ c] 1 AudioPlayer:executeOnFocusChanged:action=pauseMediaPlayer Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.744 [ c] 9 MediaPlayer:pausedCalled Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.746 [ 2] 0 MediaPlayer:handlePauseCalled:idPassed=4,currentId=4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.754 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audio_sink Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.754 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=resample Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.754 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=conv Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.756 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=identity Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.756 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aconv Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aqueue Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=abin Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=streamsynchronizer1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=audiotee Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=playsink Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=inputselector1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=aacparse1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=multiqueue1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.757 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=tsdemux1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.758 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=typefind Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.758 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=decodebin1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.758 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=source Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.758 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=uridecodebin1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.758 [ 2] 9 MediaPlayer:messageReceived:type=state-changed,source=playbin1 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.758 [ 2] 9 MediaPlayer:State Change:oldState=PLAYING,newState=PAUSED,pendingState=VOID_PENDING Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.758 [ 2] 0 MediaPlayer:callingOnPlaybackPaused:currentId=4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: /sys/class/leds/pca9956b:26/brightness Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.758 [ c] 1 AudioPlayer:executeOnPlaybackPaused:id=4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.759 [ c] 1 AudioPlayer:sendEventWithTokenAndOffset:eventName=PlaybackPaused Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.759 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.759 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.759 [ c] 0 EventBuilder:buildJsonEventString:messageId=9e427173-b27d-40e3-9a77-8c83cddcc4fa,namespace=AudioPlayer,name=PlaybackPaused Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.759 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.759 [ c] 0 AudioPlayer:changeActivity:from=PLAYING,to=PAUSED Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ c] 0 AudioPlayer:executeProvideState:sendToken=false,stateRequestToken=0 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ f] 9 AudioInputProcessor:onFocusChanged:newFocus=FOREGROUND Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ f] 5 AudioActivityTracker:notifyOfActivityUpdates Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ b] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=FOREGROUND Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ b] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ c] 0 ContextManager:updateStateLocked:action=updatedState,namespace=AudioPlayer,name=PlaybackState Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.760 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.761 [ 9] 5 AudioActivityTracker:executeNotifyOfActivityUpdates Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.761 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.761 [ c] 1 AudioPlayer:notifyObserver:playerActivity=PAUSED Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.799 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.799 [ d] 0 HTTP2StreamPool:getStream:streamId=117,numAcquiredStreams=2 Jun 25 09:47:14 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:14.799 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:15 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:15.309 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252fe8-2f12208863b6d757-5c21bfe6-5 Jun 25 09:47:15 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:15.309 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=117,result=204 Jun 25 09:47:15 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:15.310 [ d] 0 HTTP2StreamPool:releaseStream:streamId=117,numAcquiredStreams=1 Jun 25 09:47:15 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:15.310 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:15 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:15.311 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:15 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:15.311 [ d] 0 HTTP2StreamPool:getStream:streamId=119,numAcquiredStreams=2 Jun 25 09:47:15 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:15.311 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:15 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:15.656 [ 20] 9 UrlContentToAttachmentConverter:writeUrlContentIntoStreamSuccess Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.821 [ 21] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.922 [ 21] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.935 [ 10] I DirectiveSequencer:onDirective:directive={"namespace\:"SpeechRecognizer"\,name\:"StopCapture"\,messageId\:"67e6a687-deb5-42fa-8bff-633c2542e8a3"\,dialogRequestId\:"0c199420-5b5a-46ad-a743-b98410f69279"} Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.935 [ 11] I DirectiveRouter:preHandleDirective:messageId=67e6a687-deb5-42fa-8bff-633c2542e8a3,action=calling Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.936 [ 11] 0 CapabilityAgent:addingMessageIdToMap:messageId=67e6a687-deb5-42fa-8bff-633c2542e8a3 Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.936 [ 12] I DirectiveRouter:handleDirective:messageId=67e6a687-deb5-42fa-8bff-633c2542e8a3,action=calling Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.936 [ b] 0 AudioInputProcessor:stopCapture:stopImmediately=true Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.936 [ b] 0 AudioInputProcessor:setState:from=RECOGNIZING,to=BUSY Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.936 [ b] 0 DirectiveProcessor:onHandlingCompeted:messageId=67e6a687-deb5-42fa-8bff-633c2542e8a3,directiveBeingPreHandled=(nullptr) Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.936 [ b] 0 CapabilityAgent:removingMessageIdFromMap:messageId=67e6a687-deb5-42fa-8bff-633c2542e8a3 Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.936 [ e] 0 DialogUXStateAggregator:setState:from=LISTENING,to=THINKING Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: ########################### Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: # Thinking... # Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: ########################### Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: UIManager::onDialogUXStateChanged state = THINKING Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: InteractionManager::onDialogUXStateChanged to THINKING Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: ######## QTISoundTrigger::stopRecording() 0 Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: QAHWManager::StopRecorder() 0 Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: setAllOff Called Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:16.945 [ d] I InProcessAttachmentReader:readFailed:reason=SDS is closed Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: exited lab processing Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: counter of buffer lastWakeWordAndUserUtteranceEndIndex = 248960bytes to read 182400 - old style, ignore, bytes read 113280 Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: event_handler_thread - exited capture_lab_data based on a call to doneLookahead() Jun 25 09:47:16 apq8009 AlexaClientApp[1588]: event_handler_thread - qsthw_start_recognition Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.022 [ 21] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.122 [ 21] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: QTISoundTrigger::recognitionStateChanged - m_isRecognizing = 0 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: [1] callback event processed, detection counter 4 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: proceed with utterance or command Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: event_handler_thread: Success to release qti lock Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.223 [ 21] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.323 [ 21] 9 InProcessAttachmentWriter:AttachmentWriter has timed out while attempting a write. Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.380 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252ffa-1862fc2ee3b6f9e6-fdd6fbf3-3 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.381 [ 10] I DirectiveSequencer:onDirective:directive={"namespace\:"AudioPlayer"\,name\:"Stop"\,messageId\:"b6e47d44-9120-4c5f-9223-f15d97e98555"\,dialogRequestId\:"0c199420-5b5a-46ad-a743-b98410f69279"} Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.381 [ 11] I DirectiveRouter:preHandleDirective:messageId=b6e47d44-9120-4c5f-9223-f15d97e98555,action=calling Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.381 [ 11] 0 CapabilityAgent:addingMessageIdToMap:messageId=b6e47d44-9120-4c5f-9223-f15d97e98555 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.382 [ 12] I DirectiveRouter:handleDirective:messageId=b6e47d44-9120-4c5f-9223-f15d97e98555,action=calling Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.382 [ 12] 0 AudioPlayer:handleDirective:name=Stop,messageId=b6e47d44-9120-4c5f-9223-f15d97e98555 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.382 [ 12] 1 AudioPlayer:handleStopDirective Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.382 [ 12] 0 DirectiveProcessor:onHandlingCompeted:messageId=b6e47d44-9120-4c5f-9223-f15d97e98555,directiveBeingPreHandled=(nullptr) Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.382 [ 12] 0 CapabilityAgent:removingMessageIdFromMap:messageId=b6e47d44-9120-4c5f-9223-f15d97e98555 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.382 [ c] 1 AudioPlayer:executeStop:playNextItem=false,m_currentActivity=PAUSED Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.383 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.383 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=4 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.384 [ c] 9 MediaPlayer:stopCalled Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.384 [ 2] 0 MediaPlayer:handleStopCalled:idPassed=4,currentId=4 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.384 [ d] 0 AudioInputProcessor:onSendCompleted:status=SUCCESS Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.384 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=119,result=200 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.385 [ d] 0 HTTP2StreamPool:releaseStream:streamId=119,numAcquiredStreams=1 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.420 [ 2] 0 MediaPlayer:callingOnPlaybackStopped:currentId=4 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.420 [ 2] 0 AudioPlayer:onPlaybackStopped:id=4 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.420 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.420 [ c] 1 AudioPlayer:executeOnPlaybackStopped:id=4 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.420 [ c] 0 AudioPlayer:changeActivity:from=PAUSED,to=STOPPED Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.420 [ c] 0 AudioPlayer:executeProvideState:sendToken=false,stateRequestToken=0 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.420 [ 2] E MediaPlayer:saveOffsetBeforeTeardown - gst_element_query_position failed Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.420 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.421 [ 2] 9 BaseStreamSource:~BaseStreamSource Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.421 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 1 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.423 [ 2] 9 MediaPlayer:resetPipeline Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: Element 'source' is not in bin 'playbin1' Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.423 [ 2] 9 MediaPlayer:tearDownTransientPipelineElements 2 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.424 [ 21] E SdsWriter:writeFailed:reason=writerDisabled Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.424 [ 21] I InProcessAttachmentWriter:writeFailed:reason=underlying SDS is closed Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.437 [ 21] E LibCurlHttpContentFetcher:curlEasyPerformFailed:error=Failed writing received data to disk/application Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.444 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=0 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.444 [ 2] I MediaPlayer:handleGetOffsetStopped::pipelineNotSet Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.444 [ c] 0 ContextManager:updateStateLocked:action=updatedState,namespace=AudioPlayer,name=PlaybackState Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.444 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.444 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=0 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.444 [ 2] I MediaPlayer:handleGetOffsetStopped::pipelineNotSet Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ c] 1 AudioPlayer:notifyObserver:playerActivity=STOPPED Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ c] 1 AudioPlayer:sendEventWithTokenAndOffset:eventName=PlaybackStopped Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ c] 9 MediaPlayer:getOffsetCalled Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ 2] 0 MediaPlayer:handleGetOffsetCalled:idPassed=4,currentId=0 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ 2] I MediaPlayer:handleGetOffsetStopped::pipelineNotSet Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ c] 0 EventBuilder:buildJsonEventString:messageId=f66f8b78-c225-437b-a4bf-e56cea0cecd0,namespace=AudioPlayer,name=PlaybackStopped Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ c] 9 HTTP2Transport:enqueueRequest Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ c] 0 AudioPlayer:cancelTimers Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.445 [ c] 1 FocusManager:releaseChannel:channelName=Content Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.446 [ f] 0 AudioPlayer:onFocusChanged:newFocus=NONE Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.446 [ f] 5 AudioActivityTracker:notifyOfActivityUpdates Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.446 [ c] 1 AudioPlayer:executeOnFocusChanged:from=BACKGROUND,to=NONE,m_currentActivity=STOPPED Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.446 [ 9] 5 AudioActivityTracker:executeNotifyOfActivityUpdates Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.486 [ d] 0 HTTP2Transport:processNextOutgoingMessage Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.486 [ d] 0 HTTP2StreamPool:getStream:streamId=121,numAcquiredStreams=2 Jun 25 09:47:17 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:17.486 [ d] 9 HTTP2Transport:insertActiveStream:handle=0xae7fb178 Jun 25 09:47:18 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:18.231 [ d] 0 HTTP2Stream:receivedRequestId:value=x-amzn-requestid\: 0a3085fffed20d24-00001435-00252f6b-935f8898f3b7426d-087e9fcc-7 Jun 25 09:47:18 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:18.231 [ d] 0 HTTP2Transport:cleanupFinishedStream:streamId=121,result=204 Jun 25 09:47:18 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:18.231 [ d] 0 HTTP2StreamPool:releaseStream:streamId=121,numAcquiredStreams=1 Jun 25 09:47:18 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:18.231 [ d] 0 CurlEasyHandleWrapper:reset:responseCode=HTTP_RESPONSE_SUCCESS_NO_CONTENT Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.383 [ e] 0 DialogUXStateAggregator:transitionFromThinkingTimedOut Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.383 [ e] 0 DialogUXStateAggregator:setState:from=THINKING,to=IDLE Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.384 [ b] 1 FocusManager:releaseChannel:channelName=Dialog Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: ######################################## Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: # Alexa is currently idle! # Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: ######################################## Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: UIManager::onDialogUXStateChanged state = IDLE Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: InteractionManager::onDialogUXStateChanged to IDLE Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: ######## QTISoundTrigger::stopRecording() 1 Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: QAHWManager::StopRecorder() 0 Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: setAllOff Called Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.384 [ b] 0 AudioInputProcessor:setState:from=BUSY,to=IDLE Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.384 [ f] 9 AudioInputProcessor:onFocusChanged:newFocus=NONE Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.384 [ f] 5 AudioActivityTracker:notifyOfActivityUpdates Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.384 [ b] 0 AudioInputProcessor:executeOnFocusChanged:newFocus=NONE Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.384 [ b] 0 AudioInputProcessor:executeOnFocusChanged:reason=Lost focus Jun 25 09:47:19 apq8009 AlexaClientApp[1588]: 2018-06-25 09:47:19.385 [ 9] 5 AudioActivityTracker:executeNotifyOfActivityUpdates ######################################################################

priyagsenthil commented 6 years ago

Hi,

A short delay of 1~2second is expected since AVS needs to be sure that the user has finished his utterance before processing the request.

Regarding 2 we tried it in the latest version of the SDK and do not notice this delay. After asking "Alexa, play some music" Alexa responds with a SPEAK directive with TTS about what she was going to play and then the track starts playing. When we tried it on she played from Amazon music. Is there a particular music provider for whom you see a longer delay. Please advise.

Thanks Priya

mandyam commented 6 years ago

Thanks for the quick response.

Can you please update your observations regarding the delay using the same URL captured in the log above?

vaddep commented 6 years ago

Following is the URL in current case: Jun 25 09:46:54 apq8009 AlexaClientApp[1588]: 2018-06-25 09:46:54.538 [ 12] 9 AudioPlayer:PLAY:payload={"audioItem":{"audioItemId":"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#88756784-07e9-4ca7-9317-97a966d63d34:1","stream":{"offsetInMilliseconds":0,"expiryTime":"2018-06-25T09:47:49+0000","progressReport":{"progressReportDelayInMilliseconds":1000},"url":"https://d29r7idq0wxsiz.cloudfront.net/DigitalMusicDeliveryService/HPS.m3u8?m=m&dmid=203884823&c=cf&f=ts&t=10&bl=256k&s=true&e1=1529921700000&e2=1529921700000&v=V2&n=7LTOYQCR53EA2&h=b6f9e7bf95812a005ba6f8197f43c42f009f924b2d8652c0de90b5ac0707a4b0","token":"amzn1.as-ct.v1.Dee-Domain-Music#ACRI#url#ACRI#88756784-07e9-4ca7-9317-97a966d63d34:1"}},"playBehavior":"REPLACE_ALL"}

But we see this issue irrespective of URL. Is this playlist parser dependent on any of the system parameters or some configuration?

priyagsenthil commented 6 years ago

Can you upgrade to the latest release of the device SDK and check if the issue still exists. If yes, could you provide the details of the track - album, artist and music service provider where you see the issue so that we can reproduce the issue. There are no configurations around playlist parser that can make it faster or slower.

Thanks

kclchan commented 6 years ago

I am closing this issue due to inactivity. Please feel free to re-open it if it has been closed in error.