search

alexa / avs-device-sdk

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

Some microphone/call profile is being added by Bluetooth #1662

Closed brett-lynnes closed 4 years ago

brett-lynnes commented 4 years ago

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

Briefly summarize your issue:

If you say "Alexa connect bluetooth" it will connect A2DP and AVCRP to my Samsung S10+ (also happens on S6) and has some profile enabled which thinks the phone is a source for recorded ("call") audio which switches the microphone input from the Linux machine where the SDK is running to my Android phone (which isnt listening/forwarding call audio to the SDK). Saying the wakeword will no longer trigger the SDK (since it is listening on the wrong source microphone now) until I manually disconnect the "call" profile in my Android phone's Bluetooth settings. Further, it seems to stop the Bluetooth Sink and media players from functioning correctly as it stops mid-speech telling me it is connected (and refuses to play audio until the "Call" has been disabled).

What is the expected behavior?

Reconnecting Bluetooth after the initial pairing should not use 00001108-0000-1000-8000-00805f9b34fb call audio profile.

What behavior are you observing?

In PairingAgent.cpp authorizeService is getting a request to pair with 00001108-0000-1000-8000-00805f9b34fb profile during inital Pairing, i reject that... however subsequent pairings don't always call authorizeService (after pairing) which causes the profile to get used and the bad Bluetooth behavior is observed.

Provide the steps to reproduce the issue, if applicable:

Connect a Samsung S6 or S10 device to the SDK running on a Linux machine and notice the "Call" profile is enabled in the Android System Settings.

Tell us about your environment:

What version of the AVS Device SDK are you using?

  <18.0.0>

Tell us what hardware you're using:

Tell us about your OS (Type & version):

kclchan commented 4 years ago

Hi @brett-lynnes, could you attach the full DEBUG9 logs? Thanks!

caleighatamazon commented 4 years ago

I'm going to close this issue due to inactivity, but please comment on this or open a new issue if you're continuing to have problems.

brett-lynnes commented 4 years ago

I'm still debugging this from my side. the DEBUG9 logs don't have anything useful since it is on the BlueZ side of things when AVS creates an agent and registers profiles. I will post here again when I have the exact profile and where/why it is being opened.

brett-lynnes commented 3 years ago

here are the DEBUG9 logs, although i don't know if you are going to get more information than just actually reproducing this bug with an android phone.

I 15:36:07.1772 Creating Alexa Service I 15:36:07.1858 2021-06-28 22:36:07.185 [ 1] 5 CustomerDataManager:createCustomerDataManagerInteface I 15:36:07.1862 2021-06-28 22:36:07.186 [ 1] 5 AVSGatewayManager:create I 15:36:07.1862 2021-06-28 22:36:07.186 [ 1] 5 AVSGatewayManager:create:default AVS Gateway from config=https\://alexa.na.gateway.devices.a2z.com I 15:36:07.1867 2021-06-28 22:36:07.186 [ 1] 5 AVSGatewayManager:init:avsGateway=https\://alexa.na.gateway.devices.a2z.com D 15:36:07.1882 void alexaClientSDK::authorization::appAuthDelegate::AppAuthDelegate::handleAuthorizationFlow() (/home/lynnes/workspace/doppler/src/AVS/AppAuthDelegate/AppAuthDelegate.cpp:550) Moving from LWA flowstate: 0 to 3 I 15:36:07.1892 2021-06-28 22:36:07.189 [ 1] 5 DefaultEndpointBuilder:createDefaultEndpointBuilderInterface I 15:36:07.1894 2021-06-28 22:36:07.189 [ 1] 5 EndpointBuilder:finalizeAttributes I 15:36:07.1895 2021-06-28 22:36:07.189 [ 1] 5 DefaultEndpointBuilder:createDefaultEndpointCapabilitiesRegistrarInterface I 15:36:07.1896 2021-06-28 22:36:07.189 [ 1] 5 AlexaInterfaceCapabilityAgent:createDefaultAlexaInterfaceCapabilityAgent I 15:36:07.1897 2021-06-28 22:36:07.189 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.1899 2021-06-28 22:36:07.189 [ 1] 5 DirectiveSequencer:createDirectiveSequencerInterface I 15:36:07.1905 2021-06-28 22:36:07.190 [ 2] 9 DirectiveProcessor:processingLoop I 15:36:07.1905 2021-06-28 22:36:07.190 [ 1] 5 SynchronizeStateSenderFactory:createPostConnectOperationProviderInterface I 15:36:07.1906 2021-06-28 22:36:07.190 [ 1] 5 SQLiteCapabilitiesDelegateStorage:create I 15:36:07.1909 2021-06-28 22:36:07.190 [ 1] 5 SQLiteCapabilitiesDelegateStorage:open I 15:36:07.1914 2021-06-28 22:36:07.191 [ 1] 5 ContextManager:addStateProvider I 15:36:07.1916 2021-06-28 22:36:07.191 [ 1] 5 DefaultEndpointBuilder:withCapabilityConfiguration I 15:36:07.1923 2021-06-28 22:36:07.192 [ 1] 5 CaptionsComponent:createCaptionManagerInterface::captions disabled I 15:36:07.1926 2021-06-28 22:36:07.192 [ 1] 5 SQLiteDeviceSettingStorage:create I 15:36:07.1927 2021-06-28 22:36:07.192 [ 1] 5 SQLiteDeviceSettingStorage:open I 15:36:07.1928 2021-06-28 22:36:07.192 [ 1] 5 DoNotDisturbCapabilityAgent:createDoNotDisturbCapabilityAgent I 15:36:07.1929 2021-06-28 22:36:07.192 [ 1] 5 DNDSettingProtocol:create:settingName=enabled I 15:36:07.1931 2021-06-28 22:36:07.193 [ 1] 5 DNDSettingProtocol:restoreValue:setting=Alexa.DoNotDisturb\:\:enabled I 15:36:07.1931 2021-06-28 22:36:07.193 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=Alexa.DoNotDisturb\:\:enabled I 15:36:07.1931 2021-06-28 22:36:07.193 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:07.1933 2021-06-28 22:36:07.193 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.1938 2021-06-28 22:36:07.193 [ 1] 5 SharedAVSSettingProtocol:create:settingName=alarmVolumeRamp I 15:36:07.1940 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:restoreValue:setting=Alerts\:\:alarmVolumeRamp I 15:36:07.1940 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=Alerts\:\:alarmVolumeRamp I 15:36:07.1941 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:07.1942 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:create:settingName=wakeWordConfirmation I 15:36:07.1942 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:restoreValue:setting=SpeechRecognizer\:\:wakeWordConfirmation I 15:36:07.1942 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer\:\:wakeWordConfirmation I 15:36:07.1943 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:07.1944 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:create:settingName=speechConfirmation I 15:36:07.1944 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:restoreValue:setting=SpeechRecognizer\:\:speechConfirmation I 15:36:07.1944 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer\:\:speechConfirmation I 15:36:07.1945 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:07.1945 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:create:settingName=timeZone I 15:36:07.1946 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:restoreValue:setting=System\:\:timeZone I 15:36:07.1946 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=System\:\:timeZone I 15:36:07.1946 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:07.1947 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:create:settingName=networkInfo I 15:36:07.1948 2021-06-28 22:36:07.194 [ 1] 5 SharedAVSSettingProtocol:restoreValue:setting=System\:\:networkInfo I 15:36:07.1948 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=System\:\:networkInfo I 15:36:07.1949 2021-06-28 22:36:07.194 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:07.1950 2021-06-28 22:36:07.195 [ 1] 5 LocaleWakeWordsSetting:create:settingName=LocaleWakeWords I 15:36:07.1951 2021-06-28 22:36:07.195 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=System.locales I 15:36:07.1951 2021-06-28 22:36:07.195 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:07.1952 2021-06-28 22:36:07.195 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer.wakeWords I 15:36:07.1952 2021-06-28 22:36:07.195 [ 1] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:07.1953 2021-06-28 22:36:07.195 [ 1] 2 LocaleWakeWordsSetting:restoreInitialValue:wakeWords=["ALEXA"],locale=["en-US"] I 15:36:07.1959 2021-06-28 22:36:07.195 [ 1] 9 SQLiteMessageStorage:isDatabaseLegacy:reason=databaseNotLegacy I 15:36:07.1961 2021-06-28 22:36:07.196 [ 1] 5 CertifiedSender:onConnectionStatusChanged I 15:36:07.1962 2021-06-28 22:36:07.196 [ 4] 9 CertifiedSender:mainloop:reason=waitingForMessage I 15:36:07.1965 2021-06-28 22:36:07.196 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.1969 2021-06-28 22:36:07.196 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating Equalizer configuration I 15:36:07.1969 2021-06-28 22:36:07.196 [ 1] 1 InMemoryEqualizerConfiguration:validateConfiguration::Validating default Equalizer state I 15:36:07.1970 2021-06-28 22:36:07.197 [ 1] E SDKConfigEqualizerConfiguration:createFailed:reason=Unsupported mode is set as default state mode,mode=NONE I 15:36:07.1972 2021-06-28 22:36:07.197 [ 1] 5 GstreamerApplicationAudioPipelineFactory:createApplicationAudioPipelineFactoryInterface I 15:36:07.1973 2021-06-28 22:36:07.197 [ 1] 9 MediaPlayer:createCalled:name=AlertsMediaPlayer I 15:36:07.2083 2021-06-28 22:36:07.208 [ 1] I MediaPlayer:outputConversion:name=AlertsMediaPlayer,string=audio/x-raw\, format\=(string)S16LE I 15:36:07.2090 2021-06-28 22:36:07.209 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2091 2021-06-28 22:36:07.209 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AlertsMediaPlayer I 15:36:07.2092 2021-06-28 22:36:07.209 [ 5] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AlertsMediaPlayer I 15:36:07.2096 2021-06-28 22:36:07.209 [ 1] 5 SpeakerManager:executeInitializeSpeakerSettings:type=AVS_ALERTS_VOLUME I 15:36:07.2096 2021-06-28 22:36:07.209 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2096 2021-06-28 22:36:07.209 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AlertsMediaPlayer I 15:36:07.2097 2021-06-28 22:36:07.209 [ 5] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AlertsMediaPlayer I 15:36:07.2098 2021-06-28 22:36:07.209 [ 1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_ALERTS_VOLUME,sizeOfSpeakerSet=1 I 15:36:07.2099 2021-06-28 22:36:07.209 [ 1] E EqualizerRuntimeSetup:addEqualizerFailed::Equalizer not enabled I 15:36:07.2100 2021-06-28 22:36:07.210 [ 1] 5 Renderer:resetSourceId I 15:36:07.2100 2021-06-28 22:36:07.210 [ 1] 9 MediaPlayer:addObserverCalled:name=AlertsMediaPlayer I 15:36:07.2101 2021-06-28 22:36:07.210 [ 5] 0 MediaPlayer:handleAddObserverCalled:name=AlertsMediaPlayer I 15:36:07.2108 2021-06-28 22:36:07.210 [ 1] 5 AlertScheduler:setTimerForNextAlertLocked I 15:36:07.2108 2021-06-28 22:36:07.210 [ 1] 8 AlertScheduler:executeScheduleNextAlertForRendering::no work to do. I 15:36:07.2109 2021-06-28 22:36:07.210 [ 1] 9 SpeakerManager:getSpeakerSettingsCalled I 15:36:07.2111 2021-06-28 22:36:07.211 [ 6] 9 SpeakerManager:executeGetSpeakerSettingsCalled I 15:36:07.2113 2021-06-28 22:36:07.211 [ 1] 5 ContextManager:setState I 15:36:07.2116 2021-06-28 22:36:07.211 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled I 15:36:07.2116 2021-06-28 22:36:07.211 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x343a260 I 15:36:07.2117 2021-06-28 22:36:07.211 [ 8] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST I 15:36:07.2117 2021-06-28 22:36:07.211 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2121 2021-06-28 22:36:07.212 [ 1] 5 DefaultEndpointBuilder:withCapabilityConfiguration I 15:36:07.2121 2021-06-28 22:36:07.212 [ 1] 5 PlaybackRouter:createPlaybackRouterInterface I 15:36:07.2122 2021-06-28 22:36:07.212 [ 1] 9 PlaybackRouter:create::called I 15:36:07.2124 2021-06-28 22:36:07.212 [ 1] 9 MediaPlayer:createCalled:name=AudioMediaPlayer I 15:36:07.2125 2021-06-28 22:36:07.212 [ 1] I MediaPlayer:outputConversion:name=AudioMediaPlayer,string=audio/x-raw\, format\=(string)S16LE I 15:36:07.2130 2021-06-28 22:36:07.212 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2130 2021-06-28 22:36:07.213 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AudioMediaPlayer I 15:36:07.2131 2021-06-28 22:36:07.213 [ 9] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AudioMediaPlayer I 15:36:07.2132 2021-06-28 22:36:07.213 [ 1] 5 SpeakerManager:executeInitializeSpeakerSettings:type=AVS_SPEAKER_VOLUME I 15:36:07.2132 2021-06-28 22:36:07.213 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2133 2021-06-28 22:36:07.213 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=AudioMediaPlayer I 15:36:07.2133 2021-06-28 22:36:07.213 [ 9] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=AudioMediaPlayer I 15:36:07.2134 2021-06-28 22:36:07.213 [ 1] 9 SpeakerManager:executeGetSpeakerSettingsCalled I 15:36:07.2134 2021-06-28 22:36:07.213 [ 1] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SPEAKER_VOLUME I 15:36:07.2134 2021-06-28 22:36:07.213 [ 1] 5 ContextManager:setState I 15:36:07.2135 2021-06-28 22:36:07.213 [ 1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=1 I 15:36:07.2135 2021-06-28 22:36:07.213 [ 1] E EqualizerRuntimeSetup:addEqualizerFailed::Equalizer not enabled I 15:36:07.2142 2021-06-28 22:36:07.214 [ 1] 5 ContextManager:addStateProvider I 15:36:07.2144 2021-06-28 22:36:07.214 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2148 2021-06-28 22:36:07.214 [ 1] 5 BluetoothMediaInputTransformer:create I 15:36:07.2148 2021-06-28 22:36:07.214 [ 1] 5 BluetoothMediaInputTransformer:init I 15:36:07.2152 2021-06-28 22:36:07.215 [ 1] 5 PulseAudioBluetoothInitializer:create I 15:36:07.2153 2021-06-28 22:36:07.215 [ 1] 5 PulseAudioBluetoothInitializer:init I 15:36:07.2154 2021-06-28 22:36:07.215 [ 1] 5 BlueZDeviceManager:create I 15:36:07.2155 2021-06-28 22:36:07.215 [ 1] 5 BlueZDeviceManager:init I 15:36:07.2155 2021-06-28 22:36:07.215 [ 1] 5 BlueZDeviceManager:Creating connection... I 15:36:07.2156 2021-06-28 22:36:07.215 [ 1] 5 BlueZDeviceManager:Creating ObjectManagerProxy... I 15:36:07.2164 2021-06-28 22:36:07.216 [ 1] 5 BlueZDeviceManager:Retrieving BlueZ state... I 15:36:07.2170 2021-06-28 22:36:07.217 [ 1] 3 BlueZDeviceManager:Found bluetooth adapter:Path=/org/bluez/hci0 I 15:36:07.2171 2021-06-28 22:36:07.217 [ 1] 5 BlueZBluetoothDevice:create I 15:36:07.2172 2021-06-28 22:36:07.217 [ 1] 5 BlueZBluetoothDevice:init:path=/org/bluez/hci0/dev_44_F2_1B_CB_A1_5D I 15:36:07.2183 2021-06-28 22:36:07.218 [ 1] 5 BlueZBluetoothDevice:updateFriendlyName I 15:36:07.2183 2021-06-28 22:36:07.218 [ 1] 9 DBusPropertiesProxy:getStringProperty:object=/org/bluez/hci0/dev_44_F2_1B_CB_A1_5D,interface=org.bluez.Device1,property=Alias I 15:36:07.2185 2021-06-28 22:36:07.218 [ 1] 5 BlueZBluetoothDevice:queryDeviceProperty:name=Paired I 15:36:07.2188 2021-06-28 22:36:07.218 [ 1] 5 BlueZBluetoothDevice:init::deviceIsPaired I 15:36:07.2188 2021-06-28 22:36:07.218 [ 1] 5 BlueZBluetoothDevice:transitionToState:oldState=FOUND,newState=IDLE,sendEvent=true I 15:36:07.2189 2021-06-28 22:36:07.218 [ 1] 5 BlueZBluetoothDevice:getServiceUuids I 15:36:07.2189 2021-06-28 22:36:07.218 [ 1] 5 DBusPropertiesProxy:getVariantProperty I 15:36:07.2192 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:getServiceUuids I 15:36:07.2192 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00000000-deca-fade-deca-deafdecacafe I 15:36:07.2192 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001000-0000-1000-8000-00805f9b34fb I 15:36:07.2193 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:07.2193 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000110c-0000-1000-8000-00805f9b34fb I 15:36:07.2193 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000110d-0000-1000-8000-00805f9b34fb I 15:36:07.2193 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000110e-0000-1000-8000-00805f9b34fb I 15:36:07.2193 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001116-0000-1000-8000-00805f9b34fb I 15:36:07.2193 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000111f-0000-1000-8000-00805f9b34fb I 15:36:07.2194 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000112f-0000-1000-8000-00805f9b34fb I 15:36:07.2194 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001132-0000-1000-8000-00805f9b34fb I 15:36:07.2194 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001200-0000-1000-8000-00805f9b34fb I 15:36:07.2194 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001801-0000-1000-8000-00805f9b34fb I 15:36:07.2194 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:operator():uuid=02030302-1d19-415f-86f2-22a2106a0a77 I 15:36:07.2194 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:initializeServices I 15:36:07.2195 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=02030302-1d19-415f-86f2-22a2106a0a77 I 15:36:07.2195 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001801-0000-1000-8000-00805f9b34fb I 15:36:07.2195 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001132-0000-1000-8000-00805f9b34fb I 15:36:07.2195 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000112f-0000-1000-8000-00805f9b34fb I 15:36:07.2195 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001116-0000-1000-8000-00805f9b34fb I 15:36:07.2195 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001000-0000-1000-8000-00805f9b34fb I 15:36:07.2196 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00000000-deca-fade-deca-deafdecacafe I 15:36:07.2196 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000110a-0000-1000-8000-00805f9b34fb I 15:36:07.2196 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:initializeServices:supports=AudioSource I 15:36:07.2197 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:insertService I 15:36:07.2197 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:insertService:serviceUuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:07.2198 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000111f-0000-1000-8000-00805f9b34fb I 15:36:07.2198 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000110d-0000-1000-8000-00805f9b34fb I 15:36:07.2199 2021-06-28 22:36:07.219 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000110c-0000-1000-8000-00805f9b34fb I 15:36:07.2199 2021-06-28 22:36:07.219 [ 1] 5 BlueZBluetoothDevice:initializeServices:supports=A/V_RemoteControlTarget I 15:36:07.2204 2021-06-28 22:36:07.220 [ 1] 5 BlueZAVRCPTarget:create I 15:36:07.2205 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:insertService I 15:36:07.2205 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:insertService:serviceUuid=0000110c-0000-1000-8000-00805f9b34fb I 15:36:07.2205 2021-06-28 22:36:07.220 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001200-0000-1000-8000-00805f9b34fb I 15:36:07.2205 2021-06-28 22:36:07.220 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000110e-0000-1000-8000-00805f9b34fb I 15:36:07.2206 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:initializeService:supports=A/V_RemoteControl I 15:36:07.2206 2021-06-28 22:36:07.220 [ 1] 5 BlueZAVRCPController:create I 15:36:07.2207 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:insertService I 15:36:07.2207 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:insertService:serviceUuid=0000110e-0000-1000-8000-00805f9b34fb I 15:36:07.2207 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:executeIsConnectedToRelevantServices I 15:36:07.2207 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:getService:uuid=0000110b-0000-1000-8000-00805f9b34fb I 15:36:07.2208 2021-06-28 22:36:07.220 [ 1] 0 BlueZBluetoothDevice:getService:reason=serviceNotFound I 15:36:07.2208 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:getService:uuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:07.2208 2021-06-28 22:36:07.220 [ 1] 5 BlueZBluetoothDevice:queryDeviceProperty:name=Paired I 15:36:07.2211 2021-06-28 22:36:07.221 [ 1] 5 BlueZBluetoothDevice:queryDeviceProperty:name=Connected I 15:36:07.2213 2021-06-28 22:36:07.221 [ 1] 5 DBusPropertiesProxy:getVariantProperty I 15:36:07.2216 2021-06-28 22:36:07.221 [ 1] 5 BlueZBluetoothDevice:init:ClassOfDevice=7995916 I 15:36:07.2216 2021-06-28 22:36:07.221 [ 1] 7 BlueZDeviceManager:addDevice I 15:36:07.2217 2021-06-28 22:36:07.221 [ 1] 5 BlueZBluetoothDevice:getMac I 15:36:07.2217 2021-06-28 22:36:07.221 [ 1] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:07.2217 2021-06-28 22:36:07.221 [ 1] 7 BlueZDeviceManager:Device added:path=/org/bluez/hci0/dev_44_F2_1B_CB_A1_5D,mac=44\:F2\:1B\:CB\:A1\:5D,alias=iPhone I 15:36:07.2218 2021-06-28 22:36:07.221 [ 1] 5 BlueZBluetoothDevice:create I 15:36:07.2218 2021-06-28 22:36:07.221 [ 1] 5 BlueZBluetoothDevice:init:path=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4 I 15:36:07.2229 2021-06-28 22:36:07.222 [ 1] 5 BlueZBluetoothDevice:updateFriendlyName I 15:36:07.2230 2021-06-28 22:36:07.223 [ 1] 9 DBusPropertiesProxy:getStringProperty:object=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4,interface=org.bluez.Device1,property=Alias I 15:36:07.2232 2021-06-28 22:36:07.223 [ 1] 5 BlueZBluetoothDevice:queryDeviceProperty:name=Paired I 15:36:07.2235 2021-06-28 22:36:07.223 [ 1] 5 BlueZBluetoothDevice:init::deviceIsPaired I 15:36:07.2235 2021-06-28 22:36:07.223 [ 1] 5 BlueZBluetoothDevice:transitionToState:oldState=FOUND,newState=IDLE,sendEvent=true I 15:36:07.2236 2021-06-28 22:36:07.223 [ 1] 5 BlueZBluetoothDevice:getServiceUuids I 15:36:07.2236 2021-06-28 22:36:07.223 [ 1] 5 DBusPropertiesProxy:getVariantProperty I 15:36:07.2239 2021-06-28 22:36:07.223 [ 1] 5 BlueZBluetoothDevice:getServiceUuids I 15:36:07.2239 2021-06-28 22:36:07.223 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001105-0000-1000-8000-00805f9b34fb I 15:36:07.2239 2021-06-28 22:36:07.223 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001108-0000-1000-8000-00805f9b34fb I 15:36:07.2240 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:07.2240 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000110c-0000-1000-8000-00805f9b34fb I 15:36:07.2240 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000110d-0000-1000-8000-00805f9b34fb I 15:36:07.2241 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000110e-0000-1000-8000-00805f9b34fb I 15:36:07.2241 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001112-0000-1000-8000-00805f9b34fb I 15:36:07.2241 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001115-0000-1000-8000-00805f9b34fb I 15:36:07.2241 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001116-0000-1000-8000-00805f9b34fb I 15:36:07.2242 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000111f-0000-1000-8000-00805f9b34fb I 15:36:07.2242 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=0000112f-0000-1000-8000-00805f9b34fb I 15:36:07.2242 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001132-0000-1000-8000-00805f9b34fb I 15:36:07.2242 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001200-0000-1000-8000-00805f9b34fb I 15:36:07.2243 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001800-0000-1000-8000-00805f9b34fb I 15:36:07.2243 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=00001801-0000-1000-8000-00805f9b34fb I 15:36:07.2243 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=16bcfd00-253f-c348-e831-0db3e334d580 I 15:36:07.2243 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=594a34fc-31db-11ea-978f-2e728ce88125 I 15:36:07.2244 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=86130247-e942-4fe5-aa46-e30768a0c1b0 I 15:36:07.2244 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=a23d00bc-217c-123b-9c00-fc44577136ee I 15:36:07.2244 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:operator():uuid=abbafc00-e56a-484c-b832-8b17cf6cbfe8 I 15:36:07.2244 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:initializeServices I 15:36:07.2245 2021-06-28 22:36:07.224 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=a23d00bc-217c-123b-9c00-fc44577136ee I 15:36:07.2245 2021-06-28 22:36:07.224 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=594a34fc-31db-11ea-978f-2e728ce88125 I 15:36:07.2245 2021-06-28 22:36:07.224 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=abbafc00-e56a-484c-b832-8b17cf6cbfe8 I 15:36:07.2245 2021-06-28 22:36:07.224 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000110d-0000-1000-8000-00805f9b34fb I 15:36:07.2246 2021-06-28 22:36:07.224 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=86130247-e942-4fe5-aa46-e30768a0c1b0 I 15:36:07.2246 2021-06-28 22:36:07.224 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000111f-0000-1000-8000-00805f9b34fb I 15:36:07.2246 Display changed successfully I 15:36:07.2247 2021-06-28 22:36:07.224 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000110e-0000-1000-8000-00805f9b34fb CALLING LOG ROLLING HANDLER: doppler.log thyme-oldTime was: 10120589831LOG WAS RECENTLY ROTATED. APPENDING SO remote_syslog2 HAS A CHANCE TO UPDATECALLING LOG APPENDER: doppler.log rolling command was cat doppler.log >> old-doppler.log echo command was echo 'Beginning of logAppender output' >> old-doppler.log I 15:36:07.2319 2021-06-28 22:36:07.224 [ 1] 5 BlueZBluetoothDevice:initializeService:supports=A/V_RemoteControl I 15:36:07.2320 State retrieved successfully I 15:36:07.2320 2021-06-28 22:36:07.232 [ 1] 5 BlueZAVRCPController:create I 15:36:07.2321 2021-06-28 22:36:07.232 [ 1] 5 BlueZBluetoothDevice:insertService I 15:36:07.2321 2021-06-28 22:36:07.232 [ 1] 5 BlueZBluetoothDevice:insertService:serviceUuid=0000110e-0000-1000-8000-00805f9b34fb I 15:36:07.2321 2021-06-28 22:36:07.232 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000110a-0000-1000-8000-00805f9b34fb I 15:36:07.2322 2021-06-28 22:36:07.232 [ 1] 5 BlueZBluetoothDevice:initializeServices:supports=AudioSource I 15:36:07.2322 Alarms retrieved successfully I 15:36:07.2322 2021-06-28 22:36:07.232 [ 1] 5 BlueZBluetoothDevice:insertService I 15:36:07.2323 2021-06-28 22:36:07.232 [ 1] 5 BlueZBluetoothDevice:insertService:serviceUuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:07.2323 2021-06-28 22:36:07.232 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001200-0000-1000-8000-00805f9b34fb I 15:36:07.2323 2021-06-28 22:36:07.232 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000110c-0000-1000-8000-00805f9b34fb I 15:36:07.2323 2021-06-28 22:36:07.232 [ 1] 5 BlueZBluetoothDevice:initializeServices:supports=A/V_RemoteControlTarget I 15:36:07.2331 2021-06-28 22:36:07.233 [ 1] 5 BlueZAVRCPTarget:create I 15:36:07.2332 2021-06-28 22:36:07.233 [ 1] 5 BlueZBluetoothDevice:insertService I 15:36:07.2332 2021-06-28 22:36:07.233 [ 1] 5 BlueZBluetoothDevice:insertService:serviceUuid=0000110c-0000-1000-8000-00805f9b34fb I 15:36:07.2332 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001105-0000-1000-8000-00805f9b34fb I 15:36:07.2332 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001116-0000-1000-8000-00805f9b34fb I 15:36:07.2333 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001108-0000-1000-8000-00805f9b34fb I 15:36:07.2333 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001112-0000-1000-8000-00805f9b34fb I 15:36:07.2333 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=0000112f-0000-1000-8000-00805f9b34fb I 15:36:07.2333 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001115-0000-1000-8000-00805f9b34fb I 15:36:07.2333 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001132-0000-1000-8000-00805f9b34fb I 15:36:07.2334 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001801-0000-1000-8000-00805f9b34fb I 15:36:07.2334 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=00001800-0000-1000-8000-00805f9b34fb I 15:36:07.2334 2021-06-28 22:36:07.233 [ 1] 9 BlueZBluetoothDevice:initializeServices:supportedUUID=16bcfd00-253f-c348-e831-0db3e334d580 I 15:36:07.2335 2021-06-28 22:36:07.233 [ 1] 5 BlueZBluetoothDevice:executeIsConnectedToRelevantServices I 15:36:07.2335 2021-06-28 22:36:07.233 [ 1] 5 BlueZBluetoothDevice:getService:uuid=0000110b-0000-1000-8000-00805f9b34fb I 15:36:07.2335 2021-06-28 22:36:07.233 [ 1] 0 BlueZBluetoothDevice:getService:reason=serviceNotFound I 15:36:07.2335 2021-06-28 22:36:07.233 [ 1] 5 BlueZBluetoothDevice:getService:uuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:07.2335 2021-06-28 22:36:07.233 [ 1] 5 BlueZBluetoothDevice:queryDeviceProperty:name=Paired I 15:36:07.2338 2021-06-28 22:36:07.233 [ 1] 5 BlueZBluetoothDevice:queryDeviceProperty:name=Connected I 15:36:07.2341 2021-06-28 22:36:07.234 [ 1] 5 DBusPropertiesProxy:getVariantProperty I 15:36:07.2344 2021-06-28 22:36:07.234 [ 1] 5 BlueZBluetoothDevice:init:ClassOfDevice=5898764 I 15:36:07.2344 2021-06-28 22:36:07.234 [ 1] 7 BlueZDeviceManager:addDevice I 15:36:07.2345 2021-06-28 22:36:07.234 [ 1] 5 BlueZBluetoothDevice:getMac I 15:36:07.2345 2021-06-28 22:36:07.234 [ 1] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:07.2345 2021-06-28 22:36:07.234 [ 1] 7 BlueZDeviceManager:Device added:path=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4,mac=74\:9E\:F5\:1A\:2B\:A4,alias=Galaxy S10+ I 15:36:07.2346 2021-06-28 22:36:07.234 [ 1] 5 BlueZDeviceManager:Initializing Host Controller... I 15:36:07.2346 2021-06-28 22:36:07.234 [ 1] 5 BlueZHostController:create:adapterObjectPath=/org/bluez/hci0 I 15:36:07.2347 2021-06-28 22:36:07.234 [ 1] 5 BlueZHostController:init I 15:36:07.2361 2021-06-28 22:36:07.236 [ 1] 9 DBusPropertiesProxy:getStringProperty:object=/org/bluez/hci0,interface=org.bluez.Adapter1,property=Address I 15:36:07.2364 2021-06-28 22:36:07.236 [ 1] 9 DBusPropertiesProxy:getStringProperty:object=/org/bluez/hci0,interface=org.bluez.Adapter1,property=Alias I 15:36:07.2367 2021-06-28 22:36:07.236 [ 1] 5 BlueZHostController:adapterProperties:mac=44\:AF\:28\:CE\:65\:4D,friendlyName=brett-System-Product-Name I 15:36:07.2377 2021-06-28 22:36:07.237 [ a] 5 BlueZDeviceManager:Connecting signals... I 15:36:07.2379 2021-06-28 22:36:07.237 [ a] 7 DBusConnection:Subscribed to signal:service=org.bluez,interface=org.freedesktop.DBus.ObjectManager,member=InterfacesAdded,result=33 I 15:36:07.2380 2021-06-28 22:36:07.238 [ a] 7 DBusConnection:Subscribed to signal:service=org.bluez,interface=org.freedesktop.DBus.ObjectManager,member=InterfacesRemoved,result=34 I 15:36:07.2381 2021-06-28 22:36:07.238 [ a] 7 DBusConnection:Subscribed to signal:service=org.bluez,interface=org.freedesktop.DBus.Properties,member=PropertiesChanged,result=35 I 15:36:07.2381 2021-06-28 22:36:07.238 [ a] 5 BlueZDeviceManager:init::Initializing Bluetooth Media I 15:36:07.2387 2021-06-28 22:36:07.238 [ a] 5 DBusObjectBase:registerWithDBus I 15:36:07.2388 2021-06-28 22:36:07.238 [ a] 5 DBusObjectBase:Object registered:Object path=/com/amazon/alexa/sdk/sinkendpoint,Interface=org.bluez.MediaEndpoint1 I 15:36:07.2394 2021-06-28 22:36:07.239 [ a] 5 BlueZDeviceManager:init::Initializing Pairing Agent I 15:36:07.2398 2021-06-28 22:36:07.239 [ a] 5 DBusObjectBase:registerWithDBus I 15:36:07.2399 2021-06-28 22:36:07.239 [ a] 5 DBusObjectBase:Object registered:Object path=/ACSDK/Bluetooth/Agent,Interface=org.bluez.Agent1 I 15:36:07.2407 2021-06-28 22:36:07.240 [ a] 5 PairingAgent:registerAgent I 15:36:07.2410 2021-06-28 22:36:07.241 [ a] 5 PairingAgent:registerAgent::registerAgentDone I 15:36:07.2411 2021-06-28 22:36:07.241 [ a] 5 PairingAgent:requestDefaultAgent I 15:36:07.2414 2021-06-28 22:36:07.241 [ a] 5 PairingAgent:requestDefaultAgent::requestDefaultAgentSuccessful I 15:36:07.2416 2021-06-28 22:36:07.241 [ a] 5 BlueZDeviceManager:init::Initializing MRPIS Player I 15:36:07.2419 2021-06-28 22:36:07.241 [ a] 5 DBusObjectBase:registerWithDBus I 15:36:07.2420 2021-06-28 22:36:07.242 [ a] 5 DBusObjectBase:Object registered:Object path=/org/mpris/MediaPlayer2,Interface=org.mpris.MediaPlayer2.Player I 15:36:07.2420 2021-06-28 22:36:07.242 [ a] 5 MPRISPlayer:registerPlayer I 15:36:07.2425 2021-06-28 22:36:07.242 [ a] 0 MPRISPlayer:registerPlayerSucceeded:path=/org/mpris/MediaPlayer2 I 15:36:07.2427 2021-06-28 22:36:07.242 [ 1] 5 BlueZDeviceManager:BlueZDeviceManager initialized... I 15:36:07.2429 2021-06-28 22:36:07.242 [ 1] 5 PulseAudioBluetoothInitializer:onEventFired I 15:36:07.2431 2021-06-28 22:36:07.243 [ b] 5 PulseAudioBluetoothInitializer:run I 15:36:07.2432 2021-06-28 22:36:07.243 [ 1] 5 SQLiteBluetoothStorage:createBluetoothStorageInterface I 15:36:07.2432 2021-06-28 22:36:07.243 [ 1] 5 SQLiteBluetoothStorage:create I 15:36:07.2434 2021-06-28 22:36:07.243 [ 1] 5 Bluetooth:createBluetoothCapabilityAgent I 15:36:07.2435 2021-06-28 22:36:07.243 [ 1] 9 MediaPlayer:createCalled:name=BluetoothMediaPlayer I 15:36:07.2437 2021-06-28 22:36:07.243 [ 1] I MediaPlayer:outputConversion:name=BluetoothMediaPlayer,string=audio/x-raw\, format\=(string)S16LE I 15:36:07.2443 2021-06-28 22:36:07.244 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2444 2021-06-28 22:36:07.244 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=BluetoothMediaPlayer I 15:36:07.2445 2021-06-28 22:36:07.244 [ c] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=BluetoothMediaPlayer I 15:36:07.2446 2021-06-28 22:36:07.244 [ 1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=2 I 15:36:07.2446 2021-06-28 22:36:07.244 [ 1] E EqualizerRuntimeSetup:addEqualizerFailed::Equalizer not enabled I 15:36:07.2449 2021-06-28 22:36:07.244 [ 1] 5 Bluetooth:init I 15:36:07.2450 2021-06-28 22:36:07.244 [ 1] 5 SQLiteBluetoothStorage:open I 15:36:07.2452 2021-06-28 22:36:07.245 [ 1] 9 MediaPlayer:addObserverCalled:name=BluetoothMediaPlayer I 15:36:07.2453 2021-06-28 22:36:07.245 [ c] 0 MediaPlayer:handleAddObserverCalled:name=BluetoothMediaPlayer I 15:36:07.2454 2021-06-28 22:36:07.245 [ 1] 5 BlueZDeviceManager:getDiscoveredDevices I 15:36:07.2455 2021-06-28 22:36:07.245 [ 1] 5 BlueZBluetoothDevice:isConnected I 15:36:07.2457 2021-06-28 22:36:07.245 [ d] 5 BlueZBluetoothDevice:executeIsConnected I 15:36:07.2459 2021-06-28 22:36:07.245 [ 1] 9 Bluetooth:syncWithDeviceManager:reason=deviceNotConnected:Excluding I 15:36:07.2459 2021-06-28 22:36:07.245 [ 1] 5 BlueZBluetoothDevice:isConnected I 15:36:07.2460 2021-06-28 22:36:07.246 [ e] 5 BlueZBluetoothDevice:executeIsConnected I 15:36:07.2461 2021-06-28 22:36:07.246 [ 1] 9 Bluetooth:syncWithDeviceManager:reason=deviceNotConnected:Excluding I 15:36:07.2462 2021-06-28 22:36:07.246 [ 1] 5 BlueZHostController:getFriendlyName I 15:36:07.2462 2021-06-28 22:36:07.246 [ 1] 5 SQLiteBluetoothStorage:getMacToUuid I 15:36:07.2462 2021-06-28 22:36:07.246 [ 1] 5 SQLiteBluetoothStorage:getMappingsLocked:key=mac,value=uuid I 15:36:07.2463 2021-06-28 22:36:07.246 [ 1] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:07.2464 2021-06-28 22:36:07.246 [ 1] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:07.2464 2021-06-28 22:36:07.246 [ 1] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:07.2464 2021-06-28 22:36:07.246 [ 1] I SQLiteBluetoothStorage:getSingleRowLocked:reason=getStepResultFailed I 15:36:07.2465 2021-06-28 22:36:07.246 [ 1] 5 SQLiteBluetoothStorage:getUuidToCategory I 15:36:07.2465 2021-06-28 22:36:07.246 [ 1] 5 SQLiteBluetoothStorage:getMappingsLocked:key=uuid,value=category I 15:36:07.2465 2021-06-28 22:36:07.246 [ 1] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:07.2466 2021-06-28 22:36:07.246 [ 1] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:07.2466 2021-06-28 22:36:07.246 [ 1] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:07.2466 2021-06-28 22:36:07.246 [ 1] I SQLiteBluetoothStorage:getSingleRowLocked:reason=getStepResultFailed I 15:36:07.2466 2021-06-28 22:36:07.246 [ 1] 5 BlueZDeviceManager:getDiscoveredDevices I 15:36:07.2467 2021-06-28 22:36:07.246 [ 1] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:07.2467 2021-06-28 22:36:07.246 [ 1] 5 BlueZBluetoothDevice:getMac I 15:36:07.2467 2021-06-28 22:36:07.246 [ 1] 5 BlueZBluetoothDevice:isPaired I 15:36:07.2468 2021-06-28 22:36:07.246 [ d] 5 BlueZBluetoothDevice:executeIsPaired I 15:36:07.2469 2021-06-28 22:36:07.246 [ 1] 9 Bluetooth:executeUpdateContext:friendlyName=iPhone,mac=44\:F2\:1B\:CB\:A1\:5D,paired=true I 15:36:07.2469 2021-06-28 22:36:07.246 [ 1] 5 BlueZBluetoothDevice:isPaired I 15:36:07.2470 2021-06-28 22:36:07.246 [ d] 5 BlueZBluetoothDevice:executeIsPaired I 15:36:07.2470 2021-06-28 22:36:07.247 [ 1] 5 BlueZBluetoothDevice:getMac I 15:36:07.2470 2021-06-28 22:36:07.247 [ 1] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:07.2471 2021-06-28 22:36:07.247 [ 1] 5 BlueZBluetoothDevice:getSupportedServices I 15:36:07.2472 2021-06-28 22:36:07.247 [ 1] 5 BlueZBluetoothDevice:getDeviceState I 15:36:07.2477 2021-06-28 22:36:07.247 [ 1] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:07.2478 2021-06-28 22:36:07.247 [ 1] 5 BlueZBluetoothDevice:getMac I 15:36:07.2478 2021-06-28 22:36:07.247 [ 1] 5 BlueZBluetoothDevice:isPaired I 15:36:07.2478 2021-06-28 22:36:07.247 [ e] 5 BlueZBluetoothDevice:executeIsPaired I 15:36:07.2479 2021-06-28 22:36:07.247 [ 1] 9 Bluetooth:executeUpdateContext:friendlyName=Galaxy S10+,mac=74\:9E\:F5\:1A\:2B\:A4,paired=true I 15:36:07.2479 2021-06-28 22:36:07.247 [ 1] 5 BlueZBluetoothDevice:isPaired I 15:36:07.2480 2021-06-28 22:36:07.248 [ e] 5 BlueZBluetoothDevice:executeIsPaired I 15:36:07.2480 2021-06-28 22:36:07.248 [ 1] 5 BlueZBluetoothDevice:getMac I 15:36:07.2481 2021-06-28 22:36:07.248 [ 1] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:07.2481 2021-06-28 22:36:07.248 [ 1] 5 BlueZBluetoothDevice:getSupportedServices I 15:36:07.2481 2021-06-28 22:36:07.248 [ 1] 5 BlueZBluetoothDevice:getDeviceState I 15:36:07.2482 2021-06-28 22:36:07.248 [ 1] 9 Bluetooth:executeUpdateContext I 15:36:07.2483 2021-06-28 22:36:07.248 [ 1] 5 ContextManager:setState I 15:36:07.2484 2021-06-28 22:36:07.248 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2489 2021-06-28 22:36:07.248 [ 1] 5 ExternalMediaPlayer:init I 15:36:07.2489 2021-06-28 22:36:07.248 [ 1] 5 AuthorizedSender:create I 15:36:07.2490 2021-06-28 22:36:07.249 [ 1] 5 ContextManager:addStateProvider I 15:36:07.2490 2021-06-28 22:36:07.249 [ 1] 5 ContextManager:addStateProvider I 15:36:07.2492 2021-06-28 22:36:07.249 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2495 2021-06-28 22:36:07.249 [ 1] 5 InteractionModel:InteractionModelCapabilityAgent I 15:36:07.2495 2021-06-28 22:36:07.249 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2498 2021-06-28 22:36:07.249 [ 1] 5 NotificationRenderer:createNotificationRendererInterface I 15:36:07.2498 2021-06-28 22:36:07.249 [ 1] 9 MediaPlayer:createCalled:name=NotificationsMediaPlayer I 15:36:07.2500 2021-06-28 22:36:07.249 [ 1] I MediaPlayer:outputConversion:name=NotificationsMediaPlayer,string=audio/x-raw\, format\=(string)S16LE I 15:36:07.2505 2021-06-28 22:36:07.250 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2506 2021-06-28 22:36:07.250 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=NotificationsMediaPlayer I 15:36:07.2507 2021-06-28 22:36:07.250 [ f] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=NotificationsMediaPlayer I 15:36:07.2507 2021-06-28 22:36:07.250 [ 1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_ALERTS_VOLUME,sizeOfSpeakerSet=2 I 15:36:07.2508 2021-06-28 22:36:07.250 [ 1] E EqualizerRuntimeSetup:addEqualizerFailed::Equalizer not enabled I 15:36:07.2508 2021-06-28 22:36:07.250 [ 1] 5 NotificationRenderer:create I 15:36:07.2509 2021-06-28 22:36:07.250 [ 1] 9 MediaPlayer:addObserverCalled:name=NotificationsMediaPlayer I 15:36:07.2510 2021-06-28 22:36:07.250 [ f] 0 MediaPlayer:handleAddObserverCalled:name=NotificationsMediaPlayer I 15:36:07.2511 2021-06-28 22:36:07.251 [ 1] 5 SQLiteNotificationsStorage:createNotificationsStorageInterface I 15:36:07.2512 2021-06-28 22:36:07.251 [ 1] 5 NotificationsCapabilityAgent:createNotificationsCapabilityAgent I 15:36:07.2515 2021-06-28 22:36:07.251 [ 1] 5 NotificationsCapabilityAgent:init I 15:36:07.2518 2021-06-28 22:36:07.251 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2519 2021-06-28 22:36:07.251 [ 10] 5 NotificationsCapabilityAgent:executeInit I 15:36:07.2520 2021-06-28 22:36:07.251 [ b] 5 PulseAudioBluetoothInitializer:onStateChanged I 15:36:07.2521 2021-06-28 22:36:07.251 [ 10] 5 NotificationRenderer:addObserver I 15:36:07.2521 2021-06-28 22:36:07.252 [ 1] 5 UserInactivityMonitor:createUserInactivityMonitorInterface I 15:36:07.2521 2021-06-28 22:36:07.252 [ b] 5 PulseAudioBluetoothInitializer:onStateChanged:state=PA_CONTEXT_CONNECTING I 15:36:07.2522 2021-06-28 22:36:07.252 [ b] 5 PulseAudioBluetoothInitializer:setStateAndNotify I 15:36:07.2523 2021-06-28 22:36:07.252 [ 10] 5 ContextManager:addStateProvider I 15:36:07.2525 2021-06-28 22:36:07.252 [ 10] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=false,stateRequestToken=0,isEnabled=false I 15:36:07.2526 2021-06-28 22:36:07.252 [ 11] 5 PulseAudioBluetoothInitializer:onStateChanged I 15:36:07.2526 2021-06-28 22:36:07.252 [ 10] 5 ContextManager:setState I 15:36:07.2527 2021-06-28 22:36:07.252 [ 11] 5 PulseAudioBluetoothInitializer:onStateChanged:state=PA_CONTEXT_AUTHORIZING I 15:36:07.2527 2021-06-28 22:36:07.252 [ 11] 5 PulseAudioBluetoothInitializer:setStateAndNotify I 15:36:07.2528 2021-06-28 22:36:07.252 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ResetUserInactivity,handler=0x3271628,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:07.2529 2021-06-28 22:36:07.252 [ 11] 5 PulseAudioBluetoothInitializer:onStateChanged I 15:36:07.2530 2021-06-28 22:36:07.252 [ 11] 5 PulseAudioBluetoothInitializer:onStateChanged:state=PA_CONTEXT_SETTING_NAME I 15:36:07.2530 2021-06-28 22:36:07.253 [ 11] 5 PulseAudioBluetoothInitializer:setStateAndNotify I 15:36:07.2531 2021-06-28 22:36:07.253 [ 1] 9 ExternalMediaPlayer:startup I 15:36:07.2532 2021-06-28 22:36:07.253 [ 1] 9 MediaPlayer:createCalled:name=RingtoneMediaPlayer I 15:36:07.2533 2021-06-28 22:36:07.253 [ 11] 5 PulseAudioBluetoothInitializer:onStateChanged I 15:36:07.2533 2021-06-28 22:36:07.253 [ 11] 5 PulseAudioBluetoothInitializer:onStateChanged:state=PA_CONTEXT_READY I 15:36:07.2533 2021-06-28 22:36:07.253 [ 11] 5 PulseAudioBluetoothInitializer:setStateAndNotify I 15:36:07.2534 2021-06-28 22:36:07.253 [ 1] I MediaPlayer:outputConversion:name=RingtoneMediaPlayer,string=audio/x-raw\, format\=(string)S16LE I 15:36:07.2535 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2536 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-device-restore I 15:36:07.2536 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2536 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-stream-restore I 15:36:07.2537 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2537 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-card-restore I 15:36:07.2537 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2537 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-augment-properties I 15:36:07.2537 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2538 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-switch-on-port-available I 15:36:07.2538 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2538 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-switch-on-connect I 15:36:07.2538 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2539 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-udev-detect I 15:36:07.2539 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2539 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-alsa-card I 15:36:07.2539 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2540 2021-06-28 22:36:07.253 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-alsa-card I 15:36:07.2540 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2540 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-alsa-card I 15:36:07.2540 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2540 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-native-protocol-unix I 15:36:07.2541 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2541 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-default-device-restore I 15:36:07.2541 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2541 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-rescue-streams I 15:36:07.2542 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2542 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-always-sink I 15:36:07.2542 2021-06-28 22:36:07.254 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x3329ab0 I 15:36:07.2543 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2543 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-intended-roles I 15:36:07.2543 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2543 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-suspend-on-idle I 15:36:07.2544 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2544 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-console-kit I 15:36:07.2544 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2544 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-systemd-login I 15:36:07.2544 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2545 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-position-event-sounds I 15:36:07.2545 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2545 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-role-cork I 15:36:07.2545 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2546 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-snap-policy I 15:36:07.2546 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2546 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-filter-heuristics I 15:36:07.2546 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2547 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-filter-apply I 15:36:07.2547 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2547 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-x11-publish I 15:36:07.2547 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2547 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-x11-bell I 15:36:07.2548 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2548 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-x11-cork-request I 15:36:07.2548 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2548 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-x11-xsmp I 15:36:07.2549 2021-06-28 22:36:07.254 [ 1] 7 DefaultClient:initialize::metrics disabled I 15:36:07.2549 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2549 2021-06-28 22:36:07.254 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-bluetooth-policy I 15:36:07.2550 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:currentState=UNKNOWN I 15:36:07.2550 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:module=module-bluetooth-policy,desiredState=INITIALLY_LOADED I 15:36:07.2550 2021-06-28 22:36:07.255 [ 1] 7 DefaultClient:initialize::using default null SystemTimeZone I 15:36:07.2551 2021-06-28 22:36:07.255 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2551 2021-06-28 22:36:07.255 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-bluetooth-discover I 15:36:07.2551 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:currentState=UNKNOWN I 15:36:07.2551 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:module=module-bluetooth-discover,desiredState=INITIALLY_LOADED I 15:36:07.2551 2021-06-28 22:36:07.255 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2552 2021-06-28 22:36:07.255 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound:name=module-bluez5-discover I 15:36:07.2552 2021-06-28 22:36:07.255 [ 11] 9 PulseAudioBluetoothInitializer:onModuleFound I 15:36:07.2552 2021-06-28 22:36:07.255 [ 11] 0 PulseAudioBluetoothInitializer:onModuleFound::endOfList I 15:36:07.2553 2021-06-28 22:36:07.255 [ 1] 5 DefaultClient:nullCaptionManager::captions disabled I 15:36:07.2553 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:onUnloadPolicyResult I 15:36:07.2554 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:handleUnloadModuleResult:module=module-bluetooth-policy,success=1 I 15:36:07.2554 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:currentState=INITIALLY_LOADED I 15:36:07.2554 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:module=module-bluetooth-policy,desiredState=UNLOADED I 15:36:07.2554 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:onUnloadDiscoverResult I 15:36:07.2555 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:handleUnloadModuleResult:module=module-bluetooth-discover,success=1 I 15:36:07.2555 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:currentState=INITIALLY_LOADED I 15:36:07.2555 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:module=module-bluetooth-discover,desiredState=UNLOADED I 15:36:07.2556 2021-06-28 22:36:07.255 [ b] 0 PulseAudioBluetoothInitializer:run:success=bluetoothModulesUnloaded I 15:36:07.2557 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:onLoadPolicyResult I 15:36:07.2558 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:handleLoadModuleResult:module=module-bluetooth-policy,index=51 I 15:36:07.2558 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:currentState=UNLOADED I 15:36:07.2558 2021-06-28 22:36:07.255 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:module=module-bluetooth-policy,desiredState=LOADED_BY_SDK I 15:36:07.2567 2021-06-28 22:36:07.256 [ 1] 5 DeviceSetup:createDeviceSetupInterface I 15:36:07.2567 2021-06-28 22:36:07.256 [ 1] 5 DeviceSetup:create I 15:36:07.2570 2021-06-28 22:36:07.257 [ 11] 5 PulseAudioBluetoothInitializer:onLoadDiscoverResult I 15:36:07.2570 2021-06-28 22:36:07.257 [ 11] 5 PulseAudioBluetoothInitializer:handleLoadModuleResult:module=module-bluetooth-discover,index=52 I 15:36:07.2570 2021-06-28 22:36:07.257 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:currentState=UNLOADED I 15:36:07.2571 onConnectionStatusChanged: DISCONNECTED I 15:36:07.2571 2021-06-28 22:36:07.257 [ 11] 5 PulseAudioBluetoothInitializer:updateStateLocked:module=module-bluetooth-discover,desiredState=LOADED_BY_SDK I 15:36:07.2571 2021-06-28 22:36:07.257 [ b] 0 PulseAudioBluetoothInitializer:run:reason=loadModulesSuccesful W 15:36:07.2572 Calling stop animation on null animation I 15:36:07.2572 2021-06-28 22:36:07.257 [ b] 0 PulseAudioBluetoothInitializer:run::Reloading PulseAudio Bluetooth Modules Successful I 15:36:07.2573 2021-06-28 22:36:07.257 [ b] 5 PulseAudioBluetoothInitializer:cleanup I 15:36:07.2573 2021-06-28 22:36:07.257 [ 1] 5 CapabilitiesDelegate:setMessageSender I 15:36:07.2574 2021-06-28 22:36:07.257 [ b] 5 PulseAudioBluetoothInitializer:onStateChanged I 15:36:07.2576 2021-06-28 22:36:07.257 [ 1] 5 AVSGatewayManager:addObserver I 15:36:07.2576 2021-06-28 22:36:07.257 [ b] 5 PulseAudioBluetoothInitializer:onStateChanged:state=PA_CONTEXT_TERMINATED I 15:36:07.2577 2021-06-28 22:36:07.257 [ b] 5 PulseAudioBluetoothInitializer:setStateAndNotify I 15:36:07.2579 2021-06-28 22:36:07.257 [ 1] 5 CapabilitiesDelegate:onConnectionStatusChanged:connectionStatus=DISCONNECTED I 15:36:07.2581 2021-06-28 22:36:07.258 [ b] 0 PulseAudioBluetoothInitializer:cleanup::cleanupCompleted I 15:36:07.2582 2021-06-28 22:36:07.258 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x34bb540 I 15:36:07.2583 2021-06-28 22:36:07.258 [ 1] 5 EndpointRegistrationManager:onCapabilitiesStateChange:state=UNINITIALIZED,error=UNINITIALIZED,callback=true I 15:36:07.2583 2021-06-28 22:36:07.258 [ 1] 5 EndpointRegistrationManager:onCapabilityRegistrationStatusChanged I 15:36:07.2587 2021-06-28 22:36:07.258 [ 1] 9 MediaPlayer:createCalled:name=SystemSoundMediaPlayer I 15:36:07.2588 2021-06-28 22:36:07.258 [ 1] I MediaPlayer:outputConversion:name=SystemSoundMediaPlayer,string=audio/x-raw\, format\=(string)S16LE I 15:36:07.2592 2021-06-28 22:36:07.259 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2592 2021-06-28 22:36:07.259 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=SystemSoundMediaPlayer I 15:36:07.2593 2021-06-28 22:36:07.259 [ 15] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=SystemSoundMediaPlayer I 15:36:07.2594 2021-06-28 22:36:07.259 [ 1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=3 I 15:36:07.2594 2021-06-28 22:36:07.259 [ 1] E EqualizerRuntimeSetup:addEqualizerFailed::Equalizer not enabled I 15:36:07.2595 2021-06-28 22:36:07.259 [ 1] 9 MediaPlayer:addObserverCalled:name=SystemSoundMediaPlayer I 15:36:07.2595 2021-06-28 22:36:07.259 [ 15] 0 MediaPlayer:handleAddObserverCalled:name=SystemSoundMediaPlayer I 15:36:07.2599 2021-06-28 22:36:07.259 [ 1] 5 AudioInputProcessor:getSpeechRecognizerCapabilityConfiguration:wakeWords={"wakeWords"\:[{"scopes"\:["DEFAULT"]\,"values"\:[["ALEXA"]]}]} I 15:36:07.2605 2021-06-28 22:36:07.260 [ 1] 9 MediaPlayer:createCalled:name=SpeakMediaPlayer I 15:36:07.2605 2021-06-28 22:36:07.260 [ 16] 0 AudioInputProcessor:executeOnDialogUXStateChanged:newState=IDLE I 15:36:07.2606 2021-06-28 22:36:07.260 [ 1] I MediaPlayer:outputConversion:name=SpeakMediaPlayer,string=audio/x-raw\, format\=(string)S16LE I 15:36:07.2610 2021-06-28 22:36:07.261 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2610 2021-06-28 22:36:07.261 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=SpeakMediaPlayer I 15:36:07.2611 2021-06-28 22:36:07.261 [ 17] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=SpeakMediaPlayer I 15:36:07.2612 2021-06-28 22:36:07.261 [ 1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=4 I 15:36:07.2612 2021-06-28 22:36:07.261 [ 1] E EqualizerRuntimeSetup:addEqualizerFailed::Equalizer not enabled I 15:36:07.2614 2021-06-28 22:36:07.261 [ 1] 9 MediaPlayer:addObserverCalled:name=SpeakMediaPlayer I 15:36:07.2615 2021-06-28 22:36:07.261 [ 17] 0 MediaPlayer:handleAddObserverCalled:name=SpeakMediaPlayer I 15:36:07.2616 2021-06-28 22:36:07.261 [ 1] 5 ContextManager:addStateProvider I 15:36:07.2616 2021-06-28 22:36:07.261 [ 1] 9 SpeechSynthesizer:addObserver:observer=0x3303018 I 15:36:07.2617 2021-06-28 22:36:07.261 [ 1] 0 ChannelVolumeManager:getSpeakerSettings I 15:36:07.2618 2021-06-28 22:36:07.261 [ 1] 9 MediaPlayer:getSpeakerSettingsCalled:name=RingtoneMediaPlayer I 15:36:07.2619 2021-06-28 22:36:07.261 [ 19] 9 MediaPlayer:handleGetSpeakerSettingsCalled:name=RingtoneMediaPlayer I 15:36:07.2620 2021-06-28 22:36:07.262 [ 1] 0 SpeakerManager:addChannelVolumeInterfaceIntoSpeakerMap:type=AVS_SPEAKER_VOLUME,sizeOfSpeakerSet=5 I 15:36:07.2621 2021-06-28 22:36:07.262 [ 1] 5 ContextManager:addStateProvider I 15:36:07.2622 2021-06-28 22:36:07.262 [ 1] 5 DefaultEndpointBuilder:withCapabilityConfiguration I 15:36:07.2625 2021-06-28 22:36:07.262 [ 1] 5 ExternalMediaPlayer:setObserver I 15:36:07.2625 2021-06-28 22:36:07.262 [ 1] 1 AudioPlayer:setObserver I 15:36:07.2627 2021-06-28 22:36:07.262 [ 1] 3 DefaultClient:initialize::Equalizer is disabled I 15:36:07.2628 2021-06-28 22:36:07.262 [ 13] 5 TemplateRuntime:onDialogUXStateChanged:state=IDLE I 15:36:07.2635 2021-06-28 22:36:07.263 [ 1] 5 SystemCapabilityProvider:getSystemCapabilityConfiguration:locales={"locales"\:["de-DE"\,"en-AU"\,"en-CA"\,"en-GB"\,"en-IN"\,"en-US"\,"es-ES"\,"es-MX"\,"es-US"\,"fr-CA"\,"fr-FR"\,"hi-IN"\,"it-IT"\,"ja-JP"\,"pt-BR"]\,"localeCombinations"\:[["en-CA"\,"fr-CA"]\,["fr-CA"\,"en-CA"]]} I 15:36:07.2636 2021-06-28 22:36:07.263 [ 1] 5 RevokeAuthorizationHandler:create I 15:36:07.2637 2021-06-28 22:36:07.263 [ 1] 5 ApiGateway:create I 15:36:07.2638 2021-06-28 22:36:07.263 [ 1] 0 DefaultClient:initialize::Diagnostics Not Enabled I 15:36:07.2638 2021-06-28 22:36:07.263 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2639 2021-06-28 22:36:07.263 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2639 2021-06-28 22:36:07.263 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2639 2021-06-28 22:36:07.263 [ 1] 5 DefaultEndpointBuilder:withCapability I 15:36:07.2639 2021-06-28 22:36:07.263 [ 1] 5 DefaultEndpointBuilder:withCapabilityConfiguration I 15:36:07.2641 2021-06-28 22:36:07.264 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetLocales,handler=0x34ce4d0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:07.2641 2021-06-28 22:36:07.264 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=SetTimeZone,handler=0x34cdf10,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:07.2642 2021-06-28 22:36:07.264 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=RevokeAuthorization,handler=0x3216c00,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:07.2642 2021-06-28 22:36:07.264 [ 1] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=System,name=ReportState,handler=0x32e10a0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:07.2644 2021-06-28 22:36:07.264 [ 1] 5 SoftwareInfoSender:create I 15:36:07.2644 2021-06-28 22:36:07.264 [ 1] 5 SoftwareInfoSender:SoftwareInfoSender I 15:36:07.2644 2021-06-28 22:36:07.264 [ 1] 5 SoftwareInfoSender:onConnectionStatusChanged:status=DISCONNECTED,reason=ACL_CLIENT_REQUEST I 15:36:07.2645 2021-06-28 22:36:07.264 [ 1] 5 DefaultEndpointBuilder:withCapabilityConfiguration I 15:36:07.2647 2021-06-28 22:36:07.264 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled I 15:36:07.2647 2021-06-28 22:36:07.264 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x3329ac8 I 15:36:07.2647 2021-06-28 22:36:07.264 [ 1] 9 SpeakerManager:addSpeakerManagerObserverCalled I 15:36:07.2647 2021-06-28 22:36:07.264 [ 1] 9 SpeakerManager:addSpeakerManagerObserver:observer=0x310a8f8 I 15:36:07.2650 2021-06-28 22:36:07.264 [ 1] 5 TemplateRuntime:addObserver T 15:36:07.2650 #################################################

NOTIFICATION INDICATOR STATE: OFF

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

W 15:36:07.2650 Calling stop animation on null animation 15:36:07.265 NOTIFICATION_INDICATOR_CLEARED: I 15:36:07.2651 2021-06-28 22:36:07.265 [ 1b] 5 TemplateRuntime:addObserverInExecutor I 15:36:07.3794 2021-06-28 22:36:07.379 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:07.3794 2021-06-28 22:36:07.379 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0 I 15:36:07.3795 2021-06-28 22:36:07.379 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1'\, {'Class'\: <uint32 262404>}\, @as []) I 15:36:07.3795 2021-06-28 22:36:07.379 [ a] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0 I 15:36:07.3832 2021-06-28 22:36:07.383 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:07.3832 2021-06-28 22:36:07.383 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0 I 15:36:07.3833 2021-06-28 22:36:07.383 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1'\, {'UUIDs'\: <['00001112-0000-1000-8000-00805f9b34fb'\, '00001801-0000-1000-8000-00805f9b34fb'\, '0000110e-0000-1000-8000-00805f9b34fb'\, '00001800-0000-1000-8000-00805f9b34fb'\, '00001200-0000-1000-8000-00805f9b34fb'\, '0000110c-0000-1000-8000-00805f9b34fb'\, '0000110a-0000-1000-8000-00805f9b34fb'\, '0000110b-0000-1000-8000-00805f9b34fb'\, '00001108-0000-1000-8000-00805f9b34fb']>}\, @as []) I 15:36:07.3833 2021-06-28 22:36:07.383 [ a] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0 I 15:36:07.3862 2021-06-28 22:36:07.386 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:07.3862 2021-06-28 22:36:07.386 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0 I 15:36:07.3863 2021-06-28 22:36:07.386 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1'\, {'UUIDs'\: <['00001112-0000-1000-8000-00805f9b34fb'\, '00001801-0000-1000-8000-00805f9b34fb'\, '0000110e-0000-1000-8000-00805f9b34fb'\, '00001800-0000-1000-8000-00805f9b34fb'\, '00001200-0000-1000-8000-00805f9b34fb'\, '0000110c-0000-1000-8000-00805f9b34fb'\, '0000110a-0000-1000-8000-00805f9b34fb'\, '0000110b-0000-1000-8000-00805f9b34fb'\, '00001108-0000-1000-8000-00805f9b34fb']>}\, @as []) I 15:36:07.3863 2021-06-28 22:36:07.386 [ a] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0 I 15:36:07.3892 2021-06-28 22:36:07.389 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:07.3893 2021-06-28 22:36:07.389 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0 I 15:36:07.3893 2021-06-28 22:36:07.389 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1'\, {'UUIDs'\: <['00001112-0000-1000-8000-00805f9b34fb'\, '00001801-0000-1000-8000-00805f9b34fb'\, '0000110e-0000-1000-8000-00805f9b34fb'\, '00001800-0000-1000-8000-00805f9b34fb'\, '00001200-0000-1000-8000-00805f9b34fb'\, '0000110c-0000-1000-8000-00805f9b34fb'\, '0000110a-0000-1000-8000-00805f9b34fb'\, '0000110b-0000-1000-8000-00805f9b34fb'\, '00001108-0000-1000-8000-00805f9b34fb']>}\, @as []) I 15:36:07.3894 2021-06-28 22:36:07.389 [ a] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0 I 15:36:07.3921 2021-06-28 22:36:07.392 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:07.3922 2021-06-28 22:36:07.392 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0 I 15:36:07.3922 2021-06-28 22:36:07.392 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1'\, {'Class'\: <uint32 786692>}\, @as []) I 15:36:07.3923 2021-06-28 22:36:07.392 [ a] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0 I 15:36:07.3952 2021-06-28 22:36:07.395 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:07.3952 2021-06-28 22:36:07.395 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0 I 15:36:07.3953 2021-06-28 22:36:07.395 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1'\, {'UUIDs'\: <['00001112-0000-1000-8000-00805f9b34fb'\, '00001801-0000-1000-8000-00805f9b34fb'\, '0000110e-0000-1000-8000-00805f9b34fb'\, '00001800-0000-1000-8000-00805f9b34fb'\, '00001200-0000-1000-8000-00805f9b34fb'\, '0000110c-0000-1000-8000-00805f9b34fb'\, '0000110a-0000-1000-8000-00805f9b34fb'\, '0000110b-0000-1000-8000-00805f9b34fb'\, '00001108-0000-1000-8000-00805f9b34fb']>}\, @as []) I 15:36:07.3953 2021-06-28 22:36:07.395 [ a] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0 I 15:36:07.3982 2021-06-28 22:36:07.398 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:07.3983 2021-06-28 22:36:07.398 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0 I 15:36:07.3983 2021-06-28 22:36:07.398 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1'\, {'UUIDs'\: <['00001112-0000-1000-8000-00805f9b34fb'\, '00001801-0000-1000-8000-00805f9b34fb'\, '0000110e-0000-1000-8000-00805f9b34fb'\, '00001800-0000-1000-8000-00805f9b34fb'\, '00001200-0000-1000-8000-00805f9b34fb'\, '0000110c-0000-1000-8000-00805f9b34fb'\, '0000110a-0000-1000-8000-00805f9b34fb'\, '0000110b-0000-1000-8000-00805f9b34fb'\, '00001108-0000-1000-8000-00805f9b34fb']>}\, @as []) I 15:36:07.3984 2021-06-28 22:36:07.398 [ a] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0 I 15:36:07.4011 2021-06-28 22:36:07.401 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:07.4012 2021-06-28 22:36:07.401 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0 I 15:36:07.4012 2021-06-28 22:36:07.401 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Adapter1'\, {'UUIDs'\: <['00001112-0000-1000-8000-00805f9b34fb'\, '00001801-0000-1000-8000-00805f9b34fb'\, '0000110e-0000-1000-8000-00805f9b34fb'\, '00001800-0000-1000-8000-00805f9b34fb'\, '00001200-0000-1000-8000-00805f9b34fb'\, '0000110c-0000-1000-8000-00805f9b34fb'\, '0000110a-0000-1000-8000-00805f9b34fb'\, '0000110b-0000-1000-8000-00805f9b34fb'\, '00001108-0000-1000-8000-00805f9b34fb']>}\, @as []) I 15:36:07.4013 2021-06-28 22:36:07.401 [ a] 7 BlueZDeviceManager:onAdapterPropertyChanged:path=/org/bluez/hci0 T 15:36:07.6333 ###########################

Authorized!

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

15:36:07.633 ALEXA_AUTHORIZED: ALSA lib pcm_dsnoop.c:618:(snd_pcm_dsnoop_open) unable to open slave ALSA lib pcm_dmix.c:1052:(snd_pcm_dmix_open) unable to open slave ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.rear ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.center_lfe ALSA lib pcm.c:2495:(snd_pcm_open_noupdate) Unknown PCM cards.pcm.side ALSA lib pcm_dmix.c:1052:(snd_pcm_dmix_open) unable to open slave I 15:36:10.0250 2021-06-28 22:36:10.024 [ 1] I SensoryKeywordDetector:Sensory library license does not expire. I 15:36:10.0250 2021-06-28 22:36:10.025 [ 1] I SensoryKeywordDetector:Sensory library license does not expire for at least 60 more days. I 15:36:10.0291 2021-06-28 22:36:10.029 [ 1] 5 RevokeAuthorizationHandler:addObserver D 15:36:10.0293 static std::unique_ptr alexaClientSDK::dopplerApp::UserInputManager::create(std::shared_ptr, std::shared_ptr, std::shared_ptr, const EndpointIdentifier&) (/home/lynnes/workspace/doppler/src/AVS/UserInput/UserInputManager.cpp:228) Registering SIGINT and SIGTERM handlers I 15:36:10.0294 AUTH STATE CHANGE! REFRESHED : SUCCESS I 15:36:10.0295 2021-06-28 22:36:10.029 [ 1] 5 CapabilitiesDelegate:addCapabilitiesObserver:observer=0x352aad8 I 15:36:10.0296 CAPABILITIES CHANGE! UNINITIALIZED : UNINITIALIZED I 15:36:10.0303 2021-06-28 22:36:10.030 [ 1] 2 EndpointBuilder:buildImplementation:isDefault=true,#capabilities=23 I 15:36:10.0304 2021-06-28 22:36:10.030 [ 1] 5 EndpointRegistrationManager:registerEndpoint I 15:36:10.0308 2021-06-28 22:36:10.030 [ d] 5 EndpointRegistrationManager:executeRegisterEndpoint I 15:36:10.0311 2021-06-28 22:36:10.031 [ d] 5 EndpointRegistrationManager:addCapability:emptyHandler=System I 15:36:10.0312 2021-06-28 22:36:10.031 [ d] 5 ApiGateway:getConfiguration I 15:36:10.0314 2021-06-28 22:36:10.031 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.ApiGateway,name=SetGateway,handler=0x33f6800,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0316 2021-06-28 22:36:10.031 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetWakeWords,handler=0x34c2d70,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0317 2021-06-28 22:36:10.031 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetSpeechConfirmation,handler=0x34c2d70,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0317 2021-06-28 22:36:10.031 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetWakeWordConfirmation,handler=0x34c2d70,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0318 2021-06-28 22:36:10.031 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=SetEndOfSpeechOffset,handler=0x34c2d70,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0318 2021-06-28 22:36:10.031 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=StopCapture,handler=0x34c2d70,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0319 2021-06-28 22:36:10.031 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechRecognizer,name=ExpectSpeech,handler=0x34c2d70,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True I 15:36:10.0319 2021-06-28 22:36:10.031 [ d] 5 EndpointRegistrationManager:addCapability:emptyHandler=VisualActivityTracker I 15:36:10.0320 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=SetSeekPosition,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0321 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableShuffle,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0321 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableShuffle,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0322 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=DisableRepeat,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0322 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Unfavorite,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0323 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeat,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0323 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.SeekController,name=AdjustSeekPosition,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0323 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Rewind,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0324 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Previous,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0324 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaylistController,name=EnableRepeatOne,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0325 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Next,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0325 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=StartOver,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0325 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Stop,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0326 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Pause,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0326 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=Play,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0327 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Logout,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0327 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.FavoritesController,name=Favorite,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0328 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.PlaybackController,name=FastForward,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0328 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Login,handler=0x348ee20,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0328 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=Play,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0329 2021-06-28 22:36:10.032 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=ExternalMediaPlayer,name=AuthorizeDiscoveredPlayers,handler=0x348ee20,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0330 2021-06-28 22:36:10.032 [ d] 5 DoNotDisturbCapabilityAgent:getConfiguration I 15:36:10.0330 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa.DoNotDisturb,name=SetDoNotDisturb,handler=0x31865c0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0331 2021-06-28 22:36:10.033 [ d] 5 EndpointRegistrationManager:addCapability:emptyHandler=PlaybackController I 15:36:10.0331 2021-06-28 22:36:10.033 [ d] 5 EndpointRegistrationManager:addCapability:emptyHandler=Alexa.SoftwareComponentReporter I 15:36:10.0332 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlarmVolumeRamp,handler=0x343a1a0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0332 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=AdjustVolume,handler=0x343a1a0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0333 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetVolume,handler=0x343a1a0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0333 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlerts,handler=0x343a1a0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0334 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=SetAlert,handler=0x343a1a0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0334 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alerts,name=DeleteAlert,handler=0x343a1a0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0335 2021-06-28 22:36:10.033 [ d] 5 EndpointRegistrationManager:addCapability:emptyHandler=AudioActivityTracker I 15:36:10.0335 2021-06-28 22:36:10.033 [ d] 5 Bluetooth:getConfiguration I 15:36:10.0336 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=Previous,handler=0x3472a60,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0336 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=DisconnectDevices,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0337 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=Stop,handler=0x3472a60,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0337 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=ConnectByDeviceIds,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0338 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=ScanDevices,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0338 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=ExitDiscoverableMode,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0338 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=ConnectByProfile,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0339 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=PairDevices,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0339 2021-06-28 22:36:10.033 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=EnterDiscoverableMode,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0340 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=UnpairDevices,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0340 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=Next,handler=0x3472a60,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0341 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=Play,handler=0x3472a60,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0341 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Bluetooth,name=SetDeviceCategories,handler=0x3472a60,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0342 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=InteractionModel,name=RequestProcessingCompleted,handler=0x3217ee0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0342 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=InteractionModel,name=NewDialogRequest,handler=0x3217ee0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0343 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=InteractionModel,name=RequestProcessingStarted,handler=0x3217ee0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0343 2021-06-28 22:36:10.034 [ d] 5 TemplateRuntime:getConfiguration I 15:36:10.0344 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderPlayerInfo,handler=0x34cc9f0,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False I 15:36:10.0344 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=TemplateRuntime,name=RenderTemplate,handler=0x34cc9f0,policy= Mediums:MEDIUM_VISUAL10 .isBlocking:False I 15:36:10.0345 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=SpeechSynthesizer,name=Speak,handler=0x34cbb50,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:True I 15:36:10.0346 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=ClearQueue,handler=0x345e7a0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0346 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=UpdateProgressReportInterval,handler=0x345e7a0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0347 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Play,handler=0x345e7a0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0347 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=AudioPlayer,name=Stop,handler=0x345e7a0,policy= Mediums:MEDIUM_AUDIO01 .isBlocking:False I 15:36:10.0348 2021-06-28 22:36:10.034 [ d] 5 AlexaInterfaceCapabilityAgent:getConfiguration I 15:36:10.0348 2021-06-28 22:36:10.034 [ d] 5 AlexaInterfaceCapabilityAgent:registeringEventProcessedDirective:reason=defaultEndpoint I 15:36:10.0350 2021-06-28 22:36:10.034 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa,name=ReportState,handler=0x315ea50,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0350 2021-06-28 22:36:10.035 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Alexa,name=EventProcessed,handler=0x315ea50,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0351 2021-06-28 22:36:10.035 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetMute,handler=0x31901b0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0351 2021-06-28 22:36:10.035 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=SetVolume,handler=0x31901b0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0352 2021-06-28 22:36:10.035 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Speaker,name=AdjustVolume,handler=0x31901b0,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0353 2021-06-28 22:36:10.035 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=ClearIndicator,handler=0x33b0458,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0353 2021-06-28 22:36:10.035 [ d] 9 DirectiveRouter:addDirectiveHandlers:action=added,namespace=Notifications,name=SetIndicator,handler=0x33b0458,policy= Mediums:MEDIUMS_NONE00 .isBlocking:False I 15:36:10.0356 2021-06-28 22:36:10.035 [ d] 5 CapabilitiesDelegate:addOrUpdateEndpoint I 15:36:10.0364 2021-06-28 22:36:10.036 [ d] 2 EndpointRegistrationManager:executeRegisterEndpoint:result=finished I 15:36:10.0365 2021-06-28 22:36:10.036 [ e] 5 CapabilitiesDelegate:executeSendPendingEndpoints I 15:36:10.0366 2021-06-28 22:36:10.036 [ 1] 5 AVSGatewayManager:setAVSGatewayAssigner I 15:36:10.0366 2021-06-28 22:36:10.036 [ e] 5 CapabilitiesDelegate:executeSendPendingEndpoints:Deferred=Not connected I 15:36:10.0366 2021-06-28 22:36:10.036 [ 1] I MessageRouter:setAVSGateway:avsGateway=https\://alexa.na.gateway.devices.a2z.com I 15:36:10.0367 2021-06-28 22:36:10.036 [ 1] I MessageRouter:enable I 15:36:10.0367 2021-06-28 22:36:10.036 [ 1] I MessageRouter:setConnectionStatusLocked:status=PENDING,reason=ACL_CLIENT_REQUEST I 15:36:10.0373 2021-06-28 22:36:10.037 [ 1] I MessageRouter:createActiveTransportLocked:transport=0x32bbcb0,sizeOf m_transports=0 I 15:36:10.0373 2021-06-28 22:36:10.037 [ 1] I HTTP2Transport:connect:this=0x32bbcb0 I 15:36:10.0373 2021-06-28 22:36:10.037 [ 1] I HTTP2Transport:setStateLocked:this=0x32bbcb0,currentState=INIT,newState=AUTHORIZING,changedReason=ACL_CLIENT_REQUEST I 15:36:10.0375 2021-06-28 22:36:10.037 [ 1] I MessageRouter:setAsActiveTransport:transport=0x32bbcb0,sizeOf m_transports=1 I 15:36:10.0377 2021-06-28 22:36:10.037 [ 7] 5 CapabilitiesDelegate:onConnectionStatusChanged:connectionStatus=PENDING I 15:36:10.0378 2021-06-28 22:36:10.037 [ 1] 5 PulseAudioBluetoothInitializer:~PulseAudioBluetoothInitializer I 15:36:10.0378 2021-06-28 22:36:10.037 [ 1] 5 PulseAudioBluetoothInitializer:cleanup I 15:36:10.0378 2021-06-28 22:36:10.037 [ 1] 0 PulseAudioBluetoothInitializer:cleanup::cleanupCompleted I 15:36:10.0379 2021-06-28 22:36:10.037 [ 7] 5 CertifiedSender:onConnectionStatusChanged I 15:36:10.0379 2021-06-28 22:36:10.037 [ 1c] 5 AVSGatewayManager:createPostConnectOperation I 15:36:10.0380 onConnectionStatusChanged: PENDING I 15:36:10.0381 2021-06-28 22:36:10.037 [ b] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=PENDING,reason=ACL_CLIENT_REQUEST T 15:36:10.0382 #############################

Connecting...

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

I 15:36:10.0382 2021-06-28 22:36:10.038 [ 1c] 5 AVSGatewayManager:createPostConnectOperation::Gateway already verified, skipping gateway verification step I 15:36:10.0383 Initializing bleserver I 15:36:10.0384 2021-06-28 22:36:10.038 [ 7] 5 SoftwareInfoSender:onConnectionStatusChanged:status=PENDING,reason=ACL_CLIENT_REQUEST I 15:36:10.0384 2021-06-28 22:36:10.038 [ 1c] 5 SynchronizeStateSenderFactory:createPostConnectOperation I 15:36:10.0385 2021-06-28 22:36:10.038 [ 1c] 5 PostConnectSynchronizeStateSender:create D 15:36:10.0385 void DopplerIOService::start() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:82) Started Thread A2DPSrvc I 15:36:10.0386 Starting with Discoverable Mode off I 15:36:10.0387 2021-06-28 22:36:10.038 [ 1] 5 BlueZHostController:exitDiscoverableMode I 15:36:10.0387 2021-06-28 22:36:10.038 [ 1c] 5 CapabilitiesDelegate:createPostConnectOperation I 15:36:10.0388 2021-06-28 22:36:10.038 [ 1] 5 BlueZHostController:setDiscoverable:discoverable=false I 15:36:10.0388 2021-06-28 22:36:10.038 [ 1c] 5 CapabilitiesDelegate:resetCurrentDiscoveryEventSender I 15:36:10.0389 2021-06-28 22:36:10.038 [ 1c] 5 CapabilitiesDelegate:moveInFlightEndpointsToPendingLocked I 15:36:10.0390 2021-06-28 22:36:10.038 [ 1c] 5 SQLiteCapabilitiesDelegateStorage:load I 15:36:10.0392 2021-06-28 22:36:10.039 [ 1c] 5 CapabilitiesDelegate:createPostConnectOperation:num endpoints stored=1 I 15:36:10.0392 2021-06-28 22:36:10.039 [ 1c] 5 CapabilitiesDelegate:filterUnchangedPendingAddOrUpdateEndpointsLocked I 15:36:10.0394 Initializing Modeservice D 15:36:10.0395 void DopplerIOService::start() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:82) Started Thread ModeSrvc I 15:36:10.0395 At Mode Service conditional initialization to normal. D 15:36:10.0396 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:228) Shared ptr use count is 0 D 15:36:10.0397 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:233) Spinning up mode NORMAL I 15:36:10.0397 2021-06-28 22:36:10.039 [ 1] 5 SharedAVSSettingProtocol:localChange:setting=Alerts\:\:alarmVolumeRamp I 15:36:10.0398 2021-06-28 22:36:10.039 [ 1c] 9 CapabilitiesDelegate:filterUnchangedPendingAddOrUpdateEndpointsLocked:step=endpoint not be included in addOrUpdateReport I 15:36:10.0399 sampleApplication->run() I 15:36:10.0399 2021-06-28 22:36:10.039 [ 1c] 5 CapabilitiesDelegate:addStaleEndpointsToPendingDeleteLocked I 15:36:10.0400 2021-06-28 22:36:10.040 [ 16] 5 SQLiteDeviceSettingStorage:storeSetting:key=Alerts\:\:alarmVolumeRamp,status=LOCAL_CHANGE_IN_PROGRESS T 15:36:10.0400 ##############################################

AlarmVolumeRamp is "ASCENDING"

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

D 15:36:10.0401 void alexaClientSDK::VolumeService::init(std::shared_ptr, std::shared_ptr, std::shared_ptr, std::shared_ptr) (/home/lynnes/workspace/doppler/src/VolumeService.cpp:60) Getting Alexa Mute state I 15:36:10.0401 2021-06-28 22:36:10.040 [ 1c] 5 CapabilitiesDelegate:setCapabilitiesState:newCapabilitiesState=SUCCESS T 15:36:10.0401 

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

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

   SDK Version 1.24.0
I 15:36:10.0402 2021-06-28 22:36:10.040 [ 1c] 9 CapabilitiesDelegate:callingOnCapabilitiesStateChange:state=SUCCESS,error=SUCCESS T 15:36:10.0403 +----------------------------------------------------------------------------+ Options: Wake word: Simply say Alexa and begin your query. Tap to talk: Press 't' and Enter followed by your query (no need for the 'Alexa'). Hold to talk: Press 'h' followed by Enter to simulate holding a button. Then say your query (no need for the 'Alexa'). Press 'h' followed by Enter to simulate releasing a button. Stop an interaction: Press 's' and Enter to stop an ongoing interaction. Privacy mode (microphone off): Press 'm' and Enter to turn on and off the microphone. Playback Controls: Press '1' for a 'PLAY' button press. Press '2' for a 'PAUSE' button press. Press '3' for a 'NEXT' button press. Press '4' for a 'PREVIOUS' button press. Settings: Press 'c' followed by Enter at any time to see the settings screen. Speaker Control: Press 'p' followed by Enter at any time to adjust speaker settings. Firmware Version: Press 'f' followed by Enter at any time to report a different firmware version. Info: Press 'i' followed by Enter at any time to see the help screen. Reset device: Press 'k' followed by Enter at any time to reset your device. This will erase any data stored in the device and you will have to re-register your device. This option will also exit the application. Reauthorize device: Press 'z' followed by Enter at any time to re-authorize your device. This will erase any data stored in the device and initiate re-authorization. Device Setup Complete: Press 'v' followed by Enter at any time to indicate that device setup is complete.
Quit:
Press 'q' followed by Enter at any time to quit the application.

+----------------------------------------------------------------------------+

I 15:36:10.0404 CAPABILITIES CHANGE! SUCCESS : SUCCESS I 15:36:10.0405 State retrieved successfully I 15:36:10.0405 2021-06-28 22:36:10.040 [ 1c] 5 EndpointRegistrationManager:onCapabilitiesStateChange:state=SUCCESS,error=SUCCESS,callback=true T 15:36:10.0405 #######################################################

Successfully registered 1 endpoint(s).

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

I 15:36:10.0406 2021-06-28 22:36:10.040 [ 1c] 5 EndpointRegistrationManager:onCapabilityRegistrationStatusChanged I 15:36:10.0406 Alarms retrieved successfully I 15:36:10.0407 2021-06-28 22:36:10.040 [ 1c] 5 CapabilitiesDelegate:createPostConnectOperation::No change in Capabilities, skipping post connect step D 15:36:10.0408 void alexaClientSDK::VolumeService::init(std::shared_ptr, std::shared_ptr, std::shared_ptr, std::shared_ptr) (/home/lynnes/workspace/doppler/src/VolumeService.cpp:75) ->Mute is 0 I 15:36:10.0419 2021-06-28 22:36:10.040 [ d] 9 EndpointRegistrationManager:updateAddedOrUpdatedEndpoints:result=success I 15:36:10.0421 2021-06-28 22:36:10.042 [ 1c] I HTTP2Transport:handleAuthorizing:this=0x32bbcb0 I 15:36:10.0422 2021-06-28 22:36:10.042 [ 1c] I HTTP2Transport:onAuthStateChange:this=0x32bbcb0,newState=REFRESHED,error=SUCCESS I 15:36:10.0422 2021-06-28 22:36:10.042 [ 1c] I HTTP2Transport:setStateLocked:this=0x32bbcb0,currentState=AUTHORIZING,newState=CONNECTING,changedReason=SUCCESS I 15:36:10.0423 2021-06-28 22:36:10.042 [ 1d] 5 PostConnectSynchronizeStateSender:performOperation I 15:36:10.0423 2021-06-28 22:36:10.042 [ 1c] I HTTP2Transport:handleConnecting:this=0x32bbcb0 I 15:36:10.0424 2021-06-28 22:36:10.042 [ 1d] 5 PostConnectSynchronizeStateSender:fetchContext I 15:36:10.0424 2021-06-28 22:36:10.042 [ 1d] 5 ContextManager:getContext I 15:36:10.0425 2021-06-28 22:36:10.042 [ 1d] 5 ContextManager:getContextInternal I 15:36:10.0431 2021-06-28 22:36:10.043 [ 18] 5 VisualActivityTracker:provideState I 15:36:10.0433 2021-06-28 22:36:10.043 [ 13] 5 VisualActivityTracker:executeProvideState I 15:36:10.0433 2021-06-28 22:36:10.043 [ 13] 5 ContextManager:setState I 15:36:10.0435 2021-06-28 22:36:10.043 [ 18] 5 NotificationsCapabilityAgent:provideState:stateRequestToken=1 sh: 1: /opt/doppler/bin/run_gpioset20: not found I 15:36:10.0436 2021-06-28 22:36:10.043 [ 6] 5 NotificationsCapabilityAgent:executeProvideState:sendToken=true,stateRequestToken=1,isEnabled=false I 15:36:10.0437 2021-06-28 22:36:10.043 [ 6] 5 ContextManager:setState I 15:36:10.0437 2021-06-28 22:36:10.043 [ 10] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=1 D 15:36:10.0437 void alexaClientSDK::VolumeService::init(std::shared_ptr, std::shared_ptr, std::shared_ptr, std::shared_ptr) (/home/lynnes/workspace/doppler/src/VolumeService.cpp:91) Setting Mute button to white on startup I 15:36:10.0438 2021-06-28 22:36:10.043 [ 18] 9 SpeechSynthesizer:provideState:token=1 I 15:36:10.0438 2021-06-28 22:36:10.043 [ 10] 5 ExternalMediaPlayer:notifyRenderPlayerInfoCardsObservers I 15:36:10.0439 db volume is 61 I 15:36:10.0439 2021-06-28 22:36:10.043 [ 18] 0 AudioPlayer:provideState:stateRequestToken=1 I 15:36:10.0440 Installing Network Log Dispatcher W 15:36:10.0440 CALLING CHANGE VOLUME INTERNAL 61 I 15:36:10.0441 2021-06-28 22:36:10.043 [ 1b] 0 SpeechSynthesizer:executeProvideState:stateRequestToken=1,state=FINISHED I 15:36:10.0442 2021-06-28 22:36:10.043 [ 10] 0 ExternalMediaPlayer:executeProvideState:providePlaybackState={"state"\:"IDLE"\,"supportedOperations"\:[]\,"shuffle"\:"NOT_SHUFFLED"\,"repeat"\:"NOT_REPEATED"\,"favorite"\:"NOT_RATED"\,"positionMilliseconds"\:0\,"players"\:[]} I 15:36:10.0442 2021-06-28 22:36:10.044 [ 18] 5 AudioActivityTracker:provideState I 15:36:10.0443 2021-06-28 22:36:10.044 [ 12] 0 AudioPlayer:executeProvideState:sendToken=true,stateRequestToken=1 I 15:36:10.0443 2021-06-28 22:36:10.044 [ 8] 9 SpeakerManager:setMute:mute=false I 15:36:10.0444 2021-06-28 22:36:10.044 [ 10] 5 ContextManager:setState I 15:36:10.0444 2021-06-28 22:36:10.044 [ 1b] 5 ContextManager:setState I 15:36:10.0445 2021-06-28 22:36:10.044 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=7 I 15:36:10.0446 2021-06-28 22:36:10.044 [ 1e] 5 AudioActivityTracker:executeProvideState I 15:36:10.0447 2021-06-28 22:36:10.044 [ 12] 5 ContextManager:setState CALLING LOG ROLLING HANDLER: doppler.log thyme-oldTime was: 2820101567LOG WAS RECENTLY ROTATED. APPENDING SO remote_syslog2 HAS A CHANCE TO UPDATECALLING LOG APPENDER: doppler.log rolling command was cat doppler.log >> old-doppler.log echo command was echo 'Beginning of logAppender output' >> old-doppler.log I 15:36:10.0527 2021-06-28 22:36:10.044 [ 1f] 9 SpeakerManager:executeSetMuteCalled:mute=false I 15:36:10.0528 2021-06-28 22:36:10.044 [ 1e] 5 ContextManager:setState I 15:36:10.0528 2021-06-28 22:36:10.044 [ 10] 0 ExternalMediaPlayer:executeProvideState:sendToken=true,stateRequestToken=1 I 15:36:10.0529 2021-06-28 22:36:10.044 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=6 I 15:36:10.0530 2021-06-28 22:36:10.052 [ 1f] 9 SpeakerManager:executeGetSpeakerSettingsCalled I 15:36:10.0530 2021-06-28 22:36:10.052 [ 10] 0 ExternalMediaPlayer:executeProvideState:provideSessionState={"agent"\:"CQCAFYNYDC"\,"spiVersion"\:"1.0"\,"playerInFocus"\:""\,"players"\:[]} I 15:36:10.0531 2021-06-28 22:36:10.053 [ 1f] 5 SpeakerManager:executeSetMute::Device is already unmuted I 15:36:10.0531 2021-06-28 22:36:10.053 [ 10] 5 ContextManager:setState I 15:36:10.0532 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=5 I 15:36:10.0533 2021-06-28 22:36:10.053 [ 8] 9 SpeakerManager:setVolume:volume=61 I 15:36:10.0533 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=4 I 15:36:10.0534 2021-06-28 22:36:10.053 [ 1f] 9 SpeakerManager:executeSetVolumeCalled:volume=61 I 15:36:10.0534 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=3 I 15:36:10.0535 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=2 I 15:36:10.0536 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:result=stateNotAvailableYet,pendingStates=1 I 15:36:10.0536 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:token=1 I 15:36:10.0537 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:skipping state for legacy capabilityIdentifier={endpointId:,namespace:VisualActivityTracker,name:ActivityState} I 15:36:10.0538 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked I 15:36:10.0539 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked I 15:36:10.0539 2021-06-28 22:36:10.053 [ 1f] 9 SpeakerManager:executeGetSpeakerSettingsCalled I 15:36:10.0540 2021-06-28 22:36:10.053 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked I 15:36:10.0540 2021-06-28 22:36:10.054 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:volume=61 I 15:36:10.0540 2021-06-28 22:36:10.054 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked I 15:36:10.0541 2021-06-28 22:36:10.054 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:Unducked Channel Volume=61 I 15:36:10.0541 2021-06-28 22:36:10.054 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked I 15:36:10.0541 2021-06-28 22:36:10.054 [ 1f] 9 MediaPlayer:setVolumeCalled:name=SpeakMediaPlayer I 15:36:10.0542 2021-06-28 22:36:10.054 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked I 15:36:10.0542 2021-06-28 22:36:10.054 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked:skipping state for legacy capabilityIdentifier={endpointId:,namespace:AudioActivityTracker,name:ActivityState} I 15:36:10.0543 2021-06-28 22:36:10.054 [ 17] 9 MediaPlayer:handleSetVolumeCalled:name=SpeakMediaPlayer I 15:36:10.0543 2021-06-28 22:36:10.054 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked I 15:36:10.0543 2021-06-28 22:36:10.054 [ 18] 5 ContextManager:getContextAvailableCallbackIfReadyLocked I 15:36:10.0544 2021-06-28 22:36:10.054 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:volume=61 I 15:36:10.0544 2021-06-28 22:36:10.054 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:Unducked Channel Volume=61 I 15:36:10.0544 2021-06-28 22:36:10.054 [ 1f] 9 MediaPlayer:setVolumeCalled:name=RingtoneMediaPlayer I 15:36:10.0545 2021-06-28 22:36:10.054 [ 19] 9 MediaPlayer:handleSetVolumeCalled:name=RingtoneMediaPlayer I 15:36:10.0545 2021-06-28 22:36:10.054 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:volume=61 I 15:36:10.0545 2021-06-28 22:36:10.054 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:Unducked Channel Volume=61 I 15:36:10.0546 2021-06-28 22:36:10.054 [ 1f] 9 MediaPlayer:setVolumeCalled:name=SystemSoundMediaPlayer I 15:36:10.0547 2021-06-28 22:36:10.054 [ 15] 9 MediaPlayer:handleSetVolumeCalled:name=SystemSoundMediaPlayer I 15:36:10.0548 2021-06-28 22:36:10.054 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:volume=61 I 15:36:10.0549 2021-06-28 22:36:10.054 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:Unducked Channel Volume=61 I 15:36:10.0549 2021-06-28 22:36:10.054 [ 18] 5 PostConnectSynchronizeStateSender:onContextAvailable I 15:36:10.0549 2021-06-28 22:36:10.054 [ 1f] 9 MediaPlayer:setVolumeCalled:name=AudioMediaPlayer I 15:36:10.0550 2021-06-28 22:36:10.055 [ 9] 9 MediaPlayer:handleSetVolumeCalled:name=AudioMediaPlayer I 15:36:10.0551 2021-06-28 22:36:10.055 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:volume=61 I 15:36:10.0551 2021-06-28 22:36:10.055 [ 1f] 5 ChannelVolumeManager:setUnduckedVolume:Unducked Channel Volume=61 I 15:36:10.0551 2021-06-28 22:36:10.055 [ 1f] 9 MediaPlayer:setVolumeCalled:name=BluetoothMediaPlayer I 15:36:10.0552 2021-06-28 22:36:10.055 [ c] 9 MediaPlayer:handleSetVolumeCalled:name=BluetoothMediaPlayer I 15:36:10.0553 2021-06-28 22:36:10.055 [ 1f] 9 SpeakerManager:executeSetSpeakerSettingsCalled I 15:36:10.0553 2021-06-28 22:36:10.055 [ 1f] 0 SpeakerManager:executeSetVolumeSuccess:newVolume=61 I 15:36:10.0554 2021-06-28 22:36:10.055 [ 1f] 9 SpeakerManager:updateContextManagerCalled:speakerType=AVS_SPEAKER_VOLUME I 15:36:10.0554 2021-06-28 22:36:10.055 [ 1f] 5 ContextManager:setState I 15:36:10.0555 2021-06-28 22:36:10.055 [ 1f] 9 SpeakerManager:executeNotifyObserverCalled D 15:36:10.0555 bool alexaClientSDK::VolumeService::setSavedVolume(int) (/home/lynnes/workspace/doppler/src/VolumeService.cpp:240) Setting volume in database to 61 D 15:36:10.0568 void DopplerIOService::start() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:82) Started Thread NormalMode(Srvc) D 15:36:10.0568 void DopplerIOService::start() (/home/lynnes/workspace/libpai/DopplerIOService.cpp:82) Started Thread NetLogDispatch D 15:36:10.0569 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:235) Registering Handlers 15:36:10.057 DOPPLER_STARTUP: D 15:36:10.0571 void ModeService::setModeInternal(Mode, int) (/home/lynnes/workspace/doppler/src/ModeService.cpp:237) Setting up Graphics I 15:36:10.0572 newMode is NORMAL I 15:36:10.0572 registering handlers in normalmode service D 15:36:10.0572 std::__cxx11::string FirmwareVersionObserver::getFirmwareVersion() (/home/lynnes/workspace/doppler/src/FirmwareVersionObserver.cpp:24) Firmware version observer returned 15:36:10.057 SOFTWARE_FIRMARE_VERSIONS:Doppler 0.9.11 Ahab psoc D 15:36:10.0574 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:999) Searching observerlist in internaldataparser D 15:36:10.0574 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:1004) Added Button observer in internaldataparser I 15:36:10.0574 registering handlers idp postaddbuttonobserver normalmodeservice D 15:36:10.0575 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:999) Searching observerlist in internaldataparser D 15:36:10.0575 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:1004) Added Button observer in internaldataparser I 15:36:10.0575 registering handlers idp postaddbuttonobserver timeservice D 15:36:10.0576 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:999) Searching observerlist in internaldataparser D 15:36:10.0576 bool InternalDataParser::addButtonObserver(std::shared_ptr) (/home/lynnes/workspace/doppler/src/InternalDataParser.cpp:1004) Added Button observer in internaldataparser I 15:36:10.0576 registering handlers idp postaddbuttonobserver volumeservice I 15:36:10.0577 running setup graphics in normalmodeservice W 15:36:10.0577 SETUP GRAPHICS FOR NORMAL MODE WAS BOGUS... WHAT IS BROKEN HERE NOW??? I 15:36:10.0713 Volume changed successfully W 15:36:10.0715 No login key to MQTT server detected, putting paho service in key generation loop. I 15:36:10.0716 2021-06-28 22:36:10.071 [ 1f] 9 SpeakerManager:executeSendSpeakerSettingsChangedEvent T 15:36:10.0717 #########################################################################

SOURCE:LOCAL_API TYPE:AVS_SPEAKER_VOLUME VOLUME:61 MUTE:0

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

15:36:10.071 VOLUME_CHANGED:61 W 15:36:10.0719 RSBS createAnimation: [do_med_percentage_disp61|min 1|max 95|40000000] I 15:36:10.0719 2021-06-28 22:36:10.071 [ 16] 5 SettingEventSender:buildEventJson:eventName=AlarmVolumeRampChanged T 15:36:10.0720 ##############################################

AlarmVolumeRamp is "ASCENDING"

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

I 15:36:10.0725 2021-06-28 22:36:10.072 [ 16] 7 SettingEventSender:sendEvent:attempt=0 I 15:36:11.3031 2021-06-28 22:36:11.303 [ 20] I HTTP2Transport:onDownchannelConnected:this=0x32bbcb0 I 15:36:11.3031 2021-06-28 22:36:11.303 [ 20] I HTTP2Transport:setStateLocked:this=0x32bbcb0,currentState=CONNECTING,newState=POST_CONNECTING,changedReason=SUCCESS I 15:36:11.3033 2021-06-28 22:36:11.303 [ 1c] I HTTP2Transport:handlePostConnecting:this=0x32bbcb0 I 15:36:11.6635 2021-06-28 22:36:11.663 [ 1d] 5 PostConnectSynchronizeStateSender:performOperation:SynchronizeState event status=SUCCESS_NO_CONTENT I 15:36:11.6636 2021-06-28 22:36:11.663 [ 1d] I HTTP2Transport:onPostConnected:this=0x32bbcb0 I 15:36:11.6637 2021-06-28 22:36:11.663 [ 1d] I HTTP2Transport:setStateLocked:this=0x32bbcb0,currentState=POST_CONNECTING,newState=CONNECTED,changedReason=SUCCESS I 15:36:11.6638 2021-06-28 22:36:11.663 [ 1c] I HTTP2Transport:handleConnected:this=0x32bbcb0 I 15:36:11.6641 2021-06-28 22:36:11.664 [ 1c] I MessageRouter:onConnected:transport=0x32bbcb0,m_activeTransport=0x32bbcb0 I 15:36:11.6641 2021-06-28 22:36:11.664 [ 1c] I MessageRouter:setConnectionStatusLocked:status=CONNECTED,reason=ACL_CLIENT_REQUEST I 15:36:11.6644 2021-06-28 22:36:11.664 [ e] 5 CapabilitiesDelegate:onConnectionStatusChanged:connectionStatus=CONNECTED I 15:36:11.6645 2021-06-28 22:36:11.664 [ 3] 5 ReportStateHandler:sendReportState:pendingReport=false I 15:36:11.6646 2021-06-28 22:36:11.664 [ e] 5 CertifiedSender:onConnectionStatusChanged I 15:36:11.6647 2021-06-28 22:36:11.664 [ 7] 5 CapabilitiesDelegate:executeSendPendingEndpoints I 15:36:11.6647 onConnectionStatusChanged: CONNECTED I 15:36:11.6648 2021-06-28 22:36:11.664 [ 13] 1 AlertsCapabilityAgent:executeOnConnectionStatusChanged:status=CONNECTED,reason=ACL_CLIENT_REQUEST T 15:36:11.6649 ########################################

Alexa is currently idle!

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

I 15:36:11.6649 2021-06-28 22:36:11.664 [ 7] 5 CapabilitiesDelegate:executeSendPendingEndpoints:Skipped=No endpoints to register or delete I 15:36:11.6650 2021-06-28 22:36:11.664 [ 13] 9 SQLiteAlertStorage:Loading offline alerts I 15:36:11.6652 2021-06-28 22:36:11.665 [ e] 5 SoftwareInfoSender:onConnectionStatusChanged:status=CONNECTED,reason=ACL_CLIENT_REQUEST I 15:36:11.6652 2021-06-28 22:36:11.665 [ e] 5 SoftwareInfoSendRequest:create:firmwareVersion=123 I 15:36:11.6654 2021-06-28 22:36:11.665 [ 1e] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer\:\:wakeWordConfirmation I 15:36:11.6654 2021-06-28 22:36:11.665 [ e] 5 SoftwareInfoSendRequest:send:firmwareVersion=123 I 15:36:11.6655 2021-06-28 22:36:11.665 [ 1e] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:11.6656 2021-06-28 22:36:11.665 [ 1e] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=SpeechRecognizer\:\:wakeWordConfirmation,synchronized=true I 15:36:11.6656 2021-06-28 22:36:11.665 [ 1e] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized I 15:36:11.6658 2021-06-28 22:36:11.665 [ b] 5 SQLiteDeviceSettingStorage:loadSetting:key=System\:\:timeZone I 15:36:11.6660 2021-06-28 22:36:11.665 [ 18] 5 SQLiteDeviceSettingStorage:loadSetting:key=System\:\:networkInfo I 15:36:11.6661 2021-06-28 22:36:11.665 [ 10] 5 SQLiteDeviceSettingStorage:loadSetting:key=SpeechRecognizer\:\:speechConfirmation I 15:36:11.6662 2021-06-28 22:36:11.665 [ b] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:11.6662 2021-06-28 22:36:11.666 [ b] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=System\:\:timeZone,synchronized=true I 15:36:11.6663 2021-06-28 22:36:11.666 [ b] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized I 15:36:11.6664 2021-06-28 22:36:11.666 [ 18] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:11.6664 2021-06-28 22:36:11.666 [ 18] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=System\:\:networkInfo,synchronized=true I 15:36:11.6664 2021-06-28 22:36:11.666 [ 18] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized I 15:36:11.6665 2021-06-28 22:36:11.666 [ 10] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:11.6665 2021-06-28 22:36:11.666 [ 10] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=SpeechRecognizer\:\:speechConfirmation,synchronized=true I 15:36:11.6666 2021-06-28 22:36:11.666 [ 10] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized I 15:36:12.1153 2021-06-28 22:36:12.115 [ 16] 7 SettingEventSender:sendEvent:status=SUCCESS_NO_CONTENT I 15:36:12.1155 2021-06-28 22:36:12.115 [ 16] 5 SQLiteDeviceSettingStorage:updateSettingStatus I 15:36:12.1317 2021-06-28 22:36:12.131 [ 16] 5 SQLiteDeviceSettingStorage:loadSetting:key=Alerts\:\:alarmVolumeRamp I 15:36:12.1318 2021-06-28 22:36:12.131 [ 16] 5 SQLiteDeviceSettingStorage:loadSetting I 15:36:12.1318 2021-06-28 22:36:12.131 [ 16] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:setting=Alerts\:\:alarmVolumeRamp,synchronized=true I 15:36:12.1318 2021-06-28 22:36:12.131 [ 16] 5 SharedAVSSettingProtocol:executeSynchronizeOnConnected:result=alreadySynchronized I 15:36:12.2711 2021-06-28 22:36:12.271 [ 20] 9 DNDMessageRequest:sendCompleted:Completed with status=SUCCESS_NO_CONTENT I 15:36:12.4550 2021-06-28 22:36:12.455 [ 20] 5 SoftwareInfoSendRequest:onSendCompleted:status=SUCCESS_NO_CONTENT I 15:36:20.8400 2021-06-28 22:36:20.839 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:20.8401 2021-06-28 22:36:20.840 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4 I 15:36:20.8401 2021-06-28 22:36:20.840 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.Device1'\, {'Connected'\: }\, @as []) I 15:36:20.8402 2021-06-28 22:36:20.840 [ a] 7 BlueZDeviceManager:onDevicePropertyChanged:path=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4 I 15:36:20.8403 2021-06-28 22:36:20.840 [ a] 5 BlueZBluetoothDevice:onPropertyChanged:values={'Connected'\: } I 15:36:20.8404 2021-06-28 22:36:20.840 [ a] 7 BlueZDeviceManager:onDevicePropertyChanged:finished=ok I 15:36:20.8405 2021-06-28 22:36:20.840 [ 1f] 5 BlueZBluetoothDevice:executeIsConnectedToRelevantServices I 15:36:20.8405 2021-06-28 22:36:20.840 [ 1f] 5 BlueZBluetoothDevice:getService:uuid=0000110b-0000-1000-8000-00805f9b34fb I 15:36:20.8406 2021-06-28 22:36:20.840 [ 1f] 0 BlueZBluetoothDevice:getService:reason=serviceNotFound I 15:36:20.8406 2021-06-28 22:36:20.840 [ 1f] 5 BlueZBluetoothDevice:getService:uuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:20.8407 2021-06-28 22:36:20.840 [ 1f] 5 BlueZBluetoothDevice:queryDeviceProperty:name=Paired I 15:36:20.8412 2021-06-28 22:36:20.841 [ 1f] 5 BlueZBluetoothDevice:queryDeviceProperty:name=Connected I 15:36:20.8416 2021-06-28 22:36:20.841 [ 1f] 5 BlueZBluetoothDevice:transitionToState:oldState=IDLE,newState=CONNECTED,sendEvent=true I 15:36:20.8417 2021-06-28 22:36:20.841 [ 1f] 5 Bluetooth:onEventFired I 15:36:20.8418 2021-06-28 22:36:20.841 [ 1f] 5 BlueZBluetoothDevice:getMac I 15:36:20.8419 2021-06-28 22:36:20.841 [ 1f] I Bluetooth:onEventFired:event=DEVICE_STATE_CHANGED,mac=XX\:XX\:XX\:XX\:2B\:A4,state=CONNECTED I 15:36:20.8419 2021-06-28 22:36:20.841 [ 1f] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:20.8419 2021-06-28 22:36:20.841 [ 1f] 5 Bluetooth:onEventFired:friendlyName=Galaxy S10+ I 15:36:20.8421 2021-06-28 22:36:20.842 [ 8] 5 BlueZBluetoothDevice:getMac I 15:36:20.8422 2021-06-28 22:36:20.842 [ 8] 5 Bluetooth:executeRemoveBluetoothEventState:reason=noDeviceFound I 15:36:20.8422 2021-06-28 22:36:20.842 [ 8] 5 BlueZBluetoothDevice:getMac I 15:36:20.8423 2021-06-28 22:36:20.842 [ 8] 5 Bluetooth:retrieveUuid I 15:36:20.8423 2021-06-28 22:36:20.842 [ 8] 5 SQLiteBluetoothStorage:getUuid I 15:36:20.8423 2021-06-28 22:36:20.842 [ 8] 5 SQLiteBluetoothStorage:getAssociatedDataLocked I 15:36:20.8424 2021-06-28 22:36:20.842 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8425 2021-06-28 22:36:20.842 [ 8] 5 Bluetooth:retrieveDeviceCategoryByUuid I 15:36:20.8425 2021-06-28 22:36:20.842 [ 8] 5 SQLiteBluetoothStorage:getCategory I 15:36:20.8426 2021-06-28 22:36:20.842 [ 8] 5 SQLiteBluetoothStorage:getAssociatedDataLocked I 15:36:20.8426 2021-06-28 22:36:20.842 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8427 2021-06-28 22:36:20.842 [ 8] 5 Bluetooth:executeOnDeviceConnect I 15:36:20.8427 2021-06-28 22:36:20.842 [ 8] 5 BlueZBluetoothDevice:getMac I 15:36:20.8428 2021-06-28 22:36:20.842 [ 8] 5 Bluetooth:retrieveUuid I 15:36:20.8428 2021-06-28 22:36:20.842 [ 8] 5 SQLiteBluetoothStorage:getUuid I 15:36:20.8428 2021-06-28 22:36:20.842 [ 8] 5 SQLiteBluetoothStorage:getAssociatedDataLocked I 15:36:20.8429 2021-06-28 22:36:20.842 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8430 2021-06-28 22:36:20.842 [ 8] 5 Bluetooth:retrieveDeviceCategoryByUuid I 15:36:20.8430 2021-06-28 22:36:20.843 [ 8] 5 SQLiteBluetoothStorage:getCategory I 15:36:20.8430 2021-06-28 22:36:20.843 [ 8] 5 SQLiteBluetoothStorage:getAssociatedDataLocked I 15:36:20.8431 2021-06-28 22:36:20.843 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8431 2021-06-28 22:36:20.843 [ 8] 5 Bluetooth:executeOnDeviceConnect:uuid=6a2fa3cc-a6c5-438c-9f2d-a055627eb211,deviceCategory=UNKNOWN I 15:36:20.8432 2021-06-28 22:36:20.843 [ 8] 5 Bluetooth:retrieveConnectionRuleByUuid I 15:36:20.8432 2021-06-28 22:36:20.843 [ 8] 5 Bluetooth:retrieveDeviceCategoryByUuid I 15:36:20.8432 2021-06-28 22:36:20.843 [ 8] 5 SQLiteBluetoothStorage:getCategory I 15:36:20.8432 2021-06-28 22:36:20.843 [ 8] 5 SQLiteBluetoothStorage:getAssociatedDataLocked I 15:36:20.8433 2021-06-28 22:36:20.843 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8434 2021-06-28 22:36:20.843 [ 8] 5 Bluetooth:getService:uuid=0000110b-0000-1000-8000-00805f9b34fb I 15:36:20.8435 2021-06-28 22:36:20.843 [ 8] 5 BlueZBluetoothDevice:getService:uuid=0000110b-0000-1000-8000-00805f9b34fb I 15:36:20.8435 2021-06-28 22:36:20.843 [ 8] 0 BlueZBluetoothDevice:getService:reason=serviceNotFound I 15:36:20.8435 2021-06-28 22:36:20.843 [ 8] 5 Bluetooth:getService:uuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:20.8436 2021-06-28 22:36:20.843 [ 8] 5 BlueZBluetoothDevice:getService:uuid=0000110a-0000-1000-8000-00805f9b34fb I 15:36:20.8437 2021-06-28 22:36:20.843 [ 8] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:20.8438 2021-06-28 22:36:20.843 [ 8] 5 BlueZBluetoothDevice:getSupportedServices I 15:36:20.8439 2021-06-28 22:36:20.843 [ 8] 5 BlueZBluetoothDevice:getMac T 15:36:20.8441 ###########################################################################################

BLUETOOTH DEVICE CONNECTED

Name: Galaxy S10+

SUPPORTED SERVICES: AudioSource, A/V_RemoteControlTarget, A/V_RemoteControl

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

15:36:20.844 BLUETOOTH_A2DP device connected: Galaxy S10+ I 15:36:20.8443 2021-06-28 22:36:20.844 [ 8] 5 SQLiteBluetoothStorage:insertByMac I 15:36:20.8443 2021-06-28 22:36:20.844 [ 8] 5 SQLiteBluetoothStorage:getAssociatedDataLocked I 15:36:20.8444 2021-06-28 22:36:20.844 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked W 15:36:20.8445 RSBS createAnimation: [pri_alexa_bluetooth_animation|min 0|max 53|40000000] I 15:36:20.8527 2021-06-28 22:36:20.852 [ 8] 5 BlueZBluetoothDevice:getMac I 15:36:20.8527 2021-06-28 22:36:20.852 [ 8] 5 Bluetooth:retrieveUuid I 15:36:20.8527 2021-06-28 22:36:20.852 [ 8] 5 SQLiteBluetoothStorage:getUuid I 15:36:20.8528 2021-06-28 22:36:20.852 [ 8] 5 SQLiteBluetoothStorage:getAssociatedDataLocked I 15:36:20.8528 2021-06-28 22:36:20.852 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8529 2021-06-28 22:36:20.852 [ 8] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:20.8530 2021-06-28 22:36:20.853 [ 8] 5 BlueZHostController:getFriendlyName I 15:36:20.8530 2021-06-28 22:36:20.853 [ 8] 5 SQLiteBluetoothStorage:getMacToUuid I 15:36:20.8530 2021-06-28 22:36:20.853 [ 8] 5 SQLiteBluetoothStorage:getMappingsLocked:key=mac,value=uuid I 15:36:20.8531 2021-06-28 22:36:20.853 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8532 2021-06-28 22:36:20.853 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8532 2021-06-28 22:36:20.853 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8532 2021-06-28 22:36:20.853 [ 8] I SQLiteBluetoothStorage:getSingleRowLocked:reason=getStepResultFailed I 15:36:20.8533 2021-06-28 22:36:20.853 [ 8] 5 SQLiteBluetoothStorage:getUuidToCategory I 15:36:20.8533 2021-06-28 22:36:20.853 [ 8] 5 SQLiteBluetoothStorage:getMappingsLocked:key=uuid,value=category I 15:36:20.8534 2021-06-28 22:36:20.853 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8534 2021-06-28 22:36:20.853 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8534 2021-06-28 22:36:20.853 [ 8] 9 SQLiteBluetoothStorage:getSingleRowLocked I 15:36:20.8535 2021-06-28 22:36:20.853 [ 8] I SQLiteBluetoothStorage:getSingleRowLocked:reason=getStepResultFailed I 15:36:20.8535 2021-06-28 22:36:20.853 [ 8] 5 BlueZDeviceManager:getDiscoveredDevices I 15:36:20.8536 2021-06-28 22:36:20.853 [ 8] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:20.8536 2021-06-28 22:36:20.853 [ 8] 5 BlueZBluetoothDevice:getMac I 15:36:20.8536 2021-06-28 22:36:20.853 [ 8] 5 BlueZBluetoothDevice:isPaired I 15:36:20.8538 2021-06-28 22:36:20.853 [ 1a] 5 BlueZBluetoothDevice:executeIsPaired I 15:36:20.8539 2021-06-28 22:36:20.853 [ 8] 9 Bluetooth:executeUpdateContext:friendlyName=iPhone,mac=44\:F2\:1B\:CB\:A1\:5D,paired=true I 15:36:20.8539 2021-06-28 22:36:20.853 [ 8] 5 BlueZBluetoothDevice:isPaired I 15:36:20.8540 2021-06-28 22:36:20.853 [ 1a] 5 BlueZBluetoothDevice:executeIsPaired I 15:36:20.8540 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getMac I 15:36:20.8541 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:20.8541 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getSupportedServices I 15:36:20.8541 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getDeviceState I 15:36:20.8543 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:20.8543 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getMac I 15:36:20.8543 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:isPaired I 15:36:20.8544 2021-06-28 22:36:20.854 [ 1f] 5 BlueZBluetoothDevice:executeIsPaired I 15:36:20.8545 2021-06-28 22:36:20.854 [ 8] 9 Bluetooth:executeUpdateContext:friendlyName=Galaxy S10+,mac=74\:9E\:F5\:1A\:2B\:A4,paired=true I 15:36:20.8545 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:isPaired I 15:36:20.8546 2021-06-28 22:36:20.854 [ 1f] 5 BlueZBluetoothDevice:executeIsPaired I 15:36:20.8546 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getMac I 15:36:20.8547 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getFriendlyName I 15:36:20.8547 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getSupportedServices I 15:36:20.8548 2021-06-28 22:36:20.854 [ 8] 5 BlueZBluetoothDevice:getDeviceState I 15:36:20.8549 2021-06-28 22:36:20.854 [ 8] 9 Bluetooth:executeUpdateContext I 15:36:20.8549 2021-06-28 22:36:20.854 [ 8] 5 ContextManager:setState I 15:36:20.8550 2021-06-28 22:36:20.855 [ 8] 5 Bluetooth:executeSendEvent:eventName=ConnectByDeviceIdsSucceeded I 15:36:20.8552 2021-06-28 22:36:20.855 [ 8] 5 Bluetooth:onExecuteSendEventLambda:event={"event"\:{"header"\:{"namespace"\:"Bluetooth"\,"name"\:"ConnectByDeviceIdsSucceeded"\,"messageId"\:"ba3689b1-d57d-4831-8677-07060a54a647"}\,"payload"\:{"devices"\:[{"uniqueDeviceId"\:"6a2fa3cc-a6c5-438c-9f2d-a055627eb211"\,"friendlyName"\:"Galaxy S10+"}]\,"requester"\:"DEVICE"}}} I 15:36:23.2106 2021-06-28 22:36:23.210 [ a] 7 DBusObjectBase:onMethodCalledInternal:methodName=AuthorizeService I 15:36:23.2108 2021-06-28 22:36:23.210 [ a] 5 PairingAgent:authorizeService I 15:36:23.3893 2021-06-28 22:36:23.389 [ a] 7 DBusObjectBase:onMethodCalledInternal:methodName=AuthorizeService I 15:36:23.3894 2021-06-28 22:36:23.389 [ a] 5 PairingAgent:authorizeService I 15:36:23.6270 2021-06-28 22:36:23.627 [ a] 5 BlueZDeviceManager:interfacesAddedCallback I 15:36:23.6271 2021-06-28 22:36:23.627 [ a] 7 BlueZDeviceManager:onInterfaceAdded:path=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/fd6 I 15:36:23.6272 2021-06-28 22:36:23.627 [ a] 9 BlueZDeviceManager:onInterfaceAdded:Details={'org.freedesktop.DBus.Introspectable'\: @a{sv} {}\, 'org.bluez.MediaTransport1'\: {'Device'\: <objectpath '/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4'>\, 'UUID'\: <'0000110B-0000-1000-8000-00805F9B34FB'>\, 'Codec'\: <byte 0x00>\, 'Configuration'\: <[byte 0x21\, 0x15\, 0x02\, 0x35]>\, 'State'\: <'idle'>\, 'Volume'\: <uint16 127>}\, 'org.freedesktop.DBus.Properties'\: {}} I 15:36:23.6273 2021-06-28 22:36:23.627 [ a] 7 DBusObjectBase:onMethodCalledInternal:methodName=SetConfiguration I 15:36:23.6274 2021-06-28 22:36:23.627 [ a] 5 MediaEndpoint:onSetConfiguration I 15:36:23.6276 2021-06-28 22:36:23.627 [ a] 5 MediaEndpoint:Bluetooth stream parameters:numChannels=2,rate=44100 I 15:36:23.6276 2021-06-28 22:36:23.627 [ a] 3 MediaEndpoint:onSetConfiguration:mediaTransport=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/fd6 I 15:36:25.6338 2021-06-28 22:36:25.633 [ a] 5 BlueZDeviceManager:interfacesAddedCallback I 15:36:25.6339 2021-06-28 22:36:25.633 [ a] 7 BlueZDeviceManager:onInterfaceAdded:path=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/player0 I 15:36:25.6340 2021-06-28 22:36:25.633 [ a] 9 BlueZDeviceManager:onInterfaceAdded:Details={'org.freedesktop.DBus.Introspectable'\: @a{sv} {}\, 'org.bluez.MediaPlayer1'\: {'Position'\: <uint32 0>\, 'Device'\: <objectpath '/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4'>}\, 'org.freedesktop.DBus.Properties'\: {}} I 15:36:25.6340 2021-06-28 22:36:25.634 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:25.6340 2021-06-28 22:36:25.634 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4 I 15:36:25.6341 2021-06-28 22:36:25.634 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.MediaControl1'\, {'Player'\: <objectpath '/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/player0'>\, 'Connected'\: }\, @as []) I 15:36:26.1252 2021-06-28 22:36:26.125 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:26.1253 2021-06-28 22:36:26.125 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/player0 I 15:36:26.1254 2021-06-28 22:36:26.125 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.MediaPlayer1'\, {'Repeat'\: <'off'>\, 'Shuffle'\: <'off'>}\, @as []) I 15:36:26.2759 2021-06-28 22:36:26.275 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:26.2759 2021-06-28 22:36:26.275 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/player0 I 15:36:26.2760 2021-06-28 22:36:26.275 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.MediaPlayer1'\, {'Type'\: <'Audio'>\, 'Subtype'\: <'Audio Book'>\, 'Status'\: <'stopped'>\, 'Name'\: <'Media Player'>}\, @as []) I 15:36:26.2769 2021-06-28 22:36:26.276 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:26.2769 2021-06-28 22:36:26.276 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/fd6 I 15:36:26.2770 2021-06-28 22:36:26.277 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.MediaTransport1'\, {'Volume'\: <uint16 77>}\, @as []) I 15:36:26.2770 2021-06-28 22:36:26.277 [ a] 7 BlueZDeviceManager:onMediaStreamPropertyChanged:path=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/fd6 I 15:36:26.2779 2021-06-28 22:36:26.277 [ a] 9 DBusPropertiesProxy:getStringProperty:object=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/fd6,interface=org.bluez.MediaTransport1,property=UUID I 15:36:26.2783 2021-06-28 22:36:26.278 [ a] 5 BlueZDeviceManager:onMediaStreamPropertyChanged:mediaStreamUuid=0000110b-0000-1000-8000-00805f9b34fb I 15:36:26.2783 2021-06-28 22:36:26.278 [ a] 5 BlueZDeviceManager:mediaTransportStateUnchanged:action=ignoringCallback I 15:36:26.2784 2021-06-28 22:36:26.278 [ a] 7 BlueZUtils:~DBusProxy I 15:36:26.4198 2021-06-28 22:36:26.419 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:26.4199 2021-06-28 22:36:26.419 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/player0 I 15:36:26.4200 2021-06-28 22:36:26.419 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.MediaPlayer1'\, {'Track'\: <{'Title'\: <'Not Provided'>\, 'Duration'\: <uint32 0>\, 'Album'\: <''>\, 'TrackNumber'\: <uint32 1>\, 'Artist'\: <''>\, 'NumberOfTracks'\: <uint32 1>\, 'Genre'\: <''>}>}\, @as []) I 15:36:26.4882 2021-06-28 22:36:26.488 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:26.4882 2021-06-28 22:36:26.488 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/player0 I 15:36:26.4882 2021-06-28 22:36:26.488 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.MediaPlayer1'\, {'Position'\: <uint32 0>}\, @as []) I 15:36:26.6320 2021-06-28 22:36:26.631 [ a] 5 BlueZDeviceManager:propertiesChangedCallback I 15:36:26.6321 2021-06-28 22:36:26.632 [ a] 7 BlueZDeviceManager:Properties changed:objectPath=/org/bluez/hci0/dev_74_9E_F5_1A_2B_A4/player0 I 15:36:26.6321 2021-06-28 22:36:26.632 [ a] 9 BlueZDeviceManager:Details:=('org.bluez.MediaPlayer1'\, {'Position'\: <uint32 0>}\, @as [])

brett-lynnes commented 3 years ago

This is still an issue on v1.24 of the SDK and an unmodified BlueZ implementation stack on Ubuntu using PortAudio. Basically, if you connect an android phone it takes the ability to process the profile "00001108-0000-1000-8000-00805f9b34fb" to mean that the phone is connected to a device for Call Audio. This causes the microphone input to get attached to the phone (which is not actually streaming microphone data) and wakeword/audio input from the linux system microphones no longer function. If I go into my Bluetooth menu on the phone and unselect the "Calls" (leaving Audio) it functions as expected. I have solved this previously by implementing my own PairingAgent.cpp with a filter in authorizeService which rejects that profile. I would very much like to remove that hack going forward.

edit: after looking back through the BlueZ code in AVS, it appears that it is adding its profiles to the ones already started by bluetoothd on linux. it appears that my vanilla Ubuntu install puts profile "UUID: Headset (00001108-0000-1000-8000-00805f9b34fb)" in by default. It may be worth disabling default profiles that AVS does not intend to use when acting as the agent (and re-enabling as the agent exits).

brett-lynnes commented 3 years ago

Screenshot_20210628-153122_Settings