I want paly Bluetooth music by ASS device

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

Hi, all.   And how to config?
What is the expected behavior?

I want paly Bluetooth music by ASS device.
What behavior are you observing?

When compile ASS sdk , i open bluetooth config like :
-DBLUETOOTH_ENABLED=ON
-DBLUETOOTH_BLUEZ=ON
. But the music can not play by ass。
Provide the steps to reproduce the issue, if applicable:

When compile ASS sdk , i open bluetooth config like :
-DBLUETOOTH_ENABLED=ON
-DBLUETOOTH_BLUEZ=ON
.
Tell us about your environment:

What version of the AVS Device SDK are you using?
  <1.26.0>

Tell us what hardware you're using:

[ ] Desktop / Laptop
[ ] Raspberry Pi
[x] Other - tell us more:  ARM Cortex-A5

Tell us about your OS (Type & version):

[x] Linux
[ ] MacOS
[ ] Raspbian Stretch
[ ] Raspbian Jessy
[ ] Other - tell us more:

Have you tried the same use case with AVS Device SDK SampleApp?

[ ] The issue is not applicable to the AVS Device SDK SampleApp.
[x] The issue is not reproducible on the AVS Device SDK SampleApp.

I had the following questions:

Have you been able to play music via Bluetooth with only the AVS Device SDK (not the Smart Screen SDK)?
Have you installed the required dependencies specified here?

Hi Aranata:
Have you been able to play music via Bluetooth with only the AVS Device SDK (not the Smart Screen SDK)?
AVS Bluetooth is ok, and can control BT music by voice。
Have you installed the required dependencies specified here?
The dependencies had  installed.

Hi Aranata:
Here is the log of ASS SampleApp。The bluetooth have some initialization error。 Please help analyse。tks！
/etc/init.d/S49ass start
amlogic,meson8b
Set with last saved date 2022-09-02 OK
start ass.....
get amlogic A213y board
/3rd
SmartScreenSDKVersion 2.9.0
configFile /etc/AlexaClientSDKConfig.json
configFile /etc/GuiConfigSample_SmartScreenLargeLandscape.json
Running app with log level: DEBUG9
2022-09-02 00:00:01.558 [  1] I AlexaClientSdkInit:initialize:sdkversion=1.26.0
2022-09-02 00:00:01.565 [  1] I AlexaClientSdkInit:initialize:curlVersion=7.68.0
2022-09-02 00:00:01.572 [  1] 0 ConfigurationNode:initializeSuccess
2022-09-02 00:00:01.573 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:01.574 [  1] 5 SDKPrimitivesProvider:withTimerDelegateFactory
2022-09-02 00:00:01.574 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:01.574 [  1] 5 SDKPrimitivesProvider:initialize
2022-09-02 00:00:01.574 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:01.585 [  1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating Equalizer configuration
2022-09-02 00:00:01.585 [  1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating default Equalizer state
2022-09-02 00:00:01.586 [  1] E SDKConfigEqualizerConfiguration:createFailed:reason=Unsupported mode is set as default state mode,mode=NONE
2022-09-02 00:00:01.588 [  1] 9 MediaPlayer:createCalled:name=SpeakMediaPlayer
[613.744564]: DEBUG av_sync_open_session:210: new avsession id 0 fd 9
2022-09-02 00:00:03.750 [  1] I MediaPlayer:outputConversion:name=SpeakMediaPlayer,string=audio/x-raw
2022-09-02 00:00:03.766 [  1] 9 MediaPlayer:createCalled:name=AudioMediaPlayer
2022-09-02 00:00:03.768 [  1] I MediaPlayer:outputConversion:name=AudioMediaPlayer,string=audio/x-raw
2022-09-02 00:00:03.773 [  1] 9 MediaPlayer:createCalled:name=AudioMediaPlayer
2022-09-02 00:00:03.775 [  1] I MediaPlayer:outputConversion:name=AudioMediaPlayer,string=audio/x-raw
2022-09-02 00:00:03.781 [  1] 9 MediaPlayer:createCalled:name=NotificationsMediaPlayer
2022-09-02 00:00:03.783 [  1] I MediaPlayer:outputConversion:name=NotificationsMediaPlayer,string=audio/x-raw
2022-09-02 00:00:03.788 [  1] 9 MediaPlayer:createCalled:name=BluetoothMediaPlayer
2022-09-02 00:00:03.825 [  1] I MediaPlayer:outputConversion:name=BluetoothMediaPlayer,string=audio/x-raw
2022-09-02 00:00:03.830 [  1] 9 MediaPlayer:createCalled:name=RingtoneMediaPlayer
2022-09-02 00:00:03.832 [  1] I MediaPlayer:outputConversion:name=RingtoneMediaPlayer,string=audio/x-raw
2022-09-02 00:00:03.838 [  1] 9 MediaPlayer:createCalled:name=AlertsMediaPlayer
2022-09-02 00:00:03.840 [  1] I MediaPlayer:outputConversion:name=AlertsMediaPlayer,string=audio/x-raw
2022-09-02 00:00:03.845 [  1] 9 MediaPlayer:createCalled:name=SystemSoundMediaPlayer
2022-09-02 00:00:03.847 [  1] I MediaPlayer:outputConversion:name=SystemSoundMediaPlayer,string=audio/x-raw
2022-09-02 00:00:03.854 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=0
2022-09-02 00:00:03.856 [  1] 5 SQLiteDeviceSettingStorage:create
2022-09-02 00:00:03.857 [  1] 5 SQLiteBluetoothStorage:create
2022-09-02 00:00:03.859 [  1] 9 WebSocket:AccessLog
2022-09-02 00:00:03.859 [  1] 9 WebSocket:AccessLog
2022-09-02 00:00:03.860 [  1] 9 WebSocket:AccessLog
2022-09-02 00:00:03.861 [  1] 9 WebSocket:AccessLog
2022-09-02 00:00:03.862 [  1] 9 WebSocket:AccessLog
2022-09-02 00:00:03.862 [  1] 9 WebSocket:AccessLog
2022-09-02 00:00:03.862 [  1] 9 WebSocket:AccessLog
2022-09-02 00:00:03.862 [  1] 9 WebSocket:AccessLog
2022-09-02 00:00:03.864 [  1] 5 CustomerDataManager:createCustomerDataManagerInteface
2022-09-02 00:00:03.866 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:03.867 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:0
2022-09-02 00:00:03.867 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:03.867 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:03.867 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:1
2022-09-02 00:00:03.867 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:03.871 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:03.871 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:2
2022-09-02 00:00:03.871 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:03.874 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:03.874 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:03.874 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:03.875 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:03.875 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:3
2022-09-02 00:00:03.875 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:03.876 [  1] 9 ThreadPool:obtainWorker:created=0,obtained=0,releasedToPool=0,releasedFromPool=0,outstanding=0
2022-09-02 00:00:03.878 [  2] 9 TaskThread:startThread:moniker=  2,duration=2578
2022-09-02 00:00:03.882 [  1] 3 SampleApplication:initialize:APLDBVersion=1.8
2022-09-02 00:00:03.882 [  1] 3 GUIClient:setAplClientBridge
2022-09-02 00:00:03.883 [  1] 9 ThreadPool:obtainWorker:created=1,obtained=1,releasedToPool=0,releasedFromPool=0,outstanding=1
2022-09-02 00:00:03.883 [  3] 9 TaskThread:startThread:moniker=  3,duration=367
2022-09-02 00:00:03.883 [  3] 9 GUIClient:initializeAllRenderers
2022-09-02 00:00:03.883 [  3] 1 GUIClient:initializeAllRenderers:initializingWindow=smartScreenLandscape
2022-09-02 00:00:03.883 [  1] I DeviceInfo:create:result=skipDeviceType,key=deviceType
2022-09-02 00:00:03.883 [  1] I DeviceInfo:create:result=skipFriendlyName,key=friendlyName
2022-09-02 00:00:03.883 [  1] I DeviceInfo:create:result=skipRegistrationKey,key=registrationKey
2022-09-02 00:00:03.884 [  3] 9 AplClientBridge:initializeRenderer
2022-09-02 00:00:03.884 [  1] I DeviceInfo:create:result=skipProductIdKey,key=productIdKey
2022-09-02 00:00:03.884 [  3] 9 AplClientBridge:initializeRenderer
2022-09-02 00:00:03.884 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:03.885 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:4
2022-09-02 00:00:03.885 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:03.887 [  2] 0 AplClientBridge:AplCoreEngine::AplCoreExtensionManager:getExtension : aplext:e2eencryption:10
2022-09-02 00:00:03.887 [  1] I pkcs11::KeyStore:create
2022-09-02 00:00:03.887 [  2] 0 AplClientBridge:AplCoreEngine::AplCoreExtensionManager:No registered Extension : aplext:e2eencryption:10
2022-09-02 00:00:03.887 [  2] 0 AplClientBridge:AplCoreEngine::AplCoreExtensionManager:getExtension : aplext:backstack:10
2022-09-02 00:00:03.887 [  2] 0 AplClientBridge:AplCoreEngine::AplCoreExtensionManager:No registered Extension : aplext:backstack:10
2022-09-02 00:00:03.888 [  2] 0 AplClientBridge:AplCoreEngine::AplCoreExtensionManager:getExtension : aplext:audioplayer:10
2022-09-02 00:00:03.888 [  2] 0 AplClientBridge:AplCoreEngine::AplCoreExtensionManager:No registered Extension : aplext:audioplayer:10
2022-09-02 00:00:03.888 [  1] E pkcs11::Config:libraryPathMissing
2022-09-02 00:00:04.221 [  1] E pkcs11::Config:configLoadingFailed
2022-09-02 00:00:04.222 [  1] E pkcs11::KeyStore:configNull
2022-09-02 00:00:04.223 [  1] E pkcs11::KeyStore:createFailed
2022-09-02 00:00:04.227 [  1] 0 LWAAuthorizationStorage:createLWAAuthorizationStorageInterface
2022-09-02 00:00:04.228 [  1] W LWAAuthorizationStorage:createLWAAuthorizationStorageInterface::encryptionAtRestDisabled:reason=keyStoreNull
2022-09-02 00:00:04.229 [  1] 5 LWAAuthorizationStorage:createSQLiteStorage
2022-09-02 00:00:04.231 [  1] 9 LWAAuthorizationStorage:createStorageFileAndSetPermissionsSuccess:reason=fileExists
2022-09-02 00:00:04.240 [  1] 5 MiscStoragePropertiesFactory:initSuccess
2022-09-02 00:00:04.249 [  1] 0 SQLiteDatabase:tableExistsFailed:reason=table doesn't exist or there was an error checking,table=refreshToken
2022-09-02 00:00:04.250 [  1] 0 SQLiteDatabase:tableExistsFailed:reason=table doesn't exist or there was an error checking,table=userId
2022-09-02 00:00:04.250 [  1] 5 LWAAuthorizationStorage:LWAAuthorizationStorage
2022-09-02 00:00:04.253 [  1] 5 CBLAuthDelegate:create
2022-09-02 00:00:04.254 [  1] 5 CBLAuthDelegate:CBLAuthDelegate
2022-09-02 00:00:04.255 [  1] 5 CBLAuthDelegate:init
2022-09-02 00:00:04.255 [  1] 5 LWAAuthorizationConfiguration:create
2022-09-02 00:00:04.256 [  1] 5 LWAAuthorizationConfiguration:init
2022-09-02 00:00:04.256 [  1] E ConfigurationNode:getArrayFailed:reason=notAnArray
2022-09-02 00:00:04.256 [  1] 5 LWAAuthorizationConfiguration:initScopeData
2022-09-02 00:00:04.258 [  1] 9 LWAAuthorizationConfiguration:initScopeDataSucceeded
2022-09-02 00:00:04.260 [  1] 5 SQLiteCBLAuthDelegateStorage:open
2022-09-02 00:00:04.260 [  1] 5 LWAAuthorizationStorage:open
2022-09-02 00:00:04.260 [  1] 5 LWAAuthorizationStorage:openOrCreate
2022-09-02 00:00:04.263 [  1] 0 SimpleMiscStorageUriMapper:extractComponentAndTableNameSuccess:configUri=config/LWAAuthorizationStorage,componentName=config,tableName=LWAAuthorizationStorage
2022-09-02 00:00:04.267 [  1] 9 MiscStorageProperties:tableExistsSuccess:configUri=config/LWAAuthorizationStorage
2022-09-02 00:00:04.268 [  1] 9 RetryExecutor:executeSuccess:action=tableExists,retriesLeft=16
2022-09-02 00:00:04.269 [  1] 0 MiscStorageProperties:initSuccess:configUri=config/LWAAuthorizationStorage
2022-09-02 00:00:04.269 [  1] 0 MiscStorageProperties:createSuccess:configUri=config/LWAAuthorizationStorage
2022-09-02 00:00:04.270 [  4] 5 CBLAuthDelegate:handleAuthorizationFlow
2022-09-02 00:00:04.270 [  4] 5 CBLAuthDelegate:handleStarting
2022-09-02 00:00:04.270 [  4] 5 SQLiteCBLAuthDelegateStorage:getRefreshToken
2022-09-02 00:00:04.270 [  4] 5 LWAAuthorizationStorage:getRefreshToken
2022-09-02 00:00:04.271 [  1] 5 SQLiteCapabilitiesDelegateStorage:create
2022-09-02 00:00:04.272 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:04.272 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:5
2022-09-02 00:00:04.273 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:04.273 [  1] 5 SQLiteCapabilitiesDelegateStorage:open
2022-09-02 00:00:04.273 [  4] 9 MiscStorageProperties:getStringSuccess:configUri=config/LWAAuthorizationStorage,key=refreshToken
2022-09-02 00:00:04.273 [  4] 9 RetryExecutor:executeSuccess:action=getString,retriesLeft=16
2022-09-02 00:00:04.273 [  4] 0 MiscStorageProperties:getStringSuccess:configUri=config/LWAAuthorizationStorage,key=refreshToken
2022-09-02 00:00:04.273 [  4] 0 MiscStorageProperties:getStringSuccess:configUri=config/LWAAuthorizationStorage,key=refreshToken
2022-09-02 00:00:04.274 [  4] 5 CBLAuthDelegate:handleRefreshingToken
2022-09-02 00:00:04.275 [  4] 5 CBLAuthDelegate:requestRefresh
2022-09-02 00:00:04.277 [  1] 5 CBLAuthDelegate:addAuthObserver:observer=0x1f7048
2022-09-02 00:00:04.278 [  1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x1f704c
2022-09-02 00:00:04.278 [  1] 9 ThreadPool:obtainWorker:created=2,obtained=2,releasedToPool=0,releasedFromPool=0,outstanding=2
2022-09-02 00:00:04.279 [  5] 9 TaskThread:startThread:moniker=  5,duration=575
2022-09-02 00:00:04.279 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:04.279 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:04.279 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:04.280 [  1] 5 InternetConnectionMonitor:startMonitoring
2022-09-02 00:00:04.281 [  6] 5 InternetConnectionMonitor:testConnection
2022-09-02 00:00:04.281 [  6] 9 HTTPContentFetcherFactory:create::Creating a new http content fetcher
2022-09-02 00:00:04.282 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:04.615 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:6
2022-09-02 00:00:04.616 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:04.282 [  4] 0 CurlEasyHandleWrapper:initializeNetworkInterfaceName:m_interfaceName=
2022-09-02 00:00:04.624 [  6] 9 LibCurlHttpContentFetcher:stateTransition:oldState=INITIALIZED,newState=FETCHING_HEADER:State transition
2022-09-02 00:00:04.626 [  7] 9 LibCurlHttpContentFetcher:transferThread::start
2022-09-02 00:00:04.620 [  1] 5 AVSGatewayManager:create
2022-09-02 00:00:04.632 [  7] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2022-09-02 00:00:04.639 [  1] 5 AVSGatewayManager:init:avsGateway=https://alexa.na.gateway.devices.a2z.com
2022-09-02 00:00:04.645 [  1] 5 SynchronizeStateSenderFactory:create
2022-09-02 00:00:04.648 [  1] 5 BlueZDeviceManager:create
2022-09-02 00:00:04.649 [  1] 5 BlueZDeviceManager:init
2022-09-02 00:00:04.649 [  1] 5 BlueZDeviceManager:Creating connection...
2022-09-02 00:00:04.671 [  1] 5 BlueZDeviceManager:Creating ObjectManagerProxy...
2022-09-02 00:00:04.678 [  1] 5 BlueZDeviceManager:Retrieving BlueZ state...
2022-09-02 00:00:04.681 [  1] 3 BlueZDeviceManager:Found bluetooth adapter:Path=/org/bluez/hci0
2022-09-02 00:00:04.682 [  1] 5 BlueZDeviceManager:Initializing Host Controller...
2022-09-02 00:00:04.682 [  1] 5 BlueZHostController:create:adapterObjectPath=/org/bluez/hci0
2022-09-02 00:00:04.682 [  1] 5 BlueZHostController:init
2022-09-02 00:00:04.693 [  1] 9 DBusPropertiesProxy:getStringProperty:object=/org/bluez/hci0,interface=org.bluez.Adapter1,property=Address
2022-09-02 00:00:04.696 [  1] 9 DBusPropertiesProxy:getStringProperty:object=/org/bluez/hci0,interface=org.bluez.Adapter1,property=Alias
2022-09-02 00:00:04.698 [  1] 5 BlueZHostController:adapterProperties:mac=22:22:EC:74:FB:F2,friendlyName=MusicBox-08e906766cc0
2022-09-02 00:00:04.704 [  8] 5 BlueZDeviceManager:Connecting signals...
2022-09-02 00:00:04.705 [  8] 7 DBusConnection:Subscribed to signal:service=org.bluez,interface=org.freedesktop.DBus.ObjectManager,member=InterfacesAdded,result=13
2022-09-02 00:00:04.706 [  8] 7 DBusConnection:Subscribed to signal:service=org.bluez,interface=org.freedesktop.DBus.ObjectManager,member=InterfacesRemoved,result=14
2022-09-02 00:00:04.707 [  8] 7 DBusConnection:Subscribed to signal:service=org.bluez,interface=org.freedesktop.DBus.Properties,member=PropertiesChanged,result=15
2022-09-02 00:00:04.707 [  8] 5 BlueZDeviceManager:init::Initializing Bluetooth Media
2022-09-02 00:00:04.709 [  8] 5 DBusObjectBase:registerWithDBus
2022-09-02 00:00:04.710 [  8] 5 DBusObjectBase:Object registered:Object path=/com/amazon/alexa/sdk/sinkendpoint,Interface=org.bluez.MediaEndpoint1
bluetoothd[1906]: Endpoint registered: sender=:1.4 path=/com/amazon/alexa/sdk/sinkendpoint
2022-09-02 00:00:04.714 [  8] 5 BlueZDeviceManager:init::Initializing Pairing Agent
2022-09-02 00:00:04.714 [  8] 5 DBusObjectBase:registerWithDBus
2022-09-02 00:00:04.715 [  8] 5 DBusObjectBase:Object registered:Object path=/ACSDK/Bluetooth/Agent,Interface=org.bluez.Agent1
2022-09-02 00:00:04.720 [  8] 5 PairingAgent:registerAgent
2022-09-02 00:00:04.722 [  8] 5 PairingAgent:registerAgent::registerAgentDone
2022-09-02 00:00:04.722 [  8] 5 PairingAgent:requestDefaultAgent
2022-09-02 00:00:04.724 [  8] 5 PairingAgent:requestDefaultAgent::requestDefaultAgentSuccessful
2022-09-02 00:00:04.724 [  8] 5 BlueZDeviceManager:init::Initializing MRPIS Player
2022-09-02 00:00:04.724 [  8] 5 DBusObjectBase:registerWithDBus
2022-09-02 00:00:04.725 [  8] 5 DBusObjectBase:Object registered:Object path=/org/mpris/MediaPlayer2,Interface=org.mpris.MediaPlayer2.Player
2022-09-02 00:00:04.725 [  8] 5 MPRISPlayer:registerPlayer
bluetoothd[1906]: Player registered: sender=:1.4 path=/org/mpris/MediaPlayer2
2022-09-02 00:00:04.729 [  8] 0 MPRISPlayer:registerPlayerSucceeded:path=/org/mpris/MediaPlayer2
2022-09-02 00:00:04.730 [  1] 5 BlueZDeviceManager:BlueZDeviceManager initialized...
2022-09-02 00:00:04.730 [  8] 5 BlueZDeviceManager:propertiesChangedCallback
2022-09-02 00:00:04.730 [  8] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0
2022-09-02 00:00:04.732 [  8] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1', {'Class': <uint32 262144>}, @as [])
2022-09-02 00:00:04.733 [  8] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0
2022-09-02 00:00:04.733 [  8] 5 BlueZDeviceManager:propertiesChangedCallback
2022-09-02 00:00:04.733 [  8] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0
2022-09-02 00:00:04.733 [  8] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1', {'UUIDs': <['00001801-0000-1000-8000-00805f9b34fb', '00001800-0000-1000-8000-00805f9b34fb', '00001200-0000-1000-8000-00805f9b34fb', '0000110c-0000-1000-8000-00805f9b34fb', '0000110e-0000-1000-8000-00805f9b34fb', '0000110b-0000-1000-8000-00805f9b34fb']>}, @as [])
2022-09-02 00:00:04.733 [  8] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0
SetupPara. In_samps=768, InChans=2,Out_samps=768,OutChans=2,FrameNum=768
2022-09-02 00:00:04.745 [  7] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.front
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround21
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround21
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround40
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround41
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround50
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround51
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.surround71
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.iec958
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.iec958
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.iec958
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.hdmi
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.modem
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.phoneline
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'defaults.bluealsa.device'
ALSA lib conf.c:4660:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5137:(snd_config_expand) Args evaluate error: No such file or directory
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM bluealsa
ALSA lib confmisc.c:1281:(snd_func_refer) Unable to find definition 'defaults.bluealsa.device'
ALSA lib conf.c:4660:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5137:(snd_config_expand) Args evaluate error: No such file or directory
ALSA lib pcm.c:2642:(snd_pcm_open_noupdate) Unknown PCM bluealsa
ALSA lib pcm_dmix.c:1024:(snd_pcm_dmix_open) The dmix plugin supports only playback stream
ALSA lib pcm_dmix.c:1089:(snd_pcm_dmix_open) unable to open slave
ALSA lib pcm_dmix.c:1024:(snd_pcm_dmix_open) The dmix plugin supports only playback stream
ALSA lib pcm_dmix.c:1089:(snd_pcm_dmix_open) unable to open slave
ALSA lib pcm_dmix.c:1024:(snd_pcm_dmix_open) The dmix plugin supports only playback stream
ALSA lib pcm_dmix.c:1089:(snd_pcm_dmix_open) unable to open slave
ALSA lib pcm_dmix.c:1024:(snd_pcm_dmix_open) The dmix plugin supports only playback stream
ALSA lib pcm_dmix.c:1089:(snd_pcm_dmix_open) unable to open slave
ALSA lib pcm_dmix.c:1024:(snd_pcm_dmix_open) The dmix plugin supports only playback stream
ALSA lib pcm_dmix.c:1089:(snd_pcm_dmix_open) unable to open slave
ALSA lib pcm_dmix.c:1024:(snd_pcm_dmix_open) The dmix plugin supports only playback stream
ALSA lib pcm_dmix.c:1089:(snd_pcm_dmix_open) unable to open slave
2022-09-02 00:00:05.168 [  7] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
ALSA lib pcm_dmix.c:1089:(snd_pcm_dmix_open) unable to open slave
ALSA lib pcm_dmix.c:1089:(snd_pcm_dmix_open) unable to open slave
2022-09-02 00:00:05.187 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.187 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:7
2022-09-02 00:00:05.187 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.187 [  1] I PortAudioMicrophoneWrapper:startStreamingMicrophoneData
2022-09-02 00:00:05.189 [  1] 5 ExternalCapabilitiesBuilder:ExternalCapabilitiesBuilder
2022-09-02 00:00:05.191 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:05.192 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AudioMediaPlayer
2022-09-02 00:00:05.192 [  9] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AudioMediaPlayer
2022-09-02 00:00:05.193 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:05.193 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AudioMediaPlayer
2022-09-02 00:00:05.193 [  a] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AudioMediaPlayer
2022-09-02 00:00:05.210 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:05.210 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:05.210 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:05.210 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.211 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:8
2022-09-02 00:00:05.211 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.212 [  1] 5 AVSConnectionManager:AVSConnectionManager:this=0x290c58
2022-09-02 00:00:05.213 [  1] 5 AVSConnectionManager:create::Subscribing to InternetConnectionMonitor Callbacks
2022-09-02 00:00:05.267 [  7] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2022-09-02 00:00:05.547 [  1] 5 AVSConnectionManager:onConnectionStatusChanged:this=0x290c58,connected=false,isEnabled=false
2022-09-02 00:00:05.549 [  1] 5 DirectiveSequencer:createDirectiveSequencerInterface
2022-09-02 00:00:05.549 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=1
2022-09-02 00:00:05.549 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.550 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=DirectiveSequencer
2022-09-02 00:00:05.550 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.550 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=2
2022-09-02 00:00:05.550 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.550 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=DirectiveProcessor
2022-09-02 00:00:05.550 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.551 [  b] 9 DirectiveProcessor:processingLoop
2022-09-02 00:00:05.551 [  b] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.551 [  c] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.551 [  b] 9 PowerMonitor:assignThreadPowerResource:threadId=2777617424
2022-09-02 00:00:05.551 [  b] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.552 [  b] 5 ConditionVariableWrapper:waitInner
2022-09-02 00:00:05.551 [  c] 9 PowerMonitor:assignThreadPowerResource:threadId=2769224720
2022-09-02 00:00:05.552 [  c] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.552 [  c] 5 ConditionVariableWrapper:waitInner
2022-09-02 00:00:05.552 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.552 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:9
2022-09-02 00:00:05.552 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.553 [  1] 5 DefaultEndpointBuilder:createDefaultEndpointBuilderInterface
2022-09-02 00:00:05.555 [  1] 5 EndpointBuilder:finalizeAttributes
2022-09-02 00:00:05.555 [  1] 5 DefaultEndpointBuilder:createDefaultEndpointCapabilitiesRegistrarInterface
2022-09-02 00:00:05.556 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.556 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:10
2022-09-02 00:00:05.556 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.557 [  1] 5 ContextManager:addStateProvider
2022-09-02 00:00:05.559 [  1] 5 DefaultEndpointBuilder:withCapabilityConfiguration
2022-09-02 00:00:05.563 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.563 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:11
2022-09-02 00:00:05.563 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.564 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:05.564 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:05.564 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:05.564 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.565 [  1] 5 PowerMonitor:getPowerResourceManager
2022-09-02 00:00:05.565 [  1] E PowerResource:create:error=nullPowerManager
2022-09-02 00:00:05.566 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:05.566 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:05.566 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:05.567 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.567 [  1] 5 PowerMonitor:getPowerResourceManager
2022-09-02 00:00:05.567 [  1] E PowerResource:create:error=nullPowerManager
2022-09-02 00:00:05.567 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:05.567 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:05.568 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:05.568 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.568 [  1] 5 PowerMonitor:getPowerResourceManager
2022-09-02 00:00:05.568 [  1] E PowerResource:create:error=nullPowerManager
2022-09-02 00:00:05.568 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:05.569 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:05.646 [  7] 9 LibCurlHttpContentFetcher:transferThread:numTransfersLeft=1
2022-09-02 00:00:05.903 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.906 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:05.907 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.908 [  1] 5 PowerMonitor:getPowerResourceManager
2022-09-02 00:00:05.908 [  1] E PowerResource:create:error=nullPowerManager
2022-09-02 00:00:05.908 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:05.908 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.909 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.909 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.909 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.909 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.910 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.910 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.910 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.911 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:05.911 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.911 [  7] 9 LibCurlHttpContentFetcher:headerCallback:type=content-length,length=419
2022-09-02 00:00:05.912 [  7] 9 LibCurlHttpContentFetcher:headerCallback::CALLED
2022-09-02 00:00:05.912 [  7] 9 LibCurlHttpContentFetcher:bodyCallback::End of header found.
2022-09-02 00:00:05.912 [  6] 9 InternetConnectionMonitor:testConnection:contentLength=419
2022-09-02 00:00:05.911 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:05.913 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.913 [  1] 5 PowerMonitor:getPowerResourceManager
2022-09-02 00:00:05.913 [  1] E PowerResource:create:error=nullPowerManager
2022-09-02 00:00:05.913 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:05.914 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:05.914 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:05.914 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.914 [  1] 5 PowerMonitor:getPowerResourceManager
2022-09-02 00:00:05.915 [  1] E PowerResource:create:error=nullPowerManager
2022-09-02 00:00:05.916 [  7] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_HEADER,newState=HEADER_DONE:State transition
2022-09-02 00:00:05.917 [  6] 9 LibCurlHttpContentFetcher:stateTransition:oldState=HEADER_DONE,newState=FETCHING_BODY:State transition
2022-09-02 00:00:05.919 [  1] 5 AlexaInterfaceCapabilityAgent:createDefaultAlexaInterfaceCapabilityAgent
2022-09-02 00:00:05.920 [  7] 9 LibCurlHttpContentFetcher:bodyCallback:totalContentReceived=419,contentLength=419,currentContentReceived=419,remaining=0,totalBytesWritten=419
2022-09-02 00:00:05.921 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.921 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:12
2022-09-02 00:00:05.921 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.922 [  7] 7 CurlEasyHandleWrapper:getEffectiveUrl:effectiveURL=http://spectrum.s3.amazonaws.com/kindle-wifi/wifistub.html
2022-09-02 00:00:05.923 [  7] 9 LibCurlHttpContentFetcher:transferThread::end
2022-09-02 00:00:05.923 [  7] 9 LibCurlHttpContentFetcher:stateTransition:oldState=FETCHING_BODY,newState=BODY_DONE:State transition
2022-09-02 00:00:05.922 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:05.929 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=3
2022-09-02 00:00:05.929 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:05.930 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:13
2022-09-02 00:00:05.930 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:05.930 [  1] 5 SpeakerManager:configureDefaults::Loading configuration
2022-09-02 00:00:05.935 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:05.936 [  1] 5 CaptionsComponent:createCaptionManagerInterface::captions disabled
2022-09-02 00:00:06.270 [  1] 5 StubApplicationAudioPipelineFactory:addCaptionManager::captions disabled
2022-09-02 00:00:06.271 [  1] 5 StubApplicationAudioPipelineFactory:createApplicationMediaInterfaces
2022-09-02 00:00:06.272 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:06.272 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AlertsMediaPlayer
2022-09-02 00:00:06.008 [  4] 5 HttpPost:doPostSucceeded:code=200
2022-09-02 00:00:06.020 [  6] 9 InternetConnectionMonitor:testConnection::alreadyReadAllBytes
2022-09-02 00:00:06.273 [  6] 9 InternetConnectionMonitor:testConnection::Finished reading
2022-09-02 00:00:06.273 [  6] 5 InternetConnectionMonitor:updateConnectionStatus:connected=true
2022-09-02 00:00:06.274 [  6] 5 AVSConnectionManager:onConnectionStatusChanged:this=0x290c58,connected=true,isEnabled=false
2022-09-02 00:00:06.277 [  d] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AlertsMediaPlayer
2022-09-02 00:00:06.278 [  6] 9 LibCurlHttpContentFetcher:~LibCurlHttpContentFetcher
2022-09-02 00:00:06.284 [  4] 5 CBLAuthDelegate:receiveTokenResponse:code=200
2022-09-02 00:00:06.285 [  4] 5 CBLAuthDelegate:mapHTTPStatusToError:code=200,error=SUCCESS
2022-09-02 00:00:06.286 [  4] 5 CBLAuthDelegate:setAuthError:authError=SUCCESS
2022-09-02 00:00:06.287 [  4] 5 CBLAuthDelegate:setRefreshToken
2022-09-02 00:00:06.287 [  4] 5 SQLiteCBLAuthDelegateStorage:setRefreshToken
2022-09-02 00:00:06.287 [  4] 5 LWAAuthorizationStorage:setRefreshToken
2022-09-02 00:00:06.287 [  1] 5 SpeakerManager:executeInitializeSpeakerSettings:type=AVS_ALERTS_VOLUME
2022-09-02 00:00:06.293 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:06.293 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AlertsMediaPlayer
2022-09-02 00:00:06.293 [  4] 9 MiscStorageProperties:putStringSuccess:configUri=config/LWAAuthorizationStorage,key=refreshToken
2022-09-02 00:00:06.293 [  4] 9 RetryExecutor:executeSuccess:action=putString,retriesLeft=16
2022-09-02 00:00:06.294 [  4] 0 MiscStorageProperties:putStringSuccess:configUri=config/LWAAuthorizationStorage,key=refreshToken
2022-09-02 00:00:06.294 [  4] 0 MiscStorageProperties:putStringSuccess:configUri=config/LWAAuthorizationStorage,key=refreshToken
2022-09-02 00:00:06.295 [  4] 5 CBLAuthDelegate:setAuthState:newAuthState=REFRESHED
2022-09-02 00:00:06.295 [  4] 9 CBLAuthDelegate:callingOnAuthStateChange:state=REFRESHED,error=SUCCESS
2022-09-02 00:00:06.295 [  4] 9 ThreadPool:obtainWorker:created=3,obtained=3,releasedToPool=3,releasedFromPool=0,outstanding=0
2022-09-02 00:00:06.295 [  d] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AlertsMediaPlayer
2022-09-02 00:00:06.296 [  3] 9 TaskThread:startThread:moniker=  3,duration=811
2022-09-02 00:00:06.296 [  1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_ALERTS_VOLUME,sizeOfSpeakerSet=1
###########################
Authorized!
###########################
2022-09-02 00:00:06.298 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:06.298 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:14
2022-09-02 00:00:06.298 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:06.299 [  4] 9 ThreadPool:obtainWorker:created=3,obtained=4,releasedToPool=3,releasedFromPool=0,outstanding=1
2022-09-02 00:00:06.299 [  2] 9 TaskThread:startThread:moniker=  2,duration=468
2022-09-02 00:00:06.299 [  2] 9 WebSocketServer:writeMessageBegin
2022-09-02 00:00:06.300 [  2] E WebSocketServer:server::send:errorCode=15,errorCategory=websocketpp
2022-09-02 00:00:06.300 [  2] 9 WebSocketServer:writeMessageComplete
2022-09-02 00:00:06.301 [  1] 5 Renderer:resetSourceId
2022-09-02 00:00:06.301 [  1] 9 MediaPlayer:addObserverCalled:name=AlertsMediaPlayer
2022-09-02 00:00:06.302 [  d] 0 MediaPlayer:handleAddObserverCalled:name=AlertsMediaPlayer
2022-09-02 00:00:06.304 [  1] 5 Renderer:onConnectionStatusChanged:Network connected=true
2022-09-02 00:00:06.306 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=4
2022-09-02 00:00:06.306 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:06.306 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:15
2022-09-02 00:00:06.306 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:06.638 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=5
2022-09-02 00:00:06.645 [  1] 9 SQLiteMessageStorage:isDatabaseLegacy:reason=databaseNotLegacy
2022-09-02 00:00:06.647 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:06.647 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=CertifiedSender
2022-09-02 00:00:06.648 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:06.649 [  e] 9 PowerMonitor:getInstance
2022-09-02 00:00:06.649 [  e] 9 PowerMonitor:assignThreadPowerResource:threadId=2837419024
2022-09-02 00:00:06.649 [  e] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:06.650 [  e] 9 CertifiedSender:mainloop:reason=waitingForMessage
2022-09-02 00:00:06.650 [  e] 5 ConditionVariableWrapper:waitInner
2022-09-02 00:00:06.650 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:06.651 [  1] 5 CertifiedSender:onConnectionStatusChanged
2022-09-02 00:00:06.651 [  1] 5 ConditionVariableWrapper:notifyAll
2022-09-02 00:00:06.652 [  1] 5 SQLiteDeviceSettingStorage:open
2022-09-02 00:00:06.656 [  1] 5 DoNotDisturbCapabilityAgent:createDoNotDisturbCapabilityAgent
2022-09-02 00:00:06.657 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:06.658 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:16
2022-09-02 00:00:06.658 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:06.660 [  1] 5 DNDSettingProtocol:create:settingName=enabled
2022-09-02 00:00:06.661 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:06.661 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:17
2022-09-02 00:00:06.661 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:06.661 [  1] 5 DNDSettingProtocol:restoreValue:setting=Alexa.DoNotDisturb::enabled
2022-09-02 00:00:06.661 [  1] 5 SQLiteDeviceSettingStorage:loadSetting:key=Alexa.DoNotDisturb::enabled
2022-09-02 00:00:06.662 [  1] 5 SQLiteDeviceSettingStorage:loadSetting
2022-09-02 00:00:06.666 [  1] I Setting:handleSetValue:value=false3990065800
2022-09-02 00:00:06.666 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:06.667 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:06.668 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=6
2022-09-02 00:00:06.669 [  1] 5 SharedAVSSettingProtocol:create:settingName=alarmVolumeRamp
2022-09-02 00:00:06.669 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:06.669 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:18
2022-09-02 00:00:06.669 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:06.670 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:06.670 [  1] 5 SharedAVSSettingProtocol:restoreValue:setting=Alerts::alarmVolumeRamp
2022-09-02 00:00:06.670 [  1] 5 SQLiteDeviceSettingStorage:loadSetting:key=Alerts::alarmVolumeRamp
2022-09-02 00:00:06.670 [  1] 5 SQLiteDeviceSettingStorage:loadSetting
2022-09-02 00:00:06.673 [  1] I Setting:handleSetValue:value="NONE"3990065800
2022-09-02 00:00:06.674 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=7
2022-09-02 00:00:06.674 [  1] 5 SharedAVSSettingProtocol:create:settingName=wakeWordConfirmation
2022-09-02 00:00:06.674 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:06.674 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:19
2022-09-02 00:00:06.674 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:06.674 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:06.674 [  1] 5 SharedAVSSettingProtocol:restoreValue:setting=SpeechRecognizer::wakeWordConfirmation
2022-09-02 00:00:06.674 [  1] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer::wakeWordConfirmation
2022-09-02 00:00:06.675 [  1] 5 SQLiteDeviceSettingStorage:loadSetting
2022-09-02 00:00:06.675 [  1] I Setting:handleSetValue:value="NONE"3990065800
2022-09-02 00:00:07.007 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=8
2022-09-02 00:00:07.007 [  1] 5 SharedAVSSettingProtocol:create:settingName=speechConfirmation
2022-09-02 00:00:07.007 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.007 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:20
2022-09-02 00:00:07.007 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.007 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:07.007 [  1] 5 SharedAVSSettingProtocol:restoreValue:setting=SpeechRecognizer::speechConfirmation
2022-09-02 00:00:07.007 [  1] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer::speechConfirmation
2022-09-02 00:00:07.008 [  1] 5 SQLiteDeviceSettingStorage:loadSetting
2022-09-02 00:00:07.008 [  1] I Setting:handleSetValue:value="NONE"3990065800
2022-09-02 00:00:07.009 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=9
2022-09-02 00:00:07.009 [  1] 5 SharedAVSSettingProtocol:create:settingName=timeZone
2022-09-02 00:00:07.009 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.009 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:21
2022-09-02 00:00:07.009 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.009 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:07.009 [  1] 5 SharedAVSSettingProtocol:restoreValue:setting=System::timeZone
2022-09-02 00:00:07.010 [  1] 5 SQLiteDeviceSettingStorage:loadSetting:key=System::timeZone
2022-09-02 00:00:07.010 [  1] 5 SQLiteDeviceSettingStorage:loadSetting
2022-09-02 00:00:07.010 [  1] I Setting:handleSetValue:value="America/Vancouver"3990065800
2022-09-02 00:00:07.011 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=10
2022-09-02 00:00:07.011 [  1] 5 SharedAVSSettingProtocol:create:settingName=networkInfo
2022-09-02 00:00:07.011 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.011 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:22
2022-09-02 00:00:07.011 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.011 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:07.011 [  1] 5 SharedAVSSettingProtocol:restoreValue:setting=System::networkInfo
2022-09-02 00:00:07.011 [  1] 5 SQLiteDeviceSettingStorage:loadSetting:key=System::networkInfo
2022-09-02 00:00:07.012 [  1] 5 SQLiteDeviceSettingStorage:loadSetting
2022-09-02 00:00:07.012 [  1] 5 JsonUtils:findNode:reason=missingDirectChild,child=connectionType
2022-09-02 00:00:07.013 [  1] 5 JsonUtils:findNode:reason=missingDirectChild,child=ESSID
2022-09-02 00:00:07.013 [  1] 5 JsonUtils:findNode:reason=missingDirectChild,child=BSSID
2022-09-02 00:00:07.013 [  1] 5 JsonUtils:findNode:reason=missingDirectChild,child=IPAddress
2022-09-02 00:00:07.013 [  1] 5 JsonUtils:findNode:reason=missingDirectChild,child=subnetMask
2022-09-02 00:00:07.013 [  1] 5 JsonUtils:findNode:reason=missingDirectChild,child=MACAddress
2022-09-02 00:00:07.013 [  1] 5 JsonUtils:findNode:reason=missingDirectChild,child=DHCPServerAddress
2022-09-02 00:00:07.013 [  1] 5 JsonUtils:findNode:reason=missingDirectChild,child=staticIP
2022-09-02 00:00:07.014 [  1] I Setting:handleSetValue:value={}3990065800
2022-09-02 00:00:07.014 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=11
2022-09-02 00:00:07.014 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=12
2022-09-02 00:00:07.015 [  1] 5 LocaleWakeWordsSetting:create:settingName=LocaleWakeWords
2022-09-02 00:00:07.015 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.346 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:23
2022-09-02 00:00:07.347 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.347 [  1] 5 SQLiteDeviceSettingStorage:loadSetting:key=System.locales
2022-09-02 00:00:07.348 [  1] 5 SQLiteDeviceSettingStorage:loadSetting
2022-09-02 00:00:07.349 [  1] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer.wakeWords
2022-09-02 00:00:07.350 [  1] 5 SQLiteDeviceSettingStorage:loadSetting
2022-09-02 00:00:07.352 [  1] 2 LocaleWakeWordsSetting:restoreInitialValue:wakeWords=["ALEXA"],locale=["en-US"]
2022-09-02 00:00:07.353 [  1] 9 ThreadPool:obtainWorker:created=3,obtained=5,releasedToPool=5,releasedFromPool=0,outstanding=0
2022-09-02 00:00:07.354 [  5] 9 TaskThread:startThread:moniker=  5,duration=676
2022-09-02 00:00:07.354 [  5] I LocaleAssetsManager:changeAssets:Locale=["en-US"],WakeWords=["ALEXA"]
2022-09-02 00:00:07.356 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:07.361 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:07.361 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:07.362 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:07.362 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.362 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:24
2022-09-02 00:00:07.363 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.363 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.364 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:25
2022-09-02 00:00:07.364 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.374 [  1] 5 SQLiteAlertStorage:migrateAlertsDbFromV2ToV3::Alerts v3 table already exists.
2022-09-02 00:00:07.378 [  1] 5 SQLiteAlertStorage:migrateOfflineAlertsDbFromV1ToV2::Offline alerts v2 table already exists.
2022-09-02 00:00:07.382 [  1] 5 AlertScheduler:setTimerForNextAlertLocked
2022-09-02 00:00:07.382 [  1] I AlertScheduler:executeScheduleNextAlertForRendering::no work to do.
2022-09-02 00:00:07.382 [  1] 9 SpeakerManager:getSpeakerSettingsCalled
2022-09-02 00:00:07.383 [  1] 9 ThreadPool:obtainWorker:created=3,obtained=6,releasedToPool=5,releasedFromPool=0,outstanding=1
2022-09-02 00:00:07.383 [  3] 9 TaskThread:startThread:moniker=  3,duration=292
2022-09-02 00:00:07.383 [  3] 9 SpeakerManager:executeGetSpeakerSettingsCalled
2022-09-02 00:00:07.385 [  1] 5 ContextManager:setState
2022-09-02 00:00:07.385 [  1] 9 ThreadPool:obtainWorker:created=3,obtained=7,releasedToPool=5,releasedFromPool=0,outstanding=2
2022-09-02 00:00:07.385 [  2] 9 TaskThread:startThread:moniker=  2,duration=267
2022-09-02 00:00:07.386 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:07.386 [  2] I ContextManager:updateCapabilityState
2022-09-02 00:00:07.387 [  1] 9 ThreadPool:obtainWorker:created=3,obtained=8,releasedToPool=5,releasedFromPool=0,outstanding=3
2022-09-02 00:00:07.387 [  1] 9 SpeakerManager:addSpeakerManagerObserverCalled
2022-09-02 00:00:07.387 [  f] 9 TaskThread:startThread:moniker=  f,duration=714
2022-09-02 00:00:07.388 [  1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x2a5784
2022-09-02 00:00:07.388 [  f] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:07.389 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:07.389 [  2] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:07.389 [  2] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:07.391 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.391 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:26
2022-09-02 00:00:07.391 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.392 [  1] 5 DefaultEndpointBuilder:withCapabilityConfiguration
2022-09-02 00:00:07.393 [  1] 5 PlaybackRouter:createPlaybackRouterInterface
2022-09-02 00:00:07.394 [  1] 9 PlaybackRouter:create::called
2022-09-02 00:00:07.396 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.396 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:27
2022-09-02 00:00:07.730 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.733 [  1] 5 ContextManager:addStateProvider
2022-09-02 00:00:07.734 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:07.739 [  1] 5 BluetoothMediaInputTransformer:create
2022-09-02 00:00:07.740 [  1] 5 BluetoothMediaInputTransformer:init
2022-09-02 00:00:07.744 [  1] 5 Bluetooth:createBluetoothCapabilityAgent
2022-09-02 00:00:07.746 [  1] 5 StubApplicationAudioPipelineFactory:createApplicationMediaInterfaces
2022-09-02 00:00:07.747 [  1] E StubApplicationAudioPipelineFactory:createApplicationMediaInterfacesFailed:reason=not found,name=BluetoothMediaPlayer
2022-09-02 00:00:07.747 [  1] E Bluetooth:createBluetoothCapabilityAgentInterfaceFailed:reason=failed to create media player or related interfaces
2022-09-02 00:00:07.747 [  1] 5 SpeakerManager:executeInitializeSpeakerSettings:type=AVS_SPEAKER_VOLUME
2022-09-02 00:00:07.748 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:07.748 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AudioMediaPlayer
2022-09-02 00:00:07.748 [  9] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AudioMediaPlayer
2022-09-02 00:00:07.749 [  1] 9 SpeakerManager:executeGetSpeakerSettingsCalled
2022-09-02 00:00:07.750 [  1] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SPEAKER_VOLUME
2022-09-02 00:00:07.751 [  1] 5 ContextManager:setState
2022-09-02 00:00:07.751 [  2] I ContextManager:updateCapabilityState
2022-09-02 00:00:07.752 [  2] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:07.752 [  2] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:07.752 [  2] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:07.752 [  2] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:07.753 [  1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=1
2022-09-02 00:00:07.753 [  1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=2
2022-09-02 00:00:07.755 [  1] 7 SmartScreenClient:initialize::power resource management disabled
2022-09-02 00:00:07.756 [  1] 7 SmartScreenClient:initialize::using default null SystemTimeZone
2022-09-02 00:00:07.757 [  1] 5 UserInactivityMonitor:createUserInactivityMonitorInterface
2022-09-02 00:00:07.758 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:07.759 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:07.759 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:07.765 [  1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x34926c,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:07.766 [  1] 5 SmartScreenClient:nullCaptionManager::captions disabled
2022-09-02 00:00:07.768 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.768 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:28
2022-09-02 00:00:07.768 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:07.770 [  1] 5 ExternalMediaPlayer:init
2022-09-02 00:00:07.771 [  1] 5 AuthorizedSender:create
2022-09-02 00:00:07.771 [  1] 5 ContextManager:addStateProvider
2022-09-02 00:00:07.771 [  1] 5 ContextManager:addStateProvider
2022-09-02 00:00:07.772 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:07.772 [  1] 5 ExternalMediaPlayer:createAdapters
2022-09-02 00:00:07.774 [  1] 5 SmartScreenClient:nullBluetooth::Bluetooth disabled
2022-09-02 00:00:07.774 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:07.774 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:07.774 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:07.774 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:07.774 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:07.775 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:07.775 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:07.775 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:07.775 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:07.775 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:07.775 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:29
2022-09-02 00:00:08.107 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.110 [  1] 8 DialogUXStateAggregator:timeout values in milliseconds:m_timeoutForThinkingToIdle=8000,m_shortTimeoutForThinkingToIdle=200,m_timeoutForListeningToIdle=8000
2022-09-02 00:00:08.115 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:08.116 [  1] 9 ThreadPool:obtainWorker:created=4,obtained=9,releasedToPool=5,releasedFromPool=0,outstanding=4
2022-09-02 00:00:08.117 [ 10] 9 TaskThread:startThread:moniker= 10,duration=946
2022-09-02 00:00:08.118 [  1] 9 ThreadPool:obtainWorker:created=5,obtained=10,releasedToPool=5,releasedFromPool=0,outstanding=5
2022-09-02 00:00:08.119 [ 11] 9 TaskThread:startThread:moniker= 11,duration=1146
2022-09-02 00:00:08.122 [  1] 5 CapabilitiesDelegate:setMessageSender
2022-09-02 00:00:08.122 [  1] 5 AVSGatewayManager:addObserver
2022-09-02 00:00:08.125 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:08.125 [  1] 5 CapabilitiesDelegate:onConnectionStatusChanged:connectionStatus=DISCONNECTED
2022-09-02 00:00:08.128 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.129 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:30
2022-09-02 00:00:08.129 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.129 [  1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x34b77c
2022-09-02 00:00:08.132 [  1] 5 EndpointRegistrationManager:onCapabilitiesStateChange:state=UNINITIALIZED,error=UNINITIALIZED,callback=true
2022-09-02 00:00:08.132 [  1] 5 EndpointRegistrationManager:onCapabilityRegistrationStatusChanged
2022-09-02 00:00:08.133 [  1] 9 ThreadPool:obtainWorker:created=6,obtained=11,releasedToPool=5,releasedFromPool=0,outstanding=6
2022-09-02 00:00:08.134 [ 12] 9 TaskThread:startThread:moniker= 12,duration=1433
2022-09-02 00:00:08.139 [  1] 9 MediaPlayer:addObserverCalled:name=SystemSoundMediaPlayer
2022-09-02 00:00:08.139 [ 13] 0 MediaPlayer:handleAddObserverCalled:name=SystemSoundMediaPlayer
2022-09-02 00:00:08.143 [  1] 5 AudioInputProcessor:getSpeechRecognizerCapabilityConfiguration:wakeWords={"wakeWords":[{"scopes":["DEFAULT"],"values":[["ALEXA"]]}]}
2022-09-02 00:00:08.144 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:08.144 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:08.144 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:08.145 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.145 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:31
2022-09-02 00:00:08.145 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.147 [  1] 9 ThreadPool:obtainWorker:created=7,obtained=12,releasedToPool=5,releasedFromPool=0,outstanding=7
2022-09-02 00:00:08.147 [ 14] 9 TaskThread:startThread:moniker= 14,duration=812
2022-09-02 00:00:08.147 [  1] 5 StubApplicationAudioPipelineFactory:createApplicationMediaInterfaces
2022-09-02 00:00:08.148 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:08.148 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=SpeakMediaPlayer
2022-09-02 00:00:08.148 [ 15] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=SpeakMediaPlayer
2022-09-02 00:00:08.148 [  1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=3
2022-09-02 00:00:08.148 [ 14] 0 AudioInputProcessor:executeOnDialogUXStateChanged:newState=IDLE
2022-09-02 00:00:08.149 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.149 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:32
2022-09-02 00:00:08.150 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.151 [  1] 9 MediaPlayer:addObserverCalled:name=SpeakMediaPlayer
2022-09-02 00:00:08.151 [ 15] 0 MediaPlayer:handleAddObserverCalled:name=SpeakMediaPlayer
2022-09-02 00:00:08.152 [  1] 5 ContextManager:addStateProvider
2022-09-02 00:00:08.152 [ 11] 9 ThreadPool:obtainWorker:created=8,obtained=13,releasedToPool=5,releasedFromPool=0,outstanding=8
2022-09-02 00:00:08.153 [ 16] 9 TaskThread:startThread:moniker= 16,duration=509
2022-09-02 00:00:08.156 [  1] 9 SpeechSynthesizer:addObserver:observer=0x34ad4c
2022-09-02 00:00:08.488 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:08.489 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=SystemSoundMediaPlayer
2022-09-02 00:00:08.490 [ 13] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=SystemSoundMediaPlayer
2022-09-02 00:00:08.491 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:08.491 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=BluetoothMediaPlayer
2022-09-02 00:00:08.492 [ 17] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=BluetoothMediaPlayer
2022-09-02 00:00:08.494 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:08.494 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=RingtoneMediaPlayer
2022-09-02 00:00:08.495 [ 18] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=RingtoneMediaPlayer
2022-09-02 00:00:08.495 [  1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=4
2022-09-02 00:00:08.496 [  1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=5
2022-09-02 00:00:08.496 [  1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=6
2022-09-02 00:00:08.496 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:08.496 [  1] 0 DialogUXStateAggregator:onConnectionStatusChanged:engineAggregatedStatus=DISCONNECTED
2022-09-02 00:00:08.497 [ 11] 0 DialogUXStateAggregator:onConnectionStatusChangedLambda:engineType=1,engineStatus=DISCONNECTED
2022-09-02 00:00:08.497 [ 11] 0 DialogUXStateAggregator:onConnectionStatusChangedLambda:isConnected=false
2022-09-02 00:00:08.497 [ 11] 0 DialogUXStateAggregator:onConnectionStatusChangedLambda::Setting state to idle
2022-09-02 00:00:08.498 [ 11] 0 DialogUXStateAggregator:executeSetState:from=IDLE,to=IDLE,validTransition=false
2022-09-02 00:00:08.498 [  1] 0 DialogUXStateAggregator:onConnectionStatusChanged:status=DISCONNECTED:deprecated method. Nothing done.
2022-09-02 00:00:08.502 [  1] 5 NotificationRenderer:createNotificationRendererInterface
2022-09-02 00:00:08.503 [  1] 5 StubApplicationAudioPipelineFactory:createApplicationMediaInterfaces
2022-09-02 00:00:08.503 [  1] 0 ChannelVolumeManager:getSpeakerSettings
2022-09-02 00:00:08.503 [  1] 9 MediaPlayer:getSpeakerSettingsCalled:name=NotificationsMediaPlayer
2022-09-02 00:00:08.504 [ 19] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=NotificationsMediaPlayer
2022-09-02 00:00:08.505 [  1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_ALERTS_VOLUME,sizeOfSpeakerSet=2
2022-09-02 00:00:08.505 [  1] 5 NotificationRenderer:create
2022-09-02 00:00:08.506 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.506 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:33
2022-09-02 00:00:08.507 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.507 [  1] 9 MediaPlayer:addObserverCalled:name=NotificationsMediaPlayer
2022-09-02 00:00:08.508 [ 19] 0 MediaPlayer:handleAddObserverCalled:name=NotificationsMediaPlayer
2022-09-02 00:00:08.508 [  1] 5 NotificationsCapabilityAgent:createNotificationsCapabilityAgent
2022-09-02 00:00:08.510 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.510 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:34
2022-09-02 00:00:08.510 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.511 [  1] 5 NotificationsCapabilityAgent:init
2022-09-02 00:00:08.515 [  1] 9 ThreadPool:obtainWorker:created=9,obtained=14,releasedToPool=8,releasedFromPool=0,outstanding=6
2022-09-02 00:00:08.515 [  5] 9 TaskThread:startThread:moniker=  5,duration=287
2022-09-02 00:00:08.515 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:08.516 [  5] 5 NotificationsCapabilityAgent:executeInit
2022-09-02 00:00:08.516 [  5] 5 NotificationRenderer:addObserver
2022-09-02 00:00:08.516 [  5] 5 ContextManager:addStateProvider
2022-09-02 00:00:08.516 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.516 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:35
2022-09-02 00:00:08.518 [  5] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=false,stateRequestToken=0,isEnabled=false
2022-09-02 00:00:08.852 [  5] 5 ContextManager:setState
2022-09-02 00:00:08.852 [  5] 9 ThreadPool:obtainWorker:created=9,obtained=15,releasedToPool=9,releasedFromPool=0,outstanding=6
2022-09-02 00:00:08.853 [  3] 9 TaskThread:startThread:moniker=  3,duration=694
2022-09-02 00:00:08.853 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:08.852 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.855 [  1] 5 ContextManager:addStateProvider
2022-09-02 00:00:08.856 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:08.857 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:08.857 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:08.857 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:08.858 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:08.858 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:08.858 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:08.858 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:08.861 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.861 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:36
2022-09-02 00:00:08.862 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.862 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:08.862 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:08.862 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:08.862 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.863 [  1] 5 PowerMonitor:getPowerResourceManager
2022-09-02 00:00:08.863 [  1] E PowerResource:create:error=nullPowerManager
2022-09-02 00:00:08.864 [  1] W Timer:Timer:reason=nullTimerDelegateFactory:Falling back to default TimerDelegateFactory
2022-09-02 00:00:08.865 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:08.865 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:08.866 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:08.866 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:08.866 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:08.867 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:08.867 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.867 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:37
2022-09-02 00:00:08.868 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.873 [  1] 0 AlexaPresentation:initialize::Proactive state report timer disabled
2022-09-02 00:00:08.874 [  1] 3 AlexaPresentation:create:visualStateProvider=On
2022-09-02 00:00:08.874 [  1] 5 ContextManager:addStateProvider
2022-09-02 00:00:08.875 [ 11] 5 AlexaPresentation:onDialogUXStateChanged:state=IDLE
2022-09-02 00:00:08.876 [ 11] 9 ThreadPool:obtainWorker:created=9,obtained=16,releasedToPool=9,releasedFromPool=0,outstanding=7
2022-09-02 00:00:08.876 [  f] 9 TaskThread:startThread:moniker=  f,duration=1064
2022-09-02 00:00:08.877 [  1] 1 AlexaPresentation:setAPLMaxVersion:APLVersion=1.8
2022-09-02 00:00:08.878 [  1] 5 SDKPrimitivesProvider:getInstance
2022-09-02 00:00:08.879 [  1] 5 SDKPrimitivesProvider:getTimerDelegateFactory
2022-09-02 00:00:08.879 [  1] 5 SDKPrimitivesProvider:isInitialized
2022-09-02 00:00:08.879 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.879 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:38
2022-09-02 00:00:08.879 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:08.881 [  1] 5 ExternalMediaPlayer:setObserver
2022-09-02 00:00:08.881 [  1] 1 AudioPlayer:setObserver
2022-09-02 00:00:08.882 [  1] 9 ThreadPool:obtainWorker:created=9,obtained=17,releasedToPool=9,releasedFromPool=0,outstanding=8
2022-09-02 00:00:08.882 [  2] 9 TaskThread:startThread:moniker=  2,duration=303
2022-09-02 00:00:08.883 [  1] 5 ExternalCapabilitiesBuilder:withTemplateRunTime
2022-09-02 00:00:08.883 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:08.884 [ 11] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE
2022-09-02 00:00:09.218 [ 11] 9 ThreadPool:obtainWorker:created=9,obtained=18,releasedToPool=12,releasedFromPool=0,outstanding=6
2022-09-02 00:00:09.219 [ 10] 9 TaskThread:startThread:moniker= 10,duration=1111
2022-09-02 00:00:09.219 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:39
2022-09-02 00:00:09.219 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:09.221 [  1] 9 VisualCharacteristics:getVisualCharacteristicsCapabilityConfiguration
2022-09-02 00:00:09.228 [  1] 5 ContextManager:addStateProvider
2022-09-02 00:00:09.228 [  1] 3 SmartScreenClient:initialize::Equalizer is disabled
2022-09-02 00:00:09.229 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:09.229 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:40
2022-09-02 00:00:09.230 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:09.230 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:09.231 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:41
2022-09-02 00:00:09.231 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:09.234 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=13
2022-09-02 00:00:09.241 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:09.241 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:42
2022-09-02 00:00:09.241 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:09.242 [  1] 9 AbstractAVSConnectionManager:addConnectionStatusObserver:this=0x290c58,engineType=1,status=DISCONNECTED,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:09.246 [  1] 5 SystemCapabilityProvider:getSystemCapabilityConfiguration:locales={"locales":["en-GB","en-US"],"localeCombinations":[["en-US","en-GB"]]}
2022-09-02 00:00:09.247 [  1] 5 ApiGateway:create
2022-09-02 00:00:09.248 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:09.248 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=Executor:43
2022-09-02 00:00:09.248 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:09.249 [  1] 0 SmartScreenClient:initialize::Diagnostics Not Enabled
2022-09-02 00:00:09.249 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:09.249 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:09.249 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:09.249 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:09.249 [  1] 5 DefaultEndpointBuilder:withCapability
2022-09-02 00:00:09.250 [  1] 5 DefaultEndpointBuilder:withCapabilityConfiguration
2022-09-02 00:00:09.250 [  1] 5 DefaultEndpointBuilder:withCapabilityConfiguration
2022-09-02 00:00:09.250 [  1] 5 DefaultEndpointBuilder:withCapabilityConfiguration
2022-09-02 00:00:09.250 [  1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetLocales,handler=0x388070,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.250 [  1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetTimeZone,handler=0x387a28,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.251 [  1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ReportState,handler=0x388ba8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.251 [  1] 5 ExternalCapabilitiesBuilder:withVisualFocusManager
2022-09-02 00:00:09.251 [  1] 5 ExternalCapabilitiesBuilder:buildCapabilities
2022-09-02 00:00:09.251 [  1] 5 DefaultEndpointBuilder:withCapabilityConfiguration
2022-09-02 00:00:09.255 [  1] 5 BlueZBluetoothDeviceManager:~BlueZBluetoothDeviceManager
2022-09-02 00:00:09.255 [  1] 5 BlueZDeviceManager:doShutdown
bluetoothd[1906]: Endpoint unregistered: sender=:1.4 path=/com/amazon/alexa/sdk/sinkendpoint
2022-09-02 00:00:09.261 [  8] 7 DBusObjectBase:onMethodCalledInternal:methodName=Release
2022-09-02 00:00:09.261 [  8] 5 MediaEndpoint:onRelease
2022-09-02 00:00:09.261 [  1] 5 MediaEndpoint:~MediaEndpoint
2022-09-02 00:00:09.262 [  1] 5 MediaEndpoint:setOperatingMode:newMode=RELEASED
2022-09-02 00:00:09.262 [ 1a] 5 MediaEndpoint:Exiting media thread.
2022-09-02 00:00:09.263 [  1] 5 MediaEndpoint:~MediaEndpoint::MediaEndpoit finalized.
2022-09-02 00:00:09.263 [  1] 7 DBusObjectBase:~DBusObjectBase
2022-09-02 00:00:09.597 [  1] 5 PairingAgent:~PairingAgent
2022-09-02 00:00:09.597 [  1] 5 PairingAgent:unregisterAgent
2022-09-02 00:00:09.583 [  8] 5 BlueZDeviceManager:propertiesChangedCallback
2022-09-02 00:00:09.598 [  8] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0
2022-09-02 00:00:09.598 [  8] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1', {'Class': <uint32 0>}, @as [])
2022-09-02 00:00:09.599 [  8] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0
2022-09-02 00:00:09.599 [  8] 5 BlueZDeviceManager:propertiesChangedCallback
2022-09-02 00:00:09.599 [  8] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0
2022-09-02 00:00:09.599 [  8] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1', {'UUIDs': <['00001801-0000-1000-8000-00805f9b34fb', '00001800-0000-1000-8000-00805f9b34fb', '00001200-0000-1000-8000-00805f9b34fb', '0000110c-0000-1000-8000-00805f9b34fb', '0000110e-0000-1000-8000-00805f9b34fb']>}, @as [])
2022-09-02 00:00:09.600 [  8] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0
2022-09-02 00:00:09.604 [  1] 5 PairingAgent:unregisterAgent::unregisterAgentDone
2022-09-02 00:00:09.604 [  1] 7 BlueZUtils:~DBusProxy
2022-09-02 00:00:09.606 [  1] 7 DBusObjectBase:~DBusObjectBase
2022-09-02 00:00:09.607 [  1] 5 MPRISPlayer:~MPRISPlayer
2022-09-02 00:00:09.607 [  1] 5 MPRISPlayer:unregisterPlayer
bluetoothd[1906]: Player unregistered: sender=:1.4 path=/org/mpris/MediaPlayer2
2022-09-02 00:00:09.617 [  1] 0 MPRISPlayer:unregisterPlayer::unregisterPlayerSucceeded
2022-09-02 00:00:09.617 [  1] 7 DBusObjectBase:~DBusObjectBase
2022-09-02 00:00:09.617 [  1] 5 DBusConnection:close
2022-09-02 00:00:09.622 [  1] 5 BlueZDeviceManager:~BlueZDeviceManager
2022-09-02 00:00:09.622 [  1] 7 BlueZUtils:~DBusProxy
2022-09-02 00:00:09.623 [  1] 7 BlueZUtils:~DBusProxy
2022-09-02 00:00:09.625 [  1] 5 DBusConnection:close
2022-09-02 00:00:09.625 [  1] 7 BlueZUtils:~DBusProxy
2022-09-02 00:00:09.626 [  1] 7 BlueZUtils:~DBusProxy
2022-09-02 00:00:09.628 [  1] 9 SpeakerManager:addSpeakerManagerObserverCalled
2022-09-02 00:00:09.629 [  1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x1f7058
2022-09-02 00:00:09.629 [  1] 9 ThreadPool:obtainWorker:created=9,obtained=19,releasedToPool=13,releasedFromPool=0,outstanding=6
2022-09-02 00:00:09.629 [ 12] 9 TaskThread:startThread:moniker= 12,duration=321
2022-09-02 00:00:09.630 [  1] 5 TemplateRuntime:addObserver
2022-09-02 00:00:09.631 [  1] 5 AlexaPresentation:addObserver
2022-09-02 00:00:09.631 [  1] 1 AudioPlayer:addObserver
2022-09-02 00:00:09.631 [  1] 1 AudioPlayer:addObserver
2022-09-02 00:00:09.631 [  5] 9 ThreadPool:obtainWorker:created=9,obtained=20,releasedToPool=13,releasedFromPool=0,outstanding=7
2022-09-02 00:00:09.632 [  1] 9 ThreadPool:obtainWorker:created=9,obtained=21,releasedToPool=13,releasedFromPool=0,outstanding=8
2022-09-02 00:00:09.632 [  f] 5 AlexaPresentation:addObserverInExecutor
2022-09-02 00:00:09.632 [  1] 9 ThreadPool:obtainWorker:created=9,obtained=22,releasedToPool=13,releasedFromPool=0,outstanding=9
2022-09-02 00:00:09.632 [ 10] 5 TemplateRuntime:addObserverInExecutor
2022-09-02 00:00:09.633 [ 16] 9 TaskThread:startThread:moniker= 16,duration=1232
2022-09-02 00:00:09.633 [ 1b] 9 TaskThread:startThread:moniker= 1b,duration=703
2022-09-02 00:00:09.633 [ 14] 9 TaskThread:startThread:moniker= 14,duration=1159
#################################################
NOTIFICATION INDICATOR STATE: OFF
#################################################
2022-09-02 00:00:09.634 [  1] 3 GUIClient:setGUIManager
2022-09-02 00:00:09.634 [  1] 9 ThreadPool:obtainWorker:created=10,obtained=23,releasedToPool=13,releasedFromPool=0,outstanding=10
Creating Amazon Engine..
2022-09-02 00:00:09.635 [ 1c] 9 TaskThread:startThread:moniker= 1c,duration=550
2022-09-02 00:00:09.635 [ 1c] 9 ThreadPool:obtainWorker:created=11,obtained=24,releasedToPool=13,releasedFromPool=0,outstanding=11
2022-09-02 00:00:09.636 [ 1d] 9 TaskThread:startThread:moniker= 1d,duration=798
Amazon engine created
Creating DSPC Engine..
DSPC engine created
2022-09-02 00:00:09.644 [  1] 5 CBLAuthDelegate:addAuthObserver:observer=0x1df008
2022-09-02 00:00:09.645 [  1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x1df00c
2022-09-02 00:00:09.647 [ 1e] 3 GUIClient:serverThread
2022-09-02 00:00:09.647 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:09.650 [  1] 2 EndpointBuilder:buildImplementation:isDefault=true,#capabilities=27
2022-09-02 00:00:09.979 [  1] 5 EndpointRegistrationManager:registerEndpoint
2022-09-02 00:00:09.981 [  1] 9 ThreadPool:obtainWorker:created=12,obtained=25,releasedToPool=14,releasedFromPool=0,outstanding=11
2022-09-02 00:00:09.983 [  3] 9 TaskThread:startThread:moniker=  3,duration=1783
2022-09-02 00:00:09.983 [  3] 5 EndpointRegistrationManager:executeRegisterEndpoint
2022-09-02 00:00:09.984 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=Alexa.SoftwareComponentReporter
2022-09-02 00:00:09.984 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=System
2022-09-02 00:00:09.985 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=VisualActivityTracker
2022-09-02 00:00:09.985 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=Alexa.Presentation.APL.Video
2022-09-02 00:00:09.985 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=Alexa.Display
2022-09-02 00:00:09.985 [  3] 5 TemplateRuntime:getConfiguration
2022-09-02 00:00:09.985 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x386670,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2022-09-02 00:00:09.985 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x386670,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2022-09-02 00:00:09.986 [  3] 5 ApiGateway:getConfiguration
2022-09-02 00:00:09.986 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.ApiGateway,name=SetGateway,handler=0x389ba0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.987 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=Alexa.Display.Window
2022-09-02 00:00:09.987 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=PlaybackController
2022-09-02 00:00:09.987 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Unfavorite,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.987 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=AdjustSeekPosition,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:09.987 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=SetSeekPosition,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:09.987 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableShuffle,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.987 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableShuffle,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.987 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableRepeat,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.987 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Favorite,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.988 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeatOne,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:09.988 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=StartOver,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:09.988 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Stop,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.320 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Previous,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Pause,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=FastForward,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Play,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Rewind,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Logout,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeat,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Login,handler=0x349698,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Play,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Next,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=AuthorizeDiscoveredPlayers,handler=0x349698,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 5 AlexaPresentation:getConfiguration
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.Presentation.APL,name=SendTokenListData,handler=0x3856d0,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.Presentation.APL,name=UpdateIndexListData,handler=0x3856d0,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.Presentation.APL,name=SendIndexListData,handler=0x3856d0,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False
2022-09-02 00:00:10.321 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.Presentation.APL,name=RenderDocument,handler=0x3856d0,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:True
2022-09-02 00:00:10.322 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.Presentation.APL,name=ExecuteCommands,handler=0x3856d0,policy= Mediums:MEDIUMS_AUDIO_AND_VISUAL11 .isBlocking:True
2022-09-02 00:00:10.322 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlarmVolumeRamp,handler=0x2a5718,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.322 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=AdjustVolume,handler=0x2a5718,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.322 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetVolume,handler=0x2a5718,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.322 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlerts,handler=0x2a5718,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.654 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x2a5718,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.654 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x2a5718,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.654 [  3] 5 DoNotDisturbCapabilityAgent:getConfiguration
2022-09-02 00:00:10.655 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.DoNotDisturb,name=SetDoNotDisturb,handler=0x2a3450,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.655 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=UpdateProgressReportInterval,handler=0x348058,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.655 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x348058,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.655 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x348058,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.656 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x348058,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False
2022-09-02 00:00:10.656 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x29b558,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.656 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x29b558,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.656 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x29b558,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.656 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x34d858,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2022-09-02 00:00:10.657 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=AudioActivityTracker
2022-09-02 00:00:10.657 [  3] 5 EndpointRegistrationManager:addCapability:emptyHandler=Alexa.InteractionMode
2022-09-02 00:00:10.657 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetSpeechConfirmation,handler=0x34c3f8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.657 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetWakeWordConfirmation,handler=0x34c3f8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.657 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetEndOfSpeechOffset,handler=0x34c3f8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.657 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetWakeWords,handler=0x34c3f8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.658 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x34c3f8,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.658 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x34c3f8,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True
2022-09-02 00:00:10.658 [  3] 5 AlexaInterfaceCapabilityAgent:getConfiguration
2022-09-02 00:00:10.658 [  3] 5 AlexaInterfaceCapabilityAgent:registeringEventProcessedDirective:reason=defaultEndpoint
2022-09-02 00:00:10.992 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa,name=ReportState,handler=0x29ab38,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.992 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa,name=EventProcessed,handler=0x29ab38,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.992 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=ClearIndicator,handler=0x34e7fc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.992 [  3] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=SetIndicator,handler=0x34e7fc,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False
2022-09-02 00:00:10.994 [  3] 5 CapabilitiesDelegate:addOrUpdateEndpoint
2022-09-02 00:00:09.988 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:10.995 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:10.995 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:10.996 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:10.998 [ 1e] I WebSocketServer:Listening for websocket connections:interface=<IP_ADDRESS>,port=8933
2022-09-02 00:00:11.000 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.000 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.000 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.000 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.001 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.002 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.002 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.002 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.003 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.004 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.005 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.005 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.006 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.008 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.008 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.008 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=26,releasedToPool=25,releasedFromPool=0,outstanding=1
2022-09-02 00:00:11.010 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.010 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.012 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.013 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.015 [ 12] 9 TaskThread:startThread:moniker= 12,duration=7135
2022-09-02 00:00:11.016 [ 12] 5 CapabilitiesDelegate:executeSendPendingEndpoints
2022-09-02 00:00:11.016 [  3] 2 EndpointRegistrationManager:executeRegisterEndpoint:result=finished
2022-09-02 00:00:11.015 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.016 [ 12] 5 CapabilitiesDelegate:executeSendPendingEndpoints:Deferred=Not connected
2022-09-02 00:00:11.016 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.017 [  1] 5 AVSGatewayManager:setAVSGatewayAssigner
2022-09-02 00:00:11.017 [  1] I MessageRouter:setAVSGateway:avsGateway=https://alexa.na.gateway.devices.a2z.com
2022-09-02 00:00:11.018 [  1] 5 AVSConnectionManager:enable:this=0x290c58
2022-09-02 00:00:11.018 [  1] I MessageRouter:enable
2022-09-02 00:00:11.018 [  1] I MessageRouter:setConnectionStatusLocked:status=PENDING,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:11.018 [  1] 0 MessageRouter:connectionStatusChanged:reason=ACL_CLIENT_REQUEST,newStatus=PENDING
2022-09-02 00:00:11.019 [  1] 9 ThreadPool:obtainWorker:created=12,obtained=27,releasedToPool=25,releasedFromPool=0,outstanding=2
2022-09-02 00:00:11.019 [  1] 5 LibcurlHTTP2ConnectionFactory:createHTTP2Connection
2022-09-02 00:00:11.020 [  1] 5 LibcurlHTTP2Connection:init:this=0x2995d0
2022-09-02 00:00:11.020 [  5] 9 TaskThread:startThread:moniker=  5,duration=1623
2022-09-02 00:00:11.021 [ 1f] 5 LibcurlHTTP2Connection:networkLoop:this=0x2995d0
2022-09-02 00:00:11.021 [  1] 5 HTTP2Transport:create:authDelegate=0x22d780,avsGateway=https://alexa.na.gateway.devices.a2z.com,http2Connection=0x2995d0,messageConsumer=0x2975a0,attachmentManager=0x290818,transportObserver=0x29759c,postConnectFactory=0x232ca0,sharedRequestQueue=0x29774c
2022-09-02 00:00:11.022 [  1] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=14
2022-09-02 00:00:11.022 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:11.022 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=HTTP2Transport_mainLoop
2022-09-02 00:00:11.354 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:11.354 [  1] 9 PowerMonitor:getInstance
2022-09-02 00:00:11.355 [  1] 9 PowerMonitor:createLocalPowerResource:identifier=HTTP2Transport_requestActivityResource
2022-09-02 00:00:11.355 [  1] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:11.355 [  1] I MessageRouter:createActiveTransportLocked:transport=0x299dd0,sizeOf m_transports=0
2022-09-02 00:00:11.355 [  1] I HTTP2Transport:connect:this=0x299dd0
2022-09-02 00:00:11.355 [  1] I HTTP2Transport:setStateLocked:this=0x299dd0,currentState=INIT,newState=AUTHORIZING,changedReason=ACL_CLIENT_REQUEST
2022-09-02 00:00:11.356 [  1] 5 ConditionVariableWrapper:notifyAll
2022-09-02 00:00:11.357 [ 20] 7 HTTP2Transport:mainLoop:this=0x299dd0
2022-09-02 00:00:11.357 [  1] I MessageRouter:setAsActiveTransport:transport=0x299dd0,sizeOf m_transports=1
2022-09-02 00:00:11.357 [  5] 0 AVSConnectionManager:onConnectionStatusChanged:this=0x290c58,status=PENDING,engine_count=1
2022-09-02 00:00:11.358 [  5] 5 AbstractAVSConnectionManager:notifyObservers:this=0x290c58:EngineConnectionStatusDetail,engineType=1,status=PENDING,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:11.358 [  5] 0 DialogUXStateAggregator:onConnectionStatusChanged:engineAggregatedStatus=PENDING
2022-09-02 00:00:11.359 [  5] 9 ThreadPool:obtainWorker:created=12,obtained=28,releasedToPool=25,releasedFromPool=0,outstanding=3
2022-09-02 00:00:11.359 [  5] 0 DialogUXStateAggregator:onConnectionStatusChanged:status=PENDING:deprecated method. Nothing done.
2022-09-02 00:00:11.360 [  5] 5 CapabilitiesDelegate:onConnectionStatusChanged:connectionStatus=PENDING
2022-09-02 00:00:11.360 [  5] 9 ThreadPool:obtainWorker:created=12,obtained=29,releasedToPool=25,releasedFromPool=0,outstanding=4
2022-09-02 00:00:11.360 [  5] 5 CertifiedSender:onConnectionStatusChanged
2022-09-02 00:00:11.025 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.361 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.362 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.360 [ 11] 9 TaskThread:startThread:moniker= 11,duration=298
2022-09-02 00:00:11.365 [ 11] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=PENDING,reason=ACL_CLIENT_REQUEST
2022-09-02 00:00:11.365 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.365 [  1] 3 GUIClient:run
2022-09-02 00:00:11.359 [  f] 9 TaskThread:startThread:moniker=  f,duration=289
2022-09-02 00:00:11.366 [  f] 0 DialogUXStateAggregator:onConnectionStatusChangedLambda:engineType=1,engineStatus=PENDING
2022-09-02 00:00:11.366 [  f] 0 DialogUXStateAggregator:onConnectionStatusChangedLambda:isConnected=false
2022-09-02 00:00:11.366 [  f] 0 DialogUXStateAggregator:onConnectionStatusChangedLambda::Setting state to idle
2022-09-02 00:00:11.366 [  f] 0 DialogUXStateAggregator:executeSetState:from=IDLE,to=IDLE,validTransition=false
2022-09-02 00:00:11.360 [  5] 5 ConditionVariableWrapper:notifyAll
2022-09-02 00:00:11.358 [ 20] I HTTP2Transport:handleAuthorizing:this=0x299dd0
2022-09-02 00:00:11.366 [ 1e] I WebSocketServer:onConnectionOpen:remoteHost=<IP_ADDRESS>:48310
2022-09-02 00:00:11.367 [ 1e] 3 GUIClient:onConnectionOpened
2022-09-02 00:00:11.367 [  5] 9 ThreadPool:obtainWorker:created=12,obtained=30,releasedToPool=25,releasedFromPool=0,outstanding=5
2022-09-02 00:00:11.368 [  2] 9 TaskThread:startThread:moniker=  2,duration=922
2022-09-02 00:00:11.367 [ 20] 5 CBLAuthDelegate:addAuthObserver:observer=0x299e18
2022-09-02 00:00:11.369 [ 20] I HTTP2Transport:onAuthStateChange:this=0x299dd0,newState=REFRESHED,error=SUCCESS
2022-09-02 00:00:11.369 [ 20] I HTTP2Transport:setStateLocked:this=0x299dd0,currentState=AUTHORIZING,newState=CONNECTING,changedReason=SUCCESS
2022-09-02 00:00:11.369 [ 20] 5 ConditionVariableWrapper:notifyAll
2022-09-02 00:00:11.369 [ 1e] 9 ThreadPool:obtainWorker:created=12,obtained=31,releasedToPool=25,releasedFromPool=0,outstanding=6
2022-09-02 00:00:11.701 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.702 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.702 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.702 [ 10] 9 TaskThread:startThread:moniker= 10,duration=334562
2022-09-02 00:00:11.703 [ 10] 5 GUIClient:onDoNotDisturbSettingChanged
2022-09-02 00:00:11.703 [ 21] 9 GUIClient:sendInitRequestAndWait::waiting for server to be ready
2022-09-02 00:00:11.703 [ 10] 9 WebSocketServer:writeMessageBegin
2022-09-02 00:00:11.369 [ 20] 9 ConditionVariableWrapper:waitForInner:duration=3599999999999888000
2022-09-02 00:00:11.703 [ 20] I HTTP2Transport:handleConnecting:this=0x299dd0
2022-09-02 00:00:11.704 [ 20] 9 DownchannelHandler:create:context=0x299e20
#################################################
Message Server Connection Opened.
#################################################
2022-09-02 00:00:11.704 [ 20] 5 ExchangeHandler:init:context=0x299e20
2022-09-02 00:00:11.704 [ 20] 9 DownchannelHandler:init:context=0x299e20
#######################################
ALEXA STATE: CONNECTING
#######################################
2022-09-02 00:00:11.704 [ 20] 9 PowerMonitor:getInstance
#######################################
ALEXA STATE: CONNECTING
#######################################
2022-09-02 00:00:11.705 [ 20] 9 PowerMonitor:createLocalPowerResource:identifier=DownchannelHandler
2022-09-02 00:00:11.705 [ 20] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:11.706 [ 20] 9 MimeResponseSink:init:handler=0xae012250
2022-09-02 00:00:11.706 [ 20] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2022-09-02 00:00:11.706 [ 20] 7 HTTP2Transport:createAndSendRequest:this=0x299dd0,type=GET
2022-09-02 00:00:11.708 [ 20] 9 DownchannelHandler:getRequestHeaderLines
2022-09-02 00:00:11.704 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:11.710 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:11.710 [ 10] 9 WebSocketServer:writeMessageComplete
2022-09-02 00:00:11.710 [ 10] 9 WebSocketServer:writeMessageBegin
2022-09-02 00:00:11.710 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:11.711 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.711 [ 20] 9 ConditionVariableWrapper:waitForInner:duration=3599999999658357000
2022-09-02 00:00:11.703 [ 21] 3 GUIClient:start::waiting for InitResponse
2022-09-02 00:00:11.711 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.711 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.711 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.712 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.711 [ 21] 9 GUIClient:sendInitRequestAndWait:errorState=0,initMessage received=0
2022-09-02 00:00:11.713 [ 1f] 9 LibcurlHTTP2Connection:insertActiveStream:this=0x2995d0,handle=0xae002908,streamId=AVSDownChannel-1
2022-09-02 00:00:11.714 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:11.715 [ 10] 9 WebSocketServer:writeMessageComplete
2022-09-02 00:00:11.715 [ 10] 9 WebSocketServer:writeMessageBegin
2022-09-02 00:00:11.716 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:11.716 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:11.716 [ 10] 9 WebSocketServer:writeMessageComplete
2022-09-02 00:00:11.717 [ 10] 9 WebSocketServer:writeMessageBegin
2022-09-02 00:00:11.717 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:11.717 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:11.717 [ 10] 9 WebSocketServer:writeMessageComplete
2022-09-02 00:00:11.720 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.721 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.721 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.721 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.722 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.722 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.723 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.728 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.728 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.728 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.728 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.729 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.729 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.729 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.062 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.062 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.062 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.062 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.062 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.063 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.063 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:11.729 [ 10] 9 GUIClient:onMessageInExector:payload={"type":"initResponse","isSupported":true}
2022-09-02 00:00:12.063 [ 21] 9 GUIClient:sendInitRequestAndWait:errorState=0,initMessage received=1
2022-09-02 00:00:12.063 [ 21] 3 GUIClient:start::InitResponse received
2022-09-02 00:00:12.063 [ 21] 9 AplClientBridge:onConnectionOpened
2022-09-02 00:00:12.063 [ 21] 9 ThreadPool:obtainWorker:created=12,obtained=32,releasedToPool=27,releasedFromPool=0,outstanding=5
2022-09-02 00:00:12.064 [ 16] 9 TaskThread:startThread:moniker= 16,duration=583
2022-09-02 00:00:12.064 [ 10] 9 GUIClient:executeSendGuiConfiguration
2022-09-02 00:00:12.066 [ 10] 3 GUIManager:handleLocaleChange:LocaleChanged=["en-US"]
2022-09-02 00:00:12.066 [ 10] 9 GUIClient:onMessageInExector:payload={"type":"logEvent","level":"info","component":"WSClient","message":"message sent, type: initResponse"}
2022-09-02 00:00:12.066 [ 10] 9 ThreadPool:obtainWorker:created=12,obtained=33,releasedToPool=27,releasedFromPool=0,outstanding=6
2022-09-02 00:00:12.067 [ 10] 9 WebSocketServer:writeMessageBegin
2022-09-02 00:00:12.067 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:12.067 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:12.067 [ 10] 9 WebSocketServer:writeMessageComplete
2022-09-02 00:00:12.067 [ 10] 9 WebSocketServer:writeMessageBegin
2022-09-02 00:00:12.067 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:12.067 [ 10] 9 WebSocket:AccessLog
2022-09-02 00:00:12.067 [ 10] 9 WebSocketServer:writeMessageComplete
2022-09-02 00:00:12.067 [ 14] 9 TaskThread:startThread:moniker= 14,duration=839
2022-09-02 00:00:12.068 [ 14] 3 GUILogBridge:GUILog:component=WSClient:message sent, type: initResponse
2022-09-02 00:00:12.068 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.068 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.068 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.068 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.068 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.068 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.072 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.072 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.072 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.072 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.072 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.072 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.072 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.072 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.073 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.073 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.073 [ 1e] 9 WebSocket:AccessLog
2022-09-02 00:00:12.076 [ 10] 9 GUIClient:onMessageInExector:payload={"type":"deviceWindowState","payload":{"defaultWindowId":"smartScreenLandscape","instances":[{"id":"smartScreenLandscape","templateId":"smartScreenLandscape","token":null,"configuration":{"interactionMode":"smart_screen","sizeConfigurationId":"fullscreen"}}]}}
2022-09-02 00:00:12.076 [ 10] 9 ThreadPool:obtainWorker:created=12,obtained=34,releasedToPool=27,releasedFromPool=0,outstanding=7
2022-09-02 00:00:12.077 [ 1d] 9 TaskThread:startThread:moniker= 1d,duration=209
2022-09-02 00:00:12.077 [ 1d] 9 ThreadPool:obtainWorker:created=12,obtained=35,releasedToPool=27,releasedFromPool=0,outstanding=8
2022-09-02 00:00:12.078 [ 1b] 9 TaskThread:startThread:moniker= 1b,duration=458
2022-09-02 00:00:12.078 [ 10] 9 GUIClient:onMessageInExector:payload={"type":"logEvent","level":"info","component":"WSClient","message":"message sent, type: deviceWindowState"}
2022-09-02 00:00:12.078 [ 14] 3 GUILogBridge:GUILog:component=WSClient:message sent, type: deviceWindowState
2022-09-02 00:00:12.933 [ 1f] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=13,userData=0xae002888
2022-09-02 00:00:12.934 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveResponseCode:responseCode=200
2022-09-02 00:00:12.934 [ 1f] 9 MimeResponseSink:onReceiveResponseCode:responseCode=200
2022-09-02 00:00:12.934 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:12.934 [ 1f] 5 DownchannelHandler:onReceiveResponseCode:responseCode=200
2022-09-02 00:00:12.934 [ 1f] I HTTP2Transport:onDownchannelConnected:this=0x299dd0
2022-09-02 00:00:12.935 [ 1f] I HTTP2Transport:setStateLocked:this=0x299dd0,currentState=CONNECTING,newState=POST_CONNECTING,changedReason=SUCCESS
2022-09-02 00:00:12.935 [ 1f] 5 ConditionVariableWrapper:notifyAll
2022-09-02 00:00:12.935 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=HTTP/2 200
2022-09-02 00:00:12.935 [ 1f] 9 MimeResponseSink:onReceiveHeaderLine:line=HTTP/2 200
2022-09-02 00:00:12.935 [ 20] I HTTP2Transport:handlePostConnecting:this=0x299dd0
2022-09-02 00:00:12.935 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:12.936 [ 1f] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=64,userData=0xae002888
2022-09-02 00:00:12.936 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-headers: authorization,x-amz-access-token
2022-09-02 00:00:12.936 [ 1f] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-headers: authorization,x-amz-access-token
2022-09-02 00:00:12.935 [ 20] 5 SynchronizeStateSenderFactory:createPostConnectOperation
2022-09-02 00:00:12.936 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:12.937 [ 1f] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=32,userData=0xae002888
2022-09-02 00:00:12.937 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=access-control-allow-origin: *
2022-09-02 00:00:12.937 [ 1f] 9 MimeResponseSink:onReceiveHeaderLine:line=access-control-allow-origin: *
2022-09-02 00:00:12.937 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:12.937 [ 1f] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=81,userData=0xae002888
2022-09-02 00:00:12.937 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=content-type: multipart/related; boundary=------abcde123; type=application/json
2022-09-02 00:00:12.938 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:boundary=------abcde123
2022-09-02 00:00:12.938 [ 1f] 9 MimeResponseSink:onReceiveHeaderLine:line=content-type: multipart/related; boundary=------abcde123; type=application/json
2022-09-02 00:00:12.938 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:12.938 [ 1f] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=20,userData=0xae002888
2022-09-02 00:00:12.938 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=x-amzn-requestid:
2022-09-02 00:00:12.938 [ 1f] 9 MimeResponseSink:onReceiveHeaderLine:line=x-amzn-requestid:
2022-09-02 00:00:12.938 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:12.939 [ 1f] 0 MimeResponseSink:receivedRequestId:value=x-amzn-requestid:
2022-09-02 00:00:12.939 [ 1f] 9 LibcurlHTTP2Request:headerCallback:id=AVSDownChannel-1,size=1,nmemb=2,userData=0xae002888
2022-09-02 00:00:12.939 [ 20] 5 PostConnectSynchronizeStateSender:create
2022-09-02 00:00:12.939 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveHeaderLine:line=
2022-09-02 00:00:12.939 [ 1f] 9 MimeResponseSink:onReceiveHeaderLine:line=
2022-09-02 00:00:12.939 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:12.939 [ 1f] 9 LibcurlHTTP2Request:writeCallback:id=AVSDownChannel-1,size=1,nmemb=18,userData=0xae002888
2022-09-02 00:00:12.939 [ 1f] 9 HTTP2MimeResponseDecoder:onReceiveData:size=18
2022-09-02 00:00:12.940 [ 20] 9 ConditionVariableWrapper:ConditionVariableWrapper:id=15
2022-09-02 00:00:12.940 [ 20] 5 AVSGatewayManager:createPostConnectOperation
2022-09-02 00:00:12.940 [ 20] 5 AVSGatewayManager:createPostConnectOperation::Gateway already verified, skipping gateway verification step
2022-09-02 00:00:12.940 [ 20] 5 CapabilitiesDelegate:createPostConnectOperation
2022-09-02 00:00:13.273 [ 20] 5 CapabilitiesDelegate:resetCurrentDiscoveryEventSender
2022-09-02 00:00:13.274 [ 20] 5 CapabilitiesDelegate:moveInFlightEndpointsToPendingLocked
2022-09-02 00:00:13.274 [ 20] 5 SQLiteCapabilitiesDelegateStorage:load
2022-09-02 00:00:13.275 [ 20] 5 CapabilitiesDelegate:createPostConnectOperation:num endpoints stored=1
2022-09-02 00:00:13.275 [ 20] 5 CapabilitiesDelegate:filterUnchangedPendingAddOrUpdateEndpointsLocked
2022-09-02 00:00:13.279 [ 20] 9 CapabilitiesDelegate:filterUnchangedPendingAddOrUpdateEndpointsLocked:step=endpoint not be included in addOrUpdateReport
2022-09-02 00:00:13.279 [ 20] 5 CapabilitiesDelegate:addStaleEndpointsToPendingDeleteLocked
2022-09-02 00:00:13.280 [ 20] 5 CapabilitiesDelegate:setCapabilitiesState:newCapabilitiesState=SUCCESS
2022-09-02 00:00:13.280 [ 20] 9 CapabilitiesDelegate:callingOnCapabilitiesStateChange:state=SUCCESS,error=SUCCESS
2022-09-02 00:00:13.280 [ 20] 9 ThreadPool:obtainWorker:created=12,obtained=36,releasedToPool=34,releasedFromPool=0,outstanding=2
2022-09-02 00:00:13.281 [ 1c] 9 TaskThread:startThread:moniker= 1c,duration=349
######################################################
Successfully registered 1 endpoint(s)!
######################################################
2022-09-02 00:00:13.281 [ 20] 5 EndpointRegistrationManager:onCapabilitiesStateChange:state=SUCCESS,error=SUCCESS,callback=true
2022-09-02 00:00:13.282 [ 20] 5 EndpointRegistrationManager:onCapabilityRegistrationStatusChanged
2022-09-02 00:00:13.282 [ 20] 9 ThreadPool:obtainWorker:created=12,obtained=37,releasedToPool=34,releasedFromPool=0,outstanding=3
2022-09-02 00:00:13.282 [ 12] 9 TaskThread:startThread:moniker= 12,duration=300
2022-09-02 00:00:13.283 [ 12] 9 EndpointRegistrationManager:updateAddedOrUpdatedEndpoints:result=success
2022-09-02 00:00:13.284 [ 20] 5 CapabilitiesDelegate:createPostConnectOperation::No change in Capabilities, skipping post connect step
2022-09-02 00:00:13.285 [ 20] 5 PostConnectSequencer:init
2022-09-02 00:00:13.285 [ 20] 9 PowerMonitor:getInstance
2022-09-02 00:00:13.285 [ 20] 9 PowerMonitor:createLocalPowerResource:identifier=PostConnectSequencer_mainLoop
2022-09-02 00:00:13.286 [ 20] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:13.286 [ 20] 5 PostConnectSequencer:doPostConnect
2022-09-02 00:00:13.286 [ 22] 5 PostConnectSequencer:mainLoop
2022-09-02 00:00:13.286 [ 22] 9 PowerMonitor:getInstance
2022-09-02 00:00:13.286 [ 20] 5 HTTP2Transport:sendMessagesAndPings:this=0x299dd0,whileState=POST_CONNECTING
2022-09-02 00:00:13.286 [ 20] 9 ConditionVariableWrapper:waitForInner:duration=299653056000
2022-09-02 00:00:13.286 [ 22] 9 PowerMonitor:assignThreadPowerResource:threadId=2651726864
2022-09-02 00:00:13.287 [ 22] 9 PowerMonitor:isActiveLocked:isActiveLocked=false
2022-09-02 00:00:13.287 [ 22] 5 PostConnectSynchronizeStateSender:performOperation
2022-09-02 00:00:13.287 [ 22] 5 PostConnectSynchronizeStateSender:fetchContext
2022-09-02 00:00:13.287 [ 22] 5 ContextManager:getContext
2022-09-02 00:00:13.288 [ 22] 5 ContextManager:getContextInternal
2022-09-02 00:00:13.288 [ 22] 9 ThreadPool:obtainWorker:created=12,obtained=38,releasedToPool=34,releasedFromPool=0,outstanding=4
2022-09-02 00:00:13.288 [  3] 9 TaskThread:startThread:moniker=  3,duration=218
2022-09-02 00:00:13.288 [ 22] 9 ConditionVariableWrapper:waitForInner:duration=2000000000
2022-09-02 00:00:13.288 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=39,releasedToPool=34,releasedFromPool=0,outstanding=5
2022-09-02 00:00:13.289 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=40,releasedToPool=34,releasedFromPool=0,outstanding=6
2022-09-02 00:00:13.290 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=41,releasedToPool=34,releasedFromPool=0,outstanding=7
2022-09-02 00:00:13.290 [  3] 9 SpeechSynthesizer:provideState:token=1
2022-09-02 00:00:13.290 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=42,releasedToPool=34,releasedFromPool=0,outstanding=8
2022-09-02 00:00:13.625 [  3] 5 VisualActivityTracker:provideState
2022-09-02 00:00:13.625 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=43,releasedToPool=34,releasedFromPool=0,outstanding=9
2022-09-02 00:00:13.626 [  2] 9 TaskThread:startThread:moniker=  2,duration=335946
2022-09-02 00:00:13.628 [  2] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=1,state=FINISHED
2022-09-02 00:00:13.628 [  2] 5 ContextManager:setState
2022-09-02 00:00:13.291 [ 11] 9 TaskThread:startThread:moniker= 11,duration=2121
2022-09-02 00:00:13.291 [  f] 9 TaskThread:startThread:moniker=  f,duration=1387
2022-09-02 00:00:13.629 [  f] 5 ContextManager:setState
2022-09-02 00:00:13.291 [  5] 9 TaskThread:startThread:moniker=  5,duration=608
2022-09-02 00:00:13.629 [  5] 3 AlexaPresentation:executeProvideState:token=1
2022-09-02 00:00:13.629 [  5] 5 ContextManager:setState
2022-09-02 00:00:13.630 [ 1d] 9 TaskThread:startThread:moniker= 1d,duration=4295
2022-09-02 00:00:13.630 [ 1d] 5 VisualActivityTracker:executeProvideState
2022-09-02 00:00:13.630 [ 1d] 5 ContextManager:setState
2022-09-02 00:00:13.631 [  3] 0 AudioPlayer:provideState:stateRequestToken=1
2022-09-02 00:00:13.631 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=44,releasedToPool=35,releasedFromPool=0,outstanding=9
2022-09-02 00:00:13.631 [ 1b] 9 TaskThread:startThread:moniker= 1b,duration=367
2022-09-02 00:00:13.632 [ 1b] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2022-09-02 00:00:13.632 [ 1b] E AudioPlayer:attachPlaybackAttributesIfAvailableFailed::playerMissing
2022-09-02 00:00:13.633 [ 1b] 5 ContextManager:setState
2022-09-02 00:00:13.634 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=45,releasedToPool=35,releasedFromPool=0,outstanding=10
2022-09-02 00:00:13.634 [ 10] 9 TaskThread:startThread:moniker= 10,duration=427
2022-09-02 00:00:13.635 [ 10] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2022-09-02 00:00:13.637 [ 10] 0 ExternalMediaPlayer:executeProvideState:provideSessionState={"agent":"","spiVersion":"1.0","playerInFocus":"","players":[]}
2022-09-02 00:00:13.637 [ 10] 5 ContextManager:setState
2022-09-02 00:00:13.638 [  3] 5 AudioActivityTracker:provideState
2022-09-02 00:00:13.638 [  3] 9 ThreadPool:obtainWorker:created=12,obtained=46,releasedToPool=35,releasedFromPool=0,outstanding=11
2022-09-02 00:00:13.638 [ 14] 9 TaskThread:startThread:moniker= 14,duration=339
2022-09-02 00:00:13.639 [ 14] 5 AudioActivityTracker:executeProvideState
2022-09-02 00:00:13.639 [ 14] 5 ContextManager:setState
2022-09-02 00:00:13.639 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=8
2022-09-02 00:00:13.641 [ 10] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=1
2022-09-02 00:00:13.642 [ 10] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers
2022-09-02 00:00:13.642 [ 10] 0 ExternalMediaPlayer:executeProvideState:providePlaybackState={"state":"IDLE","supportedOperations":[],"shuffle":"NOT_SHUFFLED","repeat":"NOT_REPEATED","favorite":"NOT_RATED","positionMilliseconds":0,"players":[]}
2022-09-02 00:00:13.642 [ 10] 5 ContextManager:setState
2022-09-02 00:00:13.643 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:13.644 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.644 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.644 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.644 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.644 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.644 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.645 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.645 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.645 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.645 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.977 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.977 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=7
2022-09-02 00:00:13.977 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:13.978 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.978 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.978 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.978 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.978 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.978 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.979 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.979 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.979 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.979 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.979 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.979 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=6
2022-09-02 00:00:13.979 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:13.980 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.980 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.980 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.980 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.980 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.980 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.980 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.981 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.981 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.981 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.981 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.981 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=5
2022-09-02 00:00:13.981 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:13.981 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.982 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.983 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.983 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=4
2022-09-02 00:00:13.983 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:13.984 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.984 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.984 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.984 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.984 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:13.984 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.316 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.316 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.316 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.317 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.317 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.317 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=3
2022-09-02 00:00:14.317 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:14.319 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.319 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.319 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.319 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.320 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.320 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.320 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.320 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.320 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.321 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.321 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.321 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=2
2022-09-02 00:00:14.322 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:14.323 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.324 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.324 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.324 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.324 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.325 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.325 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.325 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.325 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.325 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.327 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.327 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=1
2022-09-02 00:00:14.328 [  3] I ContextManager:updateCapabilityState
2022-09-02 00:00:14.328 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.328 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.328 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.328 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.329 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.329 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.329 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.329 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.329 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.330 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.330 [  3] 5 ContextManager:updateCapabilityStateDetailed
2022-09-02 00:00:14.330 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:token=1
2022-09-02 00:00:14.331 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked
2022-09-02 00:00:14.333 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:skipping state for legacy capabilityIdentifier={endpointId:,namespace:Alexa.Presentation.APL,name:RenderedDocumentState}
2022-09-02 00:00:14.333 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked
2022-09-02 00:00:14.666 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked
2022-09-02 00:00:14.666 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:skipping state for legacy capabilityIdentifier={endpointId:,namespace:VisualActivityTracker,name:ActivityState}
2022-09-02 00:00:14.666 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked
2022-09-02 00:00:14.667 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked
2022-09-02 00:00:14.667 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked
2022-09-02 00:00:14.667 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:skipping state for legacy capabilityIdentifier={endpointId:,namespace:AudioActivityTracker,name:ActivityState}
2022-09-02 00:00:14.667 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked
2022-09-02 00:00:14.667 [  3] 5 ContextManager:getContextAvailableCallbackIfReadyLocked
2022-09-02 00:00:14.673 [  3] 5 AVSContext:toJson
2022-09-02 00:00:14.673 [  3] 5 PostConnectSynchronizeStateSender:onContextAvailable
2022-09-02 00:00:14.674 [  3] 5 ConditionVariableWrapper:notifyAll
2022-09-02 00:00:14.680 [ 22] I UUIDGeneration:low entropy on call to generate UUID:current entropy=0
2022-09-02 00:00:14.681 [ 22] 0 EventBuilder:buildJsonEventString:messageId=0e995b00-300e-4b12-84d3-199dd9e142c4,namespace=System,name=SynchronizeState
2022-09-02 00:00:14.682 [ 22] 0 EventBuilder:buildJsonEventString:event={"context":{"properties":[{"namespace":"Alerts","name":"AlertsState","value":{"allAlerts":[],"activeAlerts":[]},"timeOfSample":"2022-09-02T00:00:07.386Z","uncertaintyInMilliseconds":0},{"namespace":"Alexa.Display.Window","name":"WindowState","value":{"defaultWindowId":"smartScreenLandscape","instances":[{"id":"smartScreenLandscape","templateId":"smartScreenLandscape","token":null,"configuration":{"interactionMode":"smart_screen","sizeConfigurationId":"fullscreen"}}]},"timeOfSample":"2022-09-02T00:00:13.977Z","uncertaintyInMilliseconds":0},{"namespace":"Alexa.PlaybackStateReporter","name":"playbackState","value":{"state":"IDLE","supportedOperations":[],"shuffle":"NOT_SHUFFLED","repeat":"NOT_REPEATED","favorite":"NOT_RATED","positionMilliseconds":0,"players":[]},"timeOfSample":"2022-09-02T00:00:14.322Z","uncertaintyInMilliseconds":0},{"namespace":"AudioPlayer","name":"PlaybackState","value":{"token":"","offsetInMilliseconds":0,"playerActivity":"IDLE"},"timeOfSample":"2022-09-02T00:00:13.983Z","uncertaintyInMilliseconds":0},{"namespace":"ExternalMediaPlayer","name":"ExternalMediaPlayerState","value":{"agent":"","spiVersion":"1.0","playerInFocus":"","players":[]},"timeOfSample":"2022-09-02T00:00:14.318Z","uncertaintyInMilliseconds":0},{"namespace":"Notifications","name":"IndicatorState","value":{"isEnabled":false,"isVisualIndicatorPersisted":false},"timeOfSample":"2022-09-02T00:00:08.854Z","uncertaintyInMilliseconds":0},{"namespace":"Speaker","name":"VolumeState","value":{"volume":100,"muted":false},"timeOfSample":"2022-09-02T00:00:07.751Z","uncertaintyInMilliseconds":0},{"namespace":"SpeechSynthesizer","name":"SpeechState","value":{"token":"","offsetInMilliseconds":0,"playerActivity":"FINISHED"},"timeOfSample":"2022-09-02T00:00:13.643Z","uncertaintyInMilliseconds":0}]},"event":{"header":{"namespace":"System","name":"SynchronizeState","messageId":"0e995b00-300e-4b12-84d3-199dd9e142c4"},"payload":{}}}
2022-09-02 00:00:14.683 [ 22] 7 HTTP2Transport:sendMessage:this=0x299dd0
2022-09-02 00:00:14.683 [ 22] 5 ConditionVariableWrapper:notifyAll
2022-09-02 00:00:14.683 [ 20] 7 MessageRequestHandler:create:context=0x299e20,messageRequest=0xafe03370
2022-09-02 00:00:14.684 [ 20] 5 ExchangeHandler:init:context=0x299e20
2022-09-02 00:00:14.684 [ 20] 7 MessageRequestHandler:init:context=0x299e20,messageRequest=0xafe03370
2022-09-02 00:00:14.685 [ 20] 9 HTTP2MimeRequestEncoder:HTTP2MimeRequestEncoder:boundary=WhooHooZeerOoonie=,source=0xae00237c
2022-09-02 00:00:15.018 [ 20] 9 MimeResponseSink:init:handler=0xae002380
2022-09-02 00:00:15.018 [ 20] 9 HTTP2MimeResponseDecoder:HTTP2MimeResponseDecoder
2022-09-02 00:00:15.018 [ 20] 7 HTTP2Transport:onMessageRequestSent:this=0x299dd0,countOfUnfinishedMessageHandlers=1
2022-09-02 00:00:15.019 [ 20] 7 HTTP2Transport:createAndSendRequest:this=0x299dd0,type=POST
2022-09-02 00:00:15.020 [ 20] 9 HTTP2MimeRequestEncoder:getRequestHeaderLines
2022-09-02 00:00:15.020 [ 20] 9 MessageRequestHandler:getRequestHeaderLines
2022-09-02 00:00:15.020 [ 20] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:15.020 [ 20] 0 MessageRequestHandler:EventSent
2022-09-02 00:00:15.021 [ 20] 9 ConditionVariableWrapper:waitForInner:duration=299999599000
2022-09-02 00:00:15.050 [ 1f] 9 LibcurlHTTP2Connection:insertActiveStream:this=0x2995d0,handle=0xae013f58,streamId=AVSEvent-3
2022-09-02 00:00:15.052 [ 1f] 9 LibcurlHTTP2Request:readCallback:id=AVSEvent-3,size=1,nmemb=65536,userData=0xae00da40
2022-09-02 00:00:15.053 [ 1f] 9 HTTP2MimeRequestEncoder:onSendData:size=65536,state=NEW
2022-09-02 00:00:15.054 [ 1f] 9 HTTP2MimeRequestEncoder:setState:state=NEW,newState=GETTING_1ST_PART_HEADERS
2022-09-02 00:00:15.054 [ 1f] 9 MessageRequestHandler:getMimePartHeaderLines
2022-09-02 00:00:15.055 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:15.056 [ 1f] 9 HTTP2MimeRequestEncoder:setState:state=GETTING_1ST_PART_HEADERS,newState=SENDING_1ST_BOUNDARY
2022-09-02 00:00:15.056 [ 1f] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_1ST_BOUNDARY,newState=SENDING_PART_HEADERS
2022-09-02 00:00:15.056 [ 1f] 9 HTTP2MimeRequestEncoder:setState:state=SENDING_PART_HEADERS,newState=SENDING_PART_DATA
2022-09-02 00:00:15.056 [ 1f] 9 MessageRequestHandler:onSendMimePartData:size=65429
2022-09-02 00:00:15.056 [ 1f] 9 HTTP2Transport:onActivity:this=0x299dd0
2022-09-02 00:00:15.057 [ 1f] 9 MessageRequestHandler:onSendMimePartData:size=63500